Home | History | Annotate | Download | only in debug
      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/base_switches.h"
     10 #include "base/bind.h"
     11 #include "base/command_line.h"
     12 #include "base/debug/leak_annotations.h"
     13 #include "base/debug/trace_event.h"
     14 #include "base/debug/trace_event_synthetic_delay.h"
     15 #include "base/float_util.h"
     16 #include "base/format_macros.h"
     17 #include "base/json/string_escape.h"
     18 #include "base/lazy_instance.h"
     19 #include "base/memory/singleton.h"
     20 #include "base/message_loop/message_loop.h"
     21 #include "base/process/process_metrics.h"
     22 #include "base/stl_util.h"
     23 #include "base/strings/string_number_conversions.h"
     24 #include "base/strings/string_split.h"
     25 #include "base/strings/string_tokenizer.h"
     26 #include "base/strings/string_util.h"
     27 #include "base/strings/stringprintf.h"
     28 #include "base/strings/utf_string_conversions.h"
     29 #include "base/synchronization/cancellation_flag.h"
     30 #include "base/synchronization/waitable_event.h"
     31 #include "base/sys_info.h"
     32 #include "base/third_party/dynamic_annotations/dynamic_annotations.h"
     33 #include "base/threading/platform_thread.h"
     34 #include "base/threading/thread_id_name_manager.h"
     35 #include "base/time/time.h"
     36 
     37 #if defined(OS_WIN)
     38 #include "base/debug/trace_event_win.h"
     39 #endif
     40 
     41 class DeleteTraceLogForTesting {
     42  public:
     43   static void Delete() {
     44     Singleton<base::debug::TraceLog,
     45               LeakySingletonTraits<base::debug::TraceLog> >::OnExit(0);
     46   }
     47 };
     48 
     49 // The thread buckets for the sampling profiler.
     50 BASE_EXPORT TRACE_EVENT_API_ATOMIC_WORD g_trace_state[3];
     51 
     52 namespace base {
     53 namespace debug {
     54 
     55 namespace {
     56 
     57 // The overhead of TraceEvent above this threshold will be reported in the
     58 // trace.
     59 const int kOverheadReportThresholdInMicroseconds = 50;
     60 
     61 // String options that can be used to initialize TraceOptions.
     62 const char kRecordUntilFull[] = "record-until-full";
     63 const char kRecordContinuously[] = "record-continuously";
     64 const char kRecordAsMuchAsPossible[] = "record-as-much-as-possible";
     65 const char kTraceToConsole[] = "trace-to-console";
     66 const char kEnableSampling[] = "enable-sampling";
     67 const char kEnableSystrace[] = "enable-systrace";
     68 
     69 // Controls the number of trace events we will buffer in-memory
     70 // before throwing them away.
     71 const size_t kTraceBufferChunkSize = TraceBufferChunk::kTraceBufferChunkSize;
     72 const size_t kTraceEventVectorBigBufferChunks =
     73     512000000 / kTraceBufferChunkSize;
     74 const size_t kTraceEventVectorBufferChunks = 256000 / kTraceBufferChunkSize;
     75 const size_t kTraceEventRingBufferChunks = kTraceEventVectorBufferChunks / 4;
     76 const size_t kTraceEventBatchChunks = 1000 / kTraceBufferChunkSize;
     77 // Can store results for 30 seconds with 1 ms sampling interval.
     78 const size_t kMonitorTraceEventBufferChunks = 30000 / kTraceBufferChunkSize;
     79 // ECHO_TO_CONSOLE needs a small buffer to hold the unfinished COMPLETE events.
     80 const size_t kEchoToConsoleTraceEventBufferChunks = 256;
     81 
     82 const int kThreadFlushTimeoutMs = 3000;
     83 
     84 #if !defined(OS_NACL)
     85 // These categories will cause deadlock when ECHO_TO_CONSOLE. crbug.com/325575.
     86 const char kEchoToConsoleCategoryFilter[] = "-ipc,-task";
     87 #endif
     88 
     89 const char kSyntheticDelayCategoryFilterPrefix[] = "DELAY(";
     90 
     91 #define MAX_CATEGORY_GROUPS 100
     92 
     93 // Parallel arrays g_category_groups and g_category_group_enabled are separate
     94 // so that a pointer to a member of g_category_group_enabled can be easily
     95 // converted to an index into g_category_groups. This allows macros to deal
     96 // only with char enabled pointers from g_category_group_enabled, and we can
     97 // convert internally to determine the category name from the char enabled
     98 // pointer.
     99 const char* g_category_groups[MAX_CATEGORY_GROUPS] = {
    100   "toplevel",
    101   "tracing already shutdown",
    102   "tracing categories exhausted; must increase MAX_CATEGORY_GROUPS",
    103   "__metadata",
    104   // For reporting trace_event overhead. For thread local event buffers only.
    105   "trace_event_overhead"};
    106 
    107 // The enabled flag is char instead of bool so that the API can be used from C.
    108 unsigned char g_category_group_enabled[MAX_CATEGORY_GROUPS] = { 0 };
    109 // Indexes here have to match the g_category_groups array indexes above.
    110 const int g_category_already_shutdown = 1;
    111 const int g_category_categories_exhausted = 2;
    112 const int g_category_metadata = 3;
    113 const int g_category_trace_event_overhead = 4;
    114 const int g_num_builtin_categories = 5;
    115 // Skip default categories.
    116 base::subtle::AtomicWord g_category_index = g_num_builtin_categories;
    117 
    118 // The name of the current thread. This is used to decide if the current
    119 // thread name has changed. We combine all the seen thread names into the
    120 // output name for the thread.
    121 LazyInstance<ThreadLocalPointer<const char> >::Leaky
    122     g_current_thread_name = LAZY_INSTANCE_INITIALIZER;
    123 
    124 TimeTicks ThreadNow() {
    125   return TimeTicks::IsThreadNowSupported() ?
    126       TimeTicks::ThreadNow() : TimeTicks();
    127 }
    128 
    129 class TraceBufferRingBuffer : public TraceBuffer {
    130  public:
    131   TraceBufferRingBuffer(size_t max_chunks)
    132       : max_chunks_(max_chunks),
    133         recyclable_chunks_queue_(new size_t[queue_capacity()]),
    134         queue_head_(0),
    135         queue_tail_(max_chunks),
    136         current_iteration_index_(0),
    137         current_chunk_seq_(1) {
    138     chunks_.reserve(max_chunks);
    139     for (size_t i = 0; i < max_chunks; ++i)
    140       recyclable_chunks_queue_[i] = i;
    141   }
    142 
    143   virtual scoped_ptr<TraceBufferChunk> GetChunk(size_t* index) OVERRIDE {
    144     // Because the number of threads is much less than the number of chunks,
    145     // the queue should never be empty.
    146     DCHECK(!QueueIsEmpty());
    147 
    148     *index = recyclable_chunks_queue_[queue_head_];
    149     queue_head_ = NextQueueIndex(queue_head_);
    150     current_iteration_index_ = queue_head_;
    151 
    152     if (*index >= chunks_.size())
    153       chunks_.resize(*index + 1);
    154 
    155     TraceBufferChunk* chunk = chunks_[*index];
    156     chunks_[*index] = NULL;  // Put NULL in the slot of a in-flight chunk.
    157     if (chunk)
    158       chunk->Reset(current_chunk_seq_++);
    159     else
    160       chunk = new TraceBufferChunk(current_chunk_seq_++);
    161 
    162     return scoped_ptr<TraceBufferChunk>(chunk);
    163   }
    164 
    165   virtual void ReturnChunk(size_t index,
    166                            scoped_ptr<TraceBufferChunk> chunk) OVERRIDE {
    167     // When this method is called, the queue should not be full because it
    168     // can contain all chunks including the one to be returned.
    169     DCHECK(!QueueIsFull());
    170     DCHECK(chunk);
    171     DCHECK_LT(index, chunks_.size());
    172     DCHECK(!chunks_[index]);
    173     chunks_[index] = chunk.release();
    174     recyclable_chunks_queue_[queue_tail_] = index;
    175     queue_tail_ = NextQueueIndex(queue_tail_);
    176   }
    177 
    178   virtual bool IsFull() const OVERRIDE {
    179     return false;
    180   }
    181 
    182   virtual size_t Size() const OVERRIDE {
    183     // This is approximate because not all of the chunks are full.
    184     return chunks_.size() * kTraceBufferChunkSize;
    185   }
    186 
    187   virtual size_t Capacity() const OVERRIDE {
    188     return max_chunks_ * kTraceBufferChunkSize;
    189   }
    190 
    191   virtual TraceEvent* GetEventByHandle(TraceEventHandle handle) OVERRIDE {
    192     if (handle.chunk_index >= chunks_.size())
    193       return NULL;
    194     TraceBufferChunk* chunk = chunks_[handle.chunk_index];
    195     if (!chunk || chunk->seq() != handle.chunk_seq)
    196       return NULL;
    197     return chunk->GetEventAt(handle.event_index);
    198   }
    199 
    200   virtual const TraceBufferChunk* NextChunk() OVERRIDE {
    201     if (chunks_.empty())
    202       return NULL;
    203 
    204     while (current_iteration_index_ != queue_tail_) {
    205       size_t chunk_index = recyclable_chunks_queue_[current_iteration_index_];
    206       current_iteration_index_ = NextQueueIndex(current_iteration_index_);
    207       if (chunk_index >= chunks_.size()) // Skip uninitialized chunks.
    208         continue;
    209       DCHECK(chunks_[chunk_index]);
    210       return chunks_[chunk_index];
    211     }
    212     return NULL;
    213   }
    214 
    215   virtual scoped_ptr<TraceBuffer> CloneForIteration() const OVERRIDE {
    216     scoped_ptr<ClonedTraceBuffer> cloned_buffer(new ClonedTraceBuffer());
    217     for (size_t queue_index = queue_head_; queue_index != queue_tail_;
    218         queue_index = NextQueueIndex(queue_index)) {
    219       size_t chunk_index = recyclable_chunks_queue_[queue_index];
    220       if (chunk_index >= chunks_.size()) // Skip uninitialized chunks.
    221         continue;
    222       TraceBufferChunk* chunk = chunks_[chunk_index];
    223       cloned_buffer->chunks_.push_back(chunk ? chunk->Clone().release() : NULL);
    224     }
    225     return cloned_buffer.PassAs<TraceBuffer>();
    226   }
    227 
    228  private:
    229   class ClonedTraceBuffer : public TraceBuffer {
    230    public:
    231     ClonedTraceBuffer() : current_iteration_index_(0) {}
    232 
    233     // The only implemented method.
    234     virtual const TraceBufferChunk* NextChunk() OVERRIDE {
    235       return current_iteration_index_ < chunks_.size() ?
    236           chunks_[current_iteration_index_++] : NULL;
    237     }
    238 
    239     virtual scoped_ptr<TraceBufferChunk> GetChunk(size_t* index) OVERRIDE {
    240       NOTIMPLEMENTED();
    241       return scoped_ptr<TraceBufferChunk>();
    242     }
    243     virtual void ReturnChunk(size_t index,
    244                              scoped_ptr<TraceBufferChunk>) OVERRIDE {
    245       NOTIMPLEMENTED();
    246     }
    247     virtual bool IsFull() const OVERRIDE { return false; }
    248     virtual size_t Size() const OVERRIDE { return 0; }
    249     virtual size_t Capacity() const OVERRIDE { return 0; }
    250     virtual TraceEvent* GetEventByHandle(TraceEventHandle handle) OVERRIDE {
    251       return NULL;
    252     }
    253     virtual scoped_ptr<TraceBuffer> CloneForIteration() const OVERRIDE {
    254       NOTIMPLEMENTED();
    255       return scoped_ptr<TraceBuffer>();
    256     }
    257 
    258     size_t current_iteration_index_;
    259     ScopedVector<TraceBufferChunk> chunks_;
    260   };
    261 
    262   bool QueueIsEmpty() const {
    263     return queue_head_ == queue_tail_;
    264   }
    265 
    266   size_t QueueSize() const {
    267     return queue_tail_ > queue_head_ ? queue_tail_ - queue_head_ :
    268         queue_tail_ + queue_capacity() - queue_head_;
    269   }
    270 
    271   bool QueueIsFull() const {
    272     return QueueSize() == queue_capacity() - 1;
    273   }
    274 
    275   size_t queue_capacity() const {
    276     // One extra space to help distinguish full state and empty state.
    277     return max_chunks_ + 1;
    278   }
    279 
    280   size_t NextQueueIndex(size_t index) const {
    281     index++;
    282     if (index >= queue_capacity())
    283       index = 0;
    284     return index;
    285   }
    286 
    287   size_t max_chunks_;
    288   ScopedVector<TraceBufferChunk> chunks_;
    289 
    290   scoped_ptr<size_t[]> recyclable_chunks_queue_;
    291   size_t queue_head_;
    292   size_t queue_tail_;
    293 
    294   size_t current_iteration_index_;
    295   uint32 current_chunk_seq_;
    296 
    297   DISALLOW_COPY_AND_ASSIGN(TraceBufferRingBuffer);
    298 };
    299 
    300 class TraceBufferVector : public TraceBuffer {
    301  public:
    302   TraceBufferVector(size_t max_chunks)
    303       : in_flight_chunk_count_(0),
    304         current_iteration_index_(0),
    305         max_chunks_(max_chunks) {
    306     chunks_.reserve(max_chunks_);
    307   }
    308 
    309   virtual scoped_ptr<TraceBufferChunk> GetChunk(size_t* index) OVERRIDE {
    310     // This function may be called when adding normal events or indirectly from
    311     // AddMetadataEventsWhileLocked(). We can not DECHECK(!IsFull()) because we
    312     // have to add the metadata events and flush thread-local buffers even if
    313     // the buffer is full.
    314     *index = chunks_.size();
    315     chunks_.push_back(NULL);  // Put NULL in the slot of a in-flight chunk.
    316     ++in_flight_chunk_count_;
    317     // + 1 because zero chunk_seq is not allowed.
    318     return scoped_ptr<TraceBufferChunk>(
    319         new TraceBufferChunk(static_cast<uint32>(*index) + 1));
    320   }
    321 
    322   virtual void ReturnChunk(size_t index,
    323                            scoped_ptr<TraceBufferChunk> chunk) OVERRIDE {
    324     DCHECK_GT(in_flight_chunk_count_, 0u);
    325     DCHECK_LT(index, chunks_.size());
    326     DCHECK(!chunks_[index]);
    327     --in_flight_chunk_count_;
    328     chunks_[index] = chunk.release();
    329   }
    330 
    331   virtual bool IsFull() const OVERRIDE {
    332     return chunks_.size() >= max_chunks_;
    333   }
    334 
    335   virtual size_t Size() const OVERRIDE {
    336     // This is approximate because not all of the chunks are full.
    337     return chunks_.size() * kTraceBufferChunkSize;
    338   }
    339 
    340   virtual size_t Capacity() const OVERRIDE {
    341     return max_chunks_ * kTraceBufferChunkSize;
    342   }
    343 
    344   virtual TraceEvent* GetEventByHandle(TraceEventHandle handle) OVERRIDE {
    345     if (handle.chunk_index >= chunks_.size())
    346       return NULL;
    347     TraceBufferChunk* chunk = chunks_[handle.chunk_index];
    348     if (!chunk || chunk->seq() != handle.chunk_seq)
    349       return NULL;
    350     return chunk->GetEventAt(handle.event_index);
    351   }
    352 
    353   virtual const TraceBufferChunk* NextChunk() OVERRIDE {
    354     while (current_iteration_index_ < chunks_.size()) {
    355       // Skip in-flight chunks.
    356       const TraceBufferChunk* chunk = chunks_[current_iteration_index_++];
    357       if (chunk)
    358         return chunk;
    359     }
    360     return NULL;
    361   }
    362 
    363   virtual scoped_ptr<TraceBuffer> CloneForIteration() const OVERRIDE {
    364     NOTIMPLEMENTED();
    365     return scoped_ptr<TraceBuffer>();
    366   }
    367 
    368  private:
    369   size_t in_flight_chunk_count_;
    370   size_t current_iteration_index_;
    371   size_t max_chunks_;
    372   ScopedVector<TraceBufferChunk> chunks_;
    373 
    374   DISALLOW_COPY_AND_ASSIGN(TraceBufferVector);
    375 };
    376 
    377 template <typename T>
    378 void InitializeMetadataEvent(TraceEvent* trace_event,
    379                              int thread_id,
    380                              const char* metadata_name, const char* arg_name,
    381                              const T& value) {
    382   if (!trace_event)
    383     return;
    384 
    385   int num_args = 1;
    386   unsigned char arg_type;
    387   unsigned long long arg_value;
    388   ::trace_event_internal::SetTraceValue(value, &arg_type, &arg_value);
    389   trace_event->Initialize(thread_id,
    390                           TimeTicks(), TimeTicks(), TRACE_EVENT_PHASE_METADATA,
    391                           &g_category_group_enabled[g_category_metadata],
    392                           metadata_name, ::trace_event_internal::kNoEventId,
    393                           num_args, &arg_name, &arg_type, &arg_value, NULL,
    394                           TRACE_EVENT_FLAG_NONE);
    395 }
    396 
    397 class AutoThreadLocalBoolean {
    398  public:
    399   explicit AutoThreadLocalBoolean(ThreadLocalBoolean* thread_local_boolean)
    400       : thread_local_boolean_(thread_local_boolean) {
    401     DCHECK(!thread_local_boolean_->Get());
    402     thread_local_boolean_->Set(true);
    403   }
    404   ~AutoThreadLocalBoolean() {
    405     thread_local_boolean_->Set(false);
    406   }
    407 
    408  private:
    409   ThreadLocalBoolean* thread_local_boolean_;
    410   DISALLOW_COPY_AND_ASSIGN(AutoThreadLocalBoolean);
    411 };
    412 
    413 }  // namespace
    414 
    415 void TraceBufferChunk::Reset(uint32 new_seq) {
    416   for (size_t i = 0; i < next_free_; ++i)
    417     chunk_[i].Reset();
    418   next_free_ = 0;
    419   seq_ = new_seq;
    420 }
    421 
    422 TraceEvent* TraceBufferChunk::AddTraceEvent(size_t* event_index) {
    423   DCHECK(!IsFull());
    424   *event_index = next_free_++;
    425   return &chunk_[*event_index];
    426 }
    427 
    428 scoped_ptr<TraceBufferChunk> TraceBufferChunk::Clone() const {
    429   scoped_ptr<TraceBufferChunk> cloned_chunk(new TraceBufferChunk(seq_));
    430   cloned_chunk->next_free_ = next_free_;
    431   for (size_t i = 0; i < next_free_; ++i)
    432     cloned_chunk->chunk_[i].CopyFrom(chunk_[i]);
    433   return cloned_chunk.Pass();
    434 }
    435 
    436 // A helper class that allows the lock to be acquired in the middle of the scope
    437 // and unlocks at the end of scope if locked.
    438 class TraceLog::OptionalAutoLock {
    439  public:
    440   explicit OptionalAutoLock(Lock& lock)
    441       : lock_(lock),
    442         locked_(false) {
    443   }
    444 
    445   ~OptionalAutoLock() {
    446     if (locked_)
    447       lock_.Release();
    448   }
    449 
    450   void EnsureAcquired() {
    451     if (!locked_) {
    452       lock_.Acquire();
    453       locked_ = true;
    454     }
    455   }
    456 
    457  private:
    458   Lock& lock_;
    459   bool locked_;
    460   DISALLOW_COPY_AND_ASSIGN(OptionalAutoLock);
    461 };
    462 
    463 // Use this function instead of TraceEventHandle constructor to keep the
    464 // overhead of ScopedTracer (trace_event.h) constructor minimum.
    465 void MakeHandle(uint32 chunk_seq, size_t chunk_index, size_t event_index,
    466                 TraceEventHandle* handle) {
    467   DCHECK(chunk_seq);
    468   DCHECK(chunk_index < (1u << 16));
    469   DCHECK(event_index < (1u << 16));
    470   handle->chunk_seq = chunk_seq;
    471   handle->chunk_index = static_cast<uint16>(chunk_index);
    472   handle->event_index = static_cast<uint16>(event_index);
    473 }
    474 
    475 ////////////////////////////////////////////////////////////////////////////////
    476 //
    477 // TraceEvent
    478 //
    479 ////////////////////////////////////////////////////////////////////////////////
    480 
    481 namespace {
    482 
    483 size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; }
    484 
    485 // Copies |*member| into |*buffer|, sets |*member| to point to this new
    486 // location, and then advances |*buffer| by the amount written.
    487 void CopyTraceEventParameter(char** buffer,
    488                              const char** member,
    489                              const char* end) {
    490   if (*member) {
    491     size_t written = strlcpy(*buffer, *member, end - *buffer) + 1;
    492     DCHECK_LE(static_cast<int>(written), end - *buffer);
    493     *member = *buffer;
    494     *buffer += written;
    495   }
    496 }
    497 
    498 }  // namespace
    499 
    500 TraceEvent::TraceEvent()
    501     : duration_(TimeDelta::FromInternalValue(-1)),
    502       id_(0u),
    503       category_group_enabled_(NULL),
    504       name_(NULL),
    505       thread_id_(0),
    506       phase_(TRACE_EVENT_PHASE_BEGIN),
    507       flags_(0) {
    508   for (int i = 0; i < kTraceMaxNumArgs; ++i)
    509     arg_names_[i] = NULL;
    510   memset(arg_values_, 0, sizeof(arg_values_));
    511 }
    512 
    513 TraceEvent::~TraceEvent() {
    514 }
    515 
    516 void TraceEvent::CopyFrom(const TraceEvent& other) {
    517   timestamp_ = other.timestamp_;
    518   thread_timestamp_ = other.thread_timestamp_;
    519   duration_ = other.duration_;
    520   id_ = other.id_;
    521   category_group_enabled_ = other.category_group_enabled_;
    522   name_ = other.name_;
    523   thread_id_ = other.thread_id_;
    524   phase_ = other.phase_;
    525   flags_ = other.flags_;
    526   parameter_copy_storage_ = other.parameter_copy_storage_;
    527 
    528   for (int i = 0; i < kTraceMaxNumArgs; ++i) {
    529     arg_names_[i] = other.arg_names_[i];
    530     arg_types_[i] = other.arg_types_[i];
    531     arg_values_[i] = other.arg_values_[i];
    532     convertable_values_[i] = other.convertable_values_[i];
    533   }
    534 }
    535 
    536 void TraceEvent::Initialize(
    537     int thread_id,
    538     TimeTicks timestamp,
    539     TimeTicks thread_timestamp,
    540     char phase,
    541     const unsigned char* category_group_enabled,
    542     const char* name,
    543     unsigned long long id,
    544     int num_args,
    545     const char** arg_names,
    546     const unsigned char* arg_types,
    547     const unsigned long long* arg_values,
    548     const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
    549     unsigned char flags) {
    550   timestamp_ = timestamp;
    551   thread_timestamp_ = thread_timestamp;
    552   duration_ = TimeDelta::FromInternalValue(-1);
    553   id_ = id;
    554   category_group_enabled_ = category_group_enabled;
    555   name_ = name;
    556   thread_id_ = thread_id;
    557   phase_ = phase;
    558   flags_ = flags;
    559 
    560   // Clamp num_args since it may have been set by a third_party library.
    561   num_args = (num_args > kTraceMaxNumArgs) ? kTraceMaxNumArgs : num_args;
    562   int i = 0;
    563   for (; i < num_args; ++i) {
    564     arg_names_[i] = arg_names[i];
    565     arg_types_[i] = arg_types[i];
    566 
    567     if (arg_types[i] == TRACE_VALUE_TYPE_CONVERTABLE)
    568       convertable_values_[i] = convertable_values[i];
    569     else
    570       arg_values_[i].as_uint = arg_values[i];
    571   }
    572   for (; i < kTraceMaxNumArgs; ++i) {
    573     arg_names_[i] = NULL;
    574     arg_values_[i].as_uint = 0u;
    575     convertable_values_[i] = NULL;
    576     arg_types_[i] = TRACE_VALUE_TYPE_UINT;
    577   }
    578 
    579   bool copy = !!(flags & TRACE_EVENT_FLAG_COPY);
    580   size_t alloc_size = 0;
    581   if (copy) {
    582     alloc_size += GetAllocLength(name);
    583     for (i = 0; i < num_args; ++i) {
    584       alloc_size += GetAllocLength(arg_names_[i]);
    585       if (arg_types_[i] == TRACE_VALUE_TYPE_STRING)
    586         arg_types_[i] = TRACE_VALUE_TYPE_COPY_STRING;
    587     }
    588   }
    589 
    590   bool arg_is_copy[kTraceMaxNumArgs];
    591   for (i = 0; i < num_args; ++i) {
    592     // No copying of convertable types, we retain ownership.
    593     if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
    594       continue;
    595 
    596     // We only take a copy of arg_vals if they are of type COPY_STRING.
    597     arg_is_copy[i] = (arg_types_[i] == TRACE_VALUE_TYPE_COPY_STRING);
    598     if (arg_is_copy[i])
    599       alloc_size += GetAllocLength(arg_values_[i].as_string);
    600   }
    601 
    602   if (alloc_size) {
    603     parameter_copy_storage_ = new RefCountedString;
    604     parameter_copy_storage_->data().resize(alloc_size);
    605     char* ptr = string_as_array(&parameter_copy_storage_->data());
    606     const char* end = ptr + alloc_size;
    607     if (copy) {
    608       CopyTraceEventParameter(&ptr, &name_, end);
    609       for (i = 0; i < num_args; ++i) {
    610         CopyTraceEventParameter(&ptr, &arg_names_[i], end);
    611       }
    612     }
    613     for (i = 0; i < num_args; ++i) {
    614       if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
    615         continue;
    616       if (arg_is_copy[i])
    617         CopyTraceEventParameter(&ptr, &arg_values_[i].as_string, end);
    618     }
    619     DCHECK_EQ(end, ptr) << "Overrun by " << ptr - end;
    620   }
    621 }
    622 
    623 void TraceEvent::Reset() {
    624   // Only reset fields that won't be initialized in Initialize(), or that may
    625   // hold references to other objects.
    626   duration_ = TimeDelta::FromInternalValue(-1);
    627   parameter_copy_storage_ = NULL;
    628   for (int i = 0; i < kTraceMaxNumArgs; ++i)
    629     convertable_values_[i] = NULL;
    630 }
    631 
    632 void TraceEvent::UpdateDuration(const TimeTicks& now,
    633                                 const TimeTicks& thread_now) {
    634   DCHECK(duration_.ToInternalValue() == -1);
    635   duration_ = now - timestamp_;
    636   thread_duration_ = thread_now - thread_timestamp_;
    637 }
    638 
    639 // static
    640 void TraceEvent::AppendValueAsJSON(unsigned char type,
    641                                    TraceEvent::TraceValue value,
    642                                    std::string* out) {
    643   switch (type) {
    644     case TRACE_VALUE_TYPE_BOOL:
    645       *out += value.as_bool ? "true" : "false";
    646       break;
    647     case TRACE_VALUE_TYPE_UINT:
    648       StringAppendF(out, "%" PRIu64, static_cast<uint64>(value.as_uint));
    649       break;
    650     case TRACE_VALUE_TYPE_INT:
    651       StringAppendF(out, "%" PRId64, static_cast<int64>(value.as_int));
    652       break;
    653     case TRACE_VALUE_TYPE_DOUBLE: {
    654       // FIXME: base/json/json_writer.cc is using the same code,
    655       //        should be made into a common method.
    656       std::string real;
    657       double val = value.as_double;
    658       if (IsFinite(val)) {
    659         real = DoubleToString(val);
    660         // Ensure that the number has a .0 if there's no decimal or 'e'.  This
    661         // makes sure that when we read the JSON back, it's interpreted as a
    662         // real rather than an int.
    663         if (real.find('.') == std::string::npos &&
    664             real.find('e') == std::string::npos &&
    665             real.find('E') == std::string::npos) {
    666           real.append(".0");
    667         }
    668         // The JSON spec requires that non-integer values in the range (-1,1)
    669         // have a zero before the decimal point - ".52" is not valid, "0.52" is.
    670         if (real[0] == '.') {
    671           real.insert(0, "0");
    672         } else if (real.length() > 1 && real[0] == '-' && real[1] == '.') {
    673           // "-.1" bad "-0.1" good
    674           real.insert(1, "0");
    675         }
    676       } else if (IsNaN(val)){
    677         // The JSON spec doesn't allow NaN and Infinity (since these are
    678         // objects in EcmaScript).  Use strings instead.
    679         real = "\"NaN\"";
    680       } else if (val < 0) {
    681         real = "\"-Infinity\"";
    682       } else {
    683         real = "\"Infinity\"";
    684       }
    685       StringAppendF(out, "%s", real.c_str());
    686       break;
    687     }
    688     case TRACE_VALUE_TYPE_POINTER:
    689       // JSON only supports double and int numbers.
    690       // So as not to lose bits from a 64-bit pointer, output as a hex string.
    691       StringAppendF(out, "\"0x%" PRIx64 "\"", static_cast<uint64>(
    692                                      reinterpret_cast<intptr_t>(
    693                                      value.as_pointer)));
    694       break;
    695     case TRACE_VALUE_TYPE_STRING:
    696     case TRACE_VALUE_TYPE_COPY_STRING:
    697       EscapeJSONString(value.as_string ? value.as_string : "NULL", true, out);
    698       break;
    699     default:
    700       NOTREACHED() << "Don't know how to print this value";
    701       break;
    702   }
    703 }
    704 
    705 void TraceEvent::AppendAsJSON(std::string* out) const {
    706   int64 time_int64 = timestamp_.ToInternalValue();
    707   int process_id = TraceLog::GetInstance()->process_id();
    708   // Category group checked at category creation time.
    709   DCHECK(!strchr(name_, '"'));
    710   StringAppendF(out,
    711       "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 ","
    712       "\"ph\":\"%c\",\"name\":\"%s\",\"args\":{",
    713       TraceLog::GetCategoryGroupName(category_group_enabled_),
    714       process_id,
    715       thread_id_,
    716       time_int64,
    717       phase_,
    718       name_);
    719 
    720   // Output argument names and values, stop at first NULL argument name.
    721   for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) {
    722     if (i > 0)
    723       *out += ",";
    724     *out += "\"";
    725     *out += arg_names_[i];
    726     *out += "\":";
    727 
    728     if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
    729       convertable_values_[i]->AppendAsTraceFormat(out);
    730     else
    731       AppendValueAsJSON(arg_types_[i], arg_values_[i], out);
    732   }
    733   *out += "}";
    734 
    735   if (phase_ == TRACE_EVENT_PHASE_COMPLETE) {
    736     int64 duration = duration_.ToInternalValue();
    737     if (duration != -1)
    738       StringAppendF(out, ",\"dur\":%" PRId64, duration);
    739     if (!thread_timestamp_.is_null()) {
    740       int64 thread_duration = thread_duration_.ToInternalValue();
    741       if (thread_duration != -1)
    742         StringAppendF(out, ",\"tdur\":%" PRId64, thread_duration);
    743     }
    744   }
    745 
    746   // Output tts if thread_timestamp is valid.
    747   if (!thread_timestamp_.is_null()) {
    748     int64 thread_time_int64 = thread_timestamp_.ToInternalValue();
    749     StringAppendF(out, ",\"tts\":%" PRId64, thread_time_int64);
    750   }
    751 
    752   // If id_ is set, print it out as a hex string so we don't loose any
    753   // bits (it might be a 64-bit pointer).
    754   if (flags_ & TRACE_EVENT_FLAG_HAS_ID)
    755     StringAppendF(out, ",\"id\":\"0x%" PRIx64 "\"", static_cast<uint64>(id_));
    756 
    757   // Instant events also output their scope.
    758   if (phase_ == TRACE_EVENT_PHASE_INSTANT) {
    759     char scope = '?';
    760     switch (flags_ & TRACE_EVENT_FLAG_SCOPE_MASK) {
    761       case TRACE_EVENT_SCOPE_GLOBAL:
    762         scope = TRACE_EVENT_SCOPE_NAME_GLOBAL;
    763         break;
    764 
    765       case TRACE_EVENT_SCOPE_PROCESS:
    766         scope = TRACE_EVENT_SCOPE_NAME_PROCESS;
    767         break;
    768 
    769       case TRACE_EVENT_SCOPE_THREAD:
    770         scope = TRACE_EVENT_SCOPE_NAME_THREAD;
    771         break;
    772     }
    773     StringAppendF(out, ",\"s\":\"%c\"", scope);
    774   }
    775 
    776   *out += "}";
    777 }
    778 
    779 void TraceEvent::AppendPrettyPrinted(std::ostringstream* out) const {
    780   *out << name_ << "[";
    781   *out << TraceLog::GetCategoryGroupName(category_group_enabled_);
    782   *out << "]";
    783   if (arg_names_[0]) {
    784     *out << ", {";
    785     for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) {
    786       if (i > 0)
    787         *out << ", ";
    788       *out << arg_names_[i] << ":";
    789       std::string value_as_text;
    790 
    791       if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
    792         convertable_values_[i]->AppendAsTraceFormat(&value_as_text);
    793       else
    794         AppendValueAsJSON(arg_types_[i], arg_values_[i], &value_as_text);
    795 
    796       *out << value_as_text;
    797     }
    798     *out << "}";
    799   }
    800 }
    801 
    802 ////////////////////////////////////////////////////////////////////////////////
    803 //
    804 // TraceResultBuffer
    805 //
    806 ////////////////////////////////////////////////////////////////////////////////
    807 
    808 TraceResultBuffer::OutputCallback
    809     TraceResultBuffer::SimpleOutput::GetCallback() {
    810   return Bind(&SimpleOutput::Append, Unretained(this));
    811 }
    812 
    813 void TraceResultBuffer::SimpleOutput::Append(
    814     const std::string& json_trace_output) {
    815   json_output += json_trace_output;
    816 }
    817 
    818 TraceResultBuffer::TraceResultBuffer() : append_comma_(false) {
    819 }
    820 
    821 TraceResultBuffer::~TraceResultBuffer() {
    822 }
    823 
    824 void TraceResultBuffer::SetOutputCallback(
    825     const OutputCallback& json_chunk_callback) {
    826   output_callback_ = json_chunk_callback;
    827 }
    828 
    829 void TraceResultBuffer::Start() {
    830   append_comma_ = false;
    831   output_callback_.Run("[");
    832 }
    833 
    834 void TraceResultBuffer::AddFragment(const std::string& trace_fragment) {
    835   if (append_comma_)
    836     output_callback_.Run(",");
    837   append_comma_ = true;
    838   output_callback_.Run(trace_fragment);
    839 }
    840 
    841 void TraceResultBuffer::Finish() {
    842   output_callback_.Run("]");
    843 }
    844 
    845 ////////////////////////////////////////////////////////////////////////////////
    846 //
    847 // TraceSamplingThread
    848 //
    849 ////////////////////////////////////////////////////////////////////////////////
    850 class TraceBucketData;
    851 typedef base::Callback<void(TraceBucketData*)> TraceSampleCallback;
    852 
    853 class TraceBucketData {
    854  public:
    855   TraceBucketData(base::subtle::AtomicWord* bucket,
    856                   const char* name,
    857                   TraceSampleCallback callback);
    858   ~TraceBucketData();
    859 
    860   TRACE_EVENT_API_ATOMIC_WORD* bucket;
    861   const char* bucket_name;
    862   TraceSampleCallback callback;
    863 };
    864 
    865 // This object must be created on the IO thread.
    866 class TraceSamplingThread : public PlatformThread::Delegate {
    867  public:
    868   TraceSamplingThread();
    869   virtual ~TraceSamplingThread();
    870 
    871   // Implementation of PlatformThread::Delegate:
    872   virtual void ThreadMain() OVERRIDE;
    873 
    874   static void DefaultSamplingCallback(TraceBucketData* bucekt_data);
    875 
    876   void Stop();
    877   void WaitSamplingEventForTesting();
    878 
    879  private:
    880   friend class TraceLog;
    881 
    882   void GetSamples();
    883   // Not thread-safe. Once the ThreadMain has been called, this can no longer
    884   // be called.
    885   void RegisterSampleBucket(TRACE_EVENT_API_ATOMIC_WORD* bucket,
    886                             const char* const name,
    887                             TraceSampleCallback callback);
    888   // Splits a combined "category\0name" into the two component parts.
    889   static void ExtractCategoryAndName(const char* combined,
    890                                      const char** category,
    891                                      const char** name);
    892   std::vector<TraceBucketData> sample_buckets_;
    893   bool thread_running_;
    894   CancellationFlag cancellation_flag_;
    895   WaitableEvent waitable_event_for_testing_;
    896 };
    897 
    898 
    899 TraceSamplingThread::TraceSamplingThread()
    900     : thread_running_(false),
    901       waitable_event_for_testing_(false, false) {
    902 }
    903 
    904 TraceSamplingThread::~TraceSamplingThread() {
    905 }
    906 
    907 void TraceSamplingThread::ThreadMain() {
    908   PlatformThread::SetName("Sampling Thread");
    909   thread_running_ = true;
    910   const int kSamplingFrequencyMicroseconds = 1000;
    911   while (!cancellation_flag_.IsSet()) {
    912     PlatformThread::Sleep(
    913         TimeDelta::FromMicroseconds(kSamplingFrequencyMicroseconds));
    914     GetSamples();
    915     waitable_event_for_testing_.Signal();
    916   }
    917 }
    918 
    919 // static
    920 void TraceSamplingThread::DefaultSamplingCallback(
    921     TraceBucketData* bucket_data) {
    922   TRACE_EVENT_API_ATOMIC_WORD category_and_name =
    923       TRACE_EVENT_API_ATOMIC_LOAD(*bucket_data->bucket);
    924   if (!category_and_name)
    925     return;
    926   const char* const combined =
    927       reinterpret_cast<const char* const>(category_and_name);
    928   const char* category_group;
    929   const char* name;
    930   ExtractCategoryAndName(combined, &category_group, &name);
    931   TRACE_EVENT_API_ADD_TRACE_EVENT(TRACE_EVENT_PHASE_SAMPLE,
    932       TraceLog::GetCategoryGroupEnabled(category_group),
    933       name, 0, 0, NULL, NULL, NULL, NULL, 0);
    934 }
    935 
    936 void TraceSamplingThread::GetSamples() {
    937   for (size_t i = 0; i < sample_buckets_.size(); ++i) {
    938     TraceBucketData* bucket_data = &sample_buckets_[i];
    939     bucket_data->callback.Run(bucket_data);
    940   }
    941 }
    942 
    943 void TraceSamplingThread::RegisterSampleBucket(
    944     TRACE_EVENT_API_ATOMIC_WORD* bucket,
    945     const char* const name,
    946     TraceSampleCallback callback) {
    947   // Access to sample_buckets_ doesn't cause races with the sampling thread
    948   // that uses the sample_buckets_, because it is guaranteed that
    949   // RegisterSampleBucket is called before the sampling thread is created.
    950   DCHECK(!thread_running_);
    951   sample_buckets_.push_back(TraceBucketData(bucket, name, callback));
    952 }
    953 
    954 // static
    955 void TraceSamplingThread::ExtractCategoryAndName(const char* combined,
    956                                                  const char** category,
    957                                                  const char** name) {
    958   *category = combined;
    959   *name = &combined[strlen(combined) + 1];
    960 }
    961 
    962 void TraceSamplingThread::Stop() {
    963   cancellation_flag_.Set();
    964 }
    965 
    966 void TraceSamplingThread::WaitSamplingEventForTesting() {
    967   waitable_event_for_testing_.Wait();
    968 }
    969 
    970 TraceBucketData::TraceBucketData(base::subtle::AtomicWord* bucket,
    971                                  const char* name,
    972                                  TraceSampleCallback callback)
    973     : bucket(bucket),
    974       bucket_name(name),
    975       callback(callback) {
    976 }
    977 
    978 TraceBucketData::~TraceBucketData() {
    979 }
    980 
    981 ////////////////////////////////////////////////////////////////////////////////
    982 //
    983 // TraceOptions
    984 //
    985 ////////////////////////////////////////////////////////////////////////////////
    986 
    987 bool TraceOptions::SetFromString(const std::string& options_string) {
    988   record_mode = RECORD_UNTIL_FULL;
    989   enable_sampling = false;
    990   enable_systrace = false;
    991 
    992   std::vector<std::string> split;
    993   std::vector<std::string>::iterator iter;
    994   base::SplitString(options_string, ',', &split);
    995   for (iter = split.begin(); iter != split.end(); ++iter) {
    996     if (*iter == kRecordUntilFull) {
    997       record_mode = RECORD_UNTIL_FULL;
    998     } else if (*iter == kRecordContinuously) {
    999       record_mode = RECORD_CONTINUOUSLY;
   1000     } else if (*iter == kTraceToConsole) {
   1001       record_mode = ECHO_TO_CONSOLE;
   1002     } else if (*iter == kRecordAsMuchAsPossible) {
   1003       record_mode = RECORD_AS_MUCH_AS_POSSIBLE;
   1004     } else if (*iter == kEnableSampling) {
   1005       enable_sampling = true;
   1006     } else if (*iter == kEnableSystrace) {
   1007       enable_systrace = true;
   1008     } else {
   1009       return false;
   1010     }
   1011   }
   1012   return true;
   1013 }
   1014 
   1015 std::string TraceOptions::ToString() const {
   1016   std::string ret;
   1017   switch (record_mode) {
   1018     case RECORD_UNTIL_FULL:
   1019       ret = kRecordUntilFull;
   1020       break;
   1021     case RECORD_CONTINUOUSLY:
   1022       ret = kRecordContinuously;
   1023       break;
   1024     case ECHO_TO_CONSOLE:
   1025       ret = kTraceToConsole;
   1026       break;
   1027     case RECORD_AS_MUCH_AS_POSSIBLE:
   1028       ret = kRecordAsMuchAsPossible;
   1029       break;
   1030     default:
   1031       NOTREACHED();
   1032   }
   1033   if (enable_sampling)
   1034     ret = ret + "," + kEnableSampling;
   1035   if (enable_systrace)
   1036     ret = ret + "," + kEnableSystrace;
   1037   return ret;
   1038 }
   1039 
   1040 ////////////////////////////////////////////////////////////////////////////////
   1041 //
   1042 // TraceLog
   1043 //
   1044 ////////////////////////////////////////////////////////////////////////////////
   1045 
   1046 class TraceLog::ThreadLocalEventBuffer
   1047     : public MessageLoop::DestructionObserver {
   1048  public:
   1049   ThreadLocalEventBuffer(TraceLog* trace_log);
   1050   virtual ~ThreadLocalEventBuffer();
   1051 
   1052   TraceEvent* AddTraceEvent(TraceEventHandle* handle);
   1053 
   1054   void ReportOverhead(const TimeTicks& event_timestamp,
   1055                       const TimeTicks& event_thread_timestamp);
   1056 
   1057   TraceEvent* GetEventByHandle(TraceEventHandle handle) {
   1058     if (!chunk_ || handle.chunk_seq != chunk_->seq() ||
   1059         handle.chunk_index != chunk_index_)
   1060       return NULL;
   1061 
   1062     return chunk_->GetEventAt(handle.event_index);
   1063   }
   1064 
   1065   int generation() const { return generation_; }
   1066 
   1067  private:
   1068   // MessageLoop::DestructionObserver
   1069   virtual void WillDestroyCurrentMessageLoop() OVERRIDE;
   1070 
   1071   void FlushWhileLocked();
   1072 
   1073   void CheckThisIsCurrentBuffer() const {
   1074     DCHECK(trace_log_->thread_local_event_buffer_.Get() == this);
   1075   }
   1076 
   1077   // Since TraceLog is a leaky singleton, trace_log_ will always be valid
   1078   // as long as the thread exists.
   1079   TraceLog* trace_log_;
   1080   scoped_ptr<TraceBufferChunk> chunk_;
   1081   size_t chunk_index_;
   1082   int event_count_;
   1083   TimeDelta overhead_;
   1084   int generation_;
   1085 
   1086   DISALLOW_COPY_AND_ASSIGN(ThreadLocalEventBuffer);
   1087 };
   1088 
   1089 TraceLog::ThreadLocalEventBuffer::ThreadLocalEventBuffer(TraceLog* trace_log)
   1090     : trace_log_(trace_log),
   1091       chunk_index_(0),
   1092       event_count_(0),
   1093       generation_(trace_log->generation()) {
   1094   // ThreadLocalEventBuffer is created only if the thread has a message loop, so
   1095   // the following message_loop won't be NULL.
   1096   MessageLoop* message_loop = MessageLoop::current();
   1097   message_loop->AddDestructionObserver(this);
   1098 
   1099   AutoLock lock(trace_log->lock_);
   1100   trace_log->thread_message_loops_.insert(message_loop);
   1101 }
   1102 
   1103 TraceLog::ThreadLocalEventBuffer::~ThreadLocalEventBuffer() {
   1104   CheckThisIsCurrentBuffer();
   1105   MessageLoop::current()->RemoveDestructionObserver(this);
   1106 
   1107   // Zero event_count_ happens in either of the following cases:
   1108   // - no event generated for the thread;
   1109   // - the thread has no message loop;
   1110   // - trace_event_overhead is disabled.
   1111   if (event_count_) {
   1112     InitializeMetadataEvent(AddTraceEvent(NULL),
   1113                             static_cast<int>(base::PlatformThread::CurrentId()),
   1114                             "overhead", "average_overhead",
   1115                             overhead_.InMillisecondsF() / event_count_);
   1116   }
   1117 
   1118   {
   1119     AutoLock lock(trace_log_->lock_);
   1120     FlushWhileLocked();
   1121     trace_log_->thread_message_loops_.erase(MessageLoop::current());
   1122   }
   1123   trace_log_->thread_local_event_buffer_.Set(NULL);
   1124 }
   1125 
   1126 TraceEvent* TraceLog::ThreadLocalEventBuffer::AddTraceEvent(
   1127     TraceEventHandle* handle) {
   1128   CheckThisIsCurrentBuffer();
   1129 
   1130   if (chunk_ && chunk_->IsFull()) {
   1131     AutoLock lock(trace_log_->lock_);
   1132     FlushWhileLocked();
   1133     chunk_.reset();
   1134   }
   1135   if (!chunk_) {
   1136     AutoLock lock(trace_log_->lock_);
   1137     chunk_ = trace_log_->logged_events_->GetChunk(&chunk_index_);
   1138     trace_log_->CheckIfBufferIsFullWhileLocked();
   1139   }
   1140   if (!chunk_)
   1141     return NULL;
   1142 
   1143   size_t event_index;
   1144   TraceEvent* trace_event = chunk_->AddTraceEvent(&event_index);
   1145   if (trace_event && handle)
   1146     MakeHandle(chunk_->seq(), chunk_index_, event_index, handle);
   1147 
   1148   return trace_event;
   1149 }
   1150 
   1151 void TraceLog::ThreadLocalEventBuffer::ReportOverhead(
   1152     const TimeTicks& event_timestamp,
   1153     const TimeTicks& event_thread_timestamp) {
   1154   if (!g_category_group_enabled[g_category_trace_event_overhead])
   1155     return;
   1156 
   1157   CheckThisIsCurrentBuffer();
   1158 
   1159   event_count_++;
   1160   TimeTicks thread_now = ThreadNow();
   1161   TimeTicks now = trace_log_->OffsetNow();
   1162   TimeDelta overhead = now - event_timestamp;
   1163   if (overhead.InMicroseconds() >= kOverheadReportThresholdInMicroseconds) {
   1164     TraceEvent* trace_event = AddTraceEvent(NULL);
   1165     if (trace_event) {
   1166       trace_event->Initialize(
   1167           static_cast<int>(PlatformThread::CurrentId()),
   1168           event_timestamp, event_thread_timestamp,
   1169           TRACE_EVENT_PHASE_COMPLETE,
   1170           &g_category_group_enabled[g_category_trace_event_overhead],
   1171           "overhead", 0, 0, NULL, NULL, NULL, NULL, 0);
   1172       trace_event->UpdateDuration(now, thread_now);
   1173     }
   1174   }
   1175   overhead_ += overhead;
   1176 }
   1177 
   1178 void TraceLog::ThreadLocalEventBuffer::WillDestroyCurrentMessageLoop() {
   1179   delete this;
   1180 }
   1181 
   1182 void TraceLog::ThreadLocalEventBuffer::FlushWhileLocked() {
   1183   if (!chunk_)
   1184     return;
   1185 
   1186   trace_log_->lock_.AssertAcquired();
   1187   if (trace_log_->CheckGeneration(generation_)) {
   1188     // Return the chunk to the buffer only if the generation matches.
   1189     trace_log_->logged_events_->ReturnChunk(chunk_index_, chunk_.Pass());
   1190   }
   1191   // Otherwise this method may be called from the destructor, or TraceLog will
   1192   // find the generation mismatch and delete this buffer soon.
   1193 }
   1194 
   1195 // static
   1196 TraceLog* TraceLog::GetInstance() {
   1197   return Singleton<TraceLog, LeakySingletonTraits<TraceLog> >::get();
   1198 }
   1199 
   1200 TraceLog::TraceLog()
   1201     : mode_(DISABLED),
   1202       num_traces_recorded_(0),
   1203       event_callback_(0),
   1204       dispatching_to_observer_list_(false),
   1205       process_sort_index_(0),
   1206       process_id_hash_(0),
   1207       process_id_(0),
   1208       watch_category_(0),
   1209       trace_options_(kInternalRecordUntilFull),
   1210       sampling_thread_handle_(0),
   1211       category_filter_(CategoryFilter::kDefaultCategoryFilterString),
   1212       event_callback_category_filter_(
   1213           CategoryFilter::kDefaultCategoryFilterString),
   1214       thread_shared_chunk_index_(0),
   1215       generation_(0) {
   1216   // Trace is enabled or disabled on one thread while other threads are
   1217   // accessing the enabled flag. We don't care whether edge-case events are
   1218   // traced or not, so we allow races on the enabled flag to keep the trace
   1219   // macros fast.
   1220   // TODO(jbates): ANNOTATE_BENIGN_RACE_SIZED crashes windows TSAN bots:
   1221   // ANNOTATE_BENIGN_RACE_SIZED(g_category_group_enabled,
   1222   //                            sizeof(g_category_group_enabled),
   1223   //                           "trace_event category enabled");
   1224   for (int i = 0; i < MAX_CATEGORY_GROUPS; ++i) {
   1225     ANNOTATE_BENIGN_RACE(&g_category_group_enabled[i],
   1226                          "trace_event category enabled");
   1227   }
   1228 #if defined(OS_NACL)  // NaCl shouldn't expose the process id.
   1229   SetProcessID(0);
   1230 #else
   1231   SetProcessID(static_cast<int>(GetCurrentProcId()));
   1232 
   1233   // NaCl also shouldn't access the command line.
   1234   if (CommandLine::InitializedForCurrentProcess() &&
   1235       CommandLine::ForCurrentProcess()->HasSwitch(switches::kTraceToConsole)) {
   1236     std::string filter = CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
   1237         switches::kTraceToConsole);
   1238     if (filter.empty()) {
   1239       filter = kEchoToConsoleCategoryFilter;
   1240     } else {
   1241       filter.append(",");
   1242       filter.append(kEchoToConsoleCategoryFilter);
   1243     }
   1244 
   1245     LOG(ERROR) << "Start " << switches::kTraceToConsole
   1246                << " with CategoryFilter '" << filter << "'.";
   1247     SetEnabled(CategoryFilter(filter),
   1248                RECORDING_MODE,
   1249                TraceOptions(ECHO_TO_CONSOLE));
   1250   }
   1251 #endif
   1252 
   1253   logged_events_.reset(CreateTraceBuffer());
   1254 }
   1255 
   1256 TraceLog::~TraceLog() {
   1257 }
   1258 
   1259 const unsigned char* TraceLog::GetCategoryGroupEnabled(
   1260     const char* category_group) {
   1261   TraceLog* tracelog = GetInstance();
   1262   if (!tracelog) {
   1263     DCHECK(!g_category_group_enabled[g_category_already_shutdown]);
   1264     return &g_category_group_enabled[g_category_already_shutdown];
   1265   }
   1266   return tracelog->GetCategoryGroupEnabledInternal(category_group);
   1267 }
   1268 
   1269 const char* TraceLog::GetCategoryGroupName(
   1270     const unsigned char* category_group_enabled) {
   1271   // Calculate the index of the category group by finding
   1272   // category_group_enabled in g_category_group_enabled array.
   1273   uintptr_t category_begin =
   1274       reinterpret_cast<uintptr_t>(g_category_group_enabled);
   1275   uintptr_t category_ptr = reinterpret_cast<uintptr_t>(category_group_enabled);
   1276   DCHECK(category_ptr >= category_begin &&
   1277          category_ptr < reinterpret_cast<uintptr_t>(
   1278              g_category_group_enabled + MAX_CATEGORY_GROUPS)) <<
   1279       "out of bounds category pointer";
   1280   uintptr_t category_index =
   1281       (category_ptr - category_begin) / sizeof(g_category_group_enabled[0]);
   1282   return g_category_groups[category_index];
   1283 }
   1284 
   1285 void TraceLog::UpdateCategoryGroupEnabledFlag(size_t category_index) {
   1286   unsigned char enabled_flag = 0;
   1287   const char* category_group = g_category_groups[category_index];
   1288   if (mode_ == RECORDING_MODE &&
   1289       category_filter_.IsCategoryGroupEnabled(category_group))
   1290     enabled_flag |= ENABLED_FOR_RECORDING;
   1291   else if (mode_ == MONITORING_MODE &&
   1292       category_filter_.IsCategoryGroupEnabled(category_group))
   1293     enabled_flag |= ENABLED_FOR_MONITORING;
   1294   if (event_callback_ &&
   1295       event_callback_category_filter_.IsCategoryGroupEnabled(category_group))
   1296     enabled_flag |= ENABLED_FOR_EVENT_CALLBACK;
   1297   g_category_group_enabled[category_index] = enabled_flag;
   1298 }
   1299 
   1300 void TraceLog::UpdateCategoryGroupEnabledFlags() {
   1301   size_t category_index = base::subtle::NoBarrier_Load(&g_category_index);
   1302   for (size_t i = 0; i < category_index; i++)
   1303     UpdateCategoryGroupEnabledFlag(i);
   1304 }
   1305 
   1306 void TraceLog::UpdateSyntheticDelaysFromCategoryFilter() {
   1307   ResetTraceEventSyntheticDelays();
   1308   const CategoryFilter::StringList& delays =
   1309       category_filter_.GetSyntheticDelayValues();
   1310   CategoryFilter::StringList::const_iterator ci;
   1311   for (ci = delays.begin(); ci != delays.end(); ++ci) {
   1312     StringTokenizer tokens(*ci, ";");
   1313     if (!tokens.GetNext())
   1314       continue;
   1315     TraceEventSyntheticDelay* delay =
   1316         TraceEventSyntheticDelay::Lookup(tokens.token());
   1317     while (tokens.GetNext()) {
   1318       std::string token = tokens.token();
   1319       char* duration_end;
   1320       double target_duration = strtod(token.c_str(), &duration_end);
   1321       if (duration_end != token.c_str()) {
   1322         delay->SetTargetDuration(
   1323             TimeDelta::FromMicroseconds(target_duration * 1e6));
   1324       } else if (token == "static") {
   1325         delay->SetMode(TraceEventSyntheticDelay::STATIC);
   1326       } else if (token == "oneshot") {
   1327         delay->SetMode(TraceEventSyntheticDelay::ONE_SHOT);
   1328       } else if (token == "alternating") {
   1329         delay->SetMode(TraceEventSyntheticDelay::ALTERNATING);
   1330       }
   1331     }
   1332   }
   1333 }
   1334 
   1335 const unsigned char* TraceLog::GetCategoryGroupEnabledInternal(
   1336     const char* category_group) {
   1337   DCHECK(!strchr(category_group, '"')) <<
   1338       "Category groups may not contain double quote";
   1339   // The g_category_groups is append only, avoid using a lock for the fast path.
   1340   size_t current_category_index = base::subtle::Acquire_Load(&g_category_index);
   1341 
   1342   // Search for pre-existing category group.
   1343   for (size_t i = 0; i < current_category_index; ++i) {
   1344     if (strcmp(g_category_groups[i], category_group) == 0) {
   1345       return &g_category_group_enabled[i];
   1346     }
   1347   }
   1348 
   1349   unsigned char* category_group_enabled = NULL;
   1350   // This is the slow path: the lock is not held in the case above, so more
   1351   // than one thread could have reached here trying to add the same category.
   1352   // Only hold to lock when actually appending a new category, and
   1353   // check the categories groups again.
   1354   AutoLock lock(lock_);
   1355   size_t category_index = base::subtle::Acquire_Load(&g_category_index);
   1356   for (size_t i = 0; i < category_index; ++i) {
   1357     if (strcmp(g_category_groups[i], category_group) == 0) {
   1358       return &g_category_group_enabled[i];
   1359     }
   1360   }
   1361 
   1362   // Create a new category group.
   1363   DCHECK(category_index < MAX_CATEGORY_GROUPS) <<
   1364       "must increase MAX_CATEGORY_GROUPS";
   1365   if (category_index < MAX_CATEGORY_GROUPS) {
   1366     // Don't hold on to the category_group pointer, so that we can create
   1367     // category groups with strings not known at compile time (this is
   1368     // required by SetWatchEvent).
   1369     const char* new_group = strdup(category_group);
   1370     ANNOTATE_LEAKING_OBJECT_PTR(new_group);
   1371     g_category_groups[category_index] = new_group;
   1372     DCHECK(!g_category_group_enabled[category_index]);
   1373     // Note that if both included and excluded patterns in the
   1374     // CategoryFilter are empty, we exclude nothing,
   1375     // thereby enabling this category group.
   1376     UpdateCategoryGroupEnabledFlag(category_index);
   1377     category_group_enabled = &g_category_group_enabled[category_index];
   1378     // Update the max index now.
   1379     base::subtle::Release_Store(&g_category_index, category_index + 1);
   1380   } else {
   1381     category_group_enabled =
   1382         &g_category_group_enabled[g_category_categories_exhausted];
   1383   }
   1384   return category_group_enabled;
   1385 }
   1386 
   1387 void TraceLog::GetKnownCategoryGroups(
   1388     std::vector<std::string>* category_groups) {
   1389   AutoLock lock(lock_);
   1390   category_groups->push_back(
   1391       g_category_groups[g_category_trace_event_overhead]);
   1392   size_t category_index = base::subtle::NoBarrier_Load(&g_category_index);
   1393   for (size_t i = g_num_builtin_categories; i < category_index; i++)
   1394     category_groups->push_back(g_category_groups[i]);
   1395 }
   1396 
   1397 void TraceLog::SetEnabled(const CategoryFilter& category_filter,
   1398                           Mode mode,
   1399                           const TraceOptions& options) {
   1400   std::vector<EnabledStateObserver*> observer_list;
   1401   {
   1402     AutoLock lock(lock_);
   1403 
   1404     // Can't enable tracing when Flush() is in progress.
   1405     DCHECK(!flush_message_loop_proxy_.get());
   1406 
   1407     InternalTraceOptions new_options =
   1408         GetInternalOptionsFromTraceOptions(options);
   1409 
   1410    InternalTraceOptions old_options = trace_options();
   1411 
   1412     if (IsEnabled()) {
   1413       if (new_options != old_options) {
   1414         DLOG(ERROR) << "Attempting to re-enable tracing with a different "
   1415                     << "set of options.";
   1416       }
   1417 
   1418       if (mode != mode_) {
   1419         DLOG(ERROR) << "Attempting to re-enable tracing with a different mode.";
   1420       }
   1421 
   1422       category_filter_.Merge(category_filter);
   1423       UpdateCategoryGroupEnabledFlags();
   1424       return;
   1425     }
   1426 
   1427     if (dispatching_to_observer_list_) {
   1428       DLOG(ERROR) <<
   1429           "Cannot manipulate TraceLog::Enabled state from an observer.";
   1430       return;
   1431     }
   1432 
   1433     mode_ = mode;
   1434 
   1435     if (new_options != old_options) {
   1436       subtle::NoBarrier_Store(&trace_options_, new_options);
   1437       UseNextTraceBuffer();
   1438     }
   1439 
   1440     num_traces_recorded_++;
   1441 
   1442     category_filter_ = CategoryFilter(category_filter);
   1443     UpdateCategoryGroupEnabledFlags();
   1444     UpdateSyntheticDelaysFromCategoryFilter();
   1445 
   1446     if (new_options & kInternalEnableSampling) {
   1447       sampling_thread_.reset(new TraceSamplingThread);
   1448       sampling_thread_->RegisterSampleBucket(
   1449           &g_trace_state[0],
   1450           "bucket0",
   1451           Bind(&TraceSamplingThread::DefaultSamplingCallback));
   1452       sampling_thread_->RegisterSampleBucket(
   1453           &g_trace_state[1],
   1454           "bucket1",
   1455           Bind(&TraceSamplingThread::DefaultSamplingCallback));
   1456       sampling_thread_->RegisterSampleBucket(
   1457           &g_trace_state[2],
   1458           "bucket2",
   1459           Bind(&TraceSamplingThread::DefaultSamplingCallback));
   1460       if (!PlatformThread::Create(
   1461             0, sampling_thread_.get(), &sampling_thread_handle_)) {
   1462         DCHECK(false) << "failed to create thread";
   1463       }
   1464     }
   1465 
   1466     dispatching_to_observer_list_ = true;
   1467     observer_list = enabled_state_observer_list_;
   1468   }
   1469   // Notify observers outside the lock in case they trigger trace events.
   1470   for (size_t i = 0; i < observer_list.size(); ++i)
   1471     observer_list[i]->OnTraceLogEnabled();
   1472 
   1473   {
   1474     AutoLock lock(lock_);
   1475     dispatching_to_observer_list_ = false;
   1476   }
   1477 }
   1478 
   1479 TraceLog::InternalTraceOptions TraceLog::GetInternalOptionsFromTraceOptions(
   1480     const TraceOptions& options) {
   1481   InternalTraceOptions ret =
   1482       options.enable_sampling ? kInternalEnableSampling : kInternalNone;
   1483   switch (options.record_mode) {
   1484     case RECORD_UNTIL_FULL:
   1485       return ret | kInternalRecordUntilFull;
   1486     case RECORD_CONTINUOUSLY:
   1487       return ret | kInternalRecordContinuously;
   1488     case ECHO_TO_CONSOLE:
   1489       return ret | kInternalEchoToConsole;
   1490     case RECORD_AS_MUCH_AS_POSSIBLE:
   1491       return ret | kInternalRecordAsMuchAsPossible;
   1492   }
   1493   NOTREACHED();
   1494   return kInternalNone;
   1495 }
   1496 
   1497 CategoryFilter TraceLog::GetCurrentCategoryFilter() {
   1498   AutoLock lock(lock_);
   1499   return category_filter_;
   1500 }
   1501 
   1502 TraceOptions TraceLog::GetCurrentTraceOptions() const {
   1503   TraceOptions ret;
   1504   InternalTraceOptions option = trace_options();
   1505   ret.enable_sampling = (option & kInternalEnableSampling) != 0;
   1506   if (option & kInternalRecordUntilFull)
   1507     ret.record_mode = RECORD_UNTIL_FULL;
   1508   else if (option & kInternalRecordContinuously)
   1509     ret.record_mode = RECORD_CONTINUOUSLY;
   1510   else if (option & kInternalEchoToConsole)
   1511     ret.record_mode = ECHO_TO_CONSOLE;
   1512   else if (option & kInternalRecordAsMuchAsPossible)
   1513     ret.record_mode = RECORD_AS_MUCH_AS_POSSIBLE;
   1514   else
   1515     NOTREACHED();
   1516   return ret;
   1517 }
   1518 
   1519 void TraceLog::SetDisabled() {
   1520   AutoLock lock(lock_);
   1521   SetDisabledWhileLocked();
   1522 }
   1523 
   1524 void TraceLog::SetDisabledWhileLocked() {
   1525   lock_.AssertAcquired();
   1526 
   1527   if (!IsEnabled())
   1528     return;
   1529 
   1530   if (dispatching_to_observer_list_) {
   1531     DLOG(ERROR)
   1532         << "Cannot manipulate TraceLog::Enabled state from an observer.";
   1533     return;
   1534   }
   1535 
   1536   mode_ = DISABLED;
   1537 
   1538   if (sampling_thread_.get()) {
   1539     // Stop the sampling thread.
   1540     sampling_thread_->Stop();
   1541     lock_.Release();
   1542     PlatformThread::Join(sampling_thread_handle_);
   1543     lock_.Acquire();
   1544     sampling_thread_handle_ = PlatformThreadHandle();
   1545     sampling_thread_.reset();
   1546   }
   1547 
   1548   category_filter_.Clear();
   1549   subtle::NoBarrier_Store(&watch_category_, 0);
   1550   watch_event_name_ = "";
   1551   UpdateCategoryGroupEnabledFlags();
   1552   AddMetadataEventsWhileLocked();
   1553 
   1554   dispatching_to_observer_list_ = true;
   1555   std::vector<EnabledStateObserver*> observer_list =
   1556       enabled_state_observer_list_;
   1557 
   1558   {
   1559     // Dispatch to observers outside the lock in case the observer triggers a
   1560     // trace event.
   1561     AutoUnlock unlock(lock_);
   1562     for (size_t i = 0; i < observer_list.size(); ++i)
   1563       observer_list[i]->OnTraceLogDisabled();
   1564   }
   1565   dispatching_to_observer_list_ = false;
   1566 }
   1567 
   1568 int TraceLog::GetNumTracesRecorded() {
   1569   AutoLock lock(lock_);
   1570   if (!IsEnabled())
   1571     return -1;
   1572   return num_traces_recorded_;
   1573 }
   1574 
   1575 void TraceLog::AddEnabledStateObserver(EnabledStateObserver* listener) {
   1576   enabled_state_observer_list_.push_back(listener);
   1577 }
   1578 
   1579 void TraceLog::RemoveEnabledStateObserver(EnabledStateObserver* listener) {
   1580   std::vector<EnabledStateObserver*>::iterator it =
   1581       std::find(enabled_state_observer_list_.begin(),
   1582                 enabled_state_observer_list_.end(),
   1583                 listener);
   1584   if (it != enabled_state_observer_list_.end())
   1585     enabled_state_observer_list_.erase(it);
   1586 }
   1587 
   1588 bool TraceLog::HasEnabledStateObserver(EnabledStateObserver* listener) const {
   1589   std::vector<EnabledStateObserver*>::const_iterator it =
   1590       std::find(enabled_state_observer_list_.begin(),
   1591                 enabled_state_observer_list_.end(),
   1592                 listener);
   1593   return it != enabled_state_observer_list_.end();
   1594 }
   1595 
   1596 float TraceLog::GetBufferPercentFull() const {
   1597   AutoLock lock(lock_);
   1598   return static_cast<float>(static_cast<double>(logged_events_->Size()) /
   1599                             logged_events_->Capacity());
   1600 }
   1601 
   1602 bool TraceLog::BufferIsFull() const {
   1603   AutoLock lock(lock_);
   1604   return logged_events_->IsFull();
   1605 }
   1606 
   1607 TraceBuffer* TraceLog::CreateTraceBuffer() {
   1608   InternalTraceOptions options = trace_options();
   1609   if (options & kInternalRecordContinuously)
   1610     return new TraceBufferRingBuffer(kTraceEventRingBufferChunks);
   1611   else if ((options & kInternalEnableSampling) && mode_ == MONITORING_MODE)
   1612     return new TraceBufferRingBuffer(kMonitorTraceEventBufferChunks);
   1613   else if (options & kInternalEchoToConsole)
   1614     return new TraceBufferRingBuffer(kEchoToConsoleTraceEventBufferChunks);
   1615   else if (options & kInternalRecordAsMuchAsPossible)
   1616     return CreateTraceBufferVectorOfSize(kTraceEventVectorBigBufferChunks);
   1617   return CreateTraceBufferVectorOfSize(kTraceEventVectorBufferChunks);
   1618 }
   1619 
   1620 TraceBuffer* TraceLog::CreateTraceBufferVectorOfSize(size_t max_chunks) {
   1621   return new TraceBufferVector(max_chunks);
   1622 }
   1623 
   1624 TraceEvent* TraceLog::AddEventToThreadSharedChunkWhileLocked(
   1625     TraceEventHandle* handle, bool check_buffer_is_full) {
   1626   lock_.AssertAcquired();
   1627 
   1628   if (thread_shared_chunk_ && thread_shared_chunk_->IsFull()) {
   1629     logged_events_->ReturnChunk(thread_shared_chunk_index_,
   1630                                 thread_shared_chunk_.Pass());
   1631   }
   1632 
   1633   if (!thread_shared_chunk_) {
   1634     thread_shared_chunk_ = logged_events_->GetChunk(
   1635         &thread_shared_chunk_index_);
   1636     if (check_buffer_is_full)
   1637       CheckIfBufferIsFullWhileLocked();
   1638   }
   1639   if (!thread_shared_chunk_)
   1640     return NULL;
   1641 
   1642   size_t event_index;
   1643   TraceEvent* trace_event = thread_shared_chunk_->AddTraceEvent(&event_index);
   1644   if (trace_event && handle) {
   1645     MakeHandle(thread_shared_chunk_->seq(), thread_shared_chunk_index_,
   1646                event_index, handle);
   1647   }
   1648   return trace_event;
   1649 }
   1650 
   1651 void TraceLog::CheckIfBufferIsFullWhileLocked() {
   1652   lock_.AssertAcquired();
   1653   if (logged_events_->IsFull()) {
   1654     if (buffer_limit_reached_timestamp_.is_null()) {
   1655       buffer_limit_reached_timestamp_ = OffsetNow();
   1656     }
   1657     SetDisabledWhileLocked();
   1658   }
   1659 }
   1660 
   1661 void TraceLog::SetEventCallbackEnabled(const CategoryFilter& category_filter,
   1662                                        EventCallback cb) {
   1663   AutoLock lock(lock_);
   1664   subtle::NoBarrier_Store(&event_callback_,
   1665                           reinterpret_cast<subtle::AtomicWord>(cb));
   1666   event_callback_category_filter_ = category_filter;
   1667   UpdateCategoryGroupEnabledFlags();
   1668 };
   1669 
   1670 void TraceLog::SetEventCallbackDisabled() {
   1671   AutoLock lock(lock_);
   1672   subtle::NoBarrier_Store(&event_callback_, 0);
   1673   UpdateCategoryGroupEnabledFlags();
   1674 }
   1675 
   1676 // Flush() works as the following:
   1677 // 1. Flush() is called in threadA whose message loop is saved in
   1678 //    flush_message_loop_proxy_;
   1679 // 2. If thread_message_loops_ is not empty, threadA posts task to each message
   1680 //    loop to flush the thread local buffers; otherwise finish the flush;
   1681 // 3. FlushCurrentThread() deletes the thread local event buffer:
   1682 //    - The last batch of events of the thread are flushed into the main buffer;
   1683 //    - The message loop will be removed from thread_message_loops_;
   1684 //    If this is the last message loop, finish the flush;
   1685 // 4. If any thread hasn't finish its flush in time, finish the flush.
   1686 void TraceLog::Flush(const TraceLog::OutputCallback& cb) {
   1687   if (IsEnabled()) {
   1688     // Can't flush when tracing is enabled because otherwise PostTask would
   1689     // - generate more trace events;
   1690     // - deschedule the calling thread on some platforms causing inaccurate
   1691     //   timing of the trace events.
   1692     scoped_refptr<RefCountedString> empty_result = new RefCountedString;
   1693     if (!cb.is_null())
   1694       cb.Run(empty_result, false);
   1695     LOG(WARNING) << "Ignored TraceLog::Flush called when tracing is enabled";
   1696     return;
   1697   }
   1698 
   1699   int generation = this->generation();
   1700   // Copy of thread_message_loops_ to be used without locking.
   1701   std::vector<scoped_refptr<SingleThreadTaskRunner> >
   1702       thread_message_loop_task_runners;
   1703   {
   1704     AutoLock lock(lock_);
   1705     DCHECK(!flush_message_loop_proxy_.get());
   1706     flush_message_loop_proxy_ = MessageLoopProxy::current();
   1707     DCHECK(!thread_message_loops_.size() || flush_message_loop_proxy_.get());
   1708     flush_output_callback_ = cb;
   1709 
   1710     if (thread_shared_chunk_) {
   1711       logged_events_->ReturnChunk(thread_shared_chunk_index_,
   1712                                   thread_shared_chunk_.Pass());
   1713     }
   1714 
   1715     if (thread_message_loops_.size()) {
   1716       for (hash_set<MessageLoop*>::const_iterator it =
   1717            thread_message_loops_.begin();
   1718            it != thread_message_loops_.end(); ++it) {
   1719         thread_message_loop_task_runners.push_back((*it)->task_runner());
   1720       }
   1721     }
   1722   }
   1723 
   1724   if (thread_message_loop_task_runners.size()) {
   1725     for (size_t i = 0; i < thread_message_loop_task_runners.size(); ++i) {
   1726       thread_message_loop_task_runners[i]->PostTask(
   1727           FROM_HERE,
   1728           Bind(&TraceLog::FlushCurrentThread, Unretained(this), generation));
   1729     }
   1730     flush_message_loop_proxy_->PostDelayedTask(
   1731         FROM_HERE,
   1732         Bind(&TraceLog::OnFlushTimeout, Unretained(this), generation),
   1733         TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs));
   1734     return;
   1735   }
   1736 
   1737   FinishFlush(generation);
   1738 }
   1739 
   1740 void TraceLog::ConvertTraceEventsToTraceFormat(
   1741     scoped_ptr<TraceBuffer> logged_events,
   1742     const TraceLog::OutputCallback& flush_output_callback) {
   1743 
   1744   if (flush_output_callback.is_null())
   1745     return;
   1746 
   1747   // The callback need to be called at least once even if there is no events
   1748   // to let the caller know the completion of flush.
   1749   bool has_more_events = true;
   1750   do {
   1751     scoped_refptr<RefCountedString> json_events_str_ptr =
   1752         new RefCountedString();
   1753 
   1754     for (size_t i = 0; i < kTraceEventBatchChunks; ++i) {
   1755       const TraceBufferChunk* chunk = logged_events->NextChunk();
   1756       if (!chunk) {
   1757         has_more_events = false;
   1758         break;
   1759       }
   1760       for (size_t j = 0; j < chunk->size(); ++j) {
   1761         if (i > 0 || j > 0)
   1762           json_events_str_ptr->data().append(",");
   1763         chunk->GetEventAt(j)->AppendAsJSON(&(json_events_str_ptr->data()));
   1764       }
   1765     }
   1766 
   1767     flush_output_callback.Run(json_events_str_ptr, has_more_events);
   1768   } while (has_more_events);
   1769 }
   1770 
   1771 void TraceLog::FinishFlush(int generation) {
   1772   scoped_ptr<TraceBuffer> previous_logged_events;
   1773   OutputCallback flush_output_callback;
   1774 
   1775   if (!CheckGeneration(generation))
   1776     return;
   1777 
   1778   {
   1779     AutoLock lock(lock_);
   1780 
   1781     previous_logged_events.swap(logged_events_);
   1782     UseNextTraceBuffer();
   1783     thread_message_loops_.clear();
   1784 
   1785     flush_message_loop_proxy_ = NULL;
   1786     flush_output_callback = flush_output_callback_;
   1787     flush_output_callback_.Reset();
   1788   }
   1789 
   1790   ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(),
   1791                                   flush_output_callback);
   1792 }
   1793 
   1794 // Run in each thread holding a local event buffer.
   1795 void TraceLog::FlushCurrentThread(int generation) {
   1796   {
   1797     AutoLock lock(lock_);
   1798     if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get()) {
   1799       // This is late. The corresponding flush has finished.
   1800       return;
   1801     }
   1802   }
   1803 
   1804   // This will flush the thread local buffer.
   1805   delete thread_local_event_buffer_.Get();
   1806 
   1807   AutoLock lock(lock_);
   1808   if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get() ||
   1809       thread_message_loops_.size())
   1810     return;
   1811 
   1812   flush_message_loop_proxy_->PostTask(
   1813       FROM_HERE,
   1814       Bind(&TraceLog::FinishFlush, Unretained(this), generation));
   1815 }
   1816 
   1817 void TraceLog::OnFlushTimeout(int generation) {
   1818   {
   1819     AutoLock lock(lock_);
   1820     if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get()) {
   1821       // Flush has finished before timeout.
   1822       return;
   1823     }
   1824 
   1825     LOG(WARNING) <<
   1826         "The following threads haven't finished flush in time. "
   1827         "If this happens stably for some thread, please call "
   1828         "TraceLog::GetInstance()->SetCurrentThreadBlocksMessageLoop() from "
   1829         "the thread to avoid its trace events from being lost.";
   1830     for (hash_set<MessageLoop*>::const_iterator it =
   1831          thread_message_loops_.begin();
   1832          it != thread_message_loops_.end(); ++it) {
   1833       LOG(WARNING) << "Thread: " << (*it)->thread_name();
   1834     }
   1835   }
   1836   FinishFlush(generation);
   1837 }
   1838 
   1839 void TraceLog::FlushButLeaveBufferIntact(
   1840     const TraceLog::OutputCallback& flush_output_callback) {
   1841   scoped_ptr<TraceBuffer> previous_logged_events;
   1842   {
   1843     AutoLock lock(lock_);
   1844     AddMetadataEventsWhileLocked();
   1845     if (thread_shared_chunk_) {
   1846       // Return the chunk to the main buffer to flush the sampling data.
   1847       logged_events_->ReturnChunk(thread_shared_chunk_index_,
   1848                                   thread_shared_chunk_.Pass());
   1849     }
   1850     previous_logged_events = logged_events_->CloneForIteration().Pass();
   1851   }  // release lock
   1852 
   1853   ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(),
   1854                                   flush_output_callback);
   1855 }
   1856 
   1857 void TraceLog::UseNextTraceBuffer() {
   1858   logged_events_.reset(CreateTraceBuffer());
   1859   subtle::NoBarrier_AtomicIncrement(&generation_, 1);
   1860   thread_shared_chunk_.reset();
   1861   thread_shared_chunk_index_ = 0;
   1862 }
   1863 
   1864 TraceEventHandle TraceLog::AddTraceEvent(
   1865     char phase,
   1866     const unsigned char* category_group_enabled,
   1867     const char* name,
   1868     unsigned long long id,
   1869     int num_args,
   1870     const char** arg_names,
   1871     const unsigned char* arg_types,
   1872     const unsigned long long* arg_values,
   1873     const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
   1874     unsigned char flags) {
   1875   int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
   1876   base::TimeTicks now = base::TimeTicks::NowFromSystemTraceTime();
   1877   return AddTraceEventWithThreadIdAndTimestamp(phase, category_group_enabled,
   1878                                                name, id, thread_id, now,
   1879                                                num_args, arg_names,
   1880                                                arg_types, arg_values,
   1881                                                convertable_values, flags);
   1882 }
   1883 
   1884 TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp(
   1885     char phase,
   1886     const unsigned char* category_group_enabled,
   1887     const char* name,
   1888     unsigned long long id,
   1889     int thread_id,
   1890     const TimeTicks& timestamp,
   1891     int num_args,
   1892     const char** arg_names,
   1893     const unsigned char* arg_types,
   1894     const unsigned long long* arg_values,
   1895     const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
   1896     unsigned char flags) {
   1897   TraceEventHandle handle = { 0, 0, 0 };
   1898   if (!*category_group_enabled)
   1899     return handle;
   1900 
   1901   // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when
   1902   // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) ->
   1903   // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ...
   1904   if (thread_is_in_trace_event_.Get())
   1905     return handle;
   1906 
   1907   AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_);
   1908 
   1909   DCHECK(name);
   1910 
   1911   if (flags & TRACE_EVENT_FLAG_MANGLE_ID)
   1912     id ^= process_id_hash_;
   1913 
   1914   TimeTicks now = OffsetTimestamp(timestamp);
   1915   TimeTicks thread_now = ThreadNow();
   1916 
   1917   ThreadLocalEventBuffer* thread_local_event_buffer = NULL;
   1918   // A ThreadLocalEventBuffer needs the message loop
   1919   // - to know when the thread exits;
   1920   // - to handle the final flush.
   1921   // For a thread without a message loop or the message loop may be blocked, the
   1922   // trace events will be added into the main buffer directly.
   1923   if (!thread_blocks_message_loop_.Get() && MessageLoop::current()) {
   1924     thread_local_event_buffer = thread_local_event_buffer_.Get();
   1925     if (thread_local_event_buffer &&
   1926         !CheckGeneration(thread_local_event_buffer->generation())) {
   1927       delete thread_local_event_buffer;
   1928       thread_local_event_buffer = NULL;
   1929     }
   1930     if (!thread_local_event_buffer) {
   1931       thread_local_event_buffer = new ThreadLocalEventBuffer(this);
   1932       thread_local_event_buffer_.Set(thread_local_event_buffer);
   1933     }
   1934   }
   1935 
   1936   // Check and update the current thread name only if the event is for the
   1937   // current thread to avoid locks in most cases.
   1938   if (thread_id == static_cast<int>(PlatformThread::CurrentId())) {
   1939     const char* new_name = ThreadIdNameManager::GetInstance()->
   1940         GetName(thread_id);
   1941     // Check if the thread name has been set or changed since the previous
   1942     // call (if any), but don't bother if the new name is empty. Note this will
   1943     // not detect a thread name change within the same char* buffer address: we
   1944     // favor common case performance over corner case correctness.
   1945     if (new_name != g_current_thread_name.Get().Get() &&
   1946         new_name && *new_name) {
   1947       g_current_thread_name.Get().Set(new_name);
   1948 
   1949       AutoLock thread_info_lock(thread_info_lock_);
   1950 
   1951       hash_map<int, std::string>::iterator existing_name =
   1952           thread_names_.find(thread_id);
   1953       if (existing_name == thread_names_.end()) {
   1954         // This is a new thread id, and a new name.
   1955         thread_names_[thread_id] = new_name;
   1956       } else {
   1957         // This is a thread id that we've seen before, but potentially with a
   1958         // new name.
   1959         std::vector<StringPiece> existing_names;
   1960         Tokenize(existing_name->second, ",", &existing_names);
   1961         bool found = std::find(existing_names.begin(),
   1962                                existing_names.end(),
   1963                                new_name) != existing_names.end();
   1964         if (!found) {
   1965           if (existing_names.size())
   1966             existing_name->second.push_back(',');
   1967           existing_name->second.append(new_name);
   1968         }
   1969       }
   1970     }
   1971   }
   1972 
   1973   std::string console_message;
   1974   if (*category_group_enabled &
   1975       (ENABLED_FOR_RECORDING | ENABLED_FOR_MONITORING)) {
   1976     OptionalAutoLock lock(lock_);
   1977 
   1978     TraceEvent* trace_event = NULL;
   1979     if (thread_local_event_buffer) {
   1980       trace_event = thread_local_event_buffer->AddTraceEvent(&handle);
   1981     } else {
   1982       lock.EnsureAcquired();
   1983       trace_event = AddEventToThreadSharedChunkWhileLocked(&handle, true);
   1984     }
   1985 
   1986     if (trace_event) {
   1987       trace_event->Initialize(thread_id, now, thread_now, phase,
   1988                               category_group_enabled, name, id,
   1989                               num_args, arg_names, arg_types, arg_values,
   1990                               convertable_values, flags);
   1991 
   1992 #if defined(OS_ANDROID)
   1993       trace_event->SendToATrace();
   1994 #endif
   1995     }
   1996 
   1997     if (trace_options() & kInternalEchoToConsole) {
   1998       console_message = EventToConsoleMessage(
   1999           phase == TRACE_EVENT_PHASE_COMPLETE ? TRACE_EVENT_PHASE_BEGIN : phase,
   2000           timestamp, trace_event);
   2001     }
   2002   }
   2003 
   2004   if (console_message.size())
   2005     LOG(ERROR) << console_message;
   2006 
   2007   if (reinterpret_cast<const unsigned char*>(subtle::NoBarrier_Load(
   2008       &watch_category_)) == category_group_enabled) {
   2009     bool event_name_matches;
   2010     WatchEventCallback watch_event_callback_copy;
   2011     {
   2012       AutoLock lock(lock_);
   2013       event_name_matches = watch_event_name_ == name;
   2014       watch_event_callback_copy = watch_event_callback_;
   2015     }
   2016     if (event_name_matches) {
   2017       if (!watch_event_callback_copy.is_null())
   2018         watch_event_callback_copy.Run();
   2019     }
   2020   }
   2021 
   2022   if (*category_group_enabled & ENABLED_FOR_EVENT_CALLBACK) {
   2023     EventCallback event_callback = reinterpret_cast<EventCallback>(
   2024         subtle::NoBarrier_Load(&event_callback_));
   2025     if (event_callback) {
   2026       event_callback(now,
   2027                      phase == TRACE_EVENT_PHASE_COMPLETE ?
   2028                          TRACE_EVENT_PHASE_BEGIN : phase,
   2029                      category_group_enabled, name, id,
   2030                      num_args, arg_names, arg_types, arg_values,
   2031                      flags);
   2032     }
   2033   }
   2034 
   2035   if (thread_local_event_buffer)
   2036     thread_local_event_buffer->ReportOverhead(now, thread_now);
   2037 
   2038   return handle;
   2039 }
   2040 
   2041 // May be called when a COMPELETE event ends and the unfinished event has been
   2042 // recycled (phase == TRACE_EVENT_PHASE_END and trace_event == NULL).
   2043 std::string TraceLog::EventToConsoleMessage(unsigned char phase,
   2044                                             const TimeTicks& timestamp,
   2045                                             TraceEvent* trace_event) {
   2046   AutoLock thread_info_lock(thread_info_lock_);
   2047 
   2048   // The caller should translate TRACE_EVENT_PHASE_COMPLETE to
   2049   // TRACE_EVENT_PHASE_BEGIN or TRACE_EVENT_END.
   2050   DCHECK(phase != TRACE_EVENT_PHASE_COMPLETE);
   2051 
   2052   TimeDelta duration;
   2053   int thread_id = trace_event ?
   2054       trace_event->thread_id() : PlatformThread::CurrentId();
   2055   if (phase == TRACE_EVENT_PHASE_END) {
   2056     duration = timestamp - thread_event_start_times_[thread_id].top();
   2057     thread_event_start_times_[thread_id].pop();
   2058   }
   2059 
   2060   std::string thread_name = thread_names_[thread_id];
   2061   if (thread_colors_.find(thread_name) == thread_colors_.end())
   2062     thread_colors_[thread_name] = (thread_colors_.size() % 6) + 1;
   2063 
   2064   std::ostringstream log;
   2065   log << base::StringPrintf("%s: \x1b[0;3%dm",
   2066                             thread_name.c_str(),
   2067                             thread_colors_[thread_name]);
   2068 
   2069   size_t depth = 0;
   2070   if (thread_event_start_times_.find(thread_id) !=
   2071       thread_event_start_times_.end())
   2072     depth = thread_event_start_times_[thread_id].size();
   2073 
   2074   for (size_t i = 0; i < depth; ++i)
   2075     log << "| ";
   2076 
   2077   if (trace_event)
   2078     trace_event->AppendPrettyPrinted(&log);
   2079   if (phase == TRACE_EVENT_PHASE_END)
   2080     log << base::StringPrintf(" (%.3f ms)", duration.InMillisecondsF());
   2081 
   2082   log << "\x1b[0;m";
   2083 
   2084   if (phase == TRACE_EVENT_PHASE_BEGIN)
   2085     thread_event_start_times_[thread_id].push(timestamp);
   2086 
   2087   return log.str();
   2088 }
   2089 
   2090 void TraceLog::AddTraceEventEtw(char phase,
   2091                                 const char* name,
   2092                                 const void* id,
   2093                                 const char* extra) {
   2094 #if defined(OS_WIN)
   2095   TraceEventETWProvider::Trace(name, phase, id, extra);
   2096 #endif
   2097   INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name,
   2098                            TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
   2099 }
   2100 
   2101 void TraceLog::AddTraceEventEtw(char phase,
   2102                                 const char* name,
   2103                                 const void* id,
   2104                                 const std::string& extra) {
   2105 #if defined(OS_WIN)
   2106   TraceEventETWProvider::Trace(name, phase, id, extra);
   2107 #endif
   2108   INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name,
   2109                            TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
   2110 }
   2111 
   2112 void TraceLog::UpdateTraceEventDuration(
   2113     const unsigned char* category_group_enabled,
   2114     const char* name,
   2115     TraceEventHandle handle) {
   2116   // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when
   2117   // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) ->
   2118   // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ...
   2119   if (thread_is_in_trace_event_.Get())
   2120     return;
   2121 
   2122   AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_);
   2123 
   2124   TimeTicks thread_now = ThreadNow();
   2125   TimeTicks now = OffsetNow();
   2126 
   2127   std::string console_message;
   2128   if (*category_group_enabled & ENABLED_FOR_RECORDING) {
   2129     OptionalAutoLock lock(lock_);
   2130 
   2131     TraceEvent* trace_event = GetEventByHandleInternal(handle, &lock);
   2132     if (trace_event) {
   2133       DCHECK(trace_event->phase() == TRACE_EVENT_PHASE_COMPLETE);
   2134       trace_event->UpdateDuration(now, thread_now);
   2135 #if defined(OS_ANDROID)
   2136       trace_event->SendToATrace();
   2137 #endif
   2138     }
   2139 
   2140     if (trace_options() & kInternalEchoToConsole) {
   2141       console_message = EventToConsoleMessage(TRACE_EVENT_PHASE_END,
   2142                                               now, trace_event);
   2143     }
   2144   }
   2145 
   2146   if (console_message.size())
   2147     LOG(ERROR) << console_message;
   2148 
   2149   if (*category_group_enabled & ENABLED_FOR_EVENT_CALLBACK) {
   2150     EventCallback event_callback = reinterpret_cast<EventCallback>(
   2151         subtle::NoBarrier_Load(&event_callback_));
   2152     if (event_callback) {
   2153       event_callback(now, TRACE_EVENT_PHASE_END, category_group_enabled, name,
   2154                      trace_event_internal::kNoEventId, 0, NULL, NULL, NULL,
   2155                      TRACE_EVENT_FLAG_NONE);
   2156     }
   2157   }
   2158 }
   2159 
   2160 void TraceLog::SetWatchEvent(const std::string& category_name,
   2161                              const std::string& event_name,
   2162                              const WatchEventCallback& callback) {
   2163   const unsigned char* category = GetCategoryGroupEnabled(
   2164       category_name.c_str());
   2165   AutoLock lock(lock_);
   2166   subtle::NoBarrier_Store(&watch_category_,
   2167                           reinterpret_cast<subtle::AtomicWord>(category));
   2168   watch_event_name_ = event_name;
   2169   watch_event_callback_ = callback;
   2170 }
   2171 
   2172 void TraceLog::CancelWatchEvent() {
   2173   AutoLock lock(lock_);
   2174   subtle::NoBarrier_Store(&watch_category_, 0);
   2175   watch_event_name_ = "";
   2176   watch_event_callback_.Reset();
   2177 }
   2178 
   2179 void TraceLog::AddMetadataEventsWhileLocked() {
   2180   lock_.AssertAcquired();
   2181 
   2182 #if !defined(OS_NACL)  // NaCl shouldn't expose the process id.
   2183   InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
   2184                           0,
   2185                           "num_cpus", "number",
   2186                           base::SysInfo::NumberOfProcessors());
   2187 #endif
   2188 
   2189 
   2190   int current_thread_id = static_cast<int>(base::PlatformThread::CurrentId());
   2191   if (process_sort_index_ != 0) {
   2192     InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
   2193                             current_thread_id,
   2194                             "process_sort_index", "sort_index",
   2195                             process_sort_index_);
   2196   }
   2197 
   2198   if (process_name_.size()) {
   2199     InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
   2200                             current_thread_id,
   2201                             "process_name", "name",
   2202                             process_name_);
   2203   }
   2204 
   2205   if (process_labels_.size() > 0) {
   2206     std::vector<std::string> labels;
   2207     for(base::hash_map<int, std::string>::iterator it = process_labels_.begin();
   2208         it != process_labels_.end();
   2209         it++) {
   2210       labels.push_back(it->second);
   2211     }
   2212     InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
   2213                             current_thread_id,
   2214                             "process_labels", "labels",
   2215                             JoinString(labels, ','));
   2216   }
   2217 
   2218   // Thread sort indices.
   2219   for(hash_map<int, int>::iterator it = thread_sort_indices_.begin();
   2220       it != thread_sort_indices_.end();
   2221       it++) {
   2222     if (it->second == 0)
   2223       continue;
   2224     InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
   2225                             it->first,
   2226                             "thread_sort_index", "sort_index",
   2227                             it->second);
   2228   }
   2229 
   2230   // Thread names.
   2231   AutoLock thread_info_lock(thread_info_lock_);
   2232   for(hash_map<int, std::string>::iterator it = thread_names_.begin();
   2233       it != thread_names_.end();
   2234       it++) {
   2235     if (it->second.empty())
   2236       continue;
   2237     InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
   2238                             it->first,
   2239                             "thread_name", "name",
   2240                             it->second);
   2241   }
   2242 
   2243   // If buffer is full, add a metadata record to report this.
   2244   if (!buffer_limit_reached_timestamp_.is_null()) {
   2245     InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
   2246                             current_thread_id,
   2247                             "trace_buffer_overflowed",
   2248                             "overflowed_at_ts",
   2249                             buffer_limit_reached_timestamp_);
   2250   }
   2251 }
   2252 
   2253 void TraceLog::WaitSamplingEventForTesting() {
   2254   if (!sampling_thread_)
   2255     return;
   2256   sampling_thread_->WaitSamplingEventForTesting();
   2257 }
   2258 
   2259 void TraceLog::DeleteForTesting() {
   2260   DeleteTraceLogForTesting::Delete();
   2261 }
   2262 
   2263 TraceEvent* TraceLog::GetEventByHandle(TraceEventHandle handle) {
   2264   return GetEventByHandleInternal(handle, NULL);
   2265 }
   2266 
   2267 TraceEvent* TraceLog::GetEventByHandleInternal(TraceEventHandle handle,
   2268                                                OptionalAutoLock* lock) {
   2269   if (!handle.chunk_seq)
   2270     return NULL;
   2271 
   2272   if (thread_local_event_buffer_.Get()) {
   2273     TraceEvent* trace_event =
   2274         thread_local_event_buffer_.Get()->GetEventByHandle(handle);
   2275     if (trace_event)
   2276       return trace_event;
   2277   }
   2278 
   2279   // The event has been out-of-control of the thread local buffer.
   2280   // Try to get the event from the main buffer with a lock.
   2281   if (lock)
   2282     lock->EnsureAcquired();
   2283 
   2284   if (thread_shared_chunk_ &&
   2285       handle.chunk_index == thread_shared_chunk_index_) {
   2286     return handle.chunk_seq == thread_shared_chunk_->seq() ?
   2287         thread_shared_chunk_->GetEventAt(handle.event_index) : NULL;
   2288   }
   2289 
   2290   return logged_events_->GetEventByHandle(handle);
   2291 }
   2292 
   2293 void TraceLog::SetProcessID(int process_id) {
   2294   process_id_ = process_id;
   2295   // Create a FNV hash from the process ID for XORing.
   2296   // See http://isthe.com/chongo/tech/comp/fnv/ for algorithm details.
   2297   unsigned long long offset_basis = 14695981039346656037ull;
   2298   unsigned long long fnv_prime = 1099511628211ull;
   2299   unsigned long long pid = static_cast<unsigned long long>(process_id_);
   2300   process_id_hash_ = (offset_basis ^ pid) * fnv_prime;
   2301 }
   2302 
   2303 void TraceLog::SetProcessSortIndex(int sort_index) {
   2304   AutoLock lock(lock_);
   2305   process_sort_index_ = sort_index;
   2306 }
   2307 
   2308 void TraceLog::SetProcessName(const std::string& process_name) {
   2309   AutoLock lock(lock_);
   2310   process_name_ = process_name;
   2311 }
   2312 
   2313 void TraceLog::UpdateProcessLabel(
   2314     int label_id, const std::string& current_label) {
   2315   if(!current_label.length())
   2316     return RemoveProcessLabel(label_id);
   2317 
   2318   AutoLock lock(lock_);
   2319   process_labels_[label_id] = current_label;
   2320 }
   2321 
   2322 void TraceLog::RemoveProcessLabel(int label_id) {
   2323   AutoLock lock(lock_);
   2324   base::hash_map<int, std::string>::iterator it = process_labels_.find(
   2325       label_id);
   2326   if (it == process_labels_.end())
   2327     return;
   2328 
   2329   process_labels_.erase(it);
   2330 }
   2331 
   2332 void TraceLog::SetThreadSortIndex(PlatformThreadId thread_id, int sort_index) {
   2333   AutoLock lock(lock_);
   2334   thread_sort_indices_[static_cast<int>(thread_id)] = sort_index;
   2335 }
   2336 
   2337 void TraceLog::SetTimeOffset(TimeDelta offset) {
   2338   time_offset_ = offset;
   2339 }
   2340 
   2341 size_t TraceLog::GetObserverCountForTest() const {
   2342   return enabled_state_observer_list_.size();
   2343 }
   2344 
   2345 void TraceLog::SetCurrentThreadBlocksMessageLoop() {
   2346   thread_blocks_message_loop_.Set(true);
   2347   if (thread_local_event_buffer_.Get()) {
   2348     // This will flush the thread local buffer.
   2349     delete thread_local_event_buffer_.Get();
   2350   }
   2351 }
   2352 
   2353 bool CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
   2354     const std::string& str) {
   2355   return  str.empty() ||
   2356           str.at(0) == ' ' ||
   2357           str.at(str.length() - 1) == ' ';
   2358 }
   2359 
   2360 bool CategoryFilter::DoesCategoryGroupContainCategory(
   2361     const char* category_group,
   2362     const char* category) const {
   2363   DCHECK(category);
   2364   CStringTokenizer category_group_tokens(category_group,
   2365                           category_group + strlen(category_group), ",");
   2366   while (category_group_tokens.GetNext()) {
   2367     std::string category_group_token = category_group_tokens.token();
   2368     // Don't allow empty tokens, nor tokens with leading or trailing space.
   2369     DCHECK(!CategoryFilter::IsEmptyOrContainsLeadingOrTrailingWhitespace(
   2370         category_group_token))
   2371         << "Disallowed category string";
   2372     if (MatchPattern(category_group_token.c_str(), category))
   2373       return true;
   2374   }
   2375   return false;
   2376 }
   2377 
   2378 CategoryFilter::CategoryFilter(const std::string& filter_string) {
   2379   if (!filter_string.empty())
   2380     Initialize(filter_string);
   2381   else
   2382     Initialize(CategoryFilter::kDefaultCategoryFilterString);
   2383 }
   2384 
   2385 CategoryFilter::CategoryFilter() {
   2386     Initialize(CategoryFilter::kDefaultCategoryFilterString);
   2387 }
   2388 
   2389 CategoryFilter::CategoryFilter(const CategoryFilter& cf)
   2390     : included_(cf.included_),
   2391       disabled_(cf.disabled_),
   2392       excluded_(cf.excluded_),
   2393       delays_(cf.delays_) {
   2394 }
   2395 
   2396 CategoryFilter::~CategoryFilter() {
   2397 }
   2398 
   2399 CategoryFilter& CategoryFilter::operator=(const CategoryFilter& rhs) {
   2400   if (this == &rhs)
   2401     return *this;
   2402 
   2403   included_ = rhs.included_;
   2404   disabled_ = rhs.disabled_;
   2405   excluded_ = rhs.excluded_;
   2406   delays_ = rhs.delays_;
   2407   return *this;
   2408 }
   2409 
   2410 void CategoryFilter::Initialize(const std::string& filter_string) {
   2411   // Tokenize list of categories, delimited by ','.
   2412   StringTokenizer tokens(filter_string, ",");
   2413   // Add each token to the appropriate list (included_,excluded_).
   2414   while (tokens.GetNext()) {
   2415     std::string category = tokens.token();
   2416     // Ignore empty categories.
   2417     if (category.empty())
   2418       continue;
   2419     // Synthetic delays are of the form 'DELAY(delay;option;option;...)'.
   2420     if (category.find(kSyntheticDelayCategoryFilterPrefix) == 0 &&
   2421         category.at(category.size() - 1) == ')') {
   2422       category = category.substr(
   2423           strlen(kSyntheticDelayCategoryFilterPrefix),
   2424           category.size() - strlen(kSyntheticDelayCategoryFilterPrefix) - 1);
   2425       size_t name_length = category.find(';');
   2426       if (name_length != std::string::npos && name_length > 0 &&
   2427           name_length != category.size() - 1) {
   2428         delays_.push_back(category);
   2429       }
   2430     } else if (category.at(0) == '-') {
   2431       // Excluded categories start with '-'.
   2432       // Remove '-' from category string.
   2433       category = category.substr(1);
   2434       excluded_.push_back(category);
   2435     } else if (category.compare(0, strlen(TRACE_DISABLED_BY_DEFAULT("")),
   2436                                 TRACE_DISABLED_BY_DEFAULT("")) == 0) {
   2437       disabled_.push_back(category);
   2438     } else {
   2439       included_.push_back(category);
   2440     }
   2441   }
   2442 }
   2443 
   2444 void CategoryFilter::WriteString(const StringList& values,
   2445                                  std::string* out,
   2446                                  bool included) const {
   2447   bool prepend_comma = !out->empty();
   2448   int token_cnt = 0;
   2449   for (StringList::const_iterator ci = values.begin();
   2450        ci != values.end(); ++ci) {
   2451     if (token_cnt > 0 || prepend_comma)
   2452       StringAppendF(out, ",");
   2453     StringAppendF(out, "%s%s", (included ? "" : "-"), ci->c_str());
   2454     ++token_cnt;
   2455   }
   2456 }
   2457 
   2458 void CategoryFilter::WriteString(const StringList& delays,
   2459                                  std::string* out) const {
   2460   bool prepend_comma = !out->empty();
   2461   int token_cnt = 0;
   2462   for (StringList::const_iterator ci = delays.begin();
   2463        ci != delays.end(); ++ci) {
   2464     if (token_cnt > 0 || prepend_comma)
   2465       StringAppendF(out, ",");
   2466     StringAppendF(out, "%s%s)", kSyntheticDelayCategoryFilterPrefix,
   2467                   ci->c_str());
   2468     ++token_cnt;
   2469   }
   2470 }
   2471 
   2472 std::string CategoryFilter::ToString() const {
   2473   std::string filter_string;
   2474   WriteString(included_, &filter_string, true);
   2475   WriteString(disabled_, &filter_string, true);
   2476   WriteString(excluded_, &filter_string, false);
   2477   WriteString(delays_, &filter_string);
   2478   return filter_string;
   2479 }
   2480 
   2481 bool CategoryFilter::IsCategoryGroupEnabled(
   2482     const char* category_group_name) const {
   2483   // TraceLog should call this method only as  part of enabling/disabling
   2484   // categories.
   2485   StringList::const_iterator ci;
   2486 
   2487   // Check the disabled- filters and the disabled-* wildcard first so that a
   2488   // "*" filter does not include the disabled.
   2489   for (ci = disabled_.begin(); ci != disabled_.end(); ++ci) {
   2490     if (DoesCategoryGroupContainCategory(category_group_name, ci->c_str()))
   2491       return true;
   2492   }
   2493   if (DoesCategoryGroupContainCategory(category_group_name,
   2494                                        TRACE_DISABLED_BY_DEFAULT("*")))
   2495     return false;
   2496 
   2497   for (ci = included_.begin(); ci != included_.end(); ++ci) {
   2498     if (DoesCategoryGroupContainCategory(category_group_name, ci->c_str()))
   2499       return true;
   2500   }
   2501 
   2502   for (ci = excluded_.begin(); ci != excluded_.end(); ++ci) {
   2503     if (DoesCategoryGroupContainCategory(category_group_name, ci->c_str()))
   2504       return false;
   2505   }
   2506   // If the category group is not excluded, and there are no included patterns
   2507   // we consider this pattern enabled.
   2508   return included_.empty();
   2509 }
   2510 
   2511 bool CategoryFilter::HasIncludedPatterns() const {
   2512   return !included_.empty();
   2513 }
   2514 
   2515 void CategoryFilter::Merge(const CategoryFilter& nested_filter) {
   2516   // Keep included patterns only if both filters have an included entry.
   2517   // Otherwise, one of the filter was specifying "*" and we want to honour the
   2518   // broadest filter.
   2519   if (HasIncludedPatterns() && nested_filter.HasIncludedPatterns()) {
   2520     included_.insert(included_.end(),
   2521                      nested_filter.included_.begin(),
   2522                      nested_filter.included_.end());
   2523   } else {
   2524     included_.clear();
   2525   }
   2526 
   2527   disabled_.insert(disabled_.end(),
   2528                    nested_filter.disabled_.begin(),
   2529                    nested_filter.disabled_.end());
   2530   excluded_.insert(excluded_.end(),
   2531                    nested_filter.excluded_.begin(),
   2532                    nested_filter.excluded_.end());
   2533   delays_.insert(delays_.end(),
   2534                  nested_filter.delays_.begin(),
   2535                  nested_filter.delays_.end());
   2536 }
   2537 
   2538 void CategoryFilter::Clear() {
   2539   included_.clear();
   2540   disabled_.clear();
   2541   excluded_.clear();
   2542 }
   2543 
   2544 const CategoryFilter::StringList&
   2545     CategoryFilter::GetSyntheticDelayValues() const {
   2546   return delays_;
   2547 }
   2548 
   2549 }  // namespace debug
   2550 }  // namespace base
   2551 
   2552 namespace trace_event_internal {
   2553 
   2554 ScopedTraceBinaryEfficient::ScopedTraceBinaryEfficient(
   2555     const char* category_group, const char* name) {
   2556   // The single atom works because for now the category_group can only be "gpu".
   2557   DCHECK(strcmp(category_group, "gpu") == 0);
   2558   static TRACE_EVENT_API_ATOMIC_WORD atomic = 0;
   2559   INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO_CUSTOM_VARIABLES(
   2560       category_group, atomic, category_group_enabled_);
   2561   name_ = name;
   2562   if (*category_group_enabled_) {
   2563     event_handle_ =
   2564         TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
   2565             TRACE_EVENT_PHASE_COMPLETE, category_group_enabled_, name,
   2566             trace_event_internal::kNoEventId,
   2567             static_cast<int>(base::PlatformThread::CurrentId()),
   2568             base::TimeTicks::NowFromSystemTraceTime(),
   2569             0, NULL, NULL, NULL, NULL, TRACE_EVENT_FLAG_NONE);
   2570   }
   2571 }
   2572 
   2573 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() {
   2574   if (*category_group_enabled_) {
   2575     TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_,
   2576                                                 name_, event_handle_);
   2577   }
   2578 }
   2579 
   2580 }  // namespace trace_event_internal
   2581