Thread-local trace-event buffers

base/debug/trace_event_impl.h

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 
 #ifndef BASE_DEBUG_TRACE_EVENT_IMPL_H_
 #define BASE_DEBUG_TRACE_EVENT_IMPL_H_
 
 #include <stack>
 #include <string>
 #include <vector>
 
+#include "base/atomicops.h"
 #include "base/callback.h"
 #include "base/containers/hash_tables.h"
 #include "base/gtest_prod_util.h"
 #include "base/memory/ref_counted_memory.h"
 #include "base/memory/scoped_vector.h"
 #include "base/observer_list.h"
 #include "base/strings/string_util.h"
 #include "base/synchronization/condition_variable.h"
 #include "base/synchronization/lock.h"
 #include "base/threading/thread.h"
+#include "base/threading/thread_local.h"
 #include "base/timer/timer.h"
 
 // Older style trace macros with explicit id and extra data
 // Only these macros result in publishing data to ETW as currently implemented.
 #define TRACE_EVENT_BEGIN_ETW(name, id, extra) \
     base::debug::TraceLog::AddTraceEventEtw( \
         TRACE_EVENT_PHASE_BEGIN, \
         name, reinterpret_cast<const void*>(id), extra)
 
 #define TRACE_EVENT_END_ETW(name, id, extra) \
     base::debug::TraceLog::AddTraceEventEtw( \
         TRACE_EVENT_PHASE_END, \
         name, reinterpret_cast<const void*>(id), extra)
 
 #define TRACE_EVENT_INSTANT_ETW(name, id, extra) \
     base::debug::TraceLog::AddTraceEventEtw( \
         TRACE_EVENT_PHASE_INSTANT, \
         name, reinterpret_cast<const void*>(id), extra)
 
 template <typename Type>
 struct DefaultSingletonTraits;
 
+#if defined(COMPILER_GCC)
+namespace BASE_HASH_NAMESPACE {
+template <>
+struct hash<base::MessageLoop*> {
+  std::size_t operator()(base::MessageLoop* value) const {
+    return reinterpret_cast<std::size_t>(value);
+  }
+};
+}

[dsinclair, 2013/08/29 14:24:32]

nit:  // namespace BASE_HASH_NAMESPACE

[Xianzhu, 2013/08/29 17:42:12]

Done.

+#endif
+
 namespace base {
 
 class WaitableEvent;
+class MessageLoop;
 
 namespace debug {
 
 // For any argument of type TRACE_VALUE_TYPE_CONVERTABLE the provided
 // class must implement this interface.
 class ConvertableToTraceFormat {
  public:
   virtual ~ConvertableToTraceFormat() {}
 
   // Append the class info to the provided |out| string. The appended
@@ skipping 45 matching lines @@
                                  std::string* out);
   void AppendAsJSON(std::string* out) const;
   void AppendPrettyPrinted(std::ostringstream* out) const;
 
   static void AppendValueAsJSON(unsigned char type,
                                 TraceValue value,
                                 std::string* out);
 
   TimeTicks timestamp() const { return timestamp_; }
   TimeTicks thread_timestamp() const { return thread_timestamp_; }
+  char phase() const { return phase_; }
+  int thread_id() const { return thread_id_; }
 
   // Exposed for unittesting:
 
   const base::RefCountedString* parameter_copy_storage() const {
     return parameter_copy_storage_.get();
   }
 
   const unsigned char* category_group_enabled() const {
     return category_group_enabled_;
   }
@@ skipping 166 matching lines @@
     RECORD_UNTIL_FULL = 1 << 0,
 
     // Record until the user ends the trace. The trace buffer is a fixed size
     // and we use it as a ring buffer during recording.
     RECORD_CONTINUOUSLY = 1 << 1,
 
     // Enable the sampling profiler.
     ENABLE_SAMPLING = 1 << 2,
 
     // Echo to console. Events are discarded.
-    ECHO_TO_CONSOLE = 1 << 3
+    ECHO_TO_CONSOLE = 1 << 3,
   };
 
   static TraceLog* GetInstance();
 
   // Convert the given string to trace options. Defaults to RECORD_UNTIL_FULL if
   // the string does not provide valid options.
   static Options TraceOptionsFromString(const std::string& str);
 
   // Get set of known category groups. This can change as new code paths are
   // reached. The known category groups are inserted into |category_groups|.
   void GetKnownCategoryGroups(std::vector<std::string>* category_groups);
 
   // Retrieves the current CategoryFilter.
   const CategoryFilter& GetCurrentCategoryFilter();
 
-  Options trace_options() const { return trace_options_; }
+  Options trace_options() const {
+    return static_cast<Options>(subtle::NoBarrier_Load(&trace_options_));
+  }
 
   // Enables tracing. See CategoryFilter comments for details
   // on how to control what categories will be traced.
   void SetEnabled(const CategoryFilter& category_filter, Options options);
 
   // Disable tracing for all categories.
   void SetDisabled();
   bool IsEnabled() { return !!enable_count_; }
 
   // The number of times we have begun recording traces. If tracing is off,
@@ skipping 45 matching lines @@
                                 const char* name,
                                 unsigned long long id,
                                 int num_args,
                                 const char* const arg_names[],
                                 const unsigned char arg_types[],
                                 const unsigned long long arg_values[],
                                 unsigned char flags);
   void SetEventCallback(EventCallback cb);
 
   // Flush all collected events to the given output callback. The callback will
-  // be called one or more times with IPC-bite-size chunks. The string format is
+  // be called one or more times either synchronously or asynchronously from
+  // the current thread with IPC-bite-size chunks. The string format is
   // undefined. Use TraceResultBuffer to convert one or more trace strings to
-  // JSON.
-  typedef base::Callback<void(const scoped_refptr<base::RefCountedString>&)>
-      OutputCallback;
+  // JSON. Note: If called when tracing is enabled, the callback will be called
+  // directly with (empty_string, false).

[dsinclair, 2013/08/29 14:24:32]

Confused about the false. So, if we call when tracing is enabled, why is
'has_more_events' false? Wouldn't it be true since we're still tracing?

[Xianzhu, 2013/08/29 17:42:12]

Added comments:
Due to the implementation of thread-local buffers, flush can't be
done when tracing is enabled. If called when tracing is enabled, the
callback will be called directly with (empty_string, false) to indicate
the end of this unsuccessful flush.

(otherwise the caller should wait until a callback with false, but this won't
happen in this flush).

+  typedef base::Callback<void(const scoped_refptr<base::RefCountedString>&,
+                              bool has_more_events)> OutputCallback;
   void Flush(const OutputCallback& cb);
 
   // Called by TRACE_EVENT* macros, don't call this directly.
   // The name parameter is a category group for example:
   // TRACE_EVENT0("renderer,webkit", "WebViewImpl::HandleInputEvent")
   static const unsigned char* GetCategoryGroupEnabled(const char* name);
   static const char* GetCategoryGroupName(
       const unsigned char* category_group_enabled);
 
   // Called by TRACE_EVENT* macros, don't call this directly.
@@ skipping 126 matching lines @@
     // notifications from previous calls to AddNotificationWhileLocked, this
     // will call the NotificationCallback.
     inline void SendNotificationIfAny();
 
    private:
     TraceLog* trace_log_;
     NotificationCallback callback_copy_;
     int notification_;
   };
 
+  class ThreadLocalEventBuffer;
+
   TraceLog();
   ~TraceLog();
   const unsigned char* GetCategoryGroupEnabledInternal(const char* name);
   void AddMetadataEvents();
 
 #if defined(OS_ANDROID)
   void SendToATrace(char phase,
                     const char* category_group,
                     const char* name,
                     unsigned long long id,
                     int num_args,
                     const char** arg_names,
                     const unsigned char* arg_types,
                     const unsigned long long* arg_values,
                     scoped_ptr<ConvertableToTraceFormat> convertable_values[],
                     unsigned char flags);
   static void ApplyATraceEnabledFlag(unsigned char* category_group_enabled);
 #endif
 
   TraceBuffer* GetTraceBuffer();
 
-  // TODO(nduca): switch to per-thread trace buffers to reduce thread
-  // synchronization.
+  void AddEventToMainBufferWhileLocked(const TraceEvent& trace_event);
+  void CheckIfBufferIsFullWhileLocked(NotificationHelper* notifier);
+  void FlushNextThreadOrFinish();
+  void FlushCurrentThreadAndContinue();
+
   // This lock protects TraceLog member accesses from arbitrary threads.
   Lock lock_;
+  int locked_line_;
   int enable_count_;
   int num_traces_recorded_;
+  subtle::AtomicWord /* bool */ buffer_is_full_;
   NotificationCallback notification_callback_;
   scoped_ptr<TraceBuffer> logged_events_;
-  EventCallback event_callback_;
+  subtle::AtomicWord /* EventCallback */ event_callback_;
   bool dispatching_to_observer_list_;
   std::vector<EnabledStateObserver*> enabled_state_observer_list_;
 
   std::string process_name_;
   base::hash_map<int, std::string> process_labels_;
   int process_sort_index_;
   base::hash_map<int, int> thread_sort_indices_;
+  base::hash_map<int, std::string> thread_names_;
 
-  base::hash_map<int, std::string> thread_names_;
+  // The following two maps are used only when ECHO_TO_CONSOLE.
   base::hash_map<int, std::stack<TimeTicks> > thread_event_start_times_;
   base::hash_map<std::string, int> thread_colors_;
 
   // XORed with TraceID to make it unlikely to collide with other processes.
   unsigned long long process_id_hash_;
 
   int process_id_;
 
   TimeDelta time_offset_;
 
   // Allow tests to wake up when certain events occur.
-  const unsigned char* watch_category_;
+  subtle::AtomicWord /* const unsigned char* */ watch_category_;
   std::string watch_event_name_;
 
-  Options trace_options_;
+  subtle::AtomicWord /* Options */ trace_options_;
 
   // Sampling thread handles.
   scoped_ptr<TraceSamplingThread> sampling_thread_;
   PlatformThreadHandle sampling_thread_handle_;
 
   CategoryFilter category_filter_;
 
+  ThreadLocalPointer<ThreadLocalEventBuffer> thread_local_event_buffer_;
+
+  // Contains the message loops of threads that have had at least one event
+  // added into the local event buffer. Not using MessageLoopProxy because we
+  // need to know the life time of the message loops.
+  base::hash_set<MessageLoop*> thread_message_loops_;
+
+  // Set when asynchronous Flush is in progress.
+  OutputCallback flush_output_callback_;
+  scoped_refptr<MessageLoopProxy> flush_message_loop_proxy_;
+
   DISALLOW_COPY_AND_ASSIGN(TraceLog);
 };
 
 }  // namespace debug
 }  // namespace base
 
 #endif  // BASE_DEBUG_TRACE_EVENT_IMPL_H_