diff options
author | jbates@chromium.org <jbates@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2012-01-13 03:12:44 +0000 |
---|---|---|
committer | jbates@chromium.org <jbates@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2012-01-13 03:12:44 +0000 |
commit | 761550737a7bd68856f2a28fe389b23d135ddcc2 (patch) | |
tree | 2ee375731da5c2cb4681a04c096f3b34a0f51146 /base | |
parent | 19f9f17b1b18771f39d36087bf24bec8cd3bf98c (diff) | |
download | chromium_src-761550737a7bd68856f2a28fe389b23d135ddcc2.zip chromium_src-761550737a7bd68856f2a28fe389b23d135ddcc2.tar.gz chromium_src-761550737a7bd68856f2a28fe389b23d135ddcc2.tar.bz2 |
Allow tracing in third_party libraries
This is step 1 -- refactor the code to allow us to split up trace_event.h into trace_event.h and trace_event_export.h/cc.
Step 2 is to cut out trace_event_export.h/cc.
The _export.h/cc will be laid out so they can be copied to other third_party libraries and then tweaked to call through to chromium's internal tracing API via platform APIs or function pointers.
To make these APIs easily exportable, this change primarily aims to eliminate the custom objects (ie: TraceValue) and types that will cause problems when defined in multiple libraries. The macros and internal namespace are destined for trace_event_export.h/cc in a future CL.
BUG=109779
Review URL: http://codereview.chromium.org/9155024
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@117598 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'base')
-rw-r--r-- | base/debug/trace_event.cc | 373 | ||||
-rw-r--r-- | base/debug/trace_event.h | 715 | ||||
-rw-r--r-- | base/debug/trace_event_unittest.cc | 118 | ||||
-rw-r--r-- | base/debug/trace_event_win.cc | 6 | ||||
-rw-r--r-- | base/debug/trace_event_win.h | 10 | ||||
-rw-r--r-- | base/test/trace_event_analyzer.cc | 156 | ||||
-rw-r--r-- | base/test/trace_event_analyzer.h | 13 |
7 files changed, 819 insertions, 572 deletions
diff --git a/base/debug/trace_event.cc b/base/debug/trace_event.cc index 969af1c..c554769 100644 --- a/base/debug/trace_event.cc +++ b/base/debug/trace_event.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2011 The Chromium Authors. All rights reserved. +// Copyright (c) 2012 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -45,27 +45,21 @@ const size_t kTraceEventBatchSize = 1000; namespace { -// Specify these values when the corresponding argument of AddTraceEvent is not -// used. -static const char* kNoArgName = NULL; -static const int kNoArgValue = 0; -static const int kNoThreshholdBeginId = -1; -static const int64 kNoThresholdValue = 0; -static const int kNoEventId = 0; - -TraceCategory g_categories[TRACE_EVENT_MAX_CATEGORIES] = { - { "tracing already shutdown", false }, - { "tracing categories exhausted; must increase TRACE_EVENT_MAX_CATEGORIES", - false }, - { "__metadata", - false } +// Parallel arrays g_categories and g_category_enabled are separate so that +// a pointer to a member of g_category_enabled can be easily converted to an +// index into g_categories. This allows macros to deal only with char enabled +// pointers from g_category_enabled, and we can convert internally to determine +// the category name from the char enabled pointer. +const char* g_categories[TRACE_EVENT_MAX_CATEGORIES] = { + "tracing already shutdown", + "tracing categories exhausted; must increase TRACE_EVENT_MAX_CATEGORIES", + "__metadata", }; -const TraceCategory* const g_category_already_shutdown = - &g_categories[0]; -const TraceCategory* const g_category_categories_exhausted = - &g_categories[1]; -const TraceCategory* const g_category_metadata = - &g_categories[2]; +// The enabled flag is char instead of bool so that the API can be used from C. +unsigned char g_category_enabled[TRACE_EVENT_MAX_CATEGORIES] = { 0 }; +const int g_category_already_shutdown = 0; +const int g_category_categories_exhausted = 1; +const int g_category_metadata = 2; int g_category_index = 3; // skip initial 3 categories // The most-recently captured name of the current thread @@ -73,41 +67,35 @@ LazyInstance<ThreadLocalPointer<const char>, LeakyLazyInstanceTraits<ThreadLocalPointer<const char> > > g_current_thread_name = LAZY_INSTANCE_INITIALIZER; -} // namespace - -//////////////////////////////////////////////////////////////////////////////// -// -// TraceValue -// -//////////////////////////////////////////////////////////////////////////////// - -void TraceValue::AppendAsJSON(std::string* out) const { +void AppendValueAsJSON(unsigned char type, + TraceEvent::TraceValue value, + std::string* out) { std::string::size_type start_pos; - switch (type_) { - case TRACE_TYPE_BOOL: - *out += as_bool() ? "true" : "false"; + switch (type) { + case TRACE_VALUE_TYPE_BOOL: + *out += value.as_bool ? "true" : "false"; break; - case TRACE_TYPE_UINT: - StringAppendF(out, "%" PRIu64, as_uint()); + case TRACE_VALUE_TYPE_UINT: + StringAppendF(out, "%" PRIu64, static_cast<uint64>(value.as_uint)); break; - case TRACE_TYPE_INT: - StringAppendF(out, "%" PRId64, as_int()); + case TRACE_VALUE_TYPE_INT: + StringAppendF(out, "%" PRId64, static_cast<int64>(value.as_int)); break; - case TRACE_TYPE_DOUBLE: - StringAppendF(out, "%f", as_double()); + case TRACE_VALUE_TYPE_DOUBLE: + StringAppendF(out, "%f", value.as_double); break; - case TRACE_TYPE_POINTER: + case TRACE_VALUE_TYPE_POINTER: // JSON only supports double and int numbers. // So as not to lose bits from a 64-bit pointer, output as a hex string. StringAppendF(out, "\"%" PRIx64 "\"", static_cast<uint64>( reinterpret_cast<intptr_t>( - as_pointer()))); + value.as_pointer))); break; - case TRACE_TYPE_STRING: - case TRACE_TYPE_STATIC_STRING: + case TRACE_VALUE_TYPE_STRING: + case TRACE_VALUE_TYPE_COPY_STRING: *out += "\""; start_pos = out->size(); - *out += as_string() ? as_string() : "NULL"; + *out += value.as_string ? value.as_string : "NULL"; // insert backslash before special characters for proper json format. while ((start_pos = out->find_first_of("\\\"", start_pos)) != std::string::npos) { @@ -123,16 +111,7 @@ void TraceValue::AppendAsJSON(std::string* out) const { } } -//////////////////////////////////////////////////////////////////////////////// -// -// TraceID -// -//////////////////////////////////////////////////////////////////////////////// - -TraceID::TraceID(void* rhs) { - data_ = base::debug::TraceLog::GetInstance()->GetIntraProcessID( - static_cast<uint64>(reinterpret_cast<uintptr_t>(rhs))); -} +} // namespace //////////////////////////////////////////////////////////////////////////////// // @@ -161,7 +140,7 @@ void CopyTraceEventParameter(char** buffer, TraceEvent::TraceEvent() : id_(0u), - category_(NULL), + category_enabled_(NULL), name_(NULL), thread_id_(0), phase_(TRACE_EVENT_PHASE_BEGIN), @@ -172,43 +151,54 @@ TraceEvent::TraceEvent() TraceEvent::TraceEvent(int thread_id, TimeTicks timestamp, - TraceEventPhase phase, - const TraceCategory* category, + char phase, + const unsigned char* category_enabled, const char* name, - TraceID id, - const char* arg1_name, const TraceValue& arg1_val, - const char* arg2_name, const TraceValue& arg2_val, - TraceEventFlags flags) + unsigned long long id, + int num_args, + const char** arg_names, + const unsigned char* arg_types, + const unsigned long long* arg_values, + unsigned char flags) : timestamp_(timestamp), id_(id), - category_(category), + category_enabled_(category_enabled), name_(name), thread_id_(thread_id), phase_(phase), flags_(flags) { - COMPILE_ASSERT(kTraceMaxNumArgs == 2, TraceEvent_arg_count_out_of_sync); - arg_names_[0] = arg1_name; - arg_names_[1] = arg2_name; - arg_values_[0] = arg1_val; - arg_values_[1] = arg2_val; + // Clamp num_args since it may have been set by a third_party library. + num_args = (num_args > kTraceMaxNumArgs) ? kTraceMaxNumArgs : num_args; + int i = 0; + for (; i < num_args; ++i) { + arg_names_[i] = arg_names[i]; + arg_values_[i].as_uint = arg_values[i]; + arg_types_[i] = arg_types[i]; + } + for (; i < kTraceMaxNumArgs; ++i) { + arg_names_[i] = NULL; + arg_values_[i].as_uint = 0u; + arg_types_[i] = TRACE_VALUE_TYPE_UINT; + } bool copy = !!(flags & TRACE_EVENT_FLAG_COPY); size_t alloc_size = 0; if (copy) { alloc_size += GetAllocLength(name); - alloc_size += GetAllocLength(arg1_name); - alloc_size += GetAllocLength(arg2_name); + for (i = 0; i < num_args; ++i) { + alloc_size += GetAllocLength(arg_names_[i]); + if (arg_types_[i] == TRACE_VALUE_TYPE_STRING) + arg_types_[i] = TRACE_VALUE_TYPE_COPY_STRING; + } } - bool arg1_is_copy = (arg1_val.type() == TraceValue::TRACE_TYPE_STRING); - bool arg2_is_copy = (arg2_val.type() == TraceValue::TRACE_TYPE_STRING); - - // We only take a copy of arg_vals if they are of type string (not static - // string), regardless of the |copy| flag. - if (arg1_is_copy) - alloc_size += GetAllocLength(arg1_val.as_string()); - if (arg2_is_copy) - alloc_size += GetAllocLength(arg2_val.as_string()); + bool arg_is_copy[kTraceMaxNumArgs]; + for (i = 0; i < num_args; ++i) { + // We only take a copy of arg_vals if they are of type COPY_STRING. + arg_is_copy[i] = (arg_types_[i] == TRACE_VALUE_TYPE_COPY_STRING); + if (arg_is_copy[i]) + alloc_size += GetAllocLength(arg_values_[i].as_string); + } if (alloc_size) { parameter_copy_storage_ = new base::RefCountedString; @@ -217,13 +207,13 @@ TraceEvent::TraceEvent(int thread_id, const char* end = ptr + alloc_size; if (copy) { CopyTraceEventParameter(&ptr, &name_, end); - CopyTraceEventParameter(&ptr, &arg_names_[0], end); - CopyTraceEventParameter(&ptr, &arg_names_[1], end); + for (i = 0; i < num_args; ++i) + CopyTraceEventParameter(&ptr, &arg_names_[i], end); + } + for (i = 0; i < num_args; ++i) { + if (arg_is_copy[i]) + CopyTraceEventParameter(&ptr, &arg_values_[i].as_string, end); } - if (arg1_is_copy) - CopyTraceEventParameter(&ptr, arg_values_[0].as_assignable_string(), end); - if (arg2_is_copy) - CopyTraceEventParameter(&ptr, arg_values_[1].as_assignable_string(), end); DCHECK_EQ(end, ptr) << "Overrun by " << ptr - end; } } @@ -243,7 +233,6 @@ void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events, } void TraceEvent::AppendAsJSON(std::string* out) const { - const char phase_char = GetPhaseChar(phase_); int64 time_int64 = timestamp_.ToInternalValue(); int process_id = TraceLog::GetInstance()->process_id(); // Category name checked at category creation time. @@ -251,28 +240,28 @@ void TraceEvent::AppendAsJSON(std::string* out) const { StringAppendF(out, "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 "," "\"ph\":\"%c\",\"name\":\"%s\",\"args\":{", - category_->name, + TraceLog::GetCategoryName(category_enabled_), process_id, thread_id_, time_int64, - phase_char, + phase_, name_); // Output argument names and values, stop at first NULL argument name. - for (size_t i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { + for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { if (i > 0) *out += ","; *out += "\""; *out += arg_names_[i]; *out += "\":"; - arg_values_[i].AppendAsJSON(out); + AppendValueAsJSON(arg_types_[i], arg_values_[i], out); } *out += "}"; // If id_ is set, print it out as a hex string so we don't loose any // bits (it might be a 64-bit pointer). if (flags_ & TRACE_EVENT_FLAG_HAS_ID) - StringAppendF(out, ",\"id\":\"%" PRIx64 "\"", id_.data()); + StringAppendF(out, ",\"id\":\"%" PRIx64 "\"", static_cast<uint64>(id_)); *out += "}"; } @@ -338,47 +327,62 @@ TraceLog::TraceLog() TraceLog::~TraceLog() { } -const TraceCategory* TraceLog::GetCategory(const char* name) { +const unsigned char* TraceLog::GetCategoryEnabled(const char* name) { TraceLog* tracelog = GetInstance(); - if (!tracelog){ - DCHECK(!g_category_already_shutdown->enabled); - return g_category_already_shutdown; + if (!tracelog) { + DCHECK(!g_category_enabled[g_category_already_shutdown]); + return &g_category_enabled[g_category_already_shutdown]; } - return tracelog->GetCategoryInternal(name); + return tracelog->GetCategoryEnabledInternal(name); +} + +const char* TraceLog::GetCategoryName(const unsigned char* category_enabled) { + // Calculate the index of the category by finding category_enabled in + // g_category_enabled array. + uintptr_t category_begin = reinterpret_cast<uintptr_t>(g_category_enabled); + uintptr_t category_ptr = reinterpret_cast<uintptr_t>(category_enabled); + DCHECK(category_ptr >= category_begin && + category_ptr < reinterpret_cast<uintptr_t>(g_category_enabled + + TRACE_EVENT_MAX_CATEGORIES)) << + "out of bounds category pointer"; + uintptr_t category_index = + (category_ptr - category_begin) / sizeof(g_category_enabled[0]); + return g_categories[category_index]; } static void EnableMatchingCategory(int category_index, const std::vector<std::string>& patterns, - bool is_included) { + unsigned char is_included) { std::vector<std::string>::const_iterator ci = patterns.begin(); bool is_match = false; for (; ci != patterns.end(); ++ci) { - is_match = MatchPattern(g_categories[category_index].name, ci->c_str()); + is_match = MatchPattern(g_categories[category_index], ci->c_str()); if (is_match) break; } - ANNOTATE_BENIGN_RACE(&g_categories[category_index].enabled, + ANNOTATE_BENIGN_RACE(&g_category_enabled[category_index], "trace_event category enabled"); - g_categories[category_index].enabled = is_match ? is_included : !is_included; + g_category_enabled[category_index] = is_match ? + is_included : (is_included ^ 1); } // Enable/disable each category based on the category filters in |patterns|. // If the category name matches one of the patterns, its enabled status is set // to |is_included|. Otherwise its enabled status is set to !|is_included|. static void EnableMatchingCategories(const std::vector<std::string>& patterns, - bool is_included) { + unsigned char is_included) { for (int i = 0; i < g_category_index; i++) EnableMatchingCategory(i, patterns, is_included); } -const TraceCategory* TraceLog::GetCategoryInternal(const char* name) { +const unsigned char* TraceLog::GetCategoryEnabledInternal(const char* name) { AutoLock lock(lock_); DCHECK(!strchr(name, '"')) << "Category names may not contain double quote"; // Search for pre-existing category matching this name for (int i = 0; i < g_category_index; i++) { - if (strcmp(g_categories[i].name, name) == 0) - return &g_categories[i]; + if (strcmp(g_categories[i], name) == 0) + return &g_category_enabled[i]; } // Create a new category @@ -386,30 +390,30 @@ const TraceCategory* TraceLog::GetCategoryInternal(const char* name) { "must increase TRACE_EVENT_MAX_CATEGORIES"; if (g_category_index < TRACE_EVENT_MAX_CATEGORIES) { int new_index = g_category_index++; - g_categories[new_index].name = name; - DCHECK(!g_categories[new_index].enabled); + g_categories[new_index] = name; + DCHECK(!g_category_enabled[new_index]); if (enabled_) { // Note that if both included and excluded_categories are empty, the else // clause below excludes nothing, thereby enabling this category. if (!included_categories_.empty()) - EnableMatchingCategory(new_index, included_categories_, true); + EnableMatchingCategory(new_index, included_categories_, 1); else - EnableMatchingCategory(new_index, excluded_categories_, false); + EnableMatchingCategory(new_index, excluded_categories_, 0); } else { - ANNOTATE_BENIGN_RACE(&g_categories[new_index].enabled, + ANNOTATE_BENIGN_RACE(&g_category_enabled[new_index], "trace_event category enabled"); - g_categories[new_index].enabled = false; + g_category_enabled[new_index] = 0; } - return &g_categories[new_index]; + return &g_category_enabled[new_index]; } else { - return g_category_categories_exhausted; + return &g_category_enabled[g_category_categories_exhausted]; } } void TraceLog::GetKnownCategories(std::vector<std::string>* categories) { AutoLock lock(lock_); for (int i = 0; i < g_category_index; i++) - categories->push_back(g_categories[i].name); + categories->push_back(g_categories[i]); } void TraceLog::SetEnabled(const std::vector<std::string>& included_categories, @@ -424,9 +428,9 @@ void TraceLog::SetEnabled(const std::vector<std::string>& included_categories, // Note that if both included and excluded_categories are empty, the else // clause below excludes nothing, thereby enabling all categories. if (!included_categories_.empty()) - EnableMatchingCategories(included_categories_, true); + EnableMatchingCategories(included_categories_, 1); else - EnableMatchingCategories(excluded_categories_, false); + EnableMatchingCategories(excluded_categories_, 0); } void TraceLog::SetEnabled(const std::string& categories) { @@ -470,7 +474,7 @@ void TraceLog::SetDisabled() { included_categories_.clear(); excluded_categories_.clear(); for (int i = 0; i < g_category_index; i++) - g_categories[i].enabled = false; + g_category_enabled[i] = 0; AddThreadNameMetadataEvents(); AddClockSyncMetadataEvents(); } // release lock @@ -523,22 +527,24 @@ void TraceLog::Flush() { } } -int TraceLog::AddTraceEvent(TraceEventPhase phase, - const TraceCategory* category, +int TraceLog::AddTraceEvent(char phase, + const unsigned char* category_enabled, const char* name, - TraceID id, - const char* arg1_name, TraceValue arg1_val, - const char* arg2_name, TraceValue arg2_val, + unsigned long long id, + int num_args, + const char** arg_names, + const unsigned char* arg_types, + const unsigned long long* arg_values, int threshold_begin_id, - int64 threshold, - TraceEventFlags flags) { + long long threshold, + unsigned char flags) { DCHECK(name); TimeTicks now = TimeTicks::HighResNow(); BufferFullCallback buffer_full_callback_copy; int ret_begin_id = -1; { AutoLock lock(lock_); - if (!category->enabled) + if (!*category_enabled) return -1; if (logged_events_.size() >= kTraceEventBufferSize) return -1; @@ -592,9 +598,8 @@ int TraceLog::AddTraceEvent(TraceEventPhase phase, ret_begin_id = static_cast<int>(logged_events_.size()); logged_events_.push_back( TraceEvent(thread_id, - now, phase, category, name, id, - arg1_name, arg1_val, - arg2_name, arg2_val, + now, phase, category_enabled, name, id, + num_args, arg_names, arg_types, arg_values, flags)); if (logged_events_.size() == kTraceEventBufferSize) { @@ -608,19 +613,18 @@ int TraceLog::AddTraceEvent(TraceEventPhase phase, return ret_begin_id; } -void TraceLog::AddTraceEventEtw(TraceEventPhase phase, +void TraceLog::AddTraceEventEtw(char phase, const char* name, const void* id, const char* extra) { #if defined(OS_WIN) TraceEventETWProvider::Trace(name, phase, id, extra); #endif - INTERNAL_TRACE_EVENT_ADD(phase, - "ETW Trace Event", name, "id", id, "extra", TRACE_STR_COPY(extra), - TRACE_EVENT_FLAG_COPY); + INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name, + TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra); } -void TraceLog::AddTraceEventEtw(TraceEventPhase phase, +void TraceLog::AddTraceEventEtw(char phase, const char* name, const void* id, const std::string& extra) @@ -628,25 +632,35 @@ void TraceLog::AddTraceEventEtw(TraceEventPhase phase, #if defined(OS_WIN) TraceEventETWProvider::Trace(name, phase, id, extra); #endif - INTERNAL_TRACE_EVENT_ADD(phase, - "ETW Trace Event", name, "id", id, "extra", extra, - TRACE_EVENT_FLAG_COPY); -} - -int TraceLog::AddCounterEvent(const TraceCategory* category, - const char* name, - TraceID id, - const char* value1_name, int32 value1_val, - const char* value2_name, int32 value2_val, - TraceEventFlags flags) { - return AddTraceEvent(TRACE_EVENT_PHASE_COUNTER, - category, - name, - id, - value1_name, value1_val, - value2_name, value2_val, - -1, 0, - flags); + INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name, + TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra); +} + +void TraceLog::AddCounterEvent(const unsigned char* category_enabled, + const char* name, + unsigned long long id, + const char* value1_name, int value1_val, + const char* value2_name, int value2_val, + unsigned char flags) { + int num_args = value2_name ? 2 : 1; + const char* arg_names[2] = {value1_name, value2_name}; + unsigned char arg_types[2]; + unsigned long long arg_values[2]; + trace_event_internal::SetTraceValue(value1_val, &arg_types[0], + &arg_values[0]); + trace_event_internal::SetTraceValue(value2_val, &arg_types[1], + &arg_values[1]); + AddTraceEvent(TRACE_EVENT_PHASE_COUNTER, + category_enabled, + name, + id, + num_args, + arg_names, + arg_types, + arg_values, + trace_event_internal::kNoThreshholdBeginId, + trace_event_internal::kNoThresholdValue, + flags); } void TraceLog::AddClockSyncMetadataEvents() { @@ -693,14 +707,20 @@ void TraceLog::AddThreadNameMetadataEvents() { for(base::hash_map<int, std::string>::iterator it = thread_names_.begin(); it != thread_names_.end(); it++) { - if (!it->second.empty()) + if (!it->second.empty()) { + int num_args = 1; + const char* arg_name = "name"; + unsigned char arg_type; + unsigned long long arg_value; + trace_event_internal::SetTraceValue(it->second, &arg_type, &arg_value); logged_events_.push_back( TraceEvent(it->first, TimeTicks(), TRACE_EVENT_PHASE_METADATA, - g_category_metadata, "thread_name", 0, - "name", it->second, - NULL, 0, + &g_category_enabled[g_category_metadata], + "thread_name", trace_event_internal::kNoEventId, + num_args, &arg_name, &arg_type, &arg_value, TRACE_EVENT_FLAG_NONE)); + } } } @@ -716,38 +736,42 @@ void TraceLog::SetProcessID(int process_id) { process_id_ = process_id; // Create a FNV hash from the process ID for XORing. // See http://isthe.com/chongo/tech/comp/fnv/ for algorithm details. - uint64 offset_basis = 14695981039346656037ull; - uint64 fnv_prime = 1099511628211ull; + unsigned long long offset_basis = 14695981039346656037ull; + unsigned long long fnv_prime = 1099511628211ull; unsigned long long pid = static_cast<unsigned long long>(process_id_); process_id_hash_ = (offset_basis ^ pid) * fnv_prime; } -namespace internal { +} // namespace debug +} // namespace base + +namespace trace_event_internal { -void TraceEndOnScopeClose::Initialize(const TraceCategory* category, +void TraceEndOnScopeClose::Initialize(const unsigned char* category_enabled, const char* name) { - data_.category = category; + data_.category_enabled = category_enabled; data_.name = name; p_data_ = &data_; } void TraceEndOnScopeClose::AddEventIfEnabled() { // Only called when p_data_ is non-null. - if (p_data_->category->enabled) { - base::debug::TraceLog::GetInstance()->AddTraceEvent( + if (*p_data_->category_enabled) { + TRACE_EVENT_API_ADD_TRACE_EVENT( TRACE_EVENT_PHASE_END, - p_data_->category, + p_data_->category_enabled, p_data_->name, kNoEventId, - kNoArgName, kNoArgValue, kNoArgName, kNoArgValue, + kZeroNumArgs, NULL, NULL, NULL, kNoThreshholdBeginId, kNoThresholdValue, TRACE_EVENT_FLAG_NONE); } } -void TraceEndOnScopeCloseThreshold::Initialize(const TraceCategory* category, - const char* name, - int threshold_begin_id, - int64 threshold) { - data_.category = category; +void TraceEndOnScopeCloseThreshold::Initialize( + const unsigned char* category_enabled, + const char* name, + int threshold_begin_id, + long long threshold) { + data_.category_enabled = category_enabled; data_.name = name; data_.threshold_begin_id = threshold_begin_id; data_.threshold = threshold; @@ -756,18 +780,15 @@ void TraceEndOnScopeCloseThreshold::Initialize(const TraceCategory* category, void TraceEndOnScopeCloseThreshold::AddEventIfEnabled() { // Only called when p_data_ is non-null. - if (p_data_->category->enabled) { - base::debug::TraceLog::GetInstance()->AddTraceEvent( + if (*p_data_->category_enabled) { + TRACE_EVENT_API_ADD_TRACE_EVENT( TRACE_EVENT_PHASE_END, - p_data_->category, + p_data_->category_enabled, p_data_->name, kNoEventId, - kNoArgName, kNoArgValue, kNoArgName, kNoArgValue, + kZeroNumArgs, NULL, NULL, NULL, p_data_->threshold_begin_id, p_data_->threshold, TRACE_EVENT_FLAG_NONE); } } -} // namespace internal - -} // namespace debug -} // namespace base +} // namespace trace_event_internal diff --git a/base/debug/trace_event.h b/base/debug/trace_event.h index 444c975..a1fff3e 100644 --- a/base/debug/trace_event.h +++ b/base/debug/trace_event.h @@ -1,4 +1,4 @@ -// Copyright (c) 2011 The Chromium Authors. All rights reserved. +// Copyright (c) 2012 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -126,7 +126,7 @@ // the static variable is safe, as they will be serialized by the lock and // multiple calls will return the same pointer to the category. // -// Then the category.enabled flag is checked. This is a volatile bool, and +// Then the category_enabled flag is checked. This is a unsigned char, and // not intended to be multithread safe. It optimizes access to AddTraceEvent // which is threadsafe internally via TraceLog::lock_. The enabled flag may // cause some threads to incorrectly call or skip calling AddTraceEvent near @@ -160,9 +160,56 @@ #include "base/third_party/dynamic_annotations/dynamic_annotations.h" #include "base/timer.h" +//////////////////////////////////////////////////////////////////////////////// +// TODO(jbates): split this into a separate header. +// This header is designed to be give you trace_event macros without specifying +// how the events actually get collected and stored. If you need to expose trace +// event to some other universe, you can copy-and-paste this file and just +// implement these API macros. + +// unsigned char* +// TRACE_EVENT_API_GET_CATEGORY_ENABLED(const char* category_name) +#define TRACE_EVENT_API_GET_CATEGORY_ENABLED \ + base::debug::TraceLog::GetCategoryEnabled + +// Returns the threshold_begin_id used by TRACE_IF_LONGER_THAN macros. +// int TRACE_EVENT_API_ADD_TRACE_EVENT( +// char phase, +// const unsigned char* category_enabled, +// const char* name, +// unsigned long long id, +// int num_args, +// const char** arg_names, +// const unsigned char* arg_types, +// const unsigned long long* arg_values, +// int threshold_begin_id, +// long long threshold, +// unsigned char flags) +#define TRACE_EVENT_API_ADD_TRACE_EVENT \ + base::debug::TraceLog::GetInstance()->AddTraceEvent + +// void TRACE_EVENT_API_ADD_COUNTER_EVENT( +// const unsigned char* category_enabled, +// const char* name, +// unsigned long long id, +// const char* arg1_name, int arg1_val, +// const char* arg2_name, int arg2_val, +// unsigned char flags) +#define TRACE_EVENT_API_ADD_COUNTER_EVENT \ + base::debug::TraceLog::GetInstance()->AddCounterEvent + +// Mangle |pointer| with a process ID hash so that if |pointer| occurs on more +// than one process, it will not collide in the trace data. +// unsigned long long TRACE_EVENT_API_GET_ID_FROM_POINTER(void* pointer) +#define TRACE_EVENT_API_GET_ID_FROM_POINTER \ + base::debug::TraceLog::GetInstance()->GetInterProcessID + +//////////////////////////////////////////////////////////////////////////////// + // By default, const char* argument values are assumed to have long-lived scope // and will not be copied. Use this macro to force a const char* to be copied. -#define TRACE_STR_COPY(str) base::debug::TraceValue::StringWithCopy(str) +#define TRACE_STR_COPY(str) \ + trace_event_internal::TraceStringWithCopy(str) // Older style trace macros with explicit id and extra data // Only these macros result in publishing data to ETW as currently implemented. @@ -187,12 +234,12 @@ // - category and name strings must have application lifetime (statics or // literals). They may not include " chars. #define TRACE_EVENT0(category, name) \ - TRACE_EVENT1(category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_SCOPED(category, name) #define TRACE_EVENT1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT2(category, name, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_SCOPED(category, name, arg1_name, arg1_val) #define TRACE_EVENT2(category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ - INTERNAL_TRACE_EVENT_ADD_SCOPED( \ - category, name, arg1_name, arg1_val, arg2_name, arg2_val) + INTERNAL_TRACE_EVENT_ADD_SCOPED(category, name, arg1_name, arg1_val, \ + arg2_name, arg2_val) // Same as TRACE_EVENT except that they are not included in official builds. #ifdef OFFICIAL_BUILD @@ -229,25 +276,27 @@ // - category and name strings must have application lifetime (statics or // literals). They may not include " chars. #define TRACE_EVENT_INSTANT0(category, name) \ - TRACE_EVENT_INSTANT1(category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ + category, name, TRACE_EVENT_FLAG_NONE) #define TRACE_EVENT_INSTANT1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ + category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val) #define TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, arg1_name, arg1_val, arg2_name, arg2_val, \ - TRACE_EVENT_FLAG_NONE) + category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val, \ + arg2_name, arg2_val) #define TRACE_EVENT_COPY_INSTANT0(category, name) \ - TRACE_EVENT_COPY_INSTANT1(category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ + category, name, TRACE_EVENT_FLAG_COPY) #define TRACE_EVENT_COPY_INSTANT1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT_COPY_INSTANT2(category, name, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ + category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val) #define TRACE_EVENT_COPY_INSTANT2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, \ - arg1_name, base::debug::TraceValue::ForceCopy(arg1_val), \ - arg2_name, base::debug::TraceValue::ForceCopy(arg2_val), \ - TRACE_EVENT_FLAG_COPY) + category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val, \ + arg2_name, arg2_val) // Records a single BEGIN event called "name" immediately, with 0, 1 or 2 // associated arguments. If the category is not enabled, then this @@ -255,50 +304,54 @@ // - category and name strings must have application lifetime (statics or // literals). They may not include " chars. #define TRACE_EVENT_BEGIN0(category, name) \ - TRACE_EVENT_BEGIN1(category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, \ + category, name, TRACE_EVENT_FLAG_NONE) #define TRACE_EVENT_BEGIN1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT_BEGIN2(category, name, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, \ + category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val) #define TRACE_EVENT_BEGIN2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, \ - category, name, arg1_name, arg1_val, arg2_name, arg2_val, \ - TRACE_EVENT_FLAG_NONE) + category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val, \ + arg2_name, arg2_val) #define TRACE_EVENT_COPY_BEGIN0(category, name) \ - TRACE_EVENT_COPY_BEGIN1(category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, \ + category, name, TRACE_EVENT_FLAG_COPY) #define TRACE_EVENT_COPY_BEGIN1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT_COPY_BEGIN2(category, name, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, \ + category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val) #define TRACE_EVENT_COPY_BEGIN2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, \ - category, name, \ - arg1_name, base::debug::TraceValue::ForceCopy(arg1_val), \ - arg2_name, base::debug::TraceValue::ForceCopy(arg2_val), \ - TRACE_EVENT_FLAG_COPY) + category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val, \ + arg2_name, arg2_val) // Records a single END event for "name" immediately. If the category // is not enabled, then this does nothing. // - category and name strings must have application lifetime (statics or // literals). They may not include " chars. #define TRACE_EVENT_END0(category, name) \ - TRACE_EVENT_END1(category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, \ + category, name, TRACE_EVENT_FLAG_NONE) #define TRACE_EVENT_END1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT_END2(category, name, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, \ + category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val) #define TRACE_EVENT_END2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, \ - category, name, arg1_name, arg1_val, arg2_name, arg2_val, \ - TRACE_EVENT_FLAG_NONE) + category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val, \ + arg2_name, arg2_val) #define TRACE_EVENT_COPY_END0(category, name) \ - TRACE_EVENT_COPY_END1(category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, \ + category, name, TRACE_EVENT_FLAG_COPY) #define TRACE_EVENT_COPY_END1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT_COPY_END2(category, name, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, \ + category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val) #define TRACE_EVENT_COPY_END2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, \ - category, name, \ - arg1_name, base::debug::TraceValue::ForceCopy(arg1_val), \ - arg2_name, base::debug::TraceValue::ForceCopy(arg2_val), \ - TRACE_EVENT_FLAG_COPY) + category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val, \ + arg2_name, arg2_val) // Time threshold event: // Only record the event if the duration is greater than the specified @@ -309,15 +362,15 @@ // - category and name strings must have application lifetime (statics or // literals). They may not include " chars. #define TRACE_EVENT_IF_LONGER_THAN0(threshold_us, category, name) \ - TRACE_EVENT_IF_LONGER_THAN1(threshold_us, category, name, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_SCOPED_IF_LONGER_THAN(threshold_us, category, name) #define TRACE_EVENT_IF_LONGER_THAN1( \ - threshold_us, category, name, arg1_name, arg1_val) \ - TRACE_EVENT_IF_LONGER_THAN2(threshold_us, category, name, \ - arg1_name, arg1_val, NULL, 0) + threshold_us, category, name, arg1_name, arg1_val) \ + INTERNAL_TRACE_EVENT_ADD_SCOPED_IF_LONGER_THAN( \ + threshold_us, category, name, arg1_name, arg1_val) #define TRACE_EVENT_IF_LONGER_THAN2( \ threshold_us, category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ - INTERNAL_TRACE_EVENT_ADD_SCOPED_IF_LONGER_THAN(threshold_us, \ - category, name, arg1_name, arg1_val, arg2_name, arg2_val) + INTERNAL_TRACE_EVENT_ADD_SCOPED_IF_LONGER_THAN( \ + threshold_us, category, name, arg1_name, arg1_val, arg2_name, arg2_val) // Records the value of a counter called "name" immediately. Value // must be representable as a 32 bit integer. @@ -336,14 +389,14 @@ #define TRACE_COUNTER2(category, name, value1_name, value1_val, \ value2_name, value2_val) \ INTERNAL_TRACE_EVENT_ADD_COUNTER( \ - category, name, 0, value1_name, value1_val, value2_name, value2_val, \ + category, name, trace_event_internal::kNoEventId, \ + value1_name, value1_val, value2_name, value2_val, \ TRACE_EVENT_FLAG_NONE) #define TRACE_COPY_COUNTER2(category, name, value1_name, value1_val, \ value2_name, value2_val) \ INTERNAL_TRACE_EVENT_ADD_COUNTER( \ - category, name, 0, \ - value1_name, value1_val, \ - value2_name, value2_val, \ + category, name, trace_event_internal::kNoEventId, \ + value1_name, value1_val, value2_name, value2_val, \ TRACE_EVENT_FLAG_COPY) // Records the value of a counter called "name" immediately. Value @@ -392,48 +445,54 @@ // will be xored with a hash of the process ID so that the same pointer on // two different processes will not collide. #define TRACE_EVENT_START0(category, name, id) \ - TRACE_EVENT_START1(category, name, id, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_START, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID) #define TRACE_EVENT_START1(category, name, id, arg1_name, arg1_val) \ - TRACE_EVENT_START2(category, name, id, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_START, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID, arg1_name, arg1_val) #define TRACE_EVENT_START2(category, name, id, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_START, \ - category, name, id, arg1_name, arg1_val, arg2_name, arg2_val, \ - TRACE_EVENT_FLAG_HAS_ID) + category, name, id, TRACE_EVENT_FLAG_HAS_ID, \ + arg1_name, arg1_val, arg2_name, arg2_val) #define TRACE_EVENT_COPY_START0(category, name, id) \ - TRACE_EVENT_COPY_START1(category, name, id, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_START, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY) #define TRACE_EVENT_COPY_START1(category, name, id, arg1_name, arg1_val) \ - TRACE_EVENT_COPY_START2(category, name, id, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_START, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY, \ + arg1_name, arg1_val) #define TRACE_EVENT_COPY_START2(category, name, id, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_START, \ - category, name, id, \ - arg1_name, base::debug::TraceValue::ForceCopy(arg1_val), \ - arg2_name, base::debug::TraceValue::ForceCopy(arg2_val), \ - TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY) + category, name, id, TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY, \ + arg1_name, arg1_val, arg2_name, arg2_val) // Records a single FINISH event for "name" immediately. If the category // is not enabled, then this does nothing. #define TRACE_EVENT_FINISH0(category, name, id) \ - TRACE_EVENT_FINISH1(category, name, id, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_FINISH, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID) #define TRACE_EVENT_FINISH1(category, name, id, arg1_name, arg1_val) \ - TRACE_EVENT_FINISH2(category, name, id, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_FINISH, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID, arg1_name, arg1_val) #define TRACE_EVENT_FINISH2(category, name, id, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_FINISH, \ - category, name, id, arg1_name, arg1_val, arg2_name, arg2_val, \ - TRACE_EVENT_FLAG_HAS_ID) + category, name, id, TRACE_EVENT_FLAG_HAS_ID, \ + arg1_name, arg1_val, arg2_name, arg2_val) #define TRACE_EVENT_COPY_FINISH0(category, name, id) \ - TRACE_EVENT_COPY_FINISH1(category, name, id, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_FINISH, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY) #define TRACE_EVENT_COPY_FINISH1(category, name, id, arg1_name, arg1_val) \ - TRACE_EVENT_COPY_FINISH2(category, name, id, arg1_name, arg1_val, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_FINISH, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY, \ + arg1_name, arg1_val) #define TRACE_EVENT_COPY_FINISH2(category, name, id, arg1_name, arg1_val, \ arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_FINISH, \ - category, name, id, \ - arg1_name, base::debug::TraceValue::ForceCopy(arg1_val), \ - arg2_name, base::debug::TraceValue::ForceCopy(arg2_val), \ - TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY) + category, name, id, TRACE_EVENT_FLAG_HAS_ID | TRACE_EVENT_FLAG_COPY, \ + arg1_name, arg1_val, arg2_name, arg2_val) // Implementation detail: trace event macros create temporary variables @@ -449,23 +508,21 @@ // Implementation detail: internal macro to create static category. // - ANNOTATE_BENIGN_RACE, see Thread Safety above. #define INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category) \ - static const base::debug::TraceCategory* \ - INTERNAL_TRACE_EVENT_UID(catstatic) = NULL; \ + static const unsigned char* INTERNAL_TRACE_EVENT_UID(catstatic) = NULL; \ ANNOTATE_BENIGN_RACE(&INTERNAL_TRACE_EVENT_UID(catstatic), \ "trace_event category"); \ if (!INTERNAL_TRACE_EVENT_UID(catstatic)) \ INTERNAL_TRACE_EVENT_UID(catstatic) = \ - base::debug::TraceLog::GetCategory(category); + TRACE_EVENT_API_GET_CATEGORY_ENABLED(category); // Implementation detail: internal macro to create static category and add // event if the category is enabled. -#define INTERNAL_TRACE_EVENT_ADD( \ - phase, category, name, arg1_name, arg1_val, arg2_name, arg2_val, flags) \ +#define INTERNAL_TRACE_EVENT_ADD(phase, category, name, flags, ...) \ INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ - if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ - base::debug::TraceLog::GetInstance()->AddTraceEvent( \ - phase, INTERNAL_TRACE_EVENT_UID(catstatic), \ - name, 0, arg1_name, arg1_val, arg2_name, arg2_val, -1, 0, flags); \ + if (*INTERNAL_TRACE_EVENT_UID(catstatic)) { \ + trace_event_internal::AddTraceEvent( \ + phase, INTERNAL_TRACE_EVENT_UID(catstatic), name, \ + trace_event_internal::kNoEventId, flags, ##__VA_ARGS__); \ } // Implementation detail: internal macro to create static category and @@ -473,26 +530,26 @@ #define INTERNAL_TRACE_EVENT_ADD_COUNTER( \ category, name, id, arg1_name, arg1_val, arg2_name, arg2_val, flags) \ INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ - if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ - base::debug::TraceLog::GetInstance()->AddCounterEvent( \ + if (*INTERNAL_TRACE_EVENT_UID(catstatic)) { \ + TRACE_EVENT_API_ADD_COUNTER_EVENT( \ INTERNAL_TRACE_EVENT_UID(catstatic), \ - name, id, arg1_name, arg1_val, arg2_name, arg2_val, flags); \ + name, trace_event_internal::TraceID(id).data(), \ + arg1_name, arg1_val, arg2_name, arg2_val, flags); \ } // Implementation detail: internal macro to create static category and add begin // event if the category is enabled. Also adds the end event when the scope // ends. -#define INTERNAL_TRACE_EVENT_ADD_SCOPED( \ - category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ +#define INTERNAL_TRACE_EVENT_ADD_SCOPED(category, name, ...) \ INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ - base::debug::internal::TraceEndOnScopeClose \ + trace_event_internal::TraceEndOnScopeClose \ INTERNAL_TRACE_EVENT_UID(profileScope); \ - if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ - base::debug::TraceLog::GetInstance()->AddTraceEvent( \ + if (*INTERNAL_TRACE_EVENT_UID(catstatic)) { \ + trace_event_internal::AddTraceEvent( \ TRACE_EVENT_PHASE_BEGIN, \ INTERNAL_TRACE_EVENT_UID(catstatic), \ - name, 0, arg1_name, arg1_val, arg2_name, arg2_val, -1, 0, \ - TRACE_EVENT_FLAG_NONE); \ + name, trace_event_internal::kNoEventId, \ + TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__); \ INTERNAL_TRACE_EVENT_UID(profileScope).Initialize( \ INTERNAL_TRACE_EVENT_UID(catstatic), name); \ } @@ -501,17 +558,17 @@ // event if the category is enabled. Also adds the end event when the scope // ends. If the elapsed time is < threshold time, the begin/end pair is erased. #define INTERNAL_TRACE_EVENT_ADD_SCOPED_IF_LONGER_THAN(threshold, \ - category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ + category, name, ...) \ INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ - base::debug::internal::TraceEndOnScopeCloseThreshold \ + trace_event_internal::TraceEndOnScopeCloseThreshold \ INTERNAL_TRACE_EVENT_UID(profileScope); \ - if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ + if (*INTERNAL_TRACE_EVENT_UID(catstatic)) { \ int INTERNAL_TRACE_EVENT_UID(begin_event_id) = \ - base::debug::TraceLog::GetInstance()->AddTraceEvent( \ + trace_event_internal::AddTraceEvent( \ TRACE_EVENT_PHASE_BEGIN, \ INTERNAL_TRACE_EVENT_UID(catstatic), \ - name, 0, arg1_name, arg1_val, arg2_name, arg2_val, -1, 0, \ - TRACE_EVENT_FLAG_NONE); \ + name, trace_event_internal::kNoEventId, \ + TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__); \ INTERNAL_TRACE_EVENT_UID(profileScope).Initialize( \ INTERNAL_TRACE_EVENT_UID(catstatic), name, \ INTERNAL_TRACE_EVENT_UID(begin_event_id), threshold); \ @@ -519,13 +576,14 @@ // Implementation detail: internal macro to create static category and add // event if the category is enabled. -#define INTERNAL_TRACE_EVENT_ADD_WITH_ID(phase, category, name, id, \ - arg1_name, arg1_val, arg2_name, arg2_val, flags) \ +#define INTERNAL_TRACE_EVENT_ADD_WITH_ID(phase, category, name, id, flags, \ + ...) \ INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ - if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ - base::debug::TraceLog::GetInstance()->AddTraceEvent( \ + if (*INTERNAL_TRACE_EVENT_UID(catstatic)) { \ + trace_event_internal::AddTraceEvent( \ phase, INTERNAL_TRACE_EVENT_UID(catstatic), \ - name, id, arg1_name, arg1_val, arg2_name, arg2_val, -1, 0, flags); \ + name, trace_event_internal::TraceID(id).data(), flags, \ + ##__VA_ARGS__); \ } template <typename Type> @@ -537,173 +595,35 @@ class RefCountedString; namespace debug { -// Categories allow enabling/disabling of streams of trace events -struct TraceCategory { - const char* name; - volatile bool enabled; -}; +const int kTraceMaxNumArgs = 2; -const size_t kTraceMaxNumArgs = 2; +// Notes regarding the following definitions: +// New values can be added and propagated to third party libraries, but existing +// definitions must never be changed, because third party libraries may use old +// definitions. // Phase indicates the nature of an event entry. E.g. part of a begin/end pair. -typedef char TraceEventPhase; -#define TRACE_EVENT_PHASE_BEGIN (base::debug::TraceEventPhase('B')) -#define TRACE_EVENT_PHASE_END (base::debug::TraceEventPhase('E')) -#define TRACE_EVENT_PHASE_INSTANT (base::debug::TraceEventPhase('I')) -#define TRACE_EVENT_PHASE_START (base::debug::TraceEventPhase('S')) -#define TRACE_EVENT_PHASE_FINISH (base::debug::TraceEventPhase('F')) -#define TRACE_EVENT_PHASE_METADATA (base::debug::TraceEventPhase('M')) -#define TRACE_EVENT_PHASE_COUNTER (base::debug::TraceEventPhase('C')) - -typedef uint8 TraceEventFlags; -#define TRACE_EVENT_FLAG_NONE (base::debug::TraceEventFlags(0)) -#define TRACE_EVENT_FLAG_COPY (base::debug::TraceEventFlags(1<<0)) -#define TRACE_EVENT_FLAG_HAS_ID (base::debug::TraceEventFlags(1<<1)) - -// Simple union of values. This is much lighter weight than base::Value, which -// requires dynamic allocation and a vtable. To keep the trace runtime overhead -// low, we want constant size storage here. -class BASE_EXPORT TraceValue { - public: - enum Type { - TRACE_TYPE_UNDEFINED, - TRACE_TYPE_BOOL, - TRACE_TYPE_UINT, - TRACE_TYPE_INT, - TRACE_TYPE_DOUBLE, - TRACE_TYPE_POINTER, - TRACE_TYPE_STRING, - TRACE_TYPE_STATIC_STRING - }; - - TraceValue() : type_(TRACE_TYPE_UNDEFINED) { - value_.as_uint = 0ull; - } - TraceValue(bool rhs) : type_(TRACE_TYPE_BOOL) { - value_.as_bool = rhs; - } - TraceValue(uint64 rhs) : type_(TRACE_TYPE_UINT) { - value_.as_uint = rhs; - } - TraceValue(uint32 rhs) : type_(TRACE_TYPE_UINT) { - value_.as_uint = rhs; - } - TraceValue(uint16 rhs) : type_(TRACE_TYPE_UINT) { - value_.as_uint = rhs; - } - TraceValue(uint8 rhs) : type_(TRACE_TYPE_UINT) { - value_.as_uint = rhs; - } - TraceValue(int64 rhs) : type_(TRACE_TYPE_INT) { - value_.as_int = rhs; - } - TraceValue(int32 rhs) : type_(TRACE_TYPE_INT) { - value_.as_int = rhs; - } - TraceValue(int16 rhs) : type_(TRACE_TYPE_INT) { - value_.as_int = rhs; - } - TraceValue(int8 rhs) : type_(TRACE_TYPE_INT) { - value_.as_int = rhs; - } - TraceValue(double rhs) : type_(TRACE_TYPE_DOUBLE) { - value_.as_double = rhs; - } - TraceValue(const void* rhs) : type_(TRACE_TYPE_POINTER) { - value_.as_pointer = rhs; - } - TraceValue(const std::string& rhs) : type_(TRACE_TYPE_STRING) { - value_.as_string = rhs.c_str(); - } - TraceValue(const char* rhs) : type_(TRACE_TYPE_STATIC_STRING) { - value_.as_string = rhs; - } - - static TraceValue StringWithCopy(const char* rhs) { - TraceValue value(rhs); - if (rhs) - value.type_ = TRACE_TYPE_STRING; - return value; - } - - static TraceValue ForceCopy(const TraceValue& rhs) { - TraceValue value(rhs); - if (value.type_ == TRACE_TYPE_STATIC_STRING && value.as_string()) - value.type_ = TRACE_TYPE_STRING; - return value; - } - - bool is_string() const { - return type_ == TRACE_TYPE_STRING || type_ == TRACE_TYPE_STATIC_STRING; - } - - void AppendAsJSON(std::string* out) const; - - Type type() const { - return type_; - } - uint64 as_uint() const { - DCHECK_EQ(TRACE_TYPE_UINT, type_); - return value_.as_uint; - } - bool as_bool() const { - DCHECK_EQ(TRACE_TYPE_BOOL, type_); - return value_.as_bool; - } - int64 as_int() const { - DCHECK_EQ(TRACE_TYPE_INT, type_); - return value_.as_int; - } - double as_double() const { - DCHECK_EQ(TRACE_TYPE_DOUBLE, type_); - return value_.as_double; - } - const void* as_pointer() const { - DCHECK_EQ(TRACE_TYPE_POINTER, type_); - return value_.as_pointer; - } - const char* as_string() const { - DCHECK(is_string()); - return value_.as_string; - } - const char** as_assignable_string() { - DCHECK_EQ(TRACE_TYPE_STRING, type_); - return &value_.as_string; - } - - private: - union Value { - bool as_bool; - uint64 as_uint; - int64 as_int; - double as_double; - const void* as_pointer; - const char* as_string; - }; - - Type type_; - Value value_; -}; - -// TraceID encapsulates an ID that can either be an integer or pointer. Pointers -// are mangled with the Process ID so that they are unlikely to collide when the -// same pointer is used on different processes. -class BASE_EXPORT TraceID { - public: - TraceID() : data_(0u) {} - TraceID(void* rhs); - TraceID(unsigned long long rhs) : data_(static_cast<uint64>(rhs)) {} - TraceID(unsigned long rhs) : data_(static_cast<uint64>(rhs)) {} - TraceID(unsigned int rhs) : data_(static_cast<uint64>(rhs)) {} - TraceID(long long rhs) : data_(static_cast<uint64>(rhs)) {} - TraceID(long rhs) : data_(static_cast<uint64>(rhs)) {} - TraceID(int rhs) : data_(static_cast<uint64>(rhs)) {} - - uint64 data() const { return data_; } - - private: - uint64 data_; -}; +#define TRACE_EVENT_PHASE_BEGIN ('B') +#define TRACE_EVENT_PHASE_END ('E') +#define TRACE_EVENT_PHASE_INSTANT ('I') +#define TRACE_EVENT_PHASE_START ('S') +#define TRACE_EVENT_PHASE_FINISH ('F') +#define TRACE_EVENT_PHASE_METADATA ('M') +#define TRACE_EVENT_PHASE_COUNTER ('C') + +// Flags for changing the behavior of TRACE_EVENT_API_ADD_TRACE_EVENT. +#define TRACE_EVENT_FLAG_NONE (static_cast<unsigned char>(0)) +#define TRACE_EVENT_FLAG_COPY (static_cast<unsigned char>(1<<0)) +#define TRACE_EVENT_FLAG_HAS_ID (static_cast<unsigned char>(1<<1)) + +// Type values for identifying types in the TraceValue union. +#define TRACE_VALUE_TYPE_BOOL (static_cast<unsigned char>(1)) +#define TRACE_VALUE_TYPE_UINT (static_cast<unsigned char>(2)) +#define TRACE_VALUE_TYPE_INT (static_cast<unsigned char>(3)) +#define TRACE_VALUE_TYPE_DOUBLE (static_cast<unsigned char>(4)) +#define TRACE_VALUE_TYPE_POINTER (static_cast<unsigned char>(5)) +#define TRACE_VALUE_TYPE_STRING (static_cast<unsigned char>(6)) +#define TRACE_VALUE_TYPE_COPY_STRING (static_cast<unsigned char>(7)) // Output records are "Events" and can be obtained via the // OutputCallback whenever the tracing system decides to flush. This @@ -711,26 +631,29 @@ class BASE_EXPORT TraceID { // force it to happen. class BASE_EXPORT TraceEvent { public: + union TraceValue { + bool as_bool; + unsigned long long as_uint; + long long as_int; + double as_double; + const void* as_pointer; + const char* as_string; + }; + TraceEvent(); TraceEvent(int thread_id, TimeTicks timestamp, - TraceEventPhase phase, - const TraceCategory* category, + char phase, + const unsigned char* category_enabled, const char* name, - TraceID id, - const char* arg1_name, const TraceValue& arg1_val, - const char* arg2_name, const TraceValue& arg2_val, - TraceEventFlags flags); + unsigned long long id, + int num_args, + const char** arg_names, + const unsigned char* arg_types, + const unsigned long long* arg_values, + unsigned char flags); ~TraceEvent(); - static char GetPhaseChar(TraceEventPhase phase) { - return static_cast<char>(phase); - } - - static TraceEventPhase GetPhase(const char* phase) { - return static_cast<TraceEventPhase>(*phase); - } - // Serialize event data to JSON static void AppendEventsAsJSON(const std::vector<TraceEvent>& events, size_t start, @@ -752,15 +675,16 @@ class BASE_EXPORT TraceEvent { // Note: these are ordered by size (largest first) for optimal packing. TimeTicks timestamp_; // id_ can be used to store phase-specific data. - TraceID id_; + unsigned long long id_; TraceValue arg_values_[kTraceMaxNumArgs]; const char* arg_names_[kTraceMaxNumArgs]; - const TraceCategory* category_; + const unsigned char* category_enabled_; const char* name_; scoped_refptr<base::RefCountedString> parameter_copy_storage_; int thread_id_; - TraceEventPhase phase_; - TraceEventFlags flags_; + char phase_; + unsigned char flags_; + unsigned char arg_types_[kTraceMaxNumArgs]; }; @@ -870,7 +794,8 @@ class BASE_EXPORT TraceLog { void Flush(); // Called by TRACE_EVENT* macros, don't call this directly. - static const TraceCategory* GetCategory(const char* name); + static const unsigned char* GetCategoryEnabled(const char* name); + static const char* GetCategoryName(const unsigned char* category_enabled); // Called by TRACE_EVENT* macros, don't call this directly. // Returns the index in the internal vector of the event if it was added, or @@ -880,36 +805,41 @@ class BASE_EXPORT TraceLog { // is less than the threshold, the begin/end event pair is dropped. // If |copy| is set, |name|, |arg_name1| and |arg_name2| will be deep copied // into the event; see "Memory scoping note" and TRACE_EVENT_COPY_XXX above. - int AddTraceEvent(TraceEventPhase phase, - const TraceCategory* category, + int AddTraceEvent(char phase, + const unsigned char* category_enabled, const char* name, - TraceID id, - const char* arg1_name, TraceValue arg1_val, - const char* arg2_name, TraceValue arg2_val, + unsigned long long id, + int num_args, + const char** arg_names, + const unsigned char* arg_types, + const unsigned long long* arg_values, int threshold_begin_id, - int64 threshold, - TraceEventFlags flags); - static void AddTraceEventEtw(TraceEventPhase phase, + long long threshold, + unsigned char flags); + static void AddTraceEventEtw(char phase, const char* name, const void* id, const char* extra); - static void AddTraceEventEtw(TraceEventPhase phase, + static void AddTraceEventEtw(char phase, const char* name, const void* id, const std::string& extra); // A wrapper around AddTraceEvent used by TRACE_COUNTERx macros // that allows only integer values for the counters. - int AddCounterEvent(const TraceCategory* category, - const char* name, - TraceID id, - const char* arg1_name, int32 arg1_val, - const char* arg2_name, int32 arg2_val, - TraceEventFlags flags); - - // Mangle |id| with a hash based on the process ID so that if |id| occurs on + void AddCounterEvent(const unsigned char* category_enabled, + const char* name, + unsigned long long id, + const char* arg1_name, int arg1_val, + const char* arg2_name, int arg2_val, + unsigned char flags); + + // Mangle |ptr| with a hash based on the process ID so that if |ptr| occurs on // more than one process, it will not collide. - uint64 GetIntraProcessID(uint64 id) const { return id ^ process_id_hash_; } + unsigned long long GetInterProcessID(void* ptr) const { + return static_cast<unsigned long long>(reinterpret_cast<uintptr_t>(ptr)) ^ + process_id_hash_; + } int process_id() const { return process_id_; } @@ -937,7 +867,7 @@ class BASE_EXPORT TraceLog { TraceLog(); ~TraceLog(); - const TraceCategory* GetCategoryInternal(const char* name); + const unsigned char* GetCategoryEnabledInternal(const char* name); void AddThreadNameMetadataEvents(); void AddClockSyncMetadataEvents(); @@ -954,14 +884,180 @@ class BASE_EXPORT TraceLog { base::hash_map<int, std::string> thread_names_; // XORed with TraceID to make it unlikely to collide with other processes. - uint64 process_id_hash_; + unsigned long long process_id_hash_; int process_id_; DISALLOW_COPY_AND_ASSIGN(TraceLog); }; -namespace internal { +} // namespace debug +} // namespace base + +namespace trace_event_internal { + +// Specify these values when the corresponding argument of AddTraceEvent is not +// used. +const int kZeroNumArgs = 0; +const int kNoThreshholdBeginId = -1; +const long long kNoThresholdValue = 0; +const unsigned long long kNoEventId = 0; + +// TraceID encapsulates an ID that can either be an integer or pointer. Pointers +// are mangled with the Process ID so that they are unlikely to collide when the +// same pointer is used on different processes. +class BASE_EXPORT TraceID { + public: + explicit TraceID(void* rhs) : + data_(TRACE_EVENT_API_GET_ID_FROM_POINTER(rhs)) {} + explicit TraceID(unsigned long long rhs) : data_(rhs) {} + explicit TraceID(unsigned long rhs) : data_(rhs) {} + explicit TraceID(unsigned int rhs) : data_(rhs) {} + explicit TraceID(unsigned short rhs) : data_(rhs) {} + explicit TraceID(unsigned char rhs) : data_(rhs) {} + explicit TraceID(long long rhs) : + data_(static_cast<unsigned long long>(rhs)) {} + explicit TraceID(long rhs) : data_(static_cast<unsigned long long>(rhs)) {} + explicit TraceID(int rhs) : data_(static_cast<unsigned long long>(rhs)) {} + explicit TraceID(short rhs) : data_(static_cast<unsigned long long>(rhs)) {} + explicit TraceID(signed char rhs) : + data_(static_cast<unsigned long long>(rhs)) {} + + unsigned long long data() const { return data_; } + + private: + unsigned long long data_; +}; + +// Simple union to store various types as unsigned long long. +union TraceValueUnion { + bool as_bool; + unsigned long long as_uint; + long long as_int; + double as_double; + const void* as_pointer; + const char* as_string; +}; + +// Simple container for const char* that should be copied instead of retained. +class TraceStringWithCopy { + public: + explicit TraceStringWithCopy(const char* str) : str_(str) {} + operator const char* () const { return str_; } + private: + const char* str_; +}; + +// Define SetTraceValue for each allowed type. It stores the type and +// value in the return arguments. This allows this API to avoid declaring any +// structures so that it is portable to third_party libraries. +#define INTERNAL_DECLARE_SET_TRACE_VALUE(actual_type, \ + union_member, \ + value_type_id) \ + static inline void SetTraceValue(actual_type arg, \ + unsigned char* type, \ + unsigned long long* value) { \ + TraceValueUnion type_value; \ + type_value.union_member = arg; \ + *type = value_type_id; \ + *value = type_value.as_uint; \ + } +// Simpler form for int types that can be safely casted. +#define INTERNAL_DECLARE_SET_TRACE_VALUE_INT(actual_type, \ + value_type_id) \ + static inline void SetTraceValue(actual_type arg, \ + unsigned char* type, \ + unsigned long long* value) { \ + *type = value_type_id; \ + *value = static_cast<unsigned long long>(arg); \ + } + +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned long long, TRACE_VALUE_TYPE_UINT) +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned int, TRACE_VALUE_TYPE_UINT) +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned short, TRACE_VALUE_TYPE_UINT) +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(unsigned char, TRACE_VALUE_TYPE_UINT) +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(long long, TRACE_VALUE_TYPE_INT) +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(int, TRACE_VALUE_TYPE_INT) +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(short, TRACE_VALUE_TYPE_INT) +INTERNAL_DECLARE_SET_TRACE_VALUE_INT(signed char, TRACE_VALUE_TYPE_INT) +INTERNAL_DECLARE_SET_TRACE_VALUE(bool, as_bool, TRACE_VALUE_TYPE_BOOL) +INTERNAL_DECLARE_SET_TRACE_VALUE(double, as_double, TRACE_VALUE_TYPE_DOUBLE) +INTERNAL_DECLARE_SET_TRACE_VALUE(const void*, as_pointer, + TRACE_VALUE_TYPE_POINTER) +INTERNAL_DECLARE_SET_TRACE_VALUE(const char*, as_string, + TRACE_VALUE_TYPE_STRING) +INTERNAL_DECLARE_SET_TRACE_VALUE(const TraceStringWithCopy&, as_string, + TRACE_VALUE_TYPE_COPY_STRING) + +#undef INTERNAL_DECLARE_SET_TRACE_VALUE +#undef INTERNAL_DECLARE_SET_TRACE_VALUE_INT + +// std::string version of SetTraceValue so that trace arguments can be strings. +static inline void SetTraceValue(const std::string& arg, + unsigned char* type, + unsigned long long* value) { + TraceValueUnion type_value; + type_value.as_string = arg.c_str(); + *type = TRACE_VALUE_TYPE_COPY_STRING; + *value = type_value.as_uint; +} + +// These AddTraceEvent template functions are defined here instead of in the +// macro, because the arg_values could be temporary objects, such as +// std::string. In order to store pointers to the internal c_str and pass +// through to the tracing API, the arg_values must live throughout +// these procedures. + +static inline int AddTraceEvent(char phase, + const unsigned char* category_enabled, + const char* name, + unsigned long long id, + unsigned char flags) { + return TRACE_EVENT_API_ADD_TRACE_EVENT( + phase, category_enabled, name, id, + kZeroNumArgs, NULL, NULL, NULL, + kNoThreshholdBeginId, kNoThresholdValue, flags); +} + +template<class ARG1_TYPE> +static inline int AddTraceEvent(char phase, + const unsigned char* category_enabled, + const char* name, + unsigned long long id, + unsigned char flags, + const char* arg1_name, + const ARG1_TYPE& arg1_val) { + const int num_args = 1; + unsigned char arg_types[1]; + unsigned long long arg_values[1]; + SetTraceValue(arg1_val, &arg_types[0], &arg_values[0]); + return TRACE_EVENT_API_ADD_TRACE_EVENT( + phase, category_enabled, name, id, + num_args, &arg1_name, arg_types, arg_values, + kNoThreshholdBeginId, kNoThresholdValue, flags); +} + +template<class ARG1_TYPE, class ARG2_TYPE> +static inline int AddTraceEvent(char phase, + const unsigned char* category_enabled, + const char* name, + unsigned long long id, + unsigned char flags, + const char* arg1_name, + const ARG1_TYPE& arg1_val, + const char* arg2_name, + const ARG2_TYPE& arg2_val) { + const int num_args = 2; + const char* arg_names[2] = { arg1_name, arg2_name }; + unsigned char arg_types[2]; + unsigned long long arg_values[2]; + SetTraceValue(arg1_val, &arg_types[0], &arg_values[0]); + SetTraceValue(arg2_val, &arg_types[1], &arg_values[1]); + return TRACE_EVENT_API_ADD_TRACE_EVENT( + phase, category_enabled, name, id, + num_args, arg_names, arg_types, arg_values, + kNoThreshholdBeginId, kNoThresholdValue, flags); +} // Used by TRACE_EVENTx macro. Do not use directly. class BASE_EXPORT TraceEndOnScopeClose { @@ -973,7 +1069,7 @@ class BASE_EXPORT TraceEndOnScopeClose { AddEventIfEnabled(); } - void Initialize(const TraceCategory* category, + void Initialize(const unsigned char* category_enabled, const char* name); private: @@ -986,7 +1082,7 @@ class BASE_EXPORT TraceEndOnScopeClose { // members of this class instead, compiler warnings occur about potential // uninitialized accesses. struct Data { - const TraceCategory* category; + const unsigned char* category_enabled; const char* name; }; Data* p_data_; @@ -1005,10 +1101,10 @@ class BASE_EXPORT TraceEndOnScopeCloseThreshold { // Called by macros only when tracing is enabled at the point when the begin // event is added. - void Initialize(const TraceCategory* category, + void Initialize(const unsigned char* category_enabled, const char* name, int threshold_begin_id, - int64 threshold); + long long threshold); private: // Add the end event if the category is still enabled. @@ -1020,8 +1116,8 @@ class BASE_EXPORT TraceEndOnScopeCloseThreshold { // members of this class instead, compiler warnings occur about potential // uninitialized accesses. struct Data { - int64 threshold; - const TraceCategory* category; + long long threshold; + const unsigned char* category_enabled; const char* name; int threshold_begin_id; }; @@ -1029,9 +1125,6 @@ class BASE_EXPORT TraceEndOnScopeCloseThreshold { Data data_; }; -} // namespace internal - -} // namespace debug -} // namespace base +} // namespace trace_event_internal #endif // BASE_DEBUG_TRACE_EVENT_H_ diff --git a/base/debug/trace_event_unittest.cc b/base/debug/trace_event_unittest.cc index cb77fee..8486f90 100644 --- a/base/debug/trace_event_unittest.cc +++ b/base/debug/trace_event_unittest.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2011 The Chromium Authors. All rights reserved. +// Copyright (c) 2012 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -99,6 +99,10 @@ void TraceEventTestFixture::OnTraceDataCollected( scoped_ptr<Value> root; root.reset(base::JSONReader::Read(json_output_.json_output, false)); + if (!root.get()) { + LOG(ERROR) << json_output_.json_output; + } + ListValue* root_list = NULL; ASSERT_TRUE(root.get()); ASSERT_TRUE(root->GetAsList(&root_list)); @@ -310,6 +314,34 @@ void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) { "name1", "value1", "name2", "value2"); + TRACE_EVENT_IF_LONGER_THAN0(0, "all", "TRACE_EVENT_IF_LONGER_THAN0 call"); + TRACE_EVENT_IF_LONGER_THAN1(0, "all", "TRACE_EVENT_IF_LONGER_THAN1 call", + "name1", "value1"); + TRACE_EVENT_IF_LONGER_THAN2(0, "all", "TRACE_EVENT_IF_LONGER_THAN2 call", + "name1", "value1", + "name2", "value2"); + + TRACE_EVENT_START0("all", "TRACE_EVENT_START0 call", 5); + TRACE_EVENT_START1("all", "TRACE_EVENT_START1 call", 5, + "name1", "value1"); + TRACE_EVENT_START2("all", "TRACE_EVENT_START2 call", 5, + "name1", "value1", + "name2", "value2"); + + TRACE_EVENT_FINISH0("all", "TRACE_EVENT_FINISH0 call", 5); + TRACE_EVENT_FINISH1("all", "TRACE_EVENT_FINISH1 call", 5, + "name1", "value1"); + TRACE_EVENT_FINISH2("all", "TRACE_EVENT_FINISH2 call", 5, + "name1", "value1", + "name2", "value2"); + + TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW0 call", 5, NULL); + TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW1 call", 5, "value"); + TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW0 call", 5, NULL); + TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW1 call", 5, "value"); + TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW0 call", 5, NULL); + TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW1 call", 5, "value"); + TRACE_COUNTER1("all", "TRACE_COUNTER1 call", 31415); TRACE_COUNTER2("all", "TRACE_COUNTER2 call", "a", 30000, @@ -358,33 +390,117 @@ void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) { EXPECT_EQ("E", ph_end); } EXPECT_FIND_("TRACE_EVENT1 call"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); EXPECT_FIND_("TRACE_EVENT2 call"); EXPECT_SUB_FIND_("name1"); EXPECT_SUB_FIND_("\"value1\""); EXPECT_SUB_FIND_("name2"); EXPECT_SUB_FIND_("value\\2"); + EXPECT_FIND_("TRACE_EVENT_INSTANT0 call"); EXPECT_FIND_("TRACE_EVENT_INSTANT1 call"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); EXPECT_FIND_("TRACE_EVENT_INSTANT2 call"); EXPECT_SUB_FIND_("name1"); EXPECT_SUB_FIND_("value1"); EXPECT_SUB_FIND_("name2"); EXPECT_SUB_FIND_("value2"); + EXPECT_FIND_("TRACE_EVENT_BEGIN0 call"); EXPECT_FIND_("TRACE_EVENT_BEGIN1 call"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); EXPECT_FIND_("TRACE_EVENT_BEGIN2 call"); EXPECT_SUB_FIND_("name1"); EXPECT_SUB_FIND_("value1"); EXPECT_SUB_FIND_("name2"); EXPECT_SUB_FIND_("value2"); + EXPECT_FIND_("TRACE_EVENT_END0 call"); EXPECT_FIND_("TRACE_EVENT_END1 call"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); EXPECT_FIND_("TRACE_EVENT_END2 call"); EXPECT_SUB_FIND_("name1"); EXPECT_SUB_FIND_("value1"); EXPECT_SUB_FIND_("name2"); EXPECT_SUB_FIND_("value2"); + EXPECT_FIND_("TRACE_EVENT_IF_LONGER_THAN0 call"); + EXPECT_FIND_("TRACE_EVENT_IF_LONGER_THAN1 call"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); + EXPECT_FIND_("TRACE_EVENT_IF_LONGER_THAN2 call"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); + EXPECT_SUB_FIND_("name2"); + EXPECT_SUB_FIND_("value2"); + + EXPECT_FIND_("TRACE_EVENT_START0 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_FIND_("TRACE_EVENT_START1 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); + EXPECT_FIND_("TRACE_EVENT_START2 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); + EXPECT_SUB_FIND_("name2"); + EXPECT_SUB_FIND_("value2"); + + EXPECT_FIND_("TRACE_EVENT_FINISH0 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_FIND_("TRACE_EVENT_FINISH1 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); + EXPECT_FIND_("TRACE_EVENT_FINISH2 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("name1"); + EXPECT_SUB_FIND_("value1"); + EXPECT_SUB_FIND_("name2"); + EXPECT_SUB_FIND_("value2"); + + EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW0 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("extra"); + EXPECT_SUB_FIND_("NULL"); + EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW1 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("extra"); + EXPECT_SUB_FIND_("value"); + EXPECT_FIND_("TRACE_EVENT_END_ETW0 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("extra"); + EXPECT_SUB_FIND_("NULL"); + EXPECT_FIND_("TRACE_EVENT_END_ETW1 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("extra"); + EXPECT_SUB_FIND_("value"); + EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW0 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("extra"); + EXPECT_SUB_FIND_("NULL"); + EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW1 call"); + EXPECT_SUB_FIND_("id"); + EXPECT_SUB_FIND_("5"); + EXPECT_SUB_FIND_("extra"); + EXPECT_SUB_FIND_("value"); + EXPECT_FIND_("TRACE_COUNTER1 call"); { std::string ph; diff --git a/base/debug/trace_event_win.cc b/base/debug/trace_event_win.cc index bba4713..d5a21f4 100644 --- a/base/debug/trace_event_win.cc +++ b/base/debug/trace_event_win.cc @@ -1,4 +1,4 @@ -// Copyright (c) 2011 The Chromium Authors. All rights reserved. +// Copyright (c) 2012 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. #include "base/debug/trace_event_win.h" @@ -42,7 +42,7 @@ bool TraceEventETWProvider::StartTracing() { void TraceEventETWProvider::TraceEvent(const char* name, size_t name_len, - TraceEventPhase type, + char type, const void* id, const char* extra, size_t extra_len) { @@ -96,7 +96,7 @@ void TraceEventETWProvider::TraceEvent(const char* name, void TraceEventETWProvider::Trace(const char* name, size_t name_len, - TraceEventPhase type, + char type, const void* id, const char* extra, size_t extra_len) { diff --git a/base/debug/trace_event_win.h b/base/debug/trace_event_win.h index 7d66393..3da95ea 100644 --- a/base/debug/trace_event_win.h +++ b/base/debug/trace_event_win.h @@ -1,4 +1,4 @@ -// Copyright (c) 2011 The Chromium Authors. All rights reserved. +// Copyright (c) 2012 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. @@ -37,14 +37,14 @@ class BASE_EXPORT TraceEventETWProvider : public base::win::EtwTraceProvider { // be used for length. static void Trace(const char* name, size_t name_len, - TraceEventPhase type, + char type, const void* id, const char* extra, size_t extra_len); // Allows passing extra as a std::string for convenience. static void Trace(const char* name, - TraceEventPhase type, + char type, const void* id, const std::string& extra) { return Trace(name, -1, type, id, extra.c_str(), extra.length()); @@ -53,7 +53,7 @@ class BASE_EXPORT TraceEventETWProvider : public base::win::EtwTraceProvider { // Allows passing extra as a const char* to avoid constructing temporary // std::string instances where not needed. static void Trace(const char* name, - TraceEventPhase type, + char type, const void* id, const char* extra) { return Trace(name, -1, type, id, extra, -1); @@ -75,7 +75,7 @@ class BASE_EXPORT TraceEventETWProvider : public base::win::EtwTraceProvider { // string will be used. void TraceEvent(const char* name, size_t name_len, - TraceEventPhase type, + char type, const void* id, const char* extra, size_t extra_len); diff --git a/base/test/trace_event_analyzer.cc b/base/test/trace_event_analyzer.cc index 1341cc0..7aba0be 100644 --- a/base/test/trace_event_analyzer.cc +++ b/base/test/trace_event_analyzer.cc @@ -41,7 +41,7 @@ bool TraceEvent::SetFromJSON(const base::Value* event_value) { return false; } - phase = base::debug::TraceEvent::GetPhase(phase_str.c_str()); + phase = *phase_str.data(); bool require_origin = (phase != TRACE_EVENT_PHASE_METADATA); bool require_id = (phase == TRACE_EVENT_PHASE_START || @@ -229,7 +229,7 @@ Query Query::Bool(bool boolean) { return Query(boolean ? 1.0 : 0.0); } -Query Query::Phase(base::debug::TraceEventPhase phase) { +Query Query::Phase(char phase) { return Query(static_cast<double>(phase)); } @@ -268,17 +268,17 @@ bool Query::Evaluate(const TraceEvent& event) const { else if (CompareAsString(event, &compare_result)) return compare_result; return false; - } else { - switch (operator_) { - case OP_AND: - return left().Evaluate(event) && right().Evaluate(event); - case OP_OR: - return left().Evaluate(event) || right().Evaluate(event); - case OP_NOT: - return !left().Evaluate(event); - default: - NOTREACHED(); - } + } + // It's a logical operator. + switch (operator_) { + case OP_AND: + return left().Evaluate(event) && right().Evaluate(event); + case OP_OR: + return left().Evaluate(event) || right().Evaluate(event); + case OP_NOT: + return !left().Evaluate(event); + default: + NOTREACHED(); } NOTREACHED(); @@ -393,17 +393,11 @@ bool Query::EvaluateArithmeticOperator(const TraceEvent& event, } bool Query::GetAsDouble(const TraceEvent& event, double* num) const { - base::debug::TraceValue value; switch (type_) { case QUERY_ARITHMETIC_OPERATOR: return EvaluateArithmeticOperator(event, num); case QUERY_EVENT_MEMBER: - value = GetMemberValue(event); - if (value.type() == base::debug::TraceValue::TRACE_TYPE_DOUBLE) { - *num = value.as_double(); - return true; - } - return false; + return GetMemberValueAsDouble(event, num); case QUERY_NUMBER: *num = number_; return true; @@ -413,15 +407,9 @@ bool Query::GetAsDouble(const TraceEvent& event, double* num) const { } bool Query::GetAsString(const TraceEvent& event, std::string* str) const { - base::debug::TraceValue value; switch (type_) { case QUERY_EVENT_MEMBER: - value = GetMemberValue(event); - if (value.is_string()) { - *str = value.as_string(); - return true; - } - return false; + return GetMemberValueAsString(event, str); case QUERY_STRING: *str = string_; return true; @@ -430,7 +418,8 @@ bool Query::GetAsString(const TraceEvent& event, std::string* str) const { } } -base::debug::TraceValue Query::GetMemberValue(const TraceEvent& event) const { +bool Query::GetMemberValueAsDouble(const TraceEvent& event, + double* num) const { DCHECK(type_ == QUERY_EVENT_MEMBER); // This could be a request for a member of |event| or a member of |event|'s @@ -440,69 +429,96 @@ base::debug::TraceValue Query::GetMemberValue(const TraceEvent& event) const { // Request for member of associated event, but there is no associated event. if (!the_event) - return base::debug::TraceValue(); + return false; switch (member_) { case EVENT_PID: case OTHER_PID: - return static_cast<double>(the_event->thread.process_id); + *num = static_cast<double>(the_event->thread.process_id); + return true; case EVENT_TID: case OTHER_TID: - return static_cast<double>(the_event->thread.thread_id); + *num = static_cast<double>(the_event->thread.thread_id); + return true; case EVENT_TIME: case OTHER_TIME: - return the_event->timestamp; + *num = the_event->timestamp; + return true; case EVENT_DURATION: - { - if (the_event->has_other_event()) - return the_event->GetAbsTimeToOtherEvent(); - else - return base::debug::TraceValue(); + if (the_event->has_other_event()) { + *num = the_event->GetAbsTimeToOtherEvent(); + return true; } + return false; case EVENT_PHASE: case OTHER_PHASE: - return static_cast<double>(the_event->phase); - case EVENT_CATEGORY: - case OTHER_CATEGORY: - return the_event->category; - case EVENT_NAME: - case OTHER_NAME: - return the_event->name; - case EVENT_ID: - case OTHER_ID: - return the_event->id; + *num = static_cast<double>(the_event->phase); + return true; case EVENT_HAS_STRING_ARG: case OTHER_HAS_STRING_ARG: - return (the_event->HasStringArg(string_) ? 1.0 : 0.0); + *num = (the_event->HasStringArg(string_) ? 1.0 : 0.0); + return true; case EVENT_HAS_NUMBER_ARG: case OTHER_HAS_NUMBER_ARG: - return (the_event->HasNumberArg(string_) ? 1.0 : 0.0); + *num = (the_event->HasNumberArg(string_) ? 1.0 : 0.0); + return true; case EVENT_ARG: - case OTHER_ARG: - { - // Search for the argument name and return its value if found. + case OTHER_ARG: { + // Search for the argument name and return its value if found. + std::map<std::string, double>::const_iterator num_i = + the_event->arg_numbers.find(string_); + if (num_i == the_event->arg_numbers.end()) + return false; + *num = num_i->second; + return true; + } + case EVENT_HAS_OTHER: + // return 1.0 (true) if the other event exists + *num = event.other_event ? 1.0 : 0.0; + return true; + default: + return false; + } +} + +bool Query::GetMemberValueAsString(const TraceEvent& event, + std::string* str) const { + DCHECK(type_ == QUERY_EVENT_MEMBER); - std::map<std::string, std::string>::const_iterator str_i = - the_event->arg_strings.find(string_); - if (str_i != the_event->arg_strings.end()) - return str_i->second; + // This could be a request for a member of |event| or a member of |event|'s + // associated event. Store the target event in the_event: + const TraceEvent* the_event = (member_ < OTHER_PID) ? + &event : event.other_event; - std::map<std::string, double>::const_iterator num_i = - the_event->arg_numbers.find(string_); - if (num_i != the_event->arg_numbers.end()) - return num_i->second; + // Request for member of associated event, but there is no associated event. + if (!the_event) + return false; - return base::debug::TraceValue(); - } - case EVENT_HAS_OTHER: - { - // return 1.0 (true) if the other event exists - double result = event.other_event ? 1.0 : 0.0; - return result; - } + switch (member_) { + case EVENT_CATEGORY: + case OTHER_CATEGORY: + *str = the_event->category; + return true; + case EVENT_NAME: + case OTHER_NAME: + *str = the_event->name; + return true; + case EVENT_ID: + case OTHER_ID: + *str = the_event->id; + return true; + case EVENT_ARG: + case OTHER_ARG: { + // Search for the argument name and return its value if found. + std::map<std::string, std::string>::const_iterator str_i = + the_event->arg_strings.find(string_); + if (str_i == the_event->arg_strings.end()) + return false; + *str = str_i->second; + return true; + } default: - NOTREACHED(); - return base::debug::TraceValue(); + return false; } } diff --git a/base/test/trace_event_analyzer.h b/base/test/trace_event_analyzer.h index 949721b..4817ec8 100644 --- a/base/test/trace_event_analyzer.h +++ b/base/test/trace_event_analyzer.h @@ -152,7 +152,7 @@ struct TraceEvent { // Stored as double to match its JSON representation. double timestamp; - base::debug::TraceEventPhase phase; + char phase; std::string category; @@ -193,7 +193,7 @@ class Query { static Query Bool(bool boolean); // Compare with the given phase. - static Query Phase(base::debug::TraceEventPhase phase); + static Query Phase(char phase); // Compare with the given string pattern. Only works with == and != operators. // Example: Query(EVENT_NAME) == Query::Pattern("MyEvent*") @@ -424,10 +424,11 @@ class Query { bool EvaluateArithmeticOperator(const TraceEvent& event, double* num) const; - // For QUERY_EVENT_MEMBER Query: attempt to get the value of the Query. - // The TraceValue will either be TRACE_TYPE_DOUBLE, TRACE_TYPE_STRING, - // or if requested member does not exist, it will be TRACE_TYPE_UNDEFINED. - base::debug::TraceValue GetMemberValue(const TraceEvent& event) const; + // For QUERY_EVENT_MEMBER Query: attempt to get the double value of the Query. + bool GetMemberValueAsDouble(const TraceEvent& event, double* num) const; + + // For QUERY_EVENT_MEMBER Query: attempt to get the string value of the Query. + bool GetMemberValueAsString(const TraceEvent& event, std::string* num) const; // Does this Query represent a value? bool is_value() const { return type_ != QUERY_BOOLEAN_OPERATOR; } |