Improve usages of trace_event locks

base/debug/trace_event_impl.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "base/debug/trace_event_impl.h"
 
 #include <algorithm>
 
 #include "base/base_switches.h"
 #include "base/bind.h"
@@ skipping 1160 matching lines @@
     int thread_id,
     const TimeTicks& timestamp,
     int num_args,
     const char** arg_names,
     const unsigned char* arg_types,
     const unsigned long long* arg_values,
     scoped_ptr<ConvertableToTraceFormat> convertable_values[],
     unsigned char flags) {
   DCHECK(name);
 
-  TimeDelta duration;
-  if (phase == TRACE_EVENT_PHASE_END && trace_options_ & ECHO_TO_CONSOLE) {
-    duration = timestamp - thread_event_start_times_[thread_id].top();
-    thread_event_start_times_[thread_id].pop();
-  }
-
   if (flags & TRACE_EVENT_FLAG_MANGLE_ID)
     id ^= process_id_hash_;
 
 #if defined(OS_ANDROID)
   SendToATrace(phase, GetCategoryGroupName(category_group_enabled), name, id,
                num_args, arg_names, arg_types, arg_values, convertable_values,
                flags);
 #endif
 
+  if (!IsCategoryGroupEnabled(category_group_enabled))
+    return;
+
   TimeTicks now = timestamp - time_offset_;
   EventCallback event_callback_copy;
 
   NotificationHelper notifier(this);
 
-  do {
-    AutoLock lock(lock_);
-    if (!IsCategoryGroupEnabled(category_group_enabled))
-      return;
-
-    event_callback_copy = event_callback_;
-    if (logged_events_->IsFull())
-      break;
-
+  // Check and update the current thread name only if the event is for the
+  // current thread to avoid locks in most cases.
+  if (thread_id == static_cast<int>(PlatformThread::CurrentId())) {
     const char* new_name = ThreadIdNameManager::GetInstance()->
         GetName(thread_id);
     // Check if the thread name has been set or changed since the previous
     // call (if any), but don't bother if the new name is empty. Note this will
     // not detect a thread name change within the same char* buffer address: we
     // favor common case performance over corner case correctness.
     if (new_name != g_current_thread_name.Get().Get() &&
         new_name && *new_name) {
       g_current_thread_name.Get().Set(new_name);
 
+      AutoLock lock(lock_);
       hash_map<int, std::string>::iterator existing_name =
           thread_names_.find(thread_id);
       if (existing_name == thread_names_.end()) {
         // This is a new thread id, and a new name.
         thread_names_[thread_id] = new_name;
       } else {
         // This is a thread id that we've seen before, but potentially with a
         // new name.
         std::vector<StringPiece> existing_names;
         Tokenize(existing_name->second, ",", &existing_names);
         bool found = std::find(existing_names.begin(),
                                existing_names.end(),
                                new_name) != existing_names.end();
         if (!found) {
           existing_name->second.push_back(',');
           existing_name->second.append(new_name);
         }
       }
     }
+  }
 
-    TraceEvent trace_event(thread_id,
-        now, phase, category_group_enabled, name, id,
-        num_args, arg_names, arg_types, arg_values,
-        convertable_values, flags);
+  TraceEvent trace_event(thread_id,
+      now, phase, category_group_enabled, name, id,
+      num_args, arg_names, arg_types, arg_values,
+      convertable_values, flags);
+
+  do {
+    AutoLock lock(lock_);
+
+    event_callback_copy = event_callback_;
+    if (logged_events_->IsFull())
+      break;
 
     logged_events_->AddEvent(trace_event);
 
     if (trace_options_ & ECHO_TO_CONSOLE) {
+      TimeDelta duration;
+      if (phase == TRACE_EVENT_PHASE_END) {
+        duration = timestamp - thread_event_start_times_[thread_id].top();
+        thread_event_start_times_[thread_id].pop();
+      }
+
       std::string thread_name = thread_names_[thread_id];
       if (thread_colors_.find(thread_name) == thread_colors_.end())
         thread_colors_[thread_name] = (thread_colors_.size() % 6) + 1;
 
       std::ostringstream log;
       log << base::StringPrintf("%s: \x1b[0;3%dm",
                                 thread_name.c_str(),
                                 thread_colors_[thread_name]);
 
       size_t depth = 0;
       if (thread_event_start_times_.find(thread_id) !=
           thread_event_start_times_.end())
         depth = thread_event_start_times_[thread_id].size();
 
       for (size_t i = 0; i < depth; ++i)
         log << "| ";
 
       trace_event.AppendPrettyPrinted(&log);
       if (phase == TRACE_EVENT_PHASE_END)
         log << base::StringPrintf(" (%.3f ms)", duration.InMillisecondsF());
 
       LOG(ERROR) << log.str() << "\x1b[0;m";
+
+      if (phase == TRACE_EVENT_PHASE_BEGIN)
+        thread_event_start_times_[thread_id].push(timestamp);
     }
 
     if (logged_events_->IsFull())
       notifier.AddNotificationWhileLocked(TRACE_BUFFER_FULL);
 
     if (watch_category_ == category_group_enabled && watch_event_name_ == name)
       notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION);
   } while (0); // release lock
 
-  if (phase == TRACE_EVENT_PHASE_BEGIN && trace_options_ & ECHO_TO_CONSOLE)
-    thread_event_start_times_[thread_id].push(timestamp);
-
   notifier.SendNotificationIfAny();
   if (event_callback_copy != NULL) {
     event_callback_copy(phase, category_group_enabled, name, id,
         num_args, arg_names, arg_types, arg_values,
         flags);
   }
 }
 
 void TraceLog::AddTraceEventEtw(char phase,
                                 const char* name,
@@ skipping 160 matching lines @@
 void TraceLog::UpdateProcessLabel(
     int label_id, const std::string& current_label) {
   if(!current_label.length())
     return RemoveProcessLabel(label_id);
 
   AutoLock lock(lock_);
   process_labels_[label_id] = current_label;
 }
 
 void TraceLog::RemoveProcessLabel(int label_id) {
+  AutoLock lock(lock_);
   base::hash_map<int, std::string>::iterator it = process_labels_.find(
         label_id);
   if (it == process_labels_.end())
     return;
 
   process_labels_.erase(it);
 }
 
 void TraceLog::SetThreadSortIndex(PlatformThreadId thread_id, int sort_index) {
   AutoLock lock(lock_);
@@ skipping 208 matching lines @@
         0,                       // num_args
         NULL,                    // arg_names
         NULL,                    // arg_types
         NULL,                    // arg_values
         NULL,                    // convertable values
         TRACE_EVENT_FLAG_NONE);  // flags
   }
 }
 
 }  // namespace trace_event_internal