Chromium Code Reviews| OLD | NEW |
|---|---|
| 1 // Copyright 2015 The Chromium Authors. All rights reserved. | 1 // Copyright 2015 The Chromium Authors. All rights reserved. |
| 2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
| 3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
| 4 | 4 |
| 5 #include "base/trace_event/trace_log.h" | 5 #include "base/trace_event/trace_log.h" |
| 6 | 6 |
| 7 #include <algorithm> | 7 #include <algorithm> |
| 8 #include <cmath> | 8 #include <cmath> |
| 9 #include <memory> | 9 #include <memory> |
| 10 #include <utility> | 10 #include <utility> |
| 11 | 11 |
| 12 #include "base/base_switches.h" | 12 #include "base/base_switches.h" |
| 13 #include "base/bind.h" | 13 #include "base/bind.h" |
| 14 #include "base/command_line.h" | 14 #include "base/command_line.h" |
| 15 #include "base/debug/leak_annotations.h" | 15 #include "base/debug/leak_annotations.h" |
| 16 #include "base/lazy_instance.h" | |
| 17 #include "base/location.h" | 16 #include "base/location.h" |
| 18 #include "base/macros.h" | 17 #include "base/macros.h" |
| 19 #include "base/memory/ptr_util.h" | 18 #include "base/memory/ptr_util.h" |
| 20 #include "base/memory/ref_counted_memory.h" | 19 #include "base/memory/ref_counted_memory.h" |
| 21 #include "base/memory/singleton.h" | 20 #include "base/memory/singleton.h" |
| 22 #include "base/message_loop/message_loop.h" | 21 #include "base/message_loop/message_loop.h" |
| 23 #include "base/process/process_metrics.h" | 22 #include "base/process/process_metrics.h" |
| 24 #include "base/stl_util.h" | 23 #include "base/stl_util.h" |
| 25 #include "base/strings/string_split.h" | 24 #include "base/strings/string_split.h" |
| 26 #include "base/strings/string_tokenizer.h" | 25 #include "base/strings/string_tokenizer.h" |
| (...skipping 55 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 82 | 81 |
| 83 // ECHO_TO_CONSOLE needs a small buffer to hold the unfinished COMPLETE events. | 82 // ECHO_TO_CONSOLE needs a small buffer to hold the unfinished COMPLETE events. |
| 84 const size_t kEchoToConsoleTraceEventBufferChunks = 256; | 83 const size_t kEchoToConsoleTraceEventBufferChunks = 256; |
| 85 | 84 |
| 86 const size_t kTraceEventBufferSizeInBytes = 100 * 1024; | 85 const size_t kTraceEventBufferSizeInBytes = 100 * 1024; |
| 87 const int kThreadFlushTimeoutMs = 3000; | 86 const int kThreadFlushTimeoutMs = 3000; |
| 88 | 87 |
| 89 #define MAX_TRACE_EVENT_FILTERS 32 | 88 #define MAX_TRACE_EVENT_FILTERS 32 |
| 90 | 89 |
| 91 // List of TraceEventFilter objects from the most recent tracing session. | 90 // List of TraceEventFilter objects from the most recent tracing session. |
| 92 base::LazyInstance<std::vector<std::unique_ptr<TraceEventFilter>>>::Leaky | 91 std::vector<std::unique_ptr<TraceEventFilter>>& GetCategoryGroupFilters() { |
| 93 g_category_group_filters = LAZY_INSTANCE_INITIALIZER; | 92 static auto filters = new std::vector<std::unique_ptr<TraceEventFilter>>(); |
|
Primiano Tucci (use gerrit)
2017/02/07 16:20:36
Nice, this one seems to have caused a 5% improveme
| |
| 94 | 93 return *filters; |
| 95 // The name of the current thread. This is used to decide if the current | 94 } |
| 96 // thread name has changed. We combine all the seen thread names into the | |
| 97 // output name for the thread. | |
| 98 LazyInstance<ThreadLocalPointer<const char>>::Leaky g_current_thread_name = | |
| 99 LAZY_INSTANCE_INITIALIZER; | |
| 100 | 95 |
| 101 ThreadTicks ThreadNow() { | 96 ThreadTicks ThreadNow() { |
| 102 return ThreadTicks::IsSupported() ? ThreadTicks::Now() : ThreadTicks(); | 97 return ThreadTicks::IsSupported() ? ThreadTicks::Now() : ThreadTicks(); |
| 103 } | 98 } |
| 104 | 99 |
| 105 template <typename T> | 100 template <typename T> |
| 106 void InitializeMetadataEvent(TraceEvent* trace_event, | 101 void InitializeMetadataEvent(TraceEvent* trace_event, |
| 107 int thread_id, | 102 int thread_id, |
| 108 const char* metadata_name, | 103 const char* metadata_name, |
| 109 const char* arg_name, | 104 const char* arg_name, |
| (...skipping 52 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 162 handle->event_index = static_cast<uint16_t>(event_index); | 157 handle->event_index = static_cast<uint16_t>(event_index); |
| 163 } | 158 } |
| 164 | 159 |
| 165 template <typename Function> | 160 template <typename Function> |
| 166 void ForEachCategoryFilter(const unsigned char* category_group_enabled, | 161 void ForEachCategoryFilter(const unsigned char* category_group_enabled, |
| 167 Function filter_fn) { | 162 Function filter_fn) { |
| 168 const TraceCategory* category = | 163 const TraceCategory* category = |
| 169 CategoryRegistry::GetCategoryByStatePtr(category_group_enabled); | 164 CategoryRegistry::GetCategoryByStatePtr(category_group_enabled); |
| 170 uint32_t filter_bitmap = category->enabled_filters(); | 165 uint32_t filter_bitmap = category->enabled_filters(); |
| 171 for (int index = 0; filter_bitmap != 0; filter_bitmap >>= 1, index++) { | 166 for (int index = 0; filter_bitmap != 0; filter_bitmap >>= 1, index++) { |
| 172 if (filter_bitmap & 1 && g_category_group_filters.Get()[index]) | 167 if (filter_bitmap & 1 && GetCategoryGroupFilters()[index]) |
| 173 filter_fn(g_category_group_filters.Get()[index].get()); | 168 filter_fn(GetCategoryGroupFilters()[index].get()); |
| 174 } | 169 } |
| 175 } | 170 } |
| 176 | 171 |
| 177 } // namespace | 172 } // namespace |
| 178 | 173 |
| 179 // A helper class that allows the lock to be acquired in the middle of the scope | 174 // A helper class that allows the lock to be acquired in the middle of the scope |
| 180 // and unlocks at the end of scope if locked. | 175 // and unlocks at the end of scope if locked. |
| 181 class TraceLog::OptionalAutoLock { | 176 class TraceLog::OptionalAutoLock { |
| 182 public: | 177 public: |
| 183 explicit OptionalAutoLock(Lock* lock) : lock_(lock), locked_(false) {} | 178 explicit OptionalAutoLock(Lock* lock) : lock_(lock), locked_(false) {} |
| (...skipping 282 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 466 category->name())) { | 461 category->name())) { |
| 467 state_flags |= TraceCategory::ENABLED_FOR_ETW_EXPORT; | 462 state_flags |= TraceCategory::ENABLED_FOR_ETW_EXPORT; |
| 468 } | 463 } |
| 469 #endif | 464 #endif |
| 470 | 465 |
| 471 uint32_t enabled_filters_bitmap = 0; | 466 uint32_t enabled_filters_bitmap = 0; |
| 472 int index = 0; | 467 int index = 0; |
| 473 for (const auto& event_filter : enabled_event_filters_) { | 468 for (const auto& event_filter : enabled_event_filters_) { |
| 474 if (event_filter.IsCategoryGroupEnabled(category->name())) { | 469 if (event_filter.IsCategoryGroupEnabled(category->name())) { |
| 475 state_flags |= TraceCategory::ENABLED_FOR_FILTERING; | 470 state_flags |= TraceCategory::ENABLED_FOR_FILTERING; |
| 476 DCHECK(g_category_group_filters.Get()[index]); | 471 DCHECK(GetCategoryGroupFilters()[index]); |
| 477 enabled_filters_bitmap |= 1 << index; | 472 enabled_filters_bitmap |= 1 << index; |
| 478 } | 473 } |
| 479 if (index++ >= MAX_TRACE_EVENT_FILTERS) { | 474 if (index++ >= MAX_TRACE_EVENT_FILTERS) { |
| 480 NOTREACHED(); | 475 NOTREACHED(); |
| 481 break; | 476 break; |
| 482 } | 477 } |
| 483 } | 478 } |
| 484 category->set_enabled_filters(enabled_filters_bitmap); | 479 category->set_enabled_filters(enabled_filters_bitmap); |
| 485 category->set_state(state_flags); | 480 category->set_state(state_flags); |
| 486 } | 481 } |
| 487 | 482 |
| 488 void TraceLog::UpdateCategoryRegistry() { | 483 void TraceLog::UpdateCategoryRegistry() { |
| 489 lock_.AssertAcquired(); | 484 lock_.AssertAcquired(); |
| 490 CreateFiltersForTraceConfig(); | 485 CreateFiltersForTraceConfig(); |
| 491 for (TraceCategory& category : CategoryRegistry::GetAllCategories()) { | 486 for (TraceCategory& category : CategoryRegistry::GetAllCategories()) { |
| 492 UpdateCategoryState(&category); | 487 UpdateCategoryState(&category); |
| 493 } | 488 } |
| 494 } | 489 } |
| 495 | 490 |
| 496 void TraceLog::CreateFiltersForTraceConfig() { | 491 void TraceLog::CreateFiltersForTraceConfig() { |
| 497 if (!(enabled_modes_ & FILTERING_MODE)) | 492 if (!(enabled_modes_ & FILTERING_MODE)) |
| 498 return; | 493 return; |
| 499 | 494 |
| 500 // Filters were already added and tracing could be enabled. Filters list | 495 // Filters were already added and tracing could be enabled. Filters list |
| 501 // cannot be changed when trace events are using them. | 496 // cannot be changed when trace events are using them. |
| 502 if (g_category_group_filters.Get().size()) | 497 if (GetCategoryGroupFilters().size()) |
| 503 return; | 498 return; |
| 504 | 499 |
| 505 for (auto& filter_config : enabled_event_filters_) { | 500 for (auto& filter_config : enabled_event_filters_) { |
| 506 if (g_category_group_filters.Get().size() >= MAX_TRACE_EVENT_FILTERS) { | 501 if (GetCategoryGroupFilters().size() >= MAX_TRACE_EVENT_FILTERS) { |
| 507 NOTREACHED() | 502 NOTREACHED() |
| 508 << "Too many trace event filters installed in the current session"; | 503 << "Too many trace event filters installed in the current session"; |
| 509 break; | 504 break; |
| 510 } | 505 } |
| 511 | 506 |
| 512 std::unique_ptr<TraceEventFilter> new_filter; | 507 std::unique_ptr<TraceEventFilter> new_filter; |
| 513 const std::string& predicate_name = filter_config.predicate_name(); | 508 const std::string& predicate_name = filter_config.predicate_name(); |
| 514 if (predicate_name == EventNameFilter::kName) { | 509 if (predicate_name == EventNameFilter::kName) { |
| 515 auto whitelist = MakeUnique<std::unordered_set<std::string>>(); | 510 auto whitelist = MakeUnique<std::unordered_set<std::string>>(); |
| 516 CHECK(filter_config.GetArgAsSet("event_name_whitelist", &*whitelist)); | 511 CHECK(filter_config.GetArgAsSet("event_name_whitelist", &*whitelist)); |
| 517 new_filter = MakeUnique<EventNameFilter>(std::move(whitelist)); | 512 new_filter = MakeUnique<EventNameFilter>(std::move(whitelist)); |
| 518 } else if (predicate_name == HeapProfilerEventFilter::kName) { | 513 } else if (predicate_name == HeapProfilerEventFilter::kName) { |
| 519 new_filter = MakeUnique<HeapProfilerEventFilter>(); | 514 new_filter = MakeUnique<HeapProfilerEventFilter>(); |
| 520 } else { | 515 } else { |
| 521 if (filter_factory_for_testing_) | 516 if (filter_factory_for_testing_) |
| 522 new_filter = filter_factory_for_testing_(predicate_name); | 517 new_filter = filter_factory_for_testing_(predicate_name); |
| 523 CHECK(new_filter) << "Unknown trace filter " << predicate_name; | 518 CHECK(new_filter) << "Unknown trace filter " << predicate_name; |
| 524 } | 519 } |
| 525 g_category_group_filters.Get().push_back(std::move(new_filter)); | 520 GetCategoryGroupFilters().push_back(std::move(new_filter)); |
| 526 } | 521 } |
| 527 } | 522 } |
| 528 | 523 |
| 529 void TraceLog::UpdateSyntheticDelaysFromTraceConfig() { | 524 void TraceLog::UpdateSyntheticDelaysFromTraceConfig() { |
| 530 ResetTraceEventSyntheticDelays(); | 525 ResetTraceEventSyntheticDelays(); |
| 531 const TraceConfig::StringList& delays = | 526 const TraceConfig::StringList& delays = |
| 532 trace_config_.GetSyntheticDelayValues(); | 527 trace_config_.GetSyntheticDelayValues(); |
| 533 TraceConfig::StringList::const_iterator ci; | 528 TraceConfig::StringList::const_iterator ci; |
| 534 for (ci = delays.begin(); ci != delays.end(); ++ci) { | 529 for (ci = delays.begin(); ci != delays.end(); ++ci) { |
| 535 StringTokenizer tokens(*ci, ";"); | 530 StringTokenizer tokens(*ci, ";"); |
| (...skipping 46 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 582 // TODO(ssid): Change to NOTREACHED after fixing crbug.com/625170. | 577 // TODO(ssid): Change to NOTREACHED after fixing crbug.com/625170. |
| 583 DLOG(ERROR) | 578 DLOG(ERROR) |
| 584 << "Cannot manipulate TraceLog::Enabled state from an observer."; | 579 << "Cannot manipulate TraceLog::Enabled state from an observer."; |
| 585 return; | 580 return; |
| 586 } | 581 } |
| 587 | 582 |
| 588 // Clear all filters from previous tracing session. These filters are not | 583 // Clear all filters from previous tracing session. These filters are not |
| 589 // cleared at the end of tracing because some threads which hit trace event | 584 // cleared at the end of tracing because some threads which hit trace event |
| 590 // when disabling, could try to use the filters. | 585 // when disabling, could try to use the filters. |
| 591 if (!enabled_modes_) | 586 if (!enabled_modes_) |
| 592 g_category_group_filters.Get().clear(); | 587 GetCategoryGroupFilters().clear(); |
| 593 | 588 |
| 594 // Update trace config for recording. | 589 // Update trace config for recording. |
| 595 const bool already_recording = enabled_modes_ & RECORDING_MODE; | 590 const bool already_recording = enabled_modes_ & RECORDING_MODE; |
| 596 if (modes_to_enable & RECORDING_MODE) { | 591 if (modes_to_enable & RECORDING_MODE) { |
| 597 if (already_recording) { | 592 if (already_recording) { |
| 598 // TODO(ssid): Stop suporting enabling of RECODING_MODE when already | 593 // TODO(ssid): Stop suporting enabling of RECODING_MODE when already |
| 599 // enabled crbug.com/625170. | 594 // enabled crbug.com/625170. |
| 600 DCHECK_EQ(new_options, old_options) << "Attempting to re-enable " | 595 DCHECK_EQ(new_options, old_options) << "Attempting to re-enable " |
| 601 "tracing with a different set " | 596 "tracing with a different set " |
| 602 "of options."; | 597 "of options."; |
| (...skipping 610 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 1213 | 1208 |
| 1214 // Check and update the current thread name only if the event is for the | 1209 // Check and update the current thread name only if the event is for the |
| 1215 // current thread to avoid locks in most cases. | 1210 // current thread to avoid locks in most cases. |
| 1216 if (thread_id == static_cast<int>(PlatformThread::CurrentId())) { | 1211 if (thread_id == static_cast<int>(PlatformThread::CurrentId())) { |
| 1217 const char* new_name = | 1212 const char* new_name = |
| 1218 ThreadIdNameManager::GetInstance()->GetName(thread_id); | 1213 ThreadIdNameManager::GetInstance()->GetName(thread_id); |
| 1219 // Check if the thread name has been set or changed since the previous | 1214 // Check if the thread name has been set or changed since the previous |
| 1220 // call (if any), but don't bother if the new name is empty. Note this will | 1215 // call (if any), but don't bother if the new name is empty. Note this will |
| 1221 // not detect a thread name change within the same char* buffer address: we | 1216 // not detect a thread name change within the same char* buffer address: we |
| 1222 // favor common case performance over corner case correctness. | 1217 // favor common case performance over corner case correctness. |
| 1223 if (new_name != g_current_thread_name.Get().Get() && new_name && | 1218 static auto current_thread_name = new ThreadLocalPointer<const char>(); |
| 1224 *new_name) { | 1219 if (new_name != current_thread_name->Get() && new_name && *new_name) { |
| 1225 g_current_thread_name.Get().Set(new_name); | 1220 current_thread_name->Set(new_name); |
| 1226 | 1221 |
| 1227 AutoLock thread_info_lock(thread_info_lock_); | 1222 AutoLock thread_info_lock(thread_info_lock_); |
| 1228 | 1223 |
| 1229 hash_map<int, std::string>::iterator existing_name = | 1224 hash_map<int, std::string>::iterator existing_name = |
| 1230 thread_names_.find(thread_id); | 1225 thread_names_.find(thread_id); |
| 1231 if (existing_name == thread_names_.end()) { | 1226 if (existing_name == thread_names_.end()) { |
| 1232 // This is a new thread id, and a new name. | 1227 // This is a new thread id, and a new name. |
| 1233 thread_names_[thread_id] = new_name; | 1228 thread_names_[thread_id] = new_name; |
| 1234 } else { | 1229 } else { |
| 1235 // This is a thread id that we've seen before, but potentially with a | 1230 // This is a thread id that we've seen before, but potentially with a |
| (...skipping 486 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 1722 } | 1717 } |
| 1723 | 1718 |
| 1724 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { | 1719 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { |
| 1725 if (*category_group_enabled_) { | 1720 if (*category_group_enabled_) { |
| 1726 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, name_, | 1721 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, name_, |
| 1727 event_handle_); | 1722 event_handle_); |
| 1728 } | 1723 } |
| 1729 } | 1724 } |
| 1730 | 1725 |
| 1731 } // namespace trace_event_internal | 1726 } // namespace trace_event_internal |
| OLD | NEW |