diff options
author | jbates@chromium.org <jbates@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2012-01-23 21:03:49 +0000 |
---|---|---|
committer | jbates@chromium.org <jbates@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2012-01-23 21:03:49 +0000 |
commit | 3f087ed8909b8dfcdd2d001b2d8e35fe556a14a7 (patch) | |
tree | 84e0bd31825403376ea9f1f95a6e44fa6f8b5132 /base/debug | |
parent | ae15edeb4545771ba889980583a6c69715e658b6 (diff) | |
download | chromium_src-3f087ed8909b8dfcdd2d001b2d8e35fe556a14a7.zip chromium_src-3f087ed8909b8dfcdd2d001b2d8e35fe556a14a7.tar.gz chromium_src-3f087ed8909b8dfcdd2d001b2d8e35fe556a14a7.tar.bz2 |
Split up trace_event.h into trace_event_impl.h and add webkitplatform support.
No new features here, this is just a code split and API glue.
(Good news! I copied over trace_event.h to WebKit and verified that this all works!)
Review URL: https://chromiumcodereview.appspot.com/9213013
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@118733 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'base/debug')
-rw-r--r-- | base/debug/trace_event.cc | 741 | ||||
-rw-r--r-- | base/debug/trace_event.h | 464 | ||||
-rw-r--r-- | base/debug/trace_event_impl.cc | 720 | ||||
-rw-r--r-- | base/debug/trace_event_impl.h | 311 |
4 files changed, 1110 insertions, 1126 deletions
diff --git a/base/debug/trace_event.cc b/base/debug/trace_event.cc index c554769..be77d5a 100644 --- a/base/debug/trace_event.cc +++ b/base/debug/trace_event.cc @@ -4,747 +4,6 @@ #include "base/debug/trace_event.h" -#include <algorithm> - -#include "base/bind.h" -#include "base/file_util.h" -#include "base/format_macros.h" -#include "base/lazy_instance.h" -#include "base/memory/singleton.h" -#include "base/process_util.h" -#include "base/stringprintf.h" -#include "base/string_tokenizer.h" -#include "base/threading/platform_thread.h" -#include "base/threading/thread_local.h" -#include "base/utf_string_conversions.h" -#include "base/stl_util.h" -#include "base/sys_info.h" -#include "base/time.h" - -#if defined(OS_WIN) -#include "base/debug/trace_event_win.h" -#endif - -class DeleteTraceLogForTesting { - public: - static void Delete() { - Singleton<base::debug::TraceLog, - StaticMemorySingletonTraits<base::debug::TraceLog> >::OnExit(0); - } -}; - -namespace base { -namespace debug { - -// Controls the number of trace events we will buffer in-memory -// before throwing them away. -const size_t kTraceEventBufferSize = 500000; -const size_t kTraceEventBatchSize = 1000; - -#define TRACE_EVENT_MAX_CATEGORIES 100 - -namespace { - -// 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", -}; -// 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 -LazyInstance<ThreadLocalPointer<const char>, - LeakyLazyInstanceTraits<ThreadLocalPointer<const char> > > - g_current_thread_name = LAZY_INSTANCE_INITIALIZER; - -void AppendValueAsJSON(unsigned char type, - TraceEvent::TraceValue value, - std::string* out) { - std::string::size_type start_pos; - switch (type) { - case TRACE_VALUE_TYPE_BOOL: - *out += value.as_bool ? "true" : "false"; - break; - case TRACE_VALUE_TYPE_UINT: - StringAppendF(out, "%" PRIu64, static_cast<uint64>(value.as_uint)); - break; - case TRACE_VALUE_TYPE_INT: - StringAppendF(out, "%" PRId64, static_cast<int64>(value.as_int)); - break; - case TRACE_VALUE_TYPE_DOUBLE: - StringAppendF(out, "%f", value.as_double); - break; - 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>( - value.as_pointer))); - break; - case TRACE_VALUE_TYPE_STRING: - case TRACE_VALUE_TYPE_COPY_STRING: - *out += "\""; - start_pos = out->size(); - *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) { - out->insert(start_pos, 1, '\\'); - // skip inserted escape character and following character. - start_pos += 2; - } - *out += "\""; - break; - default: - NOTREACHED() << "Don't know how to print this value"; - break; - } -} - -} // namespace - -//////////////////////////////////////////////////////////////////////////////// -// -// TraceEvent -// -//////////////////////////////////////////////////////////////////////////////// - -namespace { - -size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; } - -// Copies |*member| into |*buffer|, sets |*member| to point to this new -// location, and then advances |*buffer| by the amount written. -void CopyTraceEventParameter(char** buffer, - const char** member, - const char* end) { - if (*member) { - size_t written = strlcpy(*buffer, *member, end - *buffer) + 1; - DCHECK_LE(static_cast<int>(written), end - *buffer); - *member = *buffer; - *buffer += written; - } -} - -} // namespace - -TraceEvent::TraceEvent() - : id_(0u), - category_enabled_(NULL), - name_(NULL), - thread_id_(0), - phase_(TRACE_EVENT_PHASE_BEGIN), - flags_(0) { - arg_names_[0] = NULL; - arg_names_[1] = NULL; -} - -TraceEvent::TraceEvent(int thread_id, - TimeTicks timestamp, - 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, - unsigned char flags) - : timestamp_(timestamp), - id_(id), - category_enabled_(category_enabled), - name_(name), - thread_id_(thread_id), - phase_(phase), - flags_(flags) { - // 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); - 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 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; - parameter_copy_storage_->data().resize(alloc_size); - char* ptr = string_as_array(¶meter_copy_storage_->data()); - const char* end = ptr + alloc_size; - if (copy) { - CopyTraceEventParameter(&ptr, &name_, 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); - } - DCHECK_EQ(end, ptr) << "Overrun by " << ptr - end; - } -} - -TraceEvent::~TraceEvent() { -} - -void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events, - size_t start, - size_t count, - std::string* out) { - for (size_t i = 0; i < count && start + i < events.size(); ++i) { - if (i > 0) - *out += ","; - events[i + start].AppendAsJSON(out); - } -} - -void TraceEvent::AppendAsJSON(std::string* out) const { - int64 time_int64 = timestamp_.ToInternalValue(); - int process_id = TraceLog::GetInstance()->process_id(); - // Category name checked at category creation time. - DCHECK(!strchr(name_, '"')); - StringAppendF(out, - "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 "," - "\"ph\":\"%c\",\"name\":\"%s\",\"args\":{", - TraceLog::GetCategoryName(category_enabled_), - process_id, - thread_id_, - time_int64, - phase_, - name_); - - // Output argument names and values, stop at first NULL argument name. - for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { - if (i > 0) - *out += ","; - *out += "\""; - *out += arg_names_[i]; - *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 "\"", static_cast<uint64>(id_)); - *out += "}"; -} - -//////////////////////////////////////////////////////////////////////////////// -// -// TraceResultBuffer -// -//////////////////////////////////////////////////////////////////////////////// - -TraceResultBuffer::OutputCallback - TraceResultBuffer::SimpleOutput::GetCallback() { - return base::Bind(&SimpleOutput::Append, base::Unretained(this)); -} - -void TraceResultBuffer::SimpleOutput::Append( - const std::string& json_trace_output) { - json_output += json_trace_output; -} - -TraceResultBuffer::TraceResultBuffer() : append_comma_(false) { -} - -TraceResultBuffer::~TraceResultBuffer() { -} - -void TraceResultBuffer::SetOutputCallback( - const OutputCallback& json_chunk_callback) { - output_callback_ = json_chunk_callback; -} - -void TraceResultBuffer::Start() { - append_comma_ = false; - output_callback_.Run("["); -} - -void TraceResultBuffer::AddFragment(const std::string& trace_fragment) { - if (append_comma_) - output_callback_.Run(","); - append_comma_ = true; - output_callback_.Run(trace_fragment); -} - -void TraceResultBuffer::Finish() { - output_callback_.Run("]"); -} - -//////////////////////////////////////////////////////////////////////////////// -// -// TraceLog -// -//////////////////////////////////////////////////////////////////////////////// - -// static -TraceLog* TraceLog::GetInstance() { - return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get(); -} - -TraceLog::TraceLog() - : enabled_(false) { - SetProcessID(static_cast<int>(base::GetCurrentProcId())); -} - -TraceLog::~TraceLog() { -} - -const unsigned char* TraceLog::GetCategoryEnabled(const char* name) { - TraceLog* tracelog = GetInstance(); - if (!tracelog) { - DCHECK(!g_category_enabled[g_category_already_shutdown]); - return &g_category_enabled[g_category_already_shutdown]; - } - 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, - 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], ci->c_str()); - if (is_match) - break; - } - ANNOTATE_BENIGN_RACE(&g_category_enabled[category_index], - "trace_event category enabled"); - 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, - unsigned char is_included) { - for (int i = 0; i < g_category_index; i++) - EnableMatchingCategory(i, patterns, is_included); -} - -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) == 0) - return &g_category_enabled[i]; - } - - // Create a new category - DCHECK(g_category_index < TRACE_EVENT_MAX_CATEGORIES) << - "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; - 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_, 1); - else - EnableMatchingCategory(new_index, excluded_categories_, 0); - } else { - ANNOTATE_BENIGN_RACE(&g_category_enabled[new_index], - "trace_event category enabled"); - g_category_enabled[new_index] = 0; - } - return &g_category_enabled[new_index]; - } else { - 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]); -} - -void TraceLog::SetEnabled(const std::vector<std::string>& included_categories, - const std::vector<std::string>& excluded_categories) { - AutoLock lock(lock_); - if (enabled_) - return; - logged_events_.reserve(1024); - enabled_ = true; - included_categories_ = included_categories; - excluded_categories_ = excluded_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_, 1); - else - EnableMatchingCategories(excluded_categories_, 0); -} - -void TraceLog::SetEnabled(const std::string& categories) { - std::vector<std::string> included, excluded; - // Tokenize list of categories, delimited by ','. - StringTokenizer tokens(categories, ","); - while (tokens.GetNext()) { - bool is_included = true; - std::string category = tokens.token(); - // Excluded categories start with '-'. - if (category.at(0) == '-') { - // Remove '-' from category string. - category = category.substr(1); - is_included = false; - } - if (is_included) - included.push_back(category); - else - excluded.push_back(category); - } - SetEnabled(included, excluded); -} - -void TraceLog::GetEnabledTraceCategories( - std::vector<std::string>* included_out, - std::vector<std::string>* excluded_out) { - AutoLock lock(lock_); - if (enabled_) { - *included_out = included_categories_; - *excluded_out = excluded_categories_; - } -} - -void TraceLog::SetDisabled() { - { - AutoLock lock(lock_); - if (!enabled_) - return; - - enabled_ = false; - included_categories_.clear(); - excluded_categories_.clear(); - for (int i = 0; i < g_category_index; i++) - g_category_enabled[i] = 0; - AddThreadNameMetadataEvents(); - AddClockSyncMetadataEvents(); - } // release lock - Flush(); -} - -void TraceLog::SetEnabled(bool enabled) { - if (enabled) - SetEnabled(std::vector<std::string>(), std::vector<std::string>()); - else - SetDisabled(); -} - -float TraceLog::GetBufferPercentFull() const { - return (float)((double)logged_events_.size()/(double)kTraceEventBufferSize); -} - -void TraceLog::SetOutputCallback(const TraceLog::OutputCallback& cb) { - AutoLock lock(lock_); - output_callback_ = cb; -} - -void TraceLog::SetBufferFullCallback(const TraceLog::BufferFullCallback& cb) { - AutoLock lock(lock_); - buffer_full_callback_ = cb; -} - -void TraceLog::Flush() { - std::vector<TraceEvent> previous_logged_events; - OutputCallback output_callback_copy; - { - AutoLock lock(lock_); - previous_logged_events.swap(logged_events_); - output_callback_copy = output_callback_; - } // release lock - - if (output_callback_copy.is_null()) - return; - - for (size_t i = 0; - i < previous_logged_events.size(); - i += kTraceEventBatchSize) { - scoped_refptr<RefCountedString> json_events_str_ptr = - new RefCountedString(); - TraceEvent::AppendEventsAsJSON(previous_logged_events, - i, - kTraceEventBatchSize, - &(json_events_str_ptr->data)); - output_callback_copy.Run(json_events_str_ptr); - } -} - -int TraceLog::AddTraceEvent(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) { - DCHECK(name); - TimeTicks now = TimeTicks::HighResNow(); - BufferFullCallback buffer_full_callback_copy; - int ret_begin_id = -1; - { - AutoLock lock(lock_); - if (!*category_enabled) - return -1; - if (logged_events_.size() >= kTraceEventBufferSize) - return -1; - - int thread_id = static_cast<int>(PlatformThread::CurrentId()); - - const char* new_name = PlatformThread::GetName(); - // Check if the thread name has been set or changed since the previous - // call (if any), but don't bother if the new name is empty. Note this will - // not detect a thread name change within the same char* buffer address: we - // favor common case performance over corner case correctness. - if (new_name != g_current_thread_name.Get().Get() && - new_name && *new_name) { - g_current_thread_name.Get().Set(new_name); - base::hash_map<int, std::string>::iterator existing_name = - thread_names_.find(thread_id); - if (existing_name == thread_names_.end()) { - // This is a new thread id, and a new name. - thread_names_[thread_id] = new_name; - } else { - // This is a thread id that we've seen before, but potentially with a - // new name. - std::vector<base::StringPiece> existing_names; - Tokenize(existing_name->second, ",", &existing_names); - bool found = std::find(existing_names.begin(), - existing_names.end(), - new_name) != existing_names.end(); - if (!found) { - existing_name->second.push_back(','); - existing_name->second.append(new_name); - } - } - } - - if (threshold_begin_id > -1) { - DCHECK(phase == TRACE_EVENT_PHASE_END); - size_t begin_i = static_cast<size_t>(threshold_begin_id); - // Return now if there has been a flush since the begin event was posted. - if (begin_i >= logged_events_.size()) - return -1; - // Determine whether to drop the begin/end pair. - TimeDelta elapsed = now - logged_events_[begin_i].timestamp(); - if (elapsed < TimeDelta::FromMicroseconds(threshold)) { - // Remove begin event and do not add end event. - // This will be expensive if there have been other events in the - // mean time (should be rare). - logged_events_.erase(logged_events_.begin() + begin_i); - return -1; - } - } - ret_begin_id = static_cast<int>(logged_events_.size()); - logged_events_.push_back( - TraceEvent(thread_id, - now, phase, category_enabled, name, id, - num_args, arg_names, arg_types, arg_values, - flags)); - - if (logged_events_.size() == kTraceEventBufferSize) { - buffer_full_callback_copy = buffer_full_callback_; - } - } // release lock - - if (!buffer_full_callback_copy.is_null()) - buffer_full_callback_copy.Run(); - - return ret_begin_id; -} - -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, - TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra); -} - -void TraceLog::AddTraceEventEtw(char phase, - const char* name, - const void* id, - const std::string& extra) -{ -#if defined(OS_WIN) - TraceEventETWProvider::Trace(name, phase, id, extra); -#endif - 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() { -#if defined(OS_ANDROID) - // Since Android does not support sched_setaffinity, we cannot establish clock - // sync unless the scheduler clock is set to global. If the trace_clock file - // can't be read, we will assume the kernel doesn't support tracing and do - // nothing. - std::string clock_mode; - if (!file_util::ReadFileToString( - FilePath("/sys/kernel/debug/tracing/trace_clock"), - &clock_mode)) - return; - - if (clock_mode != "local [global]\n") { - DLOG(WARNING) << - "The kernel's tracing clock must be set to global in order for " << - "trace_event to be synchronized with . Do this by\n" << - " echo global > /sys/kerel/debug/tracing/trace_clock"; - return; - } - - // Android's kernel trace system has a trace_marker feature: this is a file on - // debugfs that takes the written data and pushes it onto the trace - // buffer. So, to establish clock sync, we write our monotonic clock into that - // trace buffer. - TimeTicks now = TimeTicks::HighResNow(); - - double now_in_seconds = now.ToInternalValue() / 1000000.0; - std::string marker = - StringPrintf("trace_event_clock_sync: parent_ts=%f\n", - now_in_seconds); - if (file_util::WriteFile( - FilePath("/sys/kernel/debug/tracing/trace_marker"), - marker.c_str(), marker.size()) == -1) { - DLOG(WARNING) << "Couldn't write to /sys/kernel/debug/tracing/trace_marker"; - return; - } -#endif -} - -void TraceLog::AddThreadNameMetadataEvents() { - lock_.AssertAcquired(); - for(base::hash_map<int, std::string>::iterator it = thread_names_.begin(); - it != thread_names_.end(); - it++) { - 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_enabled[g_category_metadata], - "thread_name", trace_event_internal::kNoEventId, - num_args, &arg_name, &arg_type, &arg_value, - TRACE_EVENT_FLAG_NONE)); - } - } -} - -void TraceLog::DeleteForTesting() { - DeleteTraceLogForTesting::Delete(); -} - -void TraceLog::Resurrect() { - StaticMemorySingletonTraits<TraceLog>::Resurrect(); -} - -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. - 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 debug -} // namespace base - namespace trace_event_internal { void TraceEndOnScopeClose::Initialize(const unsigned char* category_enabled, diff --git a/base/debug/trace_event.h b/base/debug/trace_event.h index a1fff3e..21d1b32 100644 --- a/base/debug/trace_event.h +++ b/base/debug/trace_event.h @@ -2,6 +2,13 @@ // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. +// This header is designed to 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, +// implement the TRACE_EVENT_API macros, and do any other necessary fixup for +// the target platform. The end result is that multiple libraries can funnel +// events through to a shared trace event collector. + // Trace events are for tracking application performance and resource usage. // Macros are provided to track: // Begin and end of function calls @@ -147,87 +154,16 @@ #define BASE_DEBUG_TRACE_EVENT_H_ #pragma once -#include "build/build_config.h" - #include <string> -#include <vector> - -#include "base/callback.h" -#include "base/hash_tables.h" -#include "base/memory/ref_counted_memory.h" -#include "base/string_util.h" -#include "base/synchronization/lock.h" -#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 - -//////////////////////////////////////////////////////////////////////////////// +#include "build/build_config.h" +#include "base/debug/trace_event_impl.h" // 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) \ 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. -#define TRACE_EVENT_BEGIN_ETW(name, id, extra) \ - base::debug::TraceLog::AddTraceEventEtw( \ - TRACE_EVENT_PHASE_BEGIN, \ - name, reinterpret_cast<const void*>(id), extra) - -#define TRACE_EVENT_END_ETW(name, id, extra) \ - base::debug::TraceLog::AddTraceEventEtw( \ - TRACE_EVENT_PHASE_END, \ - name, reinterpret_cast<const void*>(id), extra) - -#define TRACE_EVENT_INSTANT_ETW(name, id, extra) \ - base::debug::TraceLog::AddTraceEventEtw( \ - TRACE_EVENT_PHASE_INSTANT, \ - name, reinterpret_cast<const void*>(id), extra) - // Records a pair of begin and end events called "name" for the current // scope, with 0, 1 or 2 associated arguments. If the category is not // enabled, then this does nothing. @@ -377,9 +313,13 @@ // - category and name strings must have application lifetime (statics or // literals). They may not include " chars. #define TRACE_COUNTER1(category, name, value) \ - TRACE_COUNTER2(category, name, "value", value, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_COUNTER, \ + category, name, TRACE_EVENT_FLAG_NONE, \ + "value", static_cast<int>(value)) #define TRACE_COPY_COUNTER1(category, name, value) \ - TRACE_COPY_COUNTER2(category, name, "value", value, NULL, 0) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_COUNTER, \ + category, name, TRACE_EVENT_FLAG_COPY, \ + "value", static_cast<int>(value)) // Records the values of a multi-parted counter called "name" immediately. // The UI will treat value1 and value2 as parts of a whole, displaying their @@ -388,16 +328,16 @@ // literals). They may not include " chars. #define TRACE_COUNTER2(category, name, value1_name, value1_val, \ value2_name, value2_val) \ - INTERNAL_TRACE_EVENT_ADD_COUNTER( \ - category, name, trace_event_internal::kNoEventId, \ - value1_name, value1_val, value2_name, value2_val, \ - TRACE_EVENT_FLAG_NONE) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_COUNTER, \ + category, name, TRACE_EVENT_FLAG_NONE, \ + value1_name, static_cast<int>(value1_val), \ + value2_name, static_cast<int>(value2_val)) #define TRACE_COPY_COUNTER2(category, name, value1_name, value1_val, \ value2_name, value2_val) \ - INTERNAL_TRACE_EVENT_ADD_COUNTER( \ - category, name, trace_event_internal::kNoEventId, \ - value1_name, value1_val, value2_name, value2_val, \ - TRACE_EVENT_FLAG_COPY) + INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_COUNTER, \ + category, name, TRACE_EVENT_FLAG_COPY, \ + value1_name, static_cast<int>(value1_val), \ + value2_name, static_cast<int>(value2_val)) // Records the value of a counter called "name" immediately. Value // must be representable as a 32 bit integer. @@ -408,9 +348,13 @@ // will be xored with a hash of the process ID so that the same pointer on // two different processes will not collide. #define TRACE_COUNTER_ID1(category, name, id, value) \ - TRACE_COUNTER_ID2(category, name, id, "value", value, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_COUNTER, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID, \ + "value", static_cast<int>(value)) #define TRACE_COPY_COUNTER_ID1(category, name, id, value) \ - TRACE_COPY_COUNTER_ID2(category, name, id, "value", value, NULL, 0) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_COUNTER, \ + category, name, id, TRACE_EVENT_FLAG_COPY | TRACE_EVENT_FLAG_HAS_ID, \ + "value", static_cast<int>(value)) // Records the values of a multi-parted counter called "name" immediately. // The UI will treat value1 and value2 as parts of a whole, displaying their @@ -423,16 +367,16 @@ // two different processes will not collide. #define TRACE_COUNTER_ID2(category, name, id, value1_name, value1_val, \ value2_name, value2_val) \ - INTERNAL_TRACE_EVENT_ADD_COUNTER( \ - category, name, id, value1_name, value1_val, value2_name, value2_val, \ - TRACE_EVENT_FLAG_HAS_ID) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_COUNTER, \ + category, name, id, TRACE_EVENT_FLAG_HAS_ID, \ + value1_name, static_cast<int>(value1_val), \ + value2_name, static_cast<int>(value2_val)) #define TRACE_COPY_COUNTER_ID2(category, name, id, value1_name, value1_val, \ value2_name, value2_val) \ - INTERNAL_TRACE_EVENT_ADD_COUNTER( \ - category, name, id, \ - value1_name, value1_val, \ - value2_name, value2_val, \ - TRACE_EVENT_FLAG_COPY|TRACE_EVENT_FLAG_HAS_ID) + INTERNAL_TRACE_EVENT_ADD_WITH_ID(TRACE_EVENT_PHASE_COUNTER, \ + category, name, id, TRACE_EVENT_FLAG_COPY | TRACE_EVENT_FLAG_HAS_ID, \ + value1_name, static_cast<int>(value1_val), \ + value2_name, static_cast<int>(value2_val)) // Records a single START event called "name" immediately, with 0, 1 or 2 @@ -495,6 +439,48 @@ arg1_name, arg1_val, arg2_name, arg2_val) +//////////////////////////////////////////////////////////////////////////////// +// Implementation specific tracing API definitions. + +// const 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 + +//////////////////////////////////////////////////////////////////////////////// + // Implementation detail: trace event macros create temporary variables // to keep instrumentation overhead low. These macros give each temporary // variable a unique name based on the line number to prevent name collissions. @@ -525,18 +511,6 @@ trace_event_internal::kNoEventId, flags, ##__VA_ARGS__); \ } -// Implementation detail: internal macro to create static category and -// add the counter event if it is enabled. -#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)) { \ - TRACE_EVENT_API_ADD_COUNTER_EVENT( \ - INTERNAL_TRACE_EVENT_UID(catstatic), \ - 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. @@ -586,17 +560,6 @@ ##__VA_ARGS__); \ } -template <typename Type> -struct StaticMemorySingletonTraits; - -namespace base { - -class RefCountedString; - -namespace debug { - -const int 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 @@ -625,275 +588,6 @@ const int kTraceMaxNumArgs = 2; #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 -// can happen at any time, on any thread, or you can programatically -// 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, - 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, - unsigned char flags); - ~TraceEvent(); - - // Serialize event data to JSON - static void AppendEventsAsJSON(const std::vector<TraceEvent>& events, - size_t start, - size_t count, - std::string* out); - void AppendAsJSON(std::string* out) const; - - TimeTicks timestamp() const { return timestamp_; } - - // Exposed for unittesting: - - const base::RefCountedString* parameter_copy_storage() const { - return parameter_copy_storage_.get(); - } - - const char* name() const { return name_; } - - private: - // Note: these are ordered by size (largest first) for optimal packing. - TimeTicks timestamp_; - // id_ can be used to store phase-specific data. - unsigned long long id_; - TraceValue arg_values_[kTraceMaxNumArgs]; - const char* arg_names_[kTraceMaxNumArgs]; - const unsigned char* category_enabled_; - const char* name_; - scoped_refptr<base::RefCountedString> parameter_copy_storage_; - int thread_id_; - char phase_; - unsigned char flags_; - unsigned char arg_types_[kTraceMaxNumArgs]; -}; - - -// TraceResultBuffer collects and converts trace fragments returned by TraceLog -// to JSON output. -class BASE_EXPORT TraceResultBuffer { - public: - typedef base::Callback<void(const std::string&)> OutputCallback; - - // If you don't need to stream JSON chunks out efficiently, and just want to - // get a complete JSON string after calling Finish, use this struct to collect - // JSON trace output. - struct BASE_EXPORT SimpleOutput { - OutputCallback GetCallback(); - void Append(const std::string& json_string); - - // Do what you want with the json_output_ string after calling - // TraceResultBuffer::Finish. - std::string json_output; - }; - - TraceResultBuffer(); - ~TraceResultBuffer(); - - // Set callback. The callback will be called during Start with the initial - // JSON output and during AddFragment and Finish with following JSON output - // chunks. The callback target must live past the last calls to - // TraceResultBuffer::Start/AddFragment/Finish. - void SetOutputCallback(const OutputCallback& json_chunk_callback); - - // Start JSON output. This resets all internal state, so you can reuse - // the TraceResultBuffer by calling Start. - void Start(); - - // Call AddFragment 0 or more times to add trace fragments from TraceLog. - void AddFragment(const std::string& trace_fragment); - - // When all fragments have been added, call Finish to complete the JSON - // formatted output. - void Finish(); - - private: - OutputCallback output_callback_; - bool append_comma_; -}; - - -class BASE_EXPORT TraceLog { - public: - static TraceLog* GetInstance(); - - // Get set of known categories. This can change as new code paths are reached. - // The known categories are inserted into |categories|. - void GetKnownCategories(std::vector<std::string>* categories); - - // Enable tracing for provided list of categories. If tracing is already - // enabled, this method does nothing -- changing categories during trace is - // not supported. - // If both included_categories and excluded_categories are empty, - // all categories are traced. - // Else if included_categories is non-empty, only those are traced. - // Else if excluded_categories is non-empty, everything but those are traced. - // Wildcards * and ? are supported (see MatchPattern in string_util.h). - void SetEnabled(const std::vector<std::string>& included_categories, - const std::vector<std::string>& excluded_categories); - - // |categories| is a comma-delimited list of category wildcards. - // A category can have an optional '-' prefix to make it an excluded category. - // All the same rules apply above, so for example, having both included and - // excluded categories in the same list would not be supported. - // - // Example: SetEnabled("test_MyTest*"); - // Example: SetEnabled("test_MyTest*,test_OtherStuff"); - // Example: SetEnabled("-excluded_category1,-excluded_category2"); - void SetEnabled(const std::string& categories); - - // Retieves the categories set via a prior call to SetEnabled(). Only - // meaningful if |IsEnabled()| is true. - void GetEnabledTraceCategories(std::vector<std::string>* included_out, - std::vector<std::string>* excluded_out); - - // Disable tracing for all categories. - void SetDisabled(); - // Helper method to enable/disable tracing for all categories. - void SetEnabled(bool enabled); - bool IsEnabled() { return enabled_; } - - float GetBufferPercentFull() const; - - // When enough events are collected, they are handed (in bulk) to - // the output callback. If no callback is set, the output will be - // silently dropped. The callback must be thread safe. The string format is - // undefined. Use TraceResultBuffer to convert one or more trace strings to - // JSON. - typedef RefCountedData<std::string> RefCountedString; - typedef base::Callback<void(const scoped_refptr<RefCountedString>&)> - OutputCallback; - void SetOutputCallback(const OutputCallback& cb); - - // The trace buffer does not flush dynamically, so when it fills up, - // subsequent trace events will be dropped. This callback is generated when - // the trace buffer is full. The callback must be thread safe. - typedef base::Callback<void(void)> BufferFullCallback; - void SetBufferFullCallback(const BufferFullCallback& cb); - - // Flushes all logged data to the callback. - void Flush(); - - // Called by TRACE_EVENT* macros, don't call this directly. - 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 - // -1 if the event was not added. - // On end events, the return value of the begin event can be specified along - // with a threshold in microseconds. If the elapsed time between begin and end - // 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(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); - static void AddTraceEventEtw(char phase, - const char* name, - const void* id, - const char* extra); - 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. - 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. - 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_; } - - // Exposed for unittesting: - - // Allows deleting our singleton instance. - static void DeleteForTesting(); - - // Allows resurrecting our singleton instance post-AtExit processing. - static void Resurrect(); - - // Allow tests to inspect TraceEvents. - size_t GetEventsSize() const { return logged_events_.size(); } - const TraceEvent& GetEventAt(size_t index) const { - DCHECK(index < logged_events_.size()); - return logged_events_[index]; - } - - void SetProcessID(int process_id); - - private: - // This allows constructor and destructor to be private and usable only - // by the Singleton class. - friend struct StaticMemorySingletonTraits<TraceLog>; - - TraceLog(); - ~TraceLog(); - const unsigned char* GetCategoryEnabledInternal(const char* name); - void AddThreadNameMetadataEvents(); - void AddClockSyncMetadataEvents(); - - // TODO(nduca): switch to per-thread trace buffers to reduce thread - // synchronization. - Lock lock_; - bool enabled_; - OutputCallback output_callback_; - BufferFullCallback buffer_full_callback_; - std::vector<TraceEvent> logged_events_; - std::vector<std::string> included_categories_; - std::vector<std::string> excluded_categories_; - - base::hash_map<int, std::string> thread_names_; - - // XORed with TraceID to make it unlikely to collide with other processes. - unsigned long long process_id_hash_; - - int process_id_; - - DISALLOW_COPY_AND_ASSIGN(TraceLog); -}; - -} // namespace debug -} // namespace base - namespace trace_event_internal { // Specify these values when the corresponding argument of AddTraceEvent is not diff --git a/base/debug/trace_event_impl.cc b/base/debug/trace_event_impl.cc new file mode 100644 index 0000000..0608c78 --- /dev/null +++ b/base/debug/trace_event_impl.cc @@ -0,0 +1,720 @@ +// 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_impl.h" + +#include <algorithm> + +#include "base/bind.h" +#include "base/debug/trace_event.h" +#include "base/file_util.h" +#include "base/format_macros.h" +#include "base/lazy_instance.h" +#include "base/memory/singleton.h" +#include "base/process_util.h" +#include "base/stringprintf.h" +#include "base/string_tokenizer.h" +#include "base/threading/platform_thread.h" +#include "base/threading/thread_local.h" +#include "base/utf_string_conversions.h" +#include "base/stl_util.h" +#include "base/sys_info.h" +#include "base/time.h" + +#if defined(OS_WIN) +#include "base/debug/trace_event_win.h" +#endif + +class DeleteTraceLogForTesting { + public: + static void Delete() { + Singleton<base::debug::TraceLog, + StaticMemorySingletonTraits<base::debug::TraceLog> >::OnExit(0); + } +}; + +namespace base { +namespace debug { + +// Controls the number of trace events we will buffer in-memory +// before throwing them away. +const size_t kTraceEventBufferSize = 500000; +const size_t kTraceEventBatchSize = 1000; + +#define TRACE_EVENT_MAX_CATEGORIES 100 + +namespace { + +// 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", +}; +// 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 +LazyInstance<ThreadLocalPointer<const char>, + LeakyLazyInstanceTraits<ThreadLocalPointer<const char> > > + g_current_thread_name = LAZY_INSTANCE_INITIALIZER; + +void AppendValueAsJSON(unsigned char type, + TraceEvent::TraceValue value, + std::string* out) { + std::string::size_type start_pos; + switch (type) { + case TRACE_VALUE_TYPE_BOOL: + *out += value.as_bool ? "true" : "false"; + break; + case TRACE_VALUE_TYPE_UINT: + StringAppendF(out, "%" PRIu64, static_cast<uint64>(value.as_uint)); + break; + case TRACE_VALUE_TYPE_INT: + StringAppendF(out, "%" PRId64, static_cast<int64>(value.as_int)); + break; + case TRACE_VALUE_TYPE_DOUBLE: + StringAppendF(out, "%f", value.as_double); + break; + 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>( + value.as_pointer))); + break; + case TRACE_VALUE_TYPE_STRING: + case TRACE_VALUE_TYPE_COPY_STRING: + *out += "\""; + start_pos = out->size(); + *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) { + out->insert(start_pos, 1, '\\'); + // skip inserted escape character and following character. + start_pos += 2; + } + *out += "\""; + break; + default: + NOTREACHED() << "Don't know how to print this value"; + break; + } +} + +} // namespace + +//////////////////////////////////////////////////////////////////////////////// +// +// TraceEvent +// +//////////////////////////////////////////////////////////////////////////////// + +namespace { + +size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; } + +// Copies |*member| into |*buffer|, sets |*member| to point to this new +// location, and then advances |*buffer| by the amount written. +void CopyTraceEventParameter(char** buffer, + const char** member, + const char* end) { + if (*member) { + size_t written = strlcpy(*buffer, *member, end - *buffer) + 1; + DCHECK_LE(static_cast<int>(written), end - *buffer); + *member = *buffer; + *buffer += written; + } +} + +} // namespace + +TraceEvent::TraceEvent() + : id_(0u), + category_enabled_(NULL), + name_(NULL), + thread_id_(0), + phase_(TRACE_EVENT_PHASE_BEGIN), + flags_(0) { + arg_names_[0] = NULL; + arg_names_[1] = NULL; +} + +TraceEvent::TraceEvent(int thread_id, + TimeTicks timestamp, + 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, + unsigned char flags) + : timestamp_(timestamp), + id_(id), + category_enabled_(category_enabled), + name_(name), + thread_id_(thread_id), + phase_(phase), + flags_(flags) { + // 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); + 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 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; + parameter_copy_storage_->data().resize(alloc_size); + char* ptr = string_as_array(¶meter_copy_storage_->data()); + const char* end = ptr + alloc_size; + if (copy) { + CopyTraceEventParameter(&ptr, &name_, 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); + } + DCHECK_EQ(end, ptr) << "Overrun by " << ptr - end; + } +} + +TraceEvent::~TraceEvent() { +} + +void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events, + size_t start, + size_t count, + std::string* out) { + for (size_t i = 0; i < count && start + i < events.size(); ++i) { + if (i > 0) + *out += ","; + events[i + start].AppendAsJSON(out); + } +} + +void TraceEvent::AppendAsJSON(std::string* out) const { + int64 time_int64 = timestamp_.ToInternalValue(); + int process_id = TraceLog::GetInstance()->process_id(); + // Category name checked at category creation time. + DCHECK(!strchr(name_, '"')); + StringAppendF(out, + "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 "," + "\"ph\":\"%c\",\"name\":\"%s\",\"args\":{", + TraceLog::GetCategoryName(category_enabled_), + process_id, + thread_id_, + time_int64, + phase_, + name_); + + // Output argument names and values, stop at first NULL argument name. + for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { + if (i > 0) + *out += ","; + *out += "\""; + *out += arg_names_[i]; + *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 "\"", static_cast<uint64>(id_)); + *out += "}"; +} + +//////////////////////////////////////////////////////////////////////////////// +// +// TraceResultBuffer +// +//////////////////////////////////////////////////////////////////////////////// + +TraceResultBuffer::OutputCallback + TraceResultBuffer::SimpleOutput::GetCallback() { + return base::Bind(&SimpleOutput::Append, base::Unretained(this)); +} + +void TraceResultBuffer::SimpleOutput::Append( + const std::string& json_trace_output) { + json_output += json_trace_output; +} + +TraceResultBuffer::TraceResultBuffer() : append_comma_(false) { +} + +TraceResultBuffer::~TraceResultBuffer() { +} + +void TraceResultBuffer::SetOutputCallback( + const OutputCallback& json_chunk_callback) { + output_callback_ = json_chunk_callback; +} + +void TraceResultBuffer::Start() { + append_comma_ = false; + output_callback_.Run("["); +} + +void TraceResultBuffer::AddFragment(const std::string& trace_fragment) { + if (append_comma_) + output_callback_.Run(","); + append_comma_ = true; + output_callback_.Run(trace_fragment); +} + +void TraceResultBuffer::Finish() { + output_callback_.Run("]"); +} + +//////////////////////////////////////////////////////////////////////////////// +// +// TraceLog +// +//////////////////////////////////////////////////////////////////////////////// + +// static +TraceLog* TraceLog::GetInstance() { + return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get(); +} + +TraceLog::TraceLog() + : enabled_(false) { + SetProcessID(static_cast<int>(base::GetCurrentProcId())); +} + +TraceLog::~TraceLog() { +} + +const unsigned char* TraceLog::GetCategoryEnabled(const char* name) { + TraceLog* tracelog = GetInstance(); + if (!tracelog) { + DCHECK(!g_category_enabled[g_category_already_shutdown]); + return &g_category_enabled[g_category_already_shutdown]; + } + 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, + 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], ci->c_str()); + if (is_match) + break; + } + ANNOTATE_BENIGN_RACE(&g_category_enabled[category_index], + "trace_event category enabled"); + 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, + unsigned char is_included) { + for (int i = 0; i < g_category_index; i++) + EnableMatchingCategory(i, patterns, is_included); +} + +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) == 0) + return &g_category_enabled[i]; + } + + // Create a new category + DCHECK(g_category_index < TRACE_EVENT_MAX_CATEGORIES) << + "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; + 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_, 1); + else + EnableMatchingCategory(new_index, excluded_categories_, 0); + } else { + ANNOTATE_BENIGN_RACE(&g_category_enabled[new_index], + "trace_event category enabled"); + g_category_enabled[new_index] = 0; + } + return &g_category_enabled[new_index]; + } else { + 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]); +} + +void TraceLog::SetEnabled(const std::vector<std::string>& included_categories, + const std::vector<std::string>& excluded_categories) { + AutoLock lock(lock_); + if (enabled_) + return; + logged_events_.reserve(1024); + enabled_ = true; + included_categories_ = included_categories; + excluded_categories_ = excluded_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_, 1); + else + EnableMatchingCategories(excluded_categories_, 0); +} + +void TraceLog::SetEnabled(const std::string& categories) { + std::vector<std::string> included, excluded; + // Tokenize list of categories, delimited by ','. + StringTokenizer tokens(categories, ","); + while (tokens.GetNext()) { + bool is_included = true; + std::string category = tokens.token(); + // Excluded categories start with '-'. + if (category.at(0) == '-') { + // Remove '-' from category string. + category = category.substr(1); + is_included = false; + } + if (is_included) + included.push_back(category); + else + excluded.push_back(category); + } + SetEnabled(included, excluded); +} + +void TraceLog::GetEnabledTraceCategories( + std::vector<std::string>* included_out, + std::vector<std::string>* excluded_out) { + AutoLock lock(lock_); + if (enabled_) { + *included_out = included_categories_; + *excluded_out = excluded_categories_; + } +} + +void TraceLog::SetDisabled() { + { + AutoLock lock(lock_); + if (!enabled_) + return; + + enabled_ = false; + included_categories_.clear(); + excluded_categories_.clear(); + for (int i = 0; i < g_category_index; i++) + g_category_enabled[i] = 0; + AddThreadNameMetadataEvents(); + AddClockSyncMetadataEvents(); + } // release lock + Flush(); +} + +void TraceLog::SetEnabled(bool enabled) { + if (enabled) + SetEnabled(std::vector<std::string>(), std::vector<std::string>()); + else + SetDisabled(); +} + +float TraceLog::GetBufferPercentFull() const { + return (float)((double)logged_events_.size()/(double)kTraceEventBufferSize); +} + +void TraceLog::SetOutputCallback(const TraceLog::OutputCallback& cb) { + AutoLock lock(lock_); + output_callback_ = cb; +} + +void TraceLog::SetBufferFullCallback(const TraceLog::BufferFullCallback& cb) { + AutoLock lock(lock_); + buffer_full_callback_ = cb; +} + +void TraceLog::Flush() { + std::vector<TraceEvent> previous_logged_events; + OutputCallback output_callback_copy; + { + AutoLock lock(lock_); + previous_logged_events.swap(logged_events_); + output_callback_copy = output_callback_; + } // release lock + + if (output_callback_copy.is_null()) + return; + + for (size_t i = 0; + i < previous_logged_events.size(); + i += kTraceEventBatchSize) { + scoped_refptr<RefCountedString> json_events_str_ptr = + new RefCountedString(); + TraceEvent::AppendEventsAsJSON(previous_logged_events, + i, + kTraceEventBatchSize, + &(json_events_str_ptr->data)); + output_callback_copy.Run(json_events_str_ptr); + } +} + +int TraceLog::AddTraceEvent(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) { + DCHECK(name); + TimeTicks now = TimeTicks::HighResNow(); + BufferFullCallback buffer_full_callback_copy; + int ret_begin_id = -1; + { + AutoLock lock(lock_); + if (!*category_enabled) + return -1; + if (logged_events_.size() >= kTraceEventBufferSize) + return -1; + + int thread_id = static_cast<int>(PlatformThread::CurrentId()); + + const char* new_name = PlatformThread::GetName(); + // Check if the thread name has been set or changed since the previous + // call (if any), but don't bother if the new name is empty. Note this will + // not detect a thread name change within the same char* buffer address: we + // favor common case performance over corner case correctness. + if (new_name != g_current_thread_name.Get().Get() && + new_name && *new_name) { + g_current_thread_name.Get().Set(new_name); + base::hash_map<int, std::string>::iterator existing_name = + thread_names_.find(thread_id); + if (existing_name == thread_names_.end()) { + // This is a new thread id, and a new name. + thread_names_[thread_id] = new_name; + } else { + // This is a thread id that we've seen before, but potentially with a + // new name. + std::vector<base::StringPiece> existing_names; + Tokenize(existing_name->second, ",", &existing_names); + bool found = std::find(existing_names.begin(), + existing_names.end(), + new_name) != existing_names.end(); + if (!found) { + existing_name->second.push_back(','); + existing_name->second.append(new_name); + } + } + } + + if (threshold_begin_id > -1) { + DCHECK(phase == TRACE_EVENT_PHASE_END); + size_t begin_i = static_cast<size_t>(threshold_begin_id); + // Return now if there has been a flush since the begin event was posted. + if (begin_i >= logged_events_.size()) + return -1; + // Determine whether to drop the begin/end pair. + TimeDelta elapsed = now - logged_events_[begin_i].timestamp(); + if (elapsed < TimeDelta::FromMicroseconds(threshold)) { + // Remove begin event and do not add end event. + // This will be expensive if there have been other events in the + // mean time (should be rare). + logged_events_.erase(logged_events_.begin() + begin_i); + return -1; + } + } + ret_begin_id = static_cast<int>(logged_events_.size()); + logged_events_.push_back( + TraceEvent(thread_id, + now, phase, category_enabled, name, id, + num_args, arg_names, arg_types, arg_values, + flags)); + + if (logged_events_.size() == kTraceEventBufferSize) { + buffer_full_callback_copy = buffer_full_callback_; + } + } // release lock + + if (!buffer_full_callback_copy.is_null()) + buffer_full_callback_copy.Run(); + + return ret_begin_id; +} + +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, + TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra); +} + +void TraceLog::AddTraceEventEtw(char phase, + const char* name, + const void* id, + const std::string& extra) +{ +#if defined(OS_WIN) + TraceEventETWProvider::Trace(name, phase, id, extra); +#endif + INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name, + TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra); +} + +void TraceLog::AddClockSyncMetadataEvents() { +#if defined(OS_ANDROID) + // Since Android does not support sched_setaffinity, we cannot establish clock + // sync unless the scheduler clock is set to global. If the trace_clock file + // can't be read, we will assume the kernel doesn't support tracing and do + // nothing. + std::string clock_mode; + if (!file_util::ReadFileToString( + FilePath("/sys/kernel/debug/tracing/trace_clock"), + &clock_mode)) + return; + + if (clock_mode != "local [global]\n") { + DLOG(WARNING) << + "The kernel's tracing clock must be set to global in order for " << + "trace_event to be synchronized with . Do this by\n" << + " echo global > /sys/kerel/debug/tracing/trace_clock"; + return; + } + + // Android's kernel trace system has a trace_marker feature: this is a file on + // debugfs that takes the written data and pushes it onto the trace + // buffer. So, to establish clock sync, we write our monotonic clock into that + // trace buffer. + TimeTicks now = TimeTicks::HighResNow(); + + double now_in_seconds = now.ToInternalValue() / 1000000.0; + std::string marker = + StringPrintf("trace_event_clock_sync: parent_ts=%f\n", + now_in_seconds); + if (file_util::WriteFile( + FilePath("/sys/kernel/debug/tracing/trace_marker"), + marker.c_str(), marker.size()) == -1) { + DLOG(WARNING) << "Couldn't write to /sys/kernel/debug/tracing/trace_marker"; + return; + } +#endif +} + +void TraceLog::AddThreadNameMetadataEvents() { + lock_.AssertAcquired(); + for(base::hash_map<int, std::string>::iterator it = thread_names_.begin(); + it != thread_names_.end(); + it++) { + 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_enabled[g_category_metadata], + "thread_name", trace_event_internal::kNoEventId, + num_args, &arg_name, &arg_type, &arg_value, + TRACE_EVENT_FLAG_NONE)); + } + } +} + +void TraceLog::DeleteForTesting() { + DeleteTraceLogForTesting::Delete(); +} + +void TraceLog::Resurrect() { + StaticMemorySingletonTraits<TraceLog>::Resurrect(); +} + +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. + 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 debug +} // namespace base diff --git a/base/debug/trace_event_impl.h b/base/debug/trace_event_impl.h new file mode 100644 index 0000000..60323b4 --- /dev/null +++ b/base/debug/trace_event_impl.h @@ -0,0 +1,311 @@ +// 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. + + +#ifndef BASE_DEBUG_TRACE_EVENT_IMPL_H_ +#define BASE_DEBUG_TRACE_EVENT_IMPL_H_ +#pragma once + +#include "build/build_config.h" + +#include <string> +#include <vector> + +#include "base/callback.h" +#include "base/hash_tables.h" +#include "base/memory/ref_counted_memory.h" +#include "base/string_util.h" +#include "base/synchronization/lock.h" +#include "base/third_party/dynamic_annotations/dynamic_annotations.h" +#include "base/timer.h" + +// Older style trace macros with explicit id and extra data +// Only these macros result in publishing data to ETW as currently implemented. +#define TRACE_EVENT_BEGIN_ETW(name, id, extra) \ + base::debug::TraceLog::AddTraceEventEtw( \ + TRACE_EVENT_PHASE_BEGIN, \ + name, reinterpret_cast<const void*>(id), extra) + +#define TRACE_EVENT_END_ETW(name, id, extra) \ + base::debug::TraceLog::AddTraceEventEtw( \ + TRACE_EVENT_PHASE_END, \ + name, reinterpret_cast<const void*>(id), extra) + +#define TRACE_EVENT_INSTANT_ETW(name, id, extra) \ + base::debug::TraceLog::AddTraceEventEtw( \ + TRACE_EVENT_PHASE_INSTANT, \ + name, reinterpret_cast<const void*>(id), extra) + +template <typename Type> +struct StaticMemorySingletonTraits; + +namespace base { + +class RefCountedString; + +namespace debug { + +const int kTraceMaxNumArgs = 2; + +// Output records are "Events" and can be obtained via the +// OutputCallback whenever the tracing system decides to flush. This +// can happen at any time, on any thread, or you can programatically +// 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, + 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, + unsigned char flags); + ~TraceEvent(); + + // Serialize event data to JSON + static void AppendEventsAsJSON(const std::vector<TraceEvent>& events, + size_t start, + size_t count, + std::string* out); + void AppendAsJSON(std::string* out) const; + + TimeTicks timestamp() const { return timestamp_; } + + // Exposed for unittesting: + + const base::RefCountedString* parameter_copy_storage() const { + return parameter_copy_storage_.get(); + } + + const char* name() const { return name_; } + + private: + // Note: these are ordered by size (largest first) for optimal packing. + TimeTicks timestamp_; + // id_ can be used to store phase-specific data. + unsigned long long id_; + TraceValue arg_values_[kTraceMaxNumArgs]; + const char* arg_names_[kTraceMaxNumArgs]; + const unsigned char* category_enabled_; + const char* name_; + scoped_refptr<base::RefCountedString> parameter_copy_storage_; + int thread_id_; + char phase_; + unsigned char flags_; + unsigned char arg_types_[kTraceMaxNumArgs]; +}; + + +// TraceResultBuffer collects and converts trace fragments returned by TraceLog +// to JSON output. +class BASE_EXPORT TraceResultBuffer { + public: + typedef base::Callback<void(const std::string&)> OutputCallback; + + // If you don't need to stream JSON chunks out efficiently, and just want to + // get a complete JSON string after calling Finish, use this struct to collect + // JSON trace output. + struct BASE_EXPORT SimpleOutput { + OutputCallback GetCallback(); + void Append(const std::string& json_string); + + // Do what you want with the json_output_ string after calling + // TraceResultBuffer::Finish. + std::string json_output; + }; + + TraceResultBuffer(); + ~TraceResultBuffer(); + + // Set callback. The callback will be called during Start with the initial + // JSON output and during AddFragment and Finish with following JSON output + // chunks. The callback target must live past the last calls to + // TraceResultBuffer::Start/AddFragment/Finish. + void SetOutputCallback(const OutputCallback& json_chunk_callback); + + // Start JSON output. This resets all internal state, so you can reuse + // the TraceResultBuffer by calling Start. + void Start(); + + // Call AddFragment 0 or more times to add trace fragments from TraceLog. + void AddFragment(const std::string& trace_fragment); + + // When all fragments have been added, call Finish to complete the JSON + // formatted output. + void Finish(); + + private: + OutputCallback output_callback_; + bool append_comma_; +}; + + +class BASE_EXPORT TraceLog { + public: + static TraceLog* GetInstance(); + + // Get set of known categories. This can change as new code paths are reached. + // The known categories are inserted into |categories|. + void GetKnownCategories(std::vector<std::string>* categories); + + // Enable tracing for provided list of categories. If tracing is already + // enabled, this method does nothing -- changing categories during trace is + // not supported. + // If both included_categories and excluded_categories are empty, + // all categories are traced. + // Else if included_categories is non-empty, only those are traced. + // Else if excluded_categories is non-empty, everything but those are traced. + // Wildcards * and ? are supported (see MatchPattern in string_util.h). + void SetEnabled(const std::vector<std::string>& included_categories, + const std::vector<std::string>& excluded_categories); + + // |categories| is a comma-delimited list of category wildcards. + // A category can have an optional '-' prefix to make it an excluded category. + // All the same rules apply above, so for example, having both included and + // excluded categories in the same list would not be supported. + // + // Example: SetEnabled("test_MyTest*"); + // Example: SetEnabled("test_MyTest*,test_OtherStuff"); + // Example: SetEnabled("-excluded_category1,-excluded_category2"); + void SetEnabled(const std::string& categories); + + // Retieves the categories set via a prior call to SetEnabled(). Only + // meaningful if |IsEnabled()| is true. + void GetEnabledTraceCategories(std::vector<std::string>* included_out, + std::vector<std::string>* excluded_out); + + // Disable tracing for all categories. + void SetDisabled(); + // Helper method to enable/disable tracing for all categories. + void SetEnabled(bool enabled); + bool IsEnabled() { return enabled_; } + + float GetBufferPercentFull() const; + + // When enough events are collected, they are handed (in bulk) to + // the output callback. If no callback is set, the output will be + // silently dropped. The callback must be thread safe. The string format is + // undefined. Use TraceResultBuffer to convert one or more trace strings to + // JSON. + typedef RefCountedData<std::string> RefCountedString; + typedef base::Callback<void(const scoped_refptr<RefCountedString>&)> + OutputCallback; + void SetOutputCallback(const OutputCallback& cb); + + // The trace buffer does not flush dynamically, so when it fills up, + // subsequent trace events will be dropped. This callback is generated when + // the trace buffer is full. The callback must be thread safe. + typedef base::Callback<void(void)> BufferFullCallback; + void SetBufferFullCallback(const BufferFullCallback& cb); + + // Flushes all logged data to the callback. + void Flush(); + + // Called by TRACE_EVENT* macros, don't call this directly. + 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 + // -1 if the event was not added. + // On end events, the return value of the begin event can be specified along + // with a threshold in microseconds. If the elapsed time between begin and end + // 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(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); + static void AddTraceEventEtw(char phase, + const char* name, + const void* id, + const char* extra); + static void AddTraceEventEtw(char phase, + const char* name, + const void* id, + const std::string& extra); + + // Mangle |ptr| with a hash based on the process ID so that if |ptr| occurs on + // more than one process, it will not collide. + 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_; } + + // Exposed for unittesting: + + // Allows deleting our singleton instance. + static void DeleteForTesting(); + + // Allows resurrecting our singleton instance post-AtExit processing. + static void Resurrect(); + + // Allow tests to inspect TraceEvents. + size_t GetEventsSize() const { return logged_events_.size(); } + const TraceEvent& GetEventAt(size_t index) const { + DCHECK(index < logged_events_.size()); + return logged_events_[index]; + } + + void SetProcessID(int process_id); + + private: + // This allows constructor and destructor to be private and usable only + // by the Singleton class. + friend struct StaticMemorySingletonTraits<TraceLog>; + + TraceLog(); + ~TraceLog(); + const unsigned char* GetCategoryEnabledInternal(const char* name); + void AddThreadNameMetadataEvents(); + void AddClockSyncMetadataEvents(); + + // TODO(nduca): switch to per-thread trace buffers to reduce thread + // synchronization. + Lock lock_; + bool enabled_; + OutputCallback output_callback_; + BufferFullCallback buffer_full_callback_; + std::vector<TraceEvent> logged_events_; + std::vector<std::string> included_categories_; + std::vector<std::string> excluded_categories_; + + base::hash_map<int, std::string> thread_names_; + + // XORed with TraceID to make it unlikely to collide with other processes. + unsigned long long process_id_hash_; + + int process_id_; + + DISALLOW_COPY_AND_ASSIGN(TraceLog); +}; + +} // namespace debug +} // namespace base + +#endif // BASE_DEBUG_TRACE_EVENT_IMPL_H_ |