base/debug/trace_event_impl.cc

   1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "base/debug/trace_event_impl.h"
   6
   7 #include <algorithm>
   8
   9 #include "base/bind.h"
  10 #include "base/debug/leak_annotations.h"
  11 #include "base/debug/trace_event.h"
  12 #include "base/format_macros.h"
  13 #include "base/lazy_instance.h"
  14 #include "base/memory/singleton.h"
  15 #include "base/process_util.h"
  16 #include "base/stl_util.h"
  17 #include "base/stringprintf.h"
  18 #include "base/string_tokenizer.h"
  19 #include "base/string_util.h"
  20 #include "base/sys_info.h"
  21 #include "base/third_party/dynamic_annotations/dynamic_annotations.h"
  22 #include "base/threading/platform_thread.h"
  23 #include "base/threading/thread_local.h"
  24 #include "base/time.h"
  25 #include "base/utf_string_conversions.h"
  26
  27 #if defined(OS_WIN)
  28 #include "base/debug/trace_event_win.h"
  29 #endif
  30
  31 class DeleteTraceLogForTesting {
  32  public:
  33   static void Delete() {
  34     Singleton<base::debug::TraceLog,
  35               StaticMemorySingletonTraits<base::debug::TraceLog> >::OnExit(0);
  36   }
  37 };
  38
  39 namespace base {
  40 namespace debug {
  41
  42 // Controls the number of trace events we will buffer in-memory
  43 // before throwing them away.
  44 const size_t kTraceEventBufferSize = 500000;
  45 const size_t kTraceEventBatchSize = 1000;
  46
  47 #define TRACE_EVENT_MAX_CATEGORIES 100
  48
  49 namespace {
  50
  51 // Parallel arrays g_categories and g_category_enabled are separate so that
  52 // a pointer to a member of g_category_enabled can be easily converted to an
  53 // index into g_categories. This allows macros to deal only with char enabled
  54 // pointers from g_category_enabled, and we can convert internally to determine
  55 // the category name from the char enabled pointer.
  56 const char* g_categories[TRACE_EVENT_MAX_CATEGORIES] = {
  57   "tracing already shutdown",
  58   "tracing categories exhausted; must increase TRACE_EVENT_MAX_CATEGORIES",
  59   "__metadata",
  60 };
  61 // The enabled flag is char instead of bool so that the API can be used from C.
  62 unsigned char g_category_enabled[TRACE_EVENT_MAX_CATEGORIES] = { 0 };
  63 const int g_category_already_shutdown = 0;
  64 const int g_category_categories_exhausted = 1;
  65 const int g_category_metadata = 2;
  66 int g_category_index = 3; // skip initial 3 categories
  67
  68 // The most-recently captured name of the current thread
  69 LazyInstance<ThreadLocalPointer<const char> >::Leaky
  70     g_current_thread_name = LAZY_INSTANCE_INITIALIZER;
  71
  72 }  // namespace
  73
  74 ////////////////////////////////////////////////////////////////////////////////
  75 //
  76 // TraceEvent
  77 //
  78 ////////////////////////////////////////////////////////////////////////////////
  79
  80 namespace {
  81
  82 size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; }
  83
  84 // Copies |*member| into |*buffer|, sets |*member| to point to this new
  85 // location, and then advances |*buffer| by the amount written.
  86 void CopyTraceEventParameter(char** buffer,
  87                              const char** member,
  88                              const char* end) {
  89   if (*member) {
  90     size_t written = strlcpy(*buffer, *member, end - *buffer) + 1;
  91     DCHECK_LE(static_cast<int>(written), end - *buffer);
  92     *member = *buffer;
  93     *buffer += written;
  94   }
  95 }
  96
  97 }  // namespace
  98
  99 TraceEvent::TraceEvent()
 100     : id_(0u),
 101       category_enabled_(NULL),
 102       name_(NULL),
 103       thread_id_(0),
 104       phase_(TRACE_EVENT_PHASE_BEGIN),
 105       flags_(0) {
 106   arg_names_[0] = NULL;
 107   arg_names_[1] = NULL;
 108   memset(arg_values_, 0, sizeof(arg_values_));
 109 }
 110
 111 TraceEvent::TraceEvent(int thread_id,
 112                        TimeTicks timestamp,
 113                        char phase,
 114                        const unsigned char* category_enabled,
 115                        const char* name,
 116                        unsigned long long id,
 117                        int num_args,
 118                        const char** arg_names,
 119                        const unsigned char* arg_types,
 120                        const unsigned long long* arg_values,
 121                        unsigned char flags)
 122     : timestamp_(timestamp),
 123       id_(id),
 124       category_enabled_(category_enabled),
 125       name_(name),
 126       thread_id_(thread_id),
 127       phase_(phase),
 128       flags_(flags) {
 129   // Clamp num_args since it may have been set by a third_party library.
 130   num_args = (num_args > kTraceMaxNumArgs) ? kTraceMaxNumArgs : num_args;
 131   int i = 0;
 132   for (; i < num_args; ++i) {
 133     arg_names_[i] = arg_names[i];
 134     arg_values_[i].as_uint = arg_values[i];
 135     arg_types_[i] = arg_types[i];
 136   }
 137   for (; i < kTraceMaxNumArgs; ++i) {
 138     arg_names_[i] = NULL;
 139     arg_values_[i].as_uint = 0u;
 140     arg_types_[i] = TRACE_VALUE_TYPE_UINT;
 141   }
 142
 143   bool copy = !!(flags & TRACE_EVENT_FLAG_COPY);
 144   size_t alloc_size = 0;
 145   if (copy) {
 146     alloc_size += GetAllocLength(name);
 147     for (i = 0; i < num_args; ++i) {
 148       alloc_size += GetAllocLength(arg_names_[i]);
 149       if (arg_types_[i] == TRACE_VALUE_TYPE_STRING)
 150         arg_types_[i] = TRACE_VALUE_TYPE_COPY_STRING;
 151     }
 152   }
 153
 154   bool arg_is_copy[kTraceMaxNumArgs];
 155   for (i = 0; i < num_args; ++i) {
 156     // We only take a copy of arg_vals if they are of type COPY_STRING.
 157     arg_is_copy[i] = (arg_types_[i] == TRACE_VALUE_TYPE_COPY_STRING);
 158     if (arg_is_copy[i])
 159       alloc_size += GetAllocLength(arg_values_[i].as_string);
 160   }
 161
 162   if (alloc_size) {
 163     parameter_copy_storage_ = new base::RefCountedString;
 164     parameter_copy_storage_->data().resize(alloc_size);
 165     char* ptr = string_as_array(&parameter_copy_storage_->data());
 166     const char* end = ptr + alloc_size;
 167     if (copy) {
 168       CopyTraceEventParameter(&ptr, &name_, end);
 169       for (i = 0; i < num_args; ++i)
 170         CopyTraceEventParameter(&ptr, &arg_names_[i], end);
 171     }
 172     for (i = 0; i < num_args; ++i) {
 173       if (arg_is_copy[i])
 174         CopyTraceEventParameter(&ptr, &arg_values_[i].as_string, end);
 175     }
 176     DCHECK_EQ(end, ptr) << "Overrun by " << ptr - end;
 177   }
 178 }
 179
 180 TraceEvent::~TraceEvent() {
 181 }
 182
 183 // static
 184 void TraceEvent::AppendValueAsJSON(unsigned char type,
 185                                    TraceEvent::TraceValue value,
 186                                    std::string* out) {
 187   std::string::size_type start_pos;
 188   switch (type) {
 189     case TRACE_VALUE_TYPE_BOOL:
 190       *out += value.as_bool ? "true" : "false";
 191       break;
 192     case TRACE_VALUE_TYPE_UINT:
 193       StringAppendF(out, "%" PRIu64, static_cast<uint64>(value.as_uint));
 194       break;
 195     case TRACE_VALUE_TYPE_INT:
 196       StringAppendF(out, "%" PRId64, static_cast<int64>(value.as_int));
 197       break;
 198     case TRACE_VALUE_TYPE_DOUBLE:
 199       StringAppendF(out, "%f", value.as_double);
 200       break;
 201     case TRACE_VALUE_TYPE_POINTER:
 202       // JSON only supports double and int numbers.
 203       // So as not to lose bits from a 64-bit pointer, output as a hex string.
 204       StringAppendF(out, "\"%" PRIx64 "\"", static_cast<uint64>(
 205                                      reinterpret_cast<intptr_t>(
 206                                      value.as_pointer)));
 207       break;
 208     case TRACE_VALUE_TYPE_STRING:
 209     case TRACE_VALUE_TYPE_COPY_STRING:
 210       *out += "\"";
 211       start_pos = out->size();
 212       *out += value.as_string ? value.as_string : "NULL";
 213       // insert backslash before special characters for proper json format.
 214       while ((start_pos = out->find_first_of("\\\"", start_pos)) !=
 215              std::string::npos) {
 216         out->insert(start_pos, 1, '\\');
 217         // skip inserted escape character and following character.
 218         start_pos += 2;
 219       }
 220       *out += "\"";
 221       break;
 222     default:
 223       NOTREACHED() << "Don't know how to print this value";
 224       break;
 225   }
 226 }
 227
 228 void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events,
 229                                     size_t start,
 230                                     size_t count,
 231                                     std::string* out) {
 232   for (size_t i = 0; i < count && start + i < events.size(); ++i) {
 233     if (i > 0)
 234       *out += ",";
 235     events[i + start].AppendAsJSON(out);
 236   }
 237 }
 238
 239 void TraceEvent::AppendAsJSON(std::string* out) const {
 240   int64 time_int64 = timestamp_.ToInternalValue();
 241   int process_id = TraceLog::GetInstance()->process_id();
 242   // Category name checked at category creation time.
 243   DCHECK(!strchr(name_, '"'));
 244   StringAppendF(out,
 245       "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 ","
 246       "\"ph\":\"%c\",\"name\":\"%s\",\"args\":{",
 247       TraceLog::GetCategoryName(category_enabled_),
 248       process_id,
 249       thread_id_,
 250       time_int64,
 251       phase_,
 252       name_);
 253
 254   // Output argument names and values, stop at first NULL argument name.
 255   for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) {
 256     if (i > 0)
 257       *out += ",";
 258     *out += "\"";
 259     *out += arg_names_[i];
 260     *out += "\":";
 261     AppendValueAsJSON(arg_types_[i], arg_values_[i], out);
 262   }
 263   *out += "}";
 264
 265   // If id_ is set, print it out as a hex string so we don't loose any
 266   // bits (it might be a 64-bit pointer).
 267   if (flags_ & TRACE_EVENT_FLAG_HAS_ID)
 268     StringAppendF(out, ",\"id\":\"%" PRIx64 "\"", static_cast<uint64>(id_));
 269   *out += "}";
 270 }
 271
 272 ////////////////////////////////////////////////////////////////////////////////
 273 //
 274 // TraceResultBuffer
 275 //
 276 ////////////////////////////////////////////////////////////////////////////////
 277
 278 TraceResultBuffer::OutputCallback
 279     TraceResultBuffer::SimpleOutput::GetCallback() {
 280   return base::Bind(&SimpleOutput::Append, base::Unretained(this));
 281 }
 282
 283 void TraceResultBuffer::SimpleOutput::Append(
 284     const std::string& json_trace_output) {
 285   json_output += json_trace_output;
 286 }
 287
 288 TraceResultBuffer::TraceResultBuffer() : append_comma_(false) {
 289 }
 290
 291 TraceResultBuffer::~TraceResultBuffer() {
 292 }
 293
 294 void TraceResultBuffer::SetOutputCallback(
 295     const OutputCallback& json_chunk_callback) {
 296   output_callback_ = json_chunk_callback;
 297 }
 298
 299 void TraceResultBuffer::Start() {
 300   append_comma_ = false;
 301   output_callback_.Run("[");
 302 }
 303
 304 void TraceResultBuffer::AddFragment(const std::string& trace_fragment) {
 305   if (append_comma_)
 306     output_callback_.Run(",");
 307   append_comma_ = true;
 308   output_callback_.Run(trace_fragment);
 309 }
 310
 311 void TraceResultBuffer::Finish() {
 312   output_callback_.Run("]");
 313 }
 314
 315 ////////////////////////////////////////////////////////////////////////////////
 316 //
 317 // TraceLog
 318 //
 319 ////////////////////////////////////////////////////////////////////////////////
 320
 321 TraceLog::NotificationHelper::NotificationHelper(TraceLog* trace_log)
 322     : trace_log_(trace_log),
 323       notification_(0) {
 324 }
 325
 326 TraceLog::NotificationHelper::~NotificationHelper() {
 327 }
 328
 329 void TraceLog::NotificationHelper::AddNotificationWhileLocked(
 330     int notification) {
 331   if (trace_log_->notification_callback_.is_null())
 332     return;
 333   if (notification_ == 0)
 334     callback_copy_ = trace_log_->notification_callback_;
 335   notification_ |= notification;
 336 }
 337
 338 void TraceLog::NotificationHelper::SendNotificationIfAny() {
 339   if (notification_)
 340     callback_copy_.Run(notification_);
 341 }
 342
 343 // static
 344 TraceLog* TraceLog::GetInstance() {
 345   return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get();
 346 }
 347
 348 TraceLog::TraceLog()
 349     : enabled_(false),
 350       dispatching_to_observer_list_(false),
 351       watch_category_(NULL) {
 352   // Trace is enabled or disabled on one thread while other threads are
 353   // accessing the enabled flag. We don't care whether edge-case events are
 354   // traced or not, so we allow races on the enabled flag to keep the trace
 355   // macros fast.
 356   // TODO(jbates): ANNOTATE_BENIGN_RACE_SIZED crashes windows TSAN bots:
 357   // ANNOTATE_BENIGN_RACE_SIZED(g_category_enabled, sizeof(g_category_enabled),
 358   //                            "trace_event category enabled");
 359   for (int i = 0; i < TRACE_EVENT_MAX_CATEGORIES; ++i) {
 360     ANNOTATE_BENIGN_RACE(&g_category_enabled[i],
 361                          "trace_event category enabled");
 362   }
 363 #if defined(OS_NACL)  // NaCl shouldn't expose the process id.
 364   SetProcessID(0);
 365 #else
 366   SetProcessID(static_cast<int>(base::GetCurrentProcId()));
 367 #endif
 368 }
 369
 370 TraceLog::~TraceLog() {
 371 }
 372
 373 const unsigned char* TraceLog::GetCategoryEnabled(const char* name) {
 374   TraceLog* tracelog = GetInstance();
 375   if (!tracelog) {
 376     DCHECK(!g_category_enabled[g_category_already_shutdown]);
 377     return &g_category_enabled[g_category_already_shutdown];
 378   }
 379   return tracelog->GetCategoryEnabledInternal(name);
 380 }
 381
 382 const char* TraceLog::GetCategoryName(const unsigned char* category_enabled) {
 383   // Calculate the index of the category by finding category_enabled in
 384   // g_category_enabled array.
 385   uintptr_t category_begin = reinterpret_cast<uintptr_t>(g_category_enabled);
 386   uintptr_t category_ptr = reinterpret_cast<uintptr_t>(category_enabled);
 387   DCHECK(category_ptr >= category_begin &&
 388          category_ptr < reinterpret_cast<uintptr_t>(g_category_enabled +
 389                                                TRACE_EVENT_MAX_CATEGORIES)) <<
 390       "out of bounds category pointer";
 391   uintptr_t category_index =
 392       (category_ptr - category_begin) / sizeof(g_category_enabled[0]);
 393   return g_categories[category_index];
 394 }
 395
 396 static void EnableMatchingCategory(int category_index,
 397                                    const std::vector<std::string>& patterns,
 398                                    unsigned char matched_value,
 399                                    unsigned char unmatched_value) {
 400   std::vector<std::string>::const_iterator ci = patterns.begin();
 401   bool is_match = false;
 402   for (; ci != patterns.end(); ++ci) {
 403     is_match = MatchPattern(g_categories[category_index], ci->c_str());
 404     if (is_match)
 405       break;
 406   }
 407   g_category_enabled[category_index] = is_match ?
 408       matched_value : unmatched_value;
 409 }
 410
 411 // Enable/disable each category based on the category filters in |patterns|.
 412 // If the category name matches one of the patterns, its enabled status is set
 413 // to |matched_value|. Otherwise its enabled status is set to |unmatched_value|.
 414 static void EnableMatchingCategories(const std::vector<std::string>& patterns,
 415                                      unsigned char matched_value,
 416                                      unsigned char unmatched_value) {
 417   for (int i = 0; i < g_category_index; i++)
 418     EnableMatchingCategory(i, patterns, matched_value, unmatched_value);
 419 }
 420
 421 const unsigned char* TraceLog::GetCategoryEnabledInternal(const char* name) {
 422   AutoLock lock(lock_);
 423   DCHECK(!strchr(name, '"')) << "Category names may not contain double quote";
 424
 425   unsigned char* category_enabled = NULL;
 426   // Search for pre-existing category matching this name
 427   for (int i = 0; i < g_category_index; i++) {
 428     if (strcmp(g_categories[i], name) == 0) {
 429       category_enabled = &g_category_enabled[i];
 430       break;
 431     }
 432   }
 433
 434   if (!category_enabled) {
 435     // Create a new category
 436     DCHECK(g_category_index < TRACE_EVENT_MAX_CATEGORIES) <<
 437         "must increase TRACE_EVENT_MAX_CATEGORIES";
 438     if (g_category_index < TRACE_EVENT_MAX_CATEGORIES) {
 439       int new_index = g_category_index++;
 440       // Don't hold on to the name pointer, so that we can create categories
 441       // with strings not known at compile time (this is required by
 442       // SetWatchEvent).
 443       const char* new_name = base::strdup(name);
 444       ANNOTATE_LEAKING_OBJECT_PTR(new_name);
 445       g_categories[new_index] = new_name;
 446       DCHECK(!g_category_enabled[new_index]);
 447       if (enabled_) {
 448         // Note that if both included and excluded_categories are empty, the
 449         // else clause below excludes nothing, thereby enabling this category.
 450         if (!included_categories_.empty()) {
 451           EnableMatchingCategory(new_index, included_categories_,
 452                                  CATEGORY_ENABLED, 0);
 453         } else {
 454           EnableMatchingCategory(new_index, excluded_categories_,
 455                                  0, CATEGORY_ENABLED);
 456         }
 457       } else {
 458         g_category_enabled[new_index] = 0;
 459       }
 460       category_enabled = &g_category_enabled[new_index];
 461     } else {
 462       category_enabled = &g_category_enabled[g_category_categories_exhausted];
 463     }
 464   }
 465 #if defined(OS_ANDROID)
 466   ApplyATraceEnabledFlag(category_enabled);
 467 #endif
 468   return category_enabled;
 469 }
 470
 471 void TraceLog::GetKnownCategories(std::vector<std::string>* categories) {
 472   AutoLock lock(lock_);
 473   for (int i = 0; i < g_category_index; i++)
 474     categories->push_back(g_categories[i]);
 475 }
 476
 477 void TraceLog::SetEnabled(const std::vector<std::string>& included_categories,
 478                           const std::vector<std::string>& excluded_categories) {
 479   AutoLock lock(lock_);
 480   if (enabled_)
 481     return;
 482
 483   if (dispatching_to_observer_list_) {
 484     DLOG(ERROR) <<
 485         "Cannot manipulate TraceLog::Enabled state from an observer.";
 486     return;
 487   }
 488
 489   dispatching_to_observer_list_ = true;
 490   FOR_EACH_OBSERVER(EnabledStateChangedObserver, enabled_state_observer_list_,
 491                     OnTraceLogWillEnable());
 492   dispatching_to_observer_list_ = false;
 493
 494   logged_events_.reserve(1024);
 495   enabled_ = true;
 496   included_categories_ = included_categories;
 497   excluded_categories_ = excluded_categories;
 498   // Note that if both included and excluded_categories are empty, the else
 499   // clause below excludes nothing, thereby enabling all categories.
 500   if (!included_categories_.empty())
 501     EnableMatchingCategories(included_categories_, CATEGORY_ENABLED, 0);
 502   else
 503     EnableMatchingCategories(excluded_categories_, 0, CATEGORY_ENABLED);
 504 }
 505
 506 void TraceLog::SetEnabled(const std::string& categories) {
 507   std::vector<std::string> included, excluded;
 508   // Tokenize list of categories, delimited by ','.
 509   StringTokenizer tokens(categories, ",");
 510   while (tokens.GetNext()) {
 511     bool is_included = true;
 512     std::string category = tokens.token();
 513     // Excluded categories start with '-'.
 514     if (category.at(0) == '-') {
 515       // Remove '-' from category string.
 516       category = category.substr(1);
 517       is_included = false;
 518     }
 519     if (is_included)
 520       included.push_back(category);
 521     else
 522       excluded.push_back(category);
 523   }
 524   SetEnabled(included, excluded);
 525 }
 526
 527 void TraceLog::GetEnabledTraceCategories(
 528     std::vector<std::string>* included_out,
 529     std::vector<std::string>* excluded_out) {
 530   AutoLock lock(lock_);
 531   if (enabled_) {
 532     *included_out = included_categories_;
 533     *excluded_out = excluded_categories_;
 534   }
 535 }
 536
 537 void TraceLog::SetDisabled() {
 538   AutoLock lock(lock_);
 539   if (!enabled_)
 540     return;
 541
 542   if (dispatching_to_observer_list_) {
 543     DLOG(ERROR)
 544         << "Cannot manipulate TraceLog::Enabled state from an observer.";
 545     return;
 546   }
 547
 548   dispatching_to_observer_list_ = true;
 549   FOR_EACH_OBSERVER(EnabledStateChangedObserver, enabled_state_observer_list_,
 550                     OnTraceLogWillDisable());
 551   dispatching_to_observer_list_ = false;
 552
 553   enabled_ = false;
 554   included_categories_.clear();
 555   excluded_categories_.clear();
 556   watch_category_ = NULL;
 557   watch_event_name_ = "";
 558   for (int i = 0; i < g_category_index; i++)
 559     g_category_enabled[i] = 0;
 560   AddThreadNameMetadataEvents();
 561 #if defined(OS_ANDROID)
 562   AddClockSyncMetadataEvents();
 563 #endif
 564 }
 565
 566 void TraceLog::SetEnabled(bool enabled) {
 567   if (enabled)
 568     SetEnabled(std::vector<std::string>(), std::vector<std::string>());
 569   else
 570     SetDisabled();
 571 }
 572
 573 void TraceLog::AddEnabledStateObserver(EnabledStateChangedObserver* listener) {
 574   enabled_state_observer_list_.AddObserver(listener);
 575 }
 576
 577 void TraceLog::RemoveEnabledStateObserver(
 578     EnabledStateChangedObserver* listener) {
 579   enabled_state_observer_list_.RemoveObserver(listener);
 580 }
 581
 582 float TraceLog::GetBufferPercentFull() const {
 583   return (float)((double)logged_events_.size()/(double)kTraceEventBufferSize);
 584 }
 585
 586 void TraceLog::SetNotificationCallback(
 587     const TraceLog::NotificationCallback& cb) {
 588   AutoLock lock(lock_);
 589   notification_callback_ = cb;
 590 }
 591
 592 void TraceLog::Flush(const TraceLog::OutputCallback& cb) {
 593   std::vector<TraceEvent> previous_logged_events;
 594   {
 595     AutoLock lock(lock_);
 596     previous_logged_events.swap(logged_events_);
 597   }  // release lock
 598
 599   for (size_t i = 0;
 600        i < previous_logged_events.size();
 601        i += kTraceEventBatchSize) {
 602     scoped_refptr<RefCountedString> json_events_str_ptr =
 603         new RefCountedString();
 604     TraceEvent::AppendEventsAsJSON(previous_logged_events,
 605                                    i,
 606                                    kTraceEventBatchSize,
 607                                    &(json_events_str_ptr->data()));
 608     cb.Run(json_events_str_ptr);
 609   }
 610 }
 611
 612 void TraceLog::AddTraceEvent(char phase,
 613                             const unsigned char* category_enabled,
 614                             const char* name,
 615                             unsigned long long id,
 616                             int num_args,
 617                             const char** arg_names,
 618                             const unsigned char* arg_types,
 619                             const unsigned long long* arg_values,
 620                             unsigned char flags) {
 621   DCHECK(name);
 622
 623 #if defined(OS_ANDROID)
 624   SendToATrace(phase, GetCategoryName(category_enabled), name,
 625                num_args, arg_names, arg_types, arg_values);
 626 #endif
 627
 628   TimeTicks now = TimeTicks::NowFromSystemTraceTime() - time_offset_;
 629   NotificationHelper notifier(this);
 630   {
 631     AutoLock lock(lock_);
 632     if (*category_enabled != CATEGORY_ENABLED)
 633       return;
 634     if (logged_events_.size() >= kTraceEventBufferSize)
 635       return;
 636
 637     int thread_id = static_cast<int>(PlatformThread::CurrentId());
 638
 639     const char* new_name = PlatformThread::GetName();
 640     // Check if the thread name has been set or changed since the previous
 641     // call (if any), but don't bother if the new name is empty. Note this will
 642     // not detect a thread name change within the same char* buffer address: we
 643     // favor common case performance over corner case correctness.
 644     if (new_name != g_current_thread_name.Get().Get() &&
 645         new_name && *new_name) {
 646       g_current_thread_name.Get().Set(new_name);
 647       base::hash_map<int, std::string>::iterator existing_name =
 648           thread_names_.find(thread_id);
 649       if (existing_name == thread_names_.end()) {
 650         // This is a new thread id, and a new name.
 651         thread_names_[thread_id] = new_name;
 652       } else {
 653         // This is a thread id that we've seen before, but potentially with a
 654         // new name.
 655         std::vector<base::StringPiece> existing_names;
 656         Tokenize(existing_name->second, ",", &existing_names);
 657         bool found = std::find(existing_names.begin(),
 658                                existing_names.end(),
 659                                new_name) != existing_names.end();
 660         if (!found) {
 661           existing_name->second.push_back(',');
 662           existing_name->second.append(new_name);
 663         }
 664       }
 665     }
 666
 667     if (flags & TRACE_EVENT_FLAG_MANGLE_ID)
 668       id ^= process_id_hash_;
 669
 670     logged_events_.push_back(
 671         TraceEvent(thread_id,
 672                    now, phase, category_enabled, name, id,
 673                    num_args, arg_names, arg_types, arg_values,
 674                    flags));
 675
 676     if (logged_events_.size() == kTraceEventBufferSize)
 677       notifier.AddNotificationWhileLocked(TRACE_BUFFER_FULL);
 678
 679     if (watch_category_ == category_enabled && watch_event_name_ == name)
 680       notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION);
 681   }  // release lock
 682
 683   notifier.SendNotificationIfAny();
 684 }
 685
 686 void TraceLog::AddTraceEventEtw(char phase,
 687                                 const char* name,
 688                                 const void* id,
 689                                 const char* extra) {
 690 #if defined(OS_WIN)
 691   TraceEventETWProvider::Trace(name, phase, id, extra);
 692 #endif
 693   INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name,
 694                            TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
 695 }
 696
 697 void TraceLog::AddTraceEventEtw(char phase,
 698                                 const char* name,
 699                                 const void* id,
 700                                 const std::string& extra)
 701 {
 702 #if defined(OS_WIN)
 703   TraceEventETWProvider::Trace(name, phase, id, extra);
 704 #endif
 705   INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name,
 706                            TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
 707 }
 708
 709 void TraceLog::SetWatchEvent(const std::string& category_name,
 710                              const std::string& event_name) {
 711   const unsigned char* category = GetCategoryEnabled(category_name.c_str());
 712   int notify_count = 0;
 713   {
 714     AutoLock lock(lock_);
 715     watch_category_ = category;
 716     watch_event_name_ = event_name;
 717
 718     // First, search existing events for watch event because we want to catch it
 719     // even if it has already occurred.
 720     for (size_t i = 0u; i < logged_events_.size(); ++i) {
 721       if (category == logged_events_[i].category_enabled() &&
 722           strcmp(event_name.c_str(), logged_events_[i].name()) == 0) {
 723         ++notify_count;
 724       }
 725     }
 726   }  // release lock
 727
 728   // Send notification for each event found.
 729   for (int i = 0; i < notify_count; ++i) {
 730     NotificationHelper notifier(this);
 731     lock_.Acquire();
 732     notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION);
 733     lock_.Release();
 734     notifier.SendNotificationIfAny();
 735   }
 736 }
 737
 738 void TraceLog::CancelWatchEvent() {
 739   AutoLock lock(lock_);
 740   watch_category_ = NULL;
 741   watch_event_name_ = "";
 742 }
 743
 744 void TraceLog::AddThreadNameMetadataEvents() {
 745   lock_.AssertAcquired();
 746   for(base::hash_map<int, std::string>::iterator it = thread_names_.begin();
 747       it != thread_names_.end();
 748       it++) {
 749     if (!it->second.empty()) {
 750       int num_args = 1;
 751       const char* arg_name = "name";
 752       unsigned char arg_type;
 753       unsigned long long arg_value;
 754       trace_event_internal::SetTraceValue(it->second, &arg_type, &arg_value);
 755       logged_events_.push_back(
 756           TraceEvent(it->first,
 757                      TimeTicks(), TRACE_EVENT_PHASE_METADATA,
 758                      &g_category_enabled[g_category_metadata],
 759                      "thread_name", trace_event_internal::kNoEventId,
 760                      num_args, &arg_name, &arg_type, &arg_value,
 761                      TRACE_EVENT_FLAG_NONE));
 762     }
 763   }
 764 }
 765
 766 void TraceLog::DeleteForTesting() {
 767   DeleteTraceLogForTesting::Delete();
 768 }
 769
 770 void TraceLog::Resurrect() {
 771   StaticMemorySingletonTraits<TraceLog>::Resurrect();
 772 }
 773
 774 void TraceLog::SetProcessID(int process_id) {
 775   process_id_ = process_id;
 776   // Create a FNV hash from the process ID for XORing.
 777   // See http://isthe.com/chongo/tech/comp/fnv/ for algorithm details.
 778   unsigned long long offset_basis = 14695981039346656037ull;
 779   unsigned long long fnv_prime = 1099511628211ull;
 780   unsigned long long pid = static_cast<unsigned long long>(process_id_);
 781   process_id_hash_ = (offset_basis ^ pid) * fnv_prime;
 782 }
 783
 784 void TraceLog::SetTimeOffset(TimeDelta offset) {
 785   time_offset_ = offset;
 786 }
 787
 788 }  // namespace debug
 789 }  // namespace base