trace_event support for thread names

base/debug/trace_event.cc

 // Copyright (c) 2011 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "base/debug/trace_event.h"
 
 #if defined(OS_WIN)
 #include "base/debug/trace_event_win.h"
 #endif
 #include "base/format_macros.h"
@@ skipping 86 matching lines @@
 namespace {
 
 const char* GetPhaseStr(TraceEventPhase phase) {
   switch(phase) {
     case TRACE_EVENT_PHASE_BEGIN:
       return "B";
     case TRACE_EVENT_PHASE_INSTANT:
       return "I";
     case TRACE_EVENT_PHASE_END:
       return "E";
+    case TRACE_EVENT_PHASE_METADATA:
+      return "M";
     default:
       NOTREACHED() << "Invalid phase argument";
       return "?";
   }
 }
 
 size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; }
 
 // Copies |*member| into |*buffer|, sets |*member| to point to this new
 // location, and then advances |*buffer| by the amount written.
@@ skipping 171 matching lines @@
     if (enabled == enabled_)
       return;
     logged_events_.reserve(1024);
     enabled_ = enabled;
     for (int i = 0; i < g_category_index; i++) {
       //TODO(scheib): If changed to enable specific categories instead of all
       // check GetCategoryInternal creation code that users TraceLog::enabled_
       g_categories[i].enabled = enabled;
     }
   } // release lock
-  if (!enabled)
+  if (!enabled) {
+    AddCurrentMetadataEvents();
     Flush();
+  }
 }
 
 float TraceLog::GetBufferPercentFull() const {
   return (float)((double)logged_events_.size()/(double)kTraceEventBufferSize);
 }
 
 void TraceLog::SetOutputCallback(const TraceLog::OutputCallback& cb) {
   AutoLock lock(lock_);
   output_callback_ = cb;
   logged_events_.clear();
@@ skipping 44 matching lines @@
   TimeTicks now = TimeTicks::Now();
 #endif
   BufferFullCallback buffer_full_callback_copy;
   int ret_begin_id = -1;
   {
     AutoLock lock(lock_);
     if (!enabled_ || !category->enabled)
       return -1;
     if (logged_events_.size() >= kTraceEventBufferSize)
       return -1;
+    PlatformThreadId thread_id = PlatformThread::CurrentId();
+    if (thread_names_.find(thread_id) == thread_names_.end()) {

[Sigurður Ásgeirsson, 2011/08/04 12:31:39]

On Windows, thread and process IDs are reused quite aggressively, so this may
end up not recording the thread name for a thread that's inherited a previously
used thread ID.
You can either (simply) set this on every event, or else you could maintain a
thread-local boolean variable "did_record_name".

[nduca, 2011/08/04 18:17:38]

Thats an awesome idea.

+      const char* name = PlatformThread::GetName();
+      // Store something even for unnamed threads so we don't keep searching the
+      // thread_names_ map every time.
+      thread_names_[thread_id] = name ? name : "";
+    }
+
     if (threshold_begin_id > -1) {
       DCHECK(phase == base::debug::TRACE_EVENT_PHASE_END);
       size_t begin_i = static_cast<size_t>(threshold_begin_id);
       // Return now if there has been a flush since the begin event was posted.
       if (begin_i >= logged_events_.size())
         return -1;
       // Determine whether to drop the begin/end pair.
       TimeDelta elapsed = now - logged_events_[begin_i].timestamp();
       if (elapsed < TimeDelta::FromMicroseconds(threshold)) {
         // Remove begin event and do not add end event.
         // This will be expensive if there have been other events in the
         // mean time (should be rare).
         logged_events_.erase(logged_events_.begin() + begin_i);
         return -1;
       }
     }
     ret_begin_id = static_cast<int>(logged_events_.size());
     logged_events_.push_back(
         TraceEvent(static_cast<unsigned long>(base::GetCurrentProcId()),
-                   PlatformThread::CurrentId(),
+                   thread_id,
                    now, phase, category, name,
                    arg1_name, arg1_val,
                    arg2_name, arg2_val,
                    copy));
 
     if (logged_events_.size() == kTraceEventBufferSize) {
       buffer_full_callback_copy = buffer_full_callback_;
     }
   } // release lock
 
@@ skipping 18 matching lines @@
     TraceLog* tracelog = TraceLog::GetInstance();
     if (!tracelog)
       return;
     tracelog->AddTraceEvent(phase, category, name,
                             "id", id,
                             "extra", extra ? extra : "",
                             -1, 0, false);
   }
 }
 
+void TraceLog::AddCurrentMetadataEvents() {
+  static const TraceCategory* metadata_category =
+      GetCategoryInternal("__metadata");
+  for(base::hash_map<PlatformThreadId, std::string>::iterator it =

[Sigurður Ásgeirsson, 2011/08/04 12:31:39]

lock_.AssertHeld().
However, I don't think you're holding the lock here, so you have a race on the
map?

[nduca, 2011/08/04 18:17:38]

Nice catch!

+          thread_names_.begin();
+      it != thread_names_.end();
+      it++) {
+    if (!it->second.empty())
+      logged_events_.push_back(
+          TraceEvent(static_cast<unsigned long>(base::GetCurrentProcId()),
+                     it->first,
+                     TimeTicks(), base::debug::TRACE_EVENT_PHASE_METADATA,
+                     metadata_category, "thread_name",
+                     "name", it->second.c_str(),
+                     NULL, 0,
+                     false));
+  }
+}
+
 void TraceLog::Resurrect() {
   StaticMemorySingletonTraits<TraceLog>::Resurrect();
 }
 
 namespace internal {
 
 void TraceEndOnScopeClose::Initialize(const TraceCategory* category,
                                       const char* name) {
   data_.category = category;
   data_.name = name;
@@ skipping 32 matching lines @@
         p_data_->name,
         NULL, 0, NULL, 0,
         p_data_->threshold_begin_id, p_data_->threshold, false);
   }
 }
 
 } // namespace internal
 
 }  // namespace debug
 }  // namespace base