Merge gpu_trace_event back into base/debug/trace_event.

Initial land attempt at http://codereview.chromium.org/6551019/
gpu_trace_event fork at http://codereview.chromium.org/6691013

- gpu_trace_event renamed to base/debug/trace_event and modified as appropriate for base::debug
- Unit Tests implemented for trace_event
- gpu_common library removed (was added only for gpu_trace_event)
- Existing calls to trace_event suffixed with _ETW to make ETW calls (see decisions and incremental plans at end of 6551019)
- GPU trace calls renamed to new calls.
- Tracing switch removed from test_shell, as linux log file support removed.

BUG=79509
TEST=trace_event_win_unittest and about:gpu

Review URL: http://codereview.chromium.org/6862002

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@84284 0039d316-1c4b-4281-b951-d872f2087c98

8 files changed, 1199 insertions, 307 deletions

diff --git a/base/base.gyp b/base/base.gyp
index 868e20e..f629350 100644
--- a/base/base.gyp
+++ b/base/base.gyp
@@ -115,6 +115,7 @@
         'cpu_unittest.cc',
         'debug/leak_tracker_unittest.cc',
         'debug/stack_trace_unittest.cc',
+        'debug/trace_event_unittest.cc',
         'debug/trace_event_win_unittest.cc',
         'dir_reader_posix_unittest.cc',
         'environment_unittest.cc',
diff --git a/base/base.gypi b/base/base.gypi
index 51f50ed..578e50d 100644
--- a/base/base.gypi
+++ b/base/base.gypi
@@ -404,7 +404,6 @@
               # regression to page cycler moz.
               'sha1_win.cc',
               'string16.cc',
-              'debug/trace_event.cc',
             ],
           },],
           ['OS=="freebsd" or OS=="openbsd"', {
diff --git a/base/debug/trace_event.cc b/base/debug/trace_event.cc
index c219cec..e1f6061 100644
--- a/base/debug/trace_event.cc
+++ b/base/debug/trace_event.cc
@@ -1,16 +1,15 @@
-// Copyright (c) 2010 The Chromium Authors. All rights reserved.
+// 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"
-#include "base/file_path.h"
-#include "base/file_util.h"
-#include "base/path_service.h"
 #include "base/process_util.h"
 #include "base/stringprintf.h"
-#include "base/threading/platform_thread.h"
 #include "base/utf_string_conversions.h"
 #include "base/time.h"
 
@@ -19,149 +18,368 @@
 namespace base {
 namespace debug {
 
-static const char* kEventTypeNames[] = {
-  "BEGIN",
-  "END",
-  "INSTANT"
+// Controls the number of trace events we will buffer in-memory
+// before throwing them away.
+const size_t kTraceEventBufferSize = 500000;
+const size_t kTraceEventBatchSize = 1000;
+
+#define TRACE_EVENT_MAX_CATEGORIES 42
+
+static TraceCategory g_categories[TRACE_EVENT_MAX_CATEGORIES] = {
+  { "tracing already shutdown", false },
+  { "tracing categories exhausted; must increase TRACE_EVENT_MAX_CATEGORIES",
+    false }
 };
+static const TraceCategory* const g_category_already_shutdown =
+    &g_categories[0];
+static const TraceCategory* const g_category_categories_exhausted =
+    &g_categories[1];
+static int g_category_index = 2; // skip initial 2 error categories
 
-static const FilePath::CharType* kLogFileName =
-    FILE_PATH_LITERAL("trace_%d.log");
+////////////////////////////////////////////////////////////////////////////////
+//
+// TraceValue
+//
+////////////////////////////////////////////////////////////////////////////////
 
-// static
-TraceLog* TraceLog::GetInstance() {
-  return Singleton<TraceLog, DefaultSingletonTraits<TraceLog> >::get();
+void TraceValue::Destroy() {
+  if (type_ == TRACE_TYPE_STRING) {
+    value_.as_string_refptr->Release();
+    value_.as_string_refptr = NULL;
+  }
+  type_ = TRACE_TYPE_UNDEFINED;
+  value_.as_uint = 0ull;
 }
 
-// static
-bool TraceLog::IsTracing() {
-  return TraceLog::GetInstance()->enabled_;
+TraceValue& TraceValue::operator=(const TraceValue& rhs) {
+  if (this == &rhs)
+    return *this;
+
+  Destroy();
+
+  type_ = rhs.type_;
+  switch(type_) {
+    case TRACE_TYPE_UNDEFINED:
+      return *this;
+    case TRACE_TYPE_BOOL:
+      value_.as_bool = rhs.value_.as_bool;
+      return *this;
+    case TRACE_TYPE_UINT:
+      value_.as_uint = rhs.value_.as_uint;
+      return *this;
+    case TRACE_TYPE_INT:
+      value_.as_int = rhs.value_.as_int;
+      return *this;
+    case TRACE_TYPE_DOUBLE:
+      value_.as_double = rhs.value_.as_double;
+      return *this;
+    case TRACE_TYPE_POINTER:
+      value_.as_pointer = rhs.value_.as_pointer;
+      return *this;
+    case TRACE_TYPE_STRING:
+      value_.as_string_refptr = rhs.value_.as_string_refptr;
+      value_.as_string_refptr->AddRef();
+      return *this;
+    default:
+      NOTREACHED();
+      return *this;
+  }
 }
 
-// static
-bool TraceLog::StartTracing() {
-  return TraceLog::GetInstance()->Start();
+void TraceValue::AppendAsJSON(std::string* out) const {
+  char temp_string[128];
+  std::string::size_type start_pos;
+  switch (type_) {
+    case TRACE_TYPE_BOOL:
+      *out += as_bool()? "true" : "false";
+      break;
+    case TRACE_TYPE_UINT:
+      base::snprintf(temp_string, arraysize(temp_string), "%llu",
+                     static_cast<unsigned long long>(as_uint()));
+      *out += temp_string;
+      break;
+    case TRACE_TYPE_INT:
+      base::snprintf(temp_string, arraysize(temp_string), "%lld",
+                     static_cast<long long>(as_int()));
+      *out += temp_string;
+      break;
+    case TRACE_TYPE_DOUBLE:
+      base::snprintf(temp_string, arraysize(temp_string), "%f", as_double());
+      *out += temp_string;
+      break;
+    case TRACE_TYPE_POINTER:
+      base::snprintf(temp_string, arraysize(temp_string), "%llu",
+                     static_cast<unsigned long long>(
+                       reinterpret_cast<intptr_t>(
+                         as_pointer())));
+      *out += temp_string;
+      break;
+    case TRACE_TYPE_STRING:
+      *out += "\"";
+      start_pos = out->size();
+      *out += as_string();
+      // replace " character with '
+      while ((start_pos = out->find_first_of('\"', start_pos)) !=
+             std::string::npos)
+        (*out)[start_pos] = '\'';
+      *out += "\"";
+      break;
+    default:
+      NOTREACHED() << "Don't know how to print this value";
+      break;
+  }
 }
 
-// static
-void TraceLog::StopTracing() {
-  return TraceLog::GetInstance()->Stop();
+////////////////////////////////////////////////////////////////////////////////
+//
+// TraceEvent
+//
+////////////////////////////////////////////////////////////////////////////////
+
+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";
+    default:
+      NOTREACHED() << "Invalid phase argument";
+      return "?";
+  }
 }
 
-void TraceLog::Trace(const std::string& name,
-                     EventType type,
-                     const void* id,
-                     const std::wstring& extra,
-                     const char* file,
-                     int line) {
-  if (!enabled_)
-    return;
-  Trace(name, type, id, WideToUTF8(extra), file, line);
+}  // namespace
+
+TraceEvent::TraceEvent()
+    : process_id(0),
+      thread_id(0),
+      phase(TRACE_EVENT_PHASE_BEGIN),
+      category(NULL),
+      name(NULL) {
+  memset(arg_names, 0, sizeof(arg_names));
 }
 
-void TraceLog::Trace(const std::string& name,
-                     EventType type,
-                     const void* id,
-                     const std::string& extra,
-                     const char* file,
-                     int line) {
-  if (!enabled_)
-    return;
+TraceEvent::~TraceEvent() {
+}
 
-#ifdef USE_UNRELIABLE_NOW
-  TimeTicks tick = TimeTicks::HighResNow();
-#else
-  TimeTicks tick = TimeTicks::Now();
-#endif
-  TimeDelta delta = tick - trace_start_time_;
-  int64 usec = delta.InMicroseconds();
-  std::string msg =
-    StringPrintf("{'pid':'0x%lx', 'tid':'0x%lx', 'type':'%s', "
-                 "'name':'%s', 'id':'%p', 'extra':'%s', 'file':'%s', "
-                 "'line_number':'%d', 'usec_begin': %" PRId64 "},\n",
-                 static_cast<unsigned long>(base::GetCurrentProcId()),
-                 static_cast<unsigned long>(PlatformThread::CurrentId()),
-                 kEventTypeNames[type],
-                 name.c_str(),
-                 id,
-                 extra.c_str(),
-                 file,
-                 line,
-                 usec);
-
-  Log(msg);
-}
-
-TraceLog::TraceLog() : enabled_(false), log_file_(NULL) {
-  base::ProcessHandle proc = base::GetCurrentProcessHandle();
-#if !defined(OS_MACOSX)
-  process_metrics_.reset(base::ProcessMetrics::CreateProcessMetrics(proc));
-#else
-  // The default port provider is sufficient to get data for the current
-  // process.
-  process_metrics_.reset(base::ProcessMetrics::CreateProcessMetrics(proc,
-                                                                    NULL));
-#endif
+void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events,
+                                    size_t start,
+                                    size_t count,
+                                    std::string* out) {
+  *out += "[";
+  for (size_t i = 0; i < count && start + i < events.size(); ++i) {
+    if (i > 0)
+      *out += ",";
+    events[i + start].AppendAsJSON(out);
+  }
+  *out += "]";
 }
 
-TraceLog::~TraceLog() {
-  Stop();
-}
-
-bool TraceLog::OpenLogFile() {
-  FilePath::StringType pid_filename =
-      StringPrintf(kLogFileName, base::GetCurrentProcId());
-  FilePath log_file_path;
-  if (!PathService::Get(base::DIR_EXE, &log_file_path))
-    return false;
-  log_file_path = log_file_path.Append(pid_filename);
-  log_file_ = file_util::OpenFile(log_file_path, "a");
-  if (!log_file_) {
-    // try the current directory
-    log_file_ = file_util::OpenFile(FilePath(pid_filename), "a");
-    if (!log_file_) {
-      return false;
-    }
+void TraceEvent::AppendAsJSON(std::string* out) const {
+  const char* phase_str = GetPhaseStr(phase);
+  int64 time_int64 = timestamp.ToInternalValue();
+  // Category name checked at category creation time.
+  DCHECK(!strchr(name, '"'));
+  StringAppendF(out,
+      "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%lld,"
+      "\"ph\":\"%s\",\"name\":\"%s\",\"args\":{",
+      category->name,
+      static_cast<int>(process_id),
+      static_cast<int>(thread_id),
+      static_cast<long long>(time_int64),
+      phase_str,
+      name);
+
+  // Output argument names and values, stop at first NULL argument name.
+  for (size_t i = 0; i < kTraceMaxNumArgs && arg_names[i]; ++i) {
+    if (i > 0)
+      *out += ",";
+    *out += "\"";
+    *out += arg_names[i];
+    *out += "\":";
+    arg_values[i].AppendAsJSON(out);
   }
-  return true;
+  *out += "}}";
+}
+
+////////////////////////////////////////////////////////////////////////////////
+//
+// TraceLog
+//
+////////////////////////////////////////////////////////////////////////////////
+
+// static
+TraceLog* TraceLog::GetInstance() {
+  return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get();
+}
+
+TraceLog::TraceLog()
+    : enabled_(false) {
+  logged_events_.reserve(1024);
 }
 
-void TraceLog::CloseLogFile() {
-  if (log_file_) {
-    file_util::CloseFile(log_file_);
+TraceLog::~TraceLog() {
+}
+
+const TraceCategory* TraceLog::GetCategory(const char* name) {
+  TraceLog* tracelog = GetInstance();
+  if (!tracelog){
+    CHECK(!g_category_already_shutdown->enabled);
+    return g_category_already_shutdown;
   }
+  return tracelog->GetCategoryInternal(name);
 }
 
-bool TraceLog::Start() {
-  if (enabled_)
-    return true;
-  enabled_ = OpenLogFile();
-  if (enabled_) {
-    Log("var raw_trace_events = [\n");
-    trace_start_time_ = TimeTicks::Now();
-    timer_.Start(TimeDelta::FromMilliseconds(250), this, &TraceLog::Heartbeat);
+const TraceCategory* TraceLog::GetCategoryInternal(const char* name) {
+  AutoLock lock(lock_);
+  DCHECK(!strchr(name, '"')) << "Names may not contain double quote char";
+
+  // Search for pre-existing category matching this name
+  for (int i = 0; i < g_category_index; i++) {
+    if (strcmp(g_categories[i].name, name) == 0)
+      return &g_categories[i];
   }
-  return enabled_;
+
+  // Create a new category
+  DCHECK(g_category_index < TRACE_EVENT_MAX_CATEGORIES) <<
+      "must increase TRACE_EVENT_MAX_CATEGORIES";
+  if (g_category_index < TRACE_EVENT_MAX_CATEGORIES) {
+    int new_index = g_category_index++;
+    g_categories[new_index].name = name;
+    DCHECK(!g_categories[new_index].enabled);
+    g_categories[new_index].enabled = enabled_;
+    return &g_categories[new_index];
+  } else {
+    return g_category_categories_exhausted;
+  }
+}
+
+void TraceLog::SetEnabled(bool enabled) {
+  {
+    AutoLock lock(lock_);
+    if (enabled == enabled_)
+      return;
+    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)
+    Flush();
+}
+
+float TraceLog::GetBufferPercentFull() const {
+  return (float)((double)logged_events_.size()/(double)kTraceEventBufferSize);
+}
+
+void TraceLog::SetOutputCallback(const TraceLog::OutputCallback& cb) {
+  Flush();
+  AutoLock lock(lock_);
+  output_callback_ = cb;
+}
+
+void TraceLog::SetBufferFullCallback(const TraceLog::BufferFullCallback& cb) {
+  AutoLock lock(lock_);
+  buffer_full_callback_ = cb;
 }
 
-void TraceLog::Stop() {
-  if (enabled_) {
-    enabled_ = false;
-    Log("];\n");
-    CloseLogFile();
-    timer_.Stop();
+void TraceLog::Flush() {
+  std::vector<TraceEvent> previous_logged_events;
+  OutputCallback output_callback_copy;
+  {
+    AutoLock lock(lock_);
+    previous_logged_events.swap(logged_events_);
+    output_callback_copy = output_callback_;
+  } // release lock
+
+  if (output_callback_copy.is_null())
+    return;
+
+  for (size_t i = 0;
+       i < previous_logged_events.size();
+       i += kTraceEventBatchSize) {
+    scoped_refptr<RefCountedString> json_events_str_ptr =
+      new RefCountedString();
+    TraceEvent::AppendEventsAsJSON(previous_logged_events,
+                                   i,
+                                   kTraceEventBatchSize,
+                                   &(json_events_str_ptr->data));
+    output_callback_copy.Run(json_events_str_ptr.get());
   }
 }
 
-void TraceLog::Heartbeat() {
-  std::string cpu = StringPrintf("%.0f", process_metrics_->GetCPUUsage());
-  TRACE_EVENT_INSTANT("heartbeat.cpu", 0, cpu);
+void TraceLog::AddTraceEvent(TraceEventPhase phase,
+                             const char* file, int line,
+                             const TraceCategory* category,
+                             const char* name,
+                             const char* arg1_name, TraceValue arg1_val,
+                             const char* arg2_name, TraceValue arg2_val) {
+  DCHECK(file && name);
+#ifdef USE_UNRELIABLE_NOW
+  TimeTicks now = TimeTicks::HighResNow();
+#else
+  TimeTicks now = TimeTicks::Now();
+#endif
+  BufferFullCallback buffer_full_callback_copy;
+  {
+    AutoLock lock(lock_);
+    if (!enabled_ || !category->enabled)
+      return;
+    if (logged_events_.size() >= kTraceEventBufferSize)
+      return;
+    logged_events_.push_back(TraceEvent());
+    TraceEvent& event = logged_events_.back();
+    event.process_id = static_cast<unsigned long>(base::GetCurrentProcId());
+    event.thread_id = PlatformThread::CurrentId();
+    event.timestamp = now;
+    event.phase = phase;
+    event.category = category;
+    event.name = name;
+    event.arg_names[0] = arg1_name;
+    event.arg_values[0] = arg1_val;
+    event.arg_names[1] = arg2_name;
+    event.arg_values[1] = arg2_val;
+    COMPILE_ASSERT(kTraceMaxNumArgs == 2, TraceEvent_arg_count_out_of_sync);
+
+    if (logged_events_.size() == kTraceEventBufferSize) {
+      buffer_full_callback_copy = buffer_full_callback_;
+    }
+  } // release lock
+
+  if (!buffer_full_callback_copy.is_null())
+    buffer_full_callback_copy.Run();
 }
 
-void TraceLog::Log(const std::string& msg) {
-  AutoLock lock(file_lock_);
+void TraceLog::AddTraceEventEtw(TraceEventPhase phase,
+                                const char* file, int line,
+                                const char* name,
+                                const void* id,
+                                const char* extra) {
+  // Legacy trace points on windows called to ETW
+#if defined(OS_WIN)
+  TraceEventETWProvider::Trace(name, phase, id, extra);
+#endif
+
+  // Also add new trace event behavior
+  static const TraceCategory* category = GetCategory("ETW Trace Event");
+  if (category->enabled) {
+    TraceLog* tracelog = TraceLog::GetInstance();
+    if (!tracelog)
+      return;
+    tracelog->AddTraceEvent(phase, file, line, category, name,
+                            "id", id,
+                            "extra", extra ? extra : "");
+  }
+}
 
-  fprintf(log_file_, "%s", msg.c_str());
+void TraceLog::Resurrect() {
+  StaticMemorySingletonTraits<TraceLog>::Resurrect();
 }
 
 }  // namespace debug
diff --git a/base/debug/trace_event.h b/base/debug/trace_event.h
index 3b4afc5..ef0fb8c 100644
--- a/base/debug/trace_event.h
+++ b/base/debug/trace_event.h
@@ -2,15 +2,40 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
-// Trace events to track application performance.  Events consist of a name
-// a type (BEGIN, END or INSTANT), a tracking id and extra string data.
-// In addition, the current process id, thread id, a timestamp down to the
-// microsecond and a file and line number of the calling location.
+// Trace events are for tracking application performance.
 //
-// The current implementation logs these events into a log file of the form
-// trace_<pid>.log where it's designed to be post-processed to generate a
-// trace report.  In the future, it may use another mechansim to facilitate
-// real-time analysis.
+// Events are issued against categories. Whereas LOG's
+// categories are statically defined, TRACE categories are created
+// implicitly with a string. For example:
+//   TRACE_EVENT_INSTANT0("MY_SUBSYSTEM", "SomeImportantEvent")
+//
+// Events can be INSTANT, or can be pairs of BEGIN and END:
+//   TRACE_EVENT_BEGIN0("MY_SUBSYSTEM", "SomethingCostly")
+//   doSomethingCostly()
+//   TRACE_EVENT_END0("MY_SUBSYSTEM", "SomethingCostly")
+//
+// A common use case is to trace entire function scopes. This
+// issues a trace BEGIN and END automatically:
+//   void doSomethingCostly() {
+//     TRACE_EVENT0("MY_SUBSYSTEM", "doSomethingCostly");
+//     ...
+//   }
+//
+// Additional parameters can be associated with an event:
+//   void doSomethingCostly2(int howMuch) {
+//     TRACE_EVENT1("MY_SUBSYSTEM", "doSomethingCostly",
+//         "howMuch", StringPrintf("%i", howMuch).c_str());
+//     ...
+//   }
+//
+// The trace system will automatically add to this information the
+// current process id, thread id, a timestamp down to the
+// microsecond, as well as the file and line number of the calling location.
+//
+// By default, trace collection is compiled in, but turned off at runtime.
+// Collecting trace data is the responsibility of the embedding
+// application. In Chrome's case, navigating to about:gpu will turn on
+// tracing and display data collected across all active processes.
 
 #ifndef BASE_DEBUG_TRACE_EVENT_H_
 #define BASE_DEBUG_TRACE_EVENT_H_
@@ -18,132 +43,406 @@
 
 #include "build/build_config.h"
 
-#if defined(OS_WIN)
-// On Windows we always pull in an alternative implementation
-// which logs to Event Tracing for Windows.
-//
-// Note that the Windows implementation is always enabled, irrespective the
-// value of the CHROMIUM_ENABLE_TRACE_EVENT define. The Windows implementation
-// is controlled by Event Tracing for Windows, which will turn tracing on only
-// if there is someone listening for the events it generates.
-#include "base/debug/trace_event_win.h"
-#else  // defined(OS_WIN)
-
 #include <string>
+#include <vector>
 
-#include "base/memory/scoped_ptr.h"
+#include "base/callback.h"
 #include "base/memory/singleton.h"
-#include "base/synchronization/lock.h"
-#include "base/time.h"
+#include "base/string_util.h"
 #include "base/timer.h"
 
-#ifndef CHROMIUM_ENABLE_TRACE_EVENT
-#define TRACE_EVENT_BEGIN(name, id, extra) ((void) 0)
-#define TRACE_EVENT_END(name, id, extra) ((void) 0)
-#define TRACE_EVENT_INSTANT(name, id, extra) ((void) 0)
-
-#else  // CHROMIUM_ENABLE_TRACE_EVENT
-// Use the following macros rather than using the TraceLog class directly as the
-// underlying implementation may change in the future.  Here's a sample usage:
-// TRACE_EVENT_BEGIN("v8.run", documentId, scriptLocation);
-// RunScript(script);
-// TRACE_EVENT_END("v8.run", documentId, scriptLocation);
-
-// Record that an event (of name, id) has begun.  All BEGIN events should have
-// corresponding END events with a matching (name, id).
-#define TRACE_EVENT_BEGIN(name, id, extra) \
-  base::debug::TraceLog::GetInstance()->Trace( \
-      name, \
-      base::debug::TraceLog::EVENT_BEGIN, \
-      reinterpret_cast<const void*>(id), \
-      extra, \
-      __FILE__, \
-      __LINE__)
-
-// Record that an event (of name, id) has ended.  All END events should have
-// corresponding BEGIN events with a matching (name, id).
-#define TRACE_EVENT_END(name, id, extra) \
-  base::debug::TraceLog::GetInstance()->Trace( \
-      name, \
-      base::debug::TraceLog::EVENT_END, \
-      reinterpret_cast<const void*>(id), \
-      extra, \
-      __FILE__, \
-      __LINE__)
-
-// Record that an event (of name, id) with no duration has happened.
-#define TRACE_EVENT_INSTANT(name, id, extra) \
-  base::debug::TraceLog::GetInstance()->Trace( \
-      name, \
-      base::debug::TraceLog::EVENT_INSTANT, \
-      reinterpret_cast<const void*>(id), \
-      extra, \
-      __FILE__, \
-      __LINE__)
-#endif  // CHROMIUM_ENABLE_TRACE_EVENT
+// 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( \
+      base::debug::TRACE_EVENT_PHASE_BEGIN, \
+      __FILE__, __LINE__, name, reinterpret_cast<const void*>(id), extra);
 
-namespace base {
+#define TRACE_EVENT_END_ETW(name, id, extra) \
+  base::debug::TraceLog::AddTraceEventEtw( \
+      base::debug::TRACE_EVENT_PHASE_END, \
+      __FILE__, __LINE__, name, reinterpret_cast<const void*>(id), extra);
+
+#define TRACE_EVENT_INSTANT_ETW(name, id, extra) \
+  base::debug::TraceLog::AddTraceEventEtw( \
+      base::debug::TRACE_EVENT_PHASE_INSTANT, \
+      __FILE__, __LINE__, name, reinterpret_cast<const void*>(id), extra);
+
+
+// Implementation detail: trace event macros create temporary variables
+// to keep instrumentation overhead low. These macros give each temporary
+// variable a unique name based on the line number to prevent name collissions.
+#define TRACE_EVENT_UNIQUE_IDENTIFIER3(a,b) a##b
+#define TRACE_EVENT_UNIQUE_IDENTIFIER2(a,b) \
+  TRACE_EVENT_UNIQUE_IDENTIFIER3(a,b)
+#define TRACE_EVENT_UNIQUE_IDENTIFIER(name_prefix) \
+  TRACE_EVENT_UNIQUE_IDENTIFIER2(name_prefix, __LINE__)
+
+// Records a pair of begin and end events called "name" for the current
+// scope, with 0, 1 or 2 associated arguments. If the category is not
+// enabled, then this does nothing.
+// - category and name strings must have application lifetime (statics or
+//   literals). They may not include " chars.
+#define TRACE_EVENT0(category, name) \
+  TRACE_EVENT1(category, name, NULL, 0)
+#define TRACE_EVENT1(category, name, arg1_name, arg1_val) \
+  TRACE_EVENT2(category, name, arg1_name, arg1_val, NULL, 0)
+#define TRACE_EVENT2(category, name, arg1_name, arg1_val, arg2_name, arg2_val) \
+  static const base::debug::TraceCategory* \
+      TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic) = \
+      base::debug::TraceLog::GetCategory(category); \
+  if (TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic)->enabled) { \
+    base::debug::TraceLog::GetInstance()->AddTraceEvent( \
+        base::debug::TRACE_EVENT_PHASE_BEGIN, \
+        __FILE__, __LINE__, \
+        TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic), \
+        name, \
+        arg1_name, arg1_val, \
+        arg2_name, arg2_val); \
+  } \
+  base::debug::internal::TraceEndOnScopeClose \
+      TRACE_EVENT_UNIQUE_IDENTIFIER(profileScope) ( \
+          __FILE__, __LINE__, \
+          TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic), name);
+
+// Records a single event called "name" immediately, with 0, 1 or 2
+// associated arguments. If the category is not enabled, then this
+// does nothing.
+// - category and name strings must have application lifetime (statics or
+//   literals). They may not include " chars.
+#define TRACE_EVENT_INSTANT0(category, name) \
+  TRACE_EVENT_INSTANT1(category, name, NULL, 0)
+#define TRACE_EVENT_INSTANT1(category, name, arg1_name, arg1_val) \
+  TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, NULL, 0)
+#define TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, \
+    arg2_name, arg2_val) \
+  static const base::debug::TraceCategory* \
+      TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic) = \
+      base::debug::TraceLog::GetCategory(category); \
+  if (TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic)->enabled) { \
+    base::debug::TraceLog::GetInstance()->AddTraceEvent( \
+        base::debug::TRACE_EVENT_PHASE_INSTANT, \
+        __FILE__, __LINE__, \
+        TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic), \
+        name, \
+        arg1_name, arg1_val, \
+        arg2_name, arg2_val); \
+  }
+
+// Records a single BEGIN event called "name" immediately, with 0, 1 or 2
+// associated arguments. If the category is not enabled, then this
+// does nothing.
+// - category and name strings must have application lifetime (statics or
+//   literals). They may not include " chars.
+#define TRACE_EVENT_BEGIN0(category, name) \
+  TRACE_EVENT_BEGIN1(category, name, NULL, 0)
+#define TRACE_EVENT_BEGIN1(category, name, arg1_name, arg1_val) \
+  TRACE_EVENT_BEGIN2(category, name, arg1_name, arg1_val, NULL, 0)
+#define TRACE_EVENT_BEGIN2(category, name, arg1_name, arg1_val, \
+    arg2_name, arg2_val) \
+  static const base::debug::TraceCategory* \
+      TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic) = \
+      base::debug::TraceLog::GetCategory(category); \
+  if (TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic)->enabled) { \
+    base::debug::TraceLog::GetInstance()->AddTraceEvent( \
+        base::debug::TRACE_EVENT_PHASE_BEGIN, \
+        __FILE__, __LINE__, \
+        TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic), \
+        name, \
+        arg1_name, arg1_val, \
+        arg2_name, arg2_val); \
+  }
+
+// Records a single END event for "name" immediately. If the category
+// is not enabled, then this does nothing.
+// - category and name strings must have application lifetime (statics or
+//   literals). They may not include " chars.
+#define TRACE_EVENT_END0(category, name) \
+  TRACE_EVENT_END1(category, name, NULL, 0)
+#define TRACE_EVENT_END1(category, name, arg1_name, arg1_val) \
+  TRACE_EVENT_END2(category, name, arg1_name, arg1_val, NULL, 0)
+#define TRACE_EVENT_END2(category, name, arg1_name, arg1_val, \
+    arg2_name, arg2_val) \
+  static const base::debug::TraceCategory* \
+      TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic) = \
+      base::debug::TraceLog::GetCategory(category); \
+  if (TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic)->enabled) { \
+    base::debug::TraceLog::GetInstance()->AddTraceEvent( \
+        base::debug::TRACE_EVENT_PHASE_END, \
+        __FILE__, __LINE__, \
+        TRACE_EVENT_UNIQUE_IDENTIFIER(catstatic), \
+        name, \
+        arg1_name, arg1_val, \
+        arg2_name, arg2_val); \
+  }
 
-class ProcessMetrics;
+namespace base {
 
 namespace debug {
 
-class BASE_API TraceLog {
+// Categories allow enabling/disabling of streams of trace events
+struct TraceCategory {
+  const char* name;
+  volatile bool enabled;
+};
+
+const size_t kTraceMaxNumArgs = 2;
+
+// Phase indicates the nature of an event entry. E.g. part of a begin/end pair.
+enum TraceEventPhase {
+  TRACE_EVENT_PHASE_BEGIN,
+  TRACE_EVENT_PHASE_END,
+  TRACE_EVENT_PHASE_INSTANT
+};
+
+// Simple union of values. This is much lighter weight than base::Value, which
+// requires dynamic allocation and a vtable. To keep the trace runtime overhead
+// low, we want constant size storage here.
+class TraceValue {
  public:
-  enum EventType {
-    EVENT_BEGIN,
-    EVENT_END,
-    EVENT_INSTANT
+  enum Type {
+    TRACE_TYPE_UNDEFINED,
+    TRACE_TYPE_BOOL,
+    TRACE_TYPE_UINT,
+    TRACE_TYPE_INT,
+    TRACE_TYPE_DOUBLE,
+    TRACE_TYPE_POINTER,
+    TRACE_TYPE_STRING
   };
 
+  TraceValue() : type_(TRACE_TYPE_UNDEFINED) {
+    value_.as_uint = 0ull;
+  }
+  TraceValue(bool rhs) : type_(TRACE_TYPE_BOOL) {
+    value_.as_bool = rhs;
+  }
+  TraceValue(uint64 rhs) : type_(TRACE_TYPE_UINT) {
+    value_.as_uint = rhs;
+  }
+  TraceValue(uint32 rhs) : type_(TRACE_TYPE_UINT) {
+    value_.as_uint = rhs;
+  }
+  TraceValue(uint16 rhs) : type_(TRACE_TYPE_UINT) {
+    value_.as_uint = rhs;
+  }
+  TraceValue(uint8 rhs) : type_(TRACE_TYPE_UINT) {
+    value_.as_uint = rhs;
+  }
+  TraceValue(int64 rhs) : type_(TRACE_TYPE_INT) {
+    value_.as_int = rhs;
+  }
+  TraceValue(int32 rhs) : type_(TRACE_TYPE_INT) {
+    value_.as_int = rhs;
+  }
+  TraceValue(int16 rhs) : type_(TRACE_TYPE_INT) {
+    value_.as_int = rhs;
+  }
+  TraceValue(int8 rhs) : type_(TRACE_TYPE_INT) {
+    value_.as_int = rhs;
+  }
+  TraceValue(double rhs) : type_(TRACE_TYPE_DOUBLE) {
+    value_.as_double = rhs;
+  }
+  TraceValue(const void* rhs) : type_(TRACE_TYPE_POINTER) {
+    value_.as_pointer = rhs;
+  }
+  TraceValue(const char* rhs) : type_(TRACE_TYPE_STRING) {
+    value_.as_string_refptr = new RefCountedString();
+    value_.as_string_refptr->AddRef();
+    DCHECK(value_.as_string_refptr->HasOneRef());
+    value_.as_string_refptr->data = rhs;
+  }
+  TraceValue(const TraceValue& rhs) : type_(TRACE_TYPE_UNDEFINED) {
+    operator=(rhs);
+  }
+  ~TraceValue() {
+    Destroy();
+  }
+
+  TraceValue& operator=(const TraceValue& rhs);
+  bool operator!=(const TraceValue& rhs) const {
+    return !operator==(rhs);
+  }
+
+  void Destroy();
+
+  void AppendAsJSON(std::string* out) const;
+
+  Type type() const {
+    return type_;
+  }
+  uint64 as_uint() const {
+    return value_.as_uint;
+  }
+  bool as_bool() const {
+    return value_.as_bool;
+  }
+  int64 as_int() const {
+    return value_.as_int;
+  }
+  double as_double() const {
+    return value_.as_double;
+  }
+  const void* as_pointer() const {
+    return value_.as_pointer;
+  }
+  const char* as_string() const {
+    return value_.as_string_refptr->data.c_str();
+  }
+
+ typedef RefCountedData<std::string> RefCountedString;
+
+ private:
+  union Value {
+    bool as_bool;
+    uint64 as_uint;
+    int64 as_int;
+    double as_double;
+    const void* as_pointer;
+    RefCountedString* as_string_refptr;
+  };
+
+  bool operator==(const TraceValue& rhs) const;
+
+  Type type_;
+  Value value_;
+};
+
+// Output records are "Events" and can be obtained via the
+// OutputCallback whenever the tracing system decides to flush. This
+// can happen at any time, on any thread, or you can programatically
+// force it to happen.
+struct TraceEvent {
+  TraceEvent();
+  ~TraceEvent();
+
+  // Serialize event data to JSON
+  static void AppendEventsAsJSON(const std::vector<TraceEvent>& events,
+                                 size_t start,
+                                 size_t count,
+                                 std::string* out);
+  void AppendAsJSON(std::string* out) const;
+
+
+  unsigned long process_id;
+  unsigned long thread_id;
+  TimeTicks timestamp;
+  TraceEventPhase phase;
+  const TraceCategory* category;
+  const char* name;
+  const char* arg_names[kTraceMaxNumArgs];
+  TraceValue arg_values[kTraceMaxNumArgs];
+};
+
+
+class BASE_API TraceLog {
+ public:
   static TraceLog* GetInstance();
 
-  // Is tracing currently enabled.
-  static bool IsTracing();
-  // Start logging trace events.
-  static bool StartTracing();
-  // Stop logging trace events.
-  static void StopTracing();
-
-  // Log a trace event of (name, type, id) with the optional extra string.
-  void Trace(const std::string& name,
-             EventType type,
-             const void* id,
-             const std::wstring& extra,
-             const char* file,
-             int line);
-  void Trace(const std::string& name,
-             EventType type,
-             const void* id,
-             const std::string& extra,
-             const char* file,
-             int line);
+  // Global enable of tracing. Currently enables all categories or not.
+  // TODO(scheib): Replace with an Enable/DisableCategory() that
+  // implicitly controls the global logging state.
+  void SetEnabled(bool enabled);
+  bool IsEnabled() { return enabled_; }
+
+  float GetBufferPercentFull() const;
+
+  // When enough events are collected, they are handed (in bulk) to
+  // the output callback. If no callback is set, the output will be
+  // silently dropped. The callback must be thread safe.
+  typedef RefCountedData<std::string> RefCountedString;
+  typedef base::Callback<void(RefCountedString*)> OutputCallback;
+  void SetOutputCallback(const OutputCallback& cb);
+
+  // The trace buffer does not flush dynamically, so when it fills up,
+  // subsequent trace events will be dropped. This callback is generated when
+  // the trace buffer is full. The callback must be thread safe.
+  typedef base::Callback<void(void)> BufferFullCallback;
+  void SetBufferFullCallback(const BufferFullCallback& cb);
+
+  // Flushes all logged data to the callback.
+  void Flush();
+
+  // Called by TRACE_EVENT* macros, don't call this directly.
+  static const TraceCategory* GetCategory(const char* name);
+
+  // Called by TRACE_EVENT* macros, don't call this directly.
+  void AddTraceEvent(TraceEventPhase phase,
+      const char* file, int line,
+      const TraceCategory* category,
+      const char* name,
+      const char* arg1_name, TraceValue arg1_val,
+      const char* arg2_name, TraceValue arg2_val);
+  static void AddTraceEventEtw(TraceEventPhase phase,
+      const char* file, int line,
+      const char* name,
+      const void* id,
+      const char* extra);
+  static void AddTraceEventEtw(TraceEventPhase phase,
+      const char* file, int line,
+      const char* name,
+      const void* id,
+      const std::string& extra) {
+    AddTraceEventEtw(phase, file, line, name, id, extra.c_str());
+  }
+
+  // Exposed for unittesting only, allows resurrecting our
+  // singleton instance post-AtExit processing.
+  static void Resurrect();
 
  private:
   // This allows constructor and destructor to be private and usable only
   // by the Singleton class.
-  friend struct DefaultSingletonTraits<TraceLog>;
+  friend struct StaticMemorySingletonTraits<TraceLog>;
 
   TraceLog();
   ~TraceLog();
-  bool OpenLogFile();
-  void CloseLogFile();
-  bool Start();
-  void Stop();
-  void Heartbeat();
-  void Log(const std::string& msg);
+  const TraceCategory* GetCategoryInternal(const char* name);
 
+  // TODO(nduca): switch to per-thread trace buffers to reduce thread
+  // synchronization.
+  Lock lock_;
   bool enabled_;
-  FILE* log_file_;
-  base::Lock file_lock_;
-  TimeTicks trace_start_time_;
-  scoped_ptr<base::ProcessMetrics> process_metrics_;
-  RepeatingTimer<TraceLog> timer_;
+  OutputCallback output_callback_;
+  BufferFullCallback buffer_full_callback_;
+  std::vector<TraceEvent> logged_events_;
+
+  DISALLOW_COPY_AND_ASSIGN(TraceLog);
+};
+
+namespace internal {
+
+// Used by TRACE_EVENTx macro. Do not use directly.
+class TraceEndOnScopeClose {
+ public:
+  TraceEndOnScopeClose(const char* file, int line,
+                       const TraceCategory* category,
+                       const char* name)
+      : file_(file)
+      , line_(line)
+      , category_(category)
+      , name_(name) { }
+
+  ~TraceEndOnScopeClose() {
+    if (category_->enabled)
+      base::debug::TraceLog::GetInstance()->AddTraceEvent(
+          base::debug::TRACE_EVENT_PHASE_END,
+          file_, line_,
+          category_,
+          name_,
+          NULL, 0, NULL, 0);
+  }
+
+ private:
+  const char* file_;
+  int line_;
+  const TraceCategory* category_;
+  const char* name_;
 };
 
+}  // namespace internal
+
 }  // namespace debug
 }  // namespace base
 
-#endif  // defined(OS_WIN)
-
 #endif  // BASE_DEBUG_TRACE_EVENT_H_
diff --git a/base/debug/trace_event_unittest.cc b/base/debug/trace_event_unittest.cc
new file mode 100644
index 0000000..360468d
--- /dev/null
+++ b/base/debug/trace_event_unittest.cc
@@ -0,0 +1,397 @@
+// 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"
+
+#include "base/bind.h"
+#include "base/command_line.h"
+#include "base/json/json_reader.h"
+#include "base/json/json_writer.h"
+#include "base/memory/scoped_ptr.h"
+#include "base/stringprintf.h"
+#include "base/synchronization/waitable_event.h"
+#include "base/threading/thread.h"
+#include "base/values.h"
+#include "testing/gmock/include/gmock/gmock.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace base {
+namespace debug {
+
+namespace {
+
+class TraceEventTestFixture : public testing::Test {
+ public:
+  void ManualTestSetUp();
+  void OnTraceDataCollected(TraceLog::RefCountedString* json_events_str);
+
+  std::string trace_string_;
+  ListValue trace_parsed_;
+
+ private:
+  // We want our singleton torn down after each test.
+  ShadowingAtExitManager at_exit_manager_;
+};
+
+void TraceEventTestFixture::ManualTestSetUp() {
+  TraceLog::Resurrect();
+  TraceLog* tracelog = TraceLog::GetInstance();
+  ASSERT_TRUE(tracelog);
+  ASSERT_FALSE(tracelog->IsEnabled());
+  tracelog->SetOutputCallback(
+    base::Bind(&TraceEventTestFixture::OnTraceDataCollected,
+               base::Unretained(this)));
+}
+
+void TraceEventTestFixture::OnTraceDataCollected(
+    TraceLog::RefCountedString* json_events_str) {
+  trace_string_ += json_events_str->data;
+
+  scoped_ptr<Value> root;
+  root.reset(base::JSONReader::Read(json_events_str->data, false));
+
+  ListValue* root_list = NULL;
+  ASSERT_TRUE(root.get());
+  ASSERT_TRUE(root->GetAsList(&root_list));
+
+  // Move items into our aggregate collection
+  while (root_list->GetSize()) {
+    Value* item = NULL;
+    root_list->Remove(0, &item);
+    trace_parsed_.Append(item);
+  }
+}
+
+bool IsStringInDict(const char* string_to_match, DictionaryValue* dict) {
+  for (DictionaryValue::key_iterator ikey = dict->begin_keys();
+       ikey != dict->end_keys(); ++ikey) {
+    Value* child = NULL;
+    if (!dict->GetWithoutPathExpansion(*ikey, &child))
+      continue;
+
+    if ((*ikey).find(string_to_match) != std::string::npos)
+      return true;
+
+    std::string value_str;
+    child->GetAsString(&value_str);
+    if (value_str.find(string_to_match) != std::string::npos)
+      return true;
+  }
+
+  // Recurse to test arguments
+  DictionaryValue* args_dict = NULL;
+  dict->GetDictionary("args", &args_dict);
+  if (args_dict)
+    return IsStringInDict(string_to_match, args_dict);
+
+  return false;
+}
+
+DictionaryValue* FindTraceEntry(const ListValue& trace_parsed,
+                                const char *string_to_match,
+                                DictionaryValue* match_after_this_item = NULL) {
+  // Scan all items
+  size_t trace_parsed_count = trace_parsed.GetSize();
+  for (size_t i = 0; i < trace_parsed_count; i++) {
+    Value* value = NULL;
+    trace_parsed.Get(i, &value);
+    if (match_after_this_item) {
+      if (value == match_after_this_item)
+         match_after_this_item = NULL;
+      continue;
+    }
+    if (!value || value->GetType() != Value::TYPE_DICTIONARY)
+      continue;
+    DictionaryValue* dict = static_cast<DictionaryValue*>(value);
+
+    if (IsStringInDict(string_to_match, dict))
+      return dict;
+  }
+  return NULL;
+}
+
+void DataCapturedCallTraces(WaitableEvent* task_complete_event) {
+  {
+    TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW call", 1122, "extrastring1");
+    TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW call", 3344, "extrastring2");
+    TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW call",
+                            5566, "extrastring3");
+
+    TRACE_EVENT0("all", "TRACE_EVENT0 call");
+    TRACE_EVENT1("all", "TRACE_EVENT1 call", "name1", "value1");
+    TRACE_EVENT2("all", "TRACE_EVENT2 call",
+                 "name1", "value1",
+                 "name2", "value2");
+
+    TRACE_EVENT_INSTANT0("all", "TRACE_EVENT_INSTANT0 call");
+    TRACE_EVENT_INSTANT1("all", "TRACE_EVENT_INSTANT1 call", "name1", "value1");
+    TRACE_EVENT_INSTANT2("all", "TRACE_EVENT_INSTANT2 call",
+                         "name1", "value1",
+                         "name2", "value2");
+
+    TRACE_EVENT_BEGIN0("all", "TRACE_EVENT_BEGIN0 call");
+    TRACE_EVENT_BEGIN1("all", "TRACE_EVENT_BEGIN1 call", "name1", "value1");
+    TRACE_EVENT_BEGIN2("all", "TRACE_EVENT_BEGIN2 call",
+                       "name1", "value1",
+                       "name2", "value2");
+
+    TRACE_EVENT_END0("all", "TRACE_EVENT_END0 call");
+    TRACE_EVENT_END1("all", "TRACE_EVENT_END1 call", "name1", "value1");
+    TRACE_EVENT_END2("all", "TRACE_EVENT_END2 call",
+                     "name1", "value1",
+                     "name2", "value2");
+  } // Scope close causes TRACE_EVENT0 etc to send their END events.
+
+  if (task_complete_event)
+    task_complete_event->Signal();
+}
+
+void DataCapturedValidateTraces(const ListValue& trace_parsed,
+                                 const std::string& trace_string) {
+  DictionaryValue* item = NULL;
+
+#define EXPECT_FIND_(string) \
+  EXPECT_TRUE((item = FindTraceEntry(trace_parsed, string)));
+#define EXPECT_NOT_FIND_(string) \
+  EXPECT_FALSE((item = FindTraceEntry(trace_parsed, string)));
+#define EXPECT_SUB_FIND_(string) \
+  if (item) EXPECT_TRUE((IsStringInDict(string, item)));
+
+  EXPECT_FIND_("ETW Trace Event");
+  EXPECT_FIND_("all");
+  EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW call");
+  {
+    int int_val = 0;
+    EXPECT_TRUE(item && item->GetInteger("args.id", &int_val));
+    EXPECT_EQ(1122, int_val);
+  }
+  EXPECT_SUB_FIND_("extrastring1");
+  EXPECT_FIND_("TRACE_EVENT_END_ETW call");
+  EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW call");
+  EXPECT_FIND_("TRACE_EVENT0 call");
+  {
+    std::string ph_begin;
+    std::string ph_end;
+    EXPECT_TRUE((item = FindTraceEntry(trace_parsed, "TRACE_EVENT0 call")));
+    EXPECT_TRUE((item && item->GetString("ph", &ph_begin)));
+    EXPECT_TRUE((item = FindTraceEntry(trace_parsed, "TRACE_EVENT0 call",
+                                       item)));
+    EXPECT_TRUE((item && item->GetString("ph", &ph_end)));
+    EXPECT_EQ("B", ph_begin);
+    EXPECT_EQ("E", ph_end);
+  }
+  EXPECT_FIND_("TRACE_EVENT1 call");
+  EXPECT_FIND_("TRACE_EVENT2 call");
+  EXPECT_SUB_FIND_("name1");
+  EXPECT_SUB_FIND_("value1");
+  EXPECT_SUB_FIND_("name2");
+  EXPECT_SUB_FIND_("value2");
+  EXPECT_FIND_("TRACE_EVENT_INSTANT0 call");
+  EXPECT_FIND_("TRACE_EVENT_INSTANT1 call");
+  EXPECT_FIND_("TRACE_EVENT_INSTANT2 call");
+  EXPECT_SUB_FIND_("name1");
+  EXPECT_SUB_FIND_("value1");
+  EXPECT_SUB_FIND_("name2");
+  EXPECT_SUB_FIND_("value2");
+  EXPECT_FIND_("TRACE_EVENT_BEGIN0 call");
+  EXPECT_FIND_("TRACE_EVENT_BEGIN1 call");
+  EXPECT_FIND_("TRACE_EVENT_BEGIN2 call");
+  EXPECT_SUB_FIND_("name1");
+  EXPECT_SUB_FIND_("value1");
+  EXPECT_SUB_FIND_("name2");
+  EXPECT_SUB_FIND_("value2");
+  EXPECT_FIND_("TRACE_EVENT_END0 call");
+  EXPECT_FIND_("TRACE_EVENT_END1 call");
+  EXPECT_FIND_("TRACE_EVENT_END2 call");
+  EXPECT_SUB_FIND_("name1");
+  EXPECT_SUB_FIND_("value1");
+  EXPECT_SUB_FIND_("name2");
+  EXPECT_SUB_FIND_("value2");
+}
+
+}  // namespace
+
+// Simple Test for emitting data and validating it was received.
+TEST_F(TraceEventTestFixture, DataCaptured) {
+  ManualTestSetUp();
+  TraceLog::GetInstance()->SetEnabled(true);
+
+  DataCapturedCallTraces(NULL);
+
+  TraceLog::GetInstance()->SetEnabled(false);
+
+  DataCapturedValidateTraces(trace_parsed_, trace_string_);
+}
+
+// Test that data sent from other threads is gathered
+TEST_F(TraceEventTestFixture, DataCapturedOnThread) {
+  ManualTestSetUp();
+  TraceLog::GetInstance()->SetEnabled(true);
+
+  Thread thread("1");
+  WaitableEvent task_complete_event(false, false);
+  thread.Start();
+
+  thread.message_loop()->PostTask(
+    FROM_HERE, NewRunnableFunction(&DataCapturedCallTraces,
+                                   &task_complete_event));
+  task_complete_event.Wait();
+
+  TraceLog::GetInstance()->SetEnabled(false);
+  thread.Stop();
+  DataCapturedValidateTraces(trace_parsed_, trace_string_);
+}
+
+namespace {
+
+void DataCapturedCallManyTraces(int thread_id, int num_events,
+                                 WaitableEvent* task_complete_event) {
+  for (int i = 0; i < num_events; i++) {
+    TRACE_EVENT_INSTANT2("all", "multi thread event",
+                         "thread", thread_id,
+                         "event", i);
+  }
+
+  if (task_complete_event)
+    task_complete_event->Signal();
+}
+
+void DataCapturedValidateManyTraces(const ListValue& trace_parsed,
+                                     const std::string& trace_string,
+                                     int num_threads, int num_events) {
+  std::map<int, std::map<int, bool> > results;
+
+  size_t trace_parsed_count = trace_parsed.GetSize();
+  for (size_t i = 0; i < trace_parsed_count; i++) {
+    Value* value = NULL;
+    trace_parsed.Get(i, &value);
+    if (!value || value->GetType() != Value::TYPE_DICTIONARY)
+      continue;
+    DictionaryValue* dict = static_cast<DictionaryValue*>(value);
+    std::string name;
+    dict->GetString("name", &name);
+    if (name != "multi thread event")
+      continue;
+
+    int thread = 0;
+    int event = 0;
+    EXPECT_TRUE(dict->GetInteger("args.thread", &thread));
+    EXPECT_TRUE(dict->GetInteger("args.event", &event));
+    results[thread][event] = true;
+  }
+
+  EXPECT_FALSE(results[-1][-1]);
+  for (int thread = 0; thread < num_threads; thread++) {
+    for (int event = 0; event < num_events; event++) {
+      EXPECT_TRUE(results[thread][event]);
+    }
+  }
+}
+
+}  // namespace
+
+// Test that data sent from multiple threads is gathered
+TEST_F(TraceEventTestFixture, DataCapturedManyThreads) {
+  ManualTestSetUp();
+  TraceLog::GetInstance()->SetEnabled(true);
+
+  const int num_threads = 4;
+  const int num_events = 4000;
+  Thread* threads[num_threads];
+  WaitableEvent* task_complete_events[num_threads];
+  for (int i = 0; i < num_threads; i++) {
+    threads[i] = new Thread(StringPrintf("Thread %d", i).c_str());
+    task_complete_events[i] = new WaitableEvent(false, false);
+    threads[i]->Start();
+    threads[i]->message_loop()->PostTask(
+      FROM_HERE, NewRunnableFunction(&DataCapturedCallManyTraces,
+                                     i, num_events, task_complete_events[i]));
+  }
+
+  for (int i = 0; i < num_threads; i++) {
+    task_complete_events[i]->Wait();
+  }
+
+  TraceLog::GetInstance()->SetEnabled(false);
+
+  for (int i = 0; i < num_threads; i++) {
+    threads[i]->Stop();
+    delete threads[i];
+    delete task_complete_events[i];
+  }
+
+  DataCapturedValidateManyTraces(trace_parsed_, trace_string_,
+                                  num_threads, num_events);
+}
+
+void TraceCallsWithCachedCategoryPointersPointers(const char* name_str) {
+  TRACE_EVENT0("category name1", name_str);
+  TRACE_EVENT_INSTANT0("category name2", name_str);
+  TRACE_EVENT_BEGIN0("category name3", name_str);
+  TRACE_EVENT_END0("category name4", name_str);
+}
+
+// Test trace calls made after tracing singleton shut down.
+//
+// The singleton is destroyed by our base::AtExitManager, but there can be
+// code still executing as the C++ static objects are destroyed. This test
+// forces the singleton to destroy early, and intentinally makes trace calls
+// afterwards.
+TEST_F(TraceEventTestFixture, AtExit) {
+  // Repeat this test a few times. Besides just showing robustness, it also
+  // allows us to test that events at shutdown do not appear with valid events
+  // recorded after the system is started again.
+  for (int i = 0; i < 4; i++) {
+    // Scope to contain the then destroy the TraceLog singleton.
+    {
+      base::ShadowingAtExitManager exit_manager_will_destroy_singletons;
+
+      // Setup TraceLog singleton inside this test's exit manager scope
+      // so that it will be destroyed when this scope closes.
+      ManualTestSetUp();
+
+      TRACE_EVENT_INSTANT0("all", "not recorded; system not enabled");
+
+      TraceLog::GetInstance()->SetEnabled(true);
+
+      TRACE_EVENT_INSTANT0("all", "is recorded 1; system has been enabled");
+      // Trace calls that will cache pointers to categories; they're valid here
+      TraceCallsWithCachedCategoryPointersPointers(
+          "is recorded 2; system has been enabled");
+
+      TraceLog::GetInstance()->SetEnabled(false);
+    } // scope to destroy singleton
+    ASSERT_FALSE(TraceLog::GetInstance());
+
+    // Now that singleton is destroyed, check what trace events were recorded
+    DictionaryValue* item = NULL;
+    ListValue& trace_parsed = trace_parsed_;
+    EXPECT_FIND_("is recorded 1");
+    EXPECT_FIND_("is recorded 2");
+    EXPECT_NOT_FIND_("not recorded");
+
+    // Make additional trace event calls on the shutdown system. They should
+    // all pass cleanly, but the data not be recorded. We'll verify that next
+    // time around the loop (the only way to flush the trace buffers).
+    TRACE_EVENT_BEGIN_ETW("not recorded; system shutdown", 0, NULL);
+    TRACE_EVENT_END_ETW("not recorded; system shutdown", 0, NULL);
+    TRACE_EVENT_INSTANT_ETW("not recorded; system shutdown", 0, NULL);
+    TRACE_EVENT0("all", "not recorded; system shutdown");
+    TRACE_EVENT_INSTANT0("all", "not recorded; system shutdown");
+    TRACE_EVENT_BEGIN0("all", "not recorded; system shutdown");
+    TRACE_EVENT_END0("all", "not recorded; system shutdown");
+
+    TRACE_EVENT0("new category 0!", "not recorded; system shutdown");
+    TRACE_EVENT_INSTANT0("new category 1!", "not recorded; system shutdown");
+    TRACE_EVENT_BEGIN0("new category 2!", "not recorded; system shutdown");
+    TRACE_EVENT_END0("new category 3!", "not recorded; system shutdown");
+
+    // Cached categories should be safe to check, and still disable traces
+    TraceCallsWithCachedCategoryPointersPointers(
+        "not recorded; system shutdown");
+  }
+}
+
+}  // namespace debug
+}  // namespace base
diff --git a/base/debug/trace_event_win.cc b/base/debug/trace_event_win.cc
index 4929944..bba4713 100644
--- a/base/debug/trace_event_win.cc
+++ b/base/debug/trace_event_win.cc
@@ -1,7 +1,6 @@
 // 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_win.h"
 
 #include "base/logging.h"
@@ -27,24 +26,26 @@ const GUID kTraceEventClass64 = {
     0x97be602d, 0x2930, 0x4ac3, 0x80, 0x46, 0xb6, 0x76, 0x3b, 0x63, 0x1d, 0xfe};
 
 
-TraceLog::TraceLog() : EtwTraceProvider(kChromeTraceProviderName) {
+TraceEventETWProvider::TraceEventETWProvider() :
+    EtwTraceProvider(kChromeTraceProviderName) {
   Register();
 }
 
-TraceLog* TraceLog::GetInstance() {
-  return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get();
+TraceEventETWProvider* TraceEventETWProvider::GetInstance() {
+  return Singleton<TraceEventETWProvider,
+      StaticMemorySingletonTraits<TraceEventETWProvider> >::get();
 }
 
-bool TraceLog::StartTracing() {
+bool TraceEventETWProvider::StartTracing() {
   return true;
 }
 
-void TraceLog::TraceEvent(const char* name,
-                          size_t name_len,
-                          EventType type,
-                          const void* id,
-                          const char* extra,
-                          size_t extra_len) {
+void TraceEventETWProvider::TraceEvent(const char* name,
+                                       size_t name_len,
+                                       TraceEventPhase type,
+                                       const void* id,
+                                       const char* extra,
+                                       size_t extra_len) {
   // Make sure we don't touch NULL.
   if (name == NULL)
     name = "";
@@ -53,14 +54,14 @@ void TraceLog::TraceEvent(const char* name,
 
   EtwEventType etw_type = 0;
   switch (type) {
-    case TraceLog::EVENT_BEGIN:
+    case TRACE_EVENT_PHASE_BEGIN:
       etw_type = kTraceEventTypeBegin;
       break;
-    case TraceLog::EVENT_END:
+    case TRACE_EVENT_PHASE_END:
       etw_type = kTraceEventTypeEnd;
       break;
 
-    case TraceLog::EVENT_INSTANT:
+    case TRACE_EVENT_PHASE_INSTANT:
       etw_type = kTraceEventTypeInstant;
       break;
 
@@ -93,13 +94,13 @@ void TraceLog::TraceEvent(const char* name,
   Log(event.get());
 }
 
-void TraceLog::Trace(const char* name,
-                     size_t name_len,
-                     EventType type,
-                     const void* id,
-                     const char* extra,
-                     size_t extra_len) {
-  TraceLog* provider = TraceLog::GetInstance();
+void TraceEventETWProvider::Trace(const char* name,
+                                  size_t name_len,
+                                  TraceEventPhase type,
+                                  const void* id,
+                                  const char* extra,
+                                  size_t extra_len) {
+  TraceEventETWProvider* provider = TraceEventETWProvider::GetInstance();
   if (provider && provider->IsTracing()) {
     // Compute the name & extra lengths if not supplied already.
     if (name_len == -1)
@@ -111,8 +112,8 @@ void TraceLog::Trace(const char* name,
   }
 }
 
-void TraceLog::Resurrect() {
-  StaticMemorySingletonTraits<TraceLog>::Resurrect();
+void TraceEventETWProvider::Resurrect() {
+  StaticMemorySingletonTraits<TraceEventETWProvider>::Resurrect();
 }
 
 }  // namespace debug
diff --git a/base/debug/trace_event_win.h b/base/debug/trace_event_win.h
index 9049bdb..6e6bcb4 100644
--- a/base/debug/trace_event_win.h
+++ b/base/debug/trace_event_win.h
@@ -10,29 +10,9 @@
 #include <string>
 
 #include "base/base_api.h"
+#include "base/debug/trace_event.h"
 #include "base/win/event_trace_provider.h"
 
-#define TRACE_EVENT_BEGIN(name, id, extra) \
-  base::debug::TraceLog::Trace( \
-      name, \
-      base::debug::TraceLog::EVENT_BEGIN, \
-      reinterpret_cast<const void*>(id), \
-      extra);
-
-#define TRACE_EVENT_END(name, id, extra) \
-  base::debug::TraceLog::Trace( \
-      name, \
-      base::debug::TraceLog::EVENT_END, \
-      reinterpret_cast<const void*>(id), \
-      extra);
-
-#define TRACE_EVENT_INSTANT(name, id, extra) \
-  base::debug::TraceLog::Trace( \
-      name, \
-      base::debug::TraceLog::EVENT_INSTANT, \
-      reinterpret_cast<const void*>(id), \
-      extra);
-
 // Fwd.
 template <typename Type>
 struct StaticMemorySingletonTraits;
@@ -42,14 +22,8 @@ namespace debug {
 
 // This EtwTraceProvider subclass implements ETW logging
 // for the macros above on Windows.
-class BASE_API TraceLog : public base::win::EtwTraceProvider {
+class BASE_API TraceEventETWProvider : public base::win::EtwTraceProvider {
  public:
-  enum EventType {
-    EVENT_BEGIN,
-    EVENT_END,
-    EVENT_INSTANT
-  };
-
   // Start logging trace events.
   // This is a noop in this implementation.
   static bool StartTracing();
@@ -63,14 +37,14 @@ class BASE_API TraceLog : public base::win::EtwTraceProvider {
   // be used for length.
   static void Trace(const char* name,
                     size_t name_len,
-                    EventType type,
+                    TraceEventPhase type,
                     const void* id,
                     const char* extra,
                     size_t extra_len);
 
   // Allows passing extra as a std::string for convenience.
   static void Trace(const char* name,
-                    EventType type,
+                    TraceEventPhase type,
                     const void* id,
                     const std::string& extra) {
     return Trace(name, -1, type, id, extra.c_str(), extra.length());
@@ -79,7 +53,7 @@ class BASE_API TraceLog : public base::win::EtwTraceProvider {
   // Allows passing extra as a const char* to avoid constructing temporary
   // std::string instances where not needed.
   static void Trace(const char* name,
-                    EventType type,
+                    TraceEventPhase type,
                     const void* id,
                     const char* extra) {
     return Trace(name, -1, type, id, extra, -1);
@@ -87,7 +61,7 @@ class BASE_API TraceLog : public base::win::EtwTraceProvider {
 
   // Retrieves the singleton.
   // Note that this may return NULL post-AtExit processing.
-  static TraceLog* GetInstance();
+  static TraceEventETWProvider* GetInstance();
 
   // Returns true iff tracing is turned on.
   bool IsTracing() {
@@ -101,7 +75,7 @@ class BASE_API TraceLog : public base::win::EtwTraceProvider {
   //    string will be used.
   void TraceEvent(const char* name,
                   size_t name_len,
-                  EventType type,
+                  TraceEventPhase type,
                   const void* id,
                   const char* extra,
                   size_t extra_len);
@@ -112,10 +86,10 @@ class BASE_API TraceLog : public base::win::EtwTraceProvider {
 
  private:
   // Ensure only the provider can construct us.
-  friend struct StaticMemorySingletonTraits<TraceLog>;
-  TraceLog();
+  friend struct StaticMemorySingletonTraits<TraceEventETWProvider>;
+  TraceEventETWProvider();
 
-  DISALLOW_COPY_AND_ASSIGN(TraceLog);
+  DISALLOW_COPY_AND_ASSIGN(TraceEventETWProvider);
 };
 
 // The ETW trace provider GUID.
diff --git a/base/debug/trace_event_win_unittest.cc b/base/debug/trace_event_win_unittest.cc
index 4c5ed45..785943e 100644
--- a/base/debug/trace_event_win_unittest.cc
+++ b/base/debug/trace_event_win_unittest.cc
@@ -1,4 +1,4 @@
-// Copyright (c) 2010 The Chromium Authors. All rights reserved.
+// 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.
 
@@ -9,8 +9,11 @@
 #include "base/at_exit.h"
 #include "base/basictypes.h"
 #include "base/file_util.h"
+#include "base/debug/trace_event.h"
+#include "base/debug/trace_event_win.h"
 #include "base/win/event_trace_consumer.h"
 #include "base/win/event_trace_controller.h"
+#include "base/win/event_trace_provider.h"
 #include "base/win/windows_version.h"
 #include "testing/gmock/include/gmock/gmock.h"
 #include "testing/gtest/include/gtest/gtest.h"
@@ -84,9 +87,9 @@ class TestEventConsumer: public EtwTraceConsumerBase<TestEventConsumer> {
 
 TestEventConsumer* TestEventConsumer::current_ = NULL;
 
-class TraceEventTest: public testing::Test {
+class TraceEventWinTest: public testing::Test {
  public:
-  TraceEventTest() {
+  TraceEventWinTest() {
   }
 
   void SetUp() {
@@ -103,10 +106,10 @@ class TraceEventTest: public testing::Test {
     // start the private, in-proc session, but on XP we need the global
     // session created and the provider enabled before we register our
     // provider.
-    TraceLog* tracelog = NULL;
+    TraceEventETWProvider* tracelog = NULL;
     if (!is_xp) {
-      TraceLog::Resurrect();
-      tracelog = TraceLog::GetInstance();
+      TraceEventETWProvider::Resurrect();
+      tracelog = TraceEventETWProvider::GetInstance();
       ASSERT_TRUE(tracelog != NULL);
       ASSERT_FALSE(tracelog->IsTracing());
     }
@@ -141,8 +144,8 @@ class TraceEventTest: public testing::Test {
                                    0));
 
     if (is_xp) {
-      TraceLog::Resurrect();
-      tracelog = TraceLog::GetInstance();
+      TraceEventETWProvider::Resurrect();
+      tracelog = TraceEventETWProvider::GetInstance();
     }
     ASSERT_TRUE(tracelog != NULL);
     EXPECT_TRUE(tracelog->IsTracing());
@@ -204,16 +207,16 @@ class TraceEventTest: public testing::Test {
 }  // namespace
 
 
-TEST_F(TraceEventTest, TraceLog) {
+TEST_F(TraceEventWinTest, TraceLog) {
   ExpectPlayLog();
 
   // The events should arrive in the same sequence as the expects.
   InSequence in_sequence;
 
   // Full argument version, passing lengths explicitly.
-  TraceLog::Trace(kName,
+  TraceEventETWProvider::Trace(kName,
                         strlen(kName),
-                        TraceLog::EVENT_BEGIN,
+                        base::debug::TRACE_EVENT_PHASE_BEGIN,
                         kId,
                         kExtra,
                         strlen(kExtra));
@@ -225,8 +228,8 @@ TEST_F(TraceEventTest, TraceLog) {
               kExtra, strlen(kExtra));
 
   // Const char* version.
-  TraceLog::Trace(static_cast<const char*>(kName),
-                        TraceLog::EVENT_END,
+  TraceEventETWProvider::Trace(static_cast<const char*>(kName),
+                        base::debug::TRACE_EVENT_PHASE_END,
                         kId,
                         static_cast<const char*>(kExtra));
 
@@ -237,8 +240,8 @@ TEST_F(TraceEventTest, TraceLog) {
               kExtra, strlen(kExtra));
 
   // std::string extra version.
-  TraceLog::Trace(static_cast<const char*>(kName),
-                        TraceLog::EVENT_INSTANT,
+  TraceEventETWProvider::Trace(static_cast<const char*>(kName),
+                        base::debug::TRACE_EVENT_PHASE_INSTANT,
                         kId,
                         std::string(kExtra));
 
@@ -250,9 +253,9 @@ TEST_F(TraceEventTest, TraceLog) {
 
 
   // Test for sanity on NULL inputs.
-  TraceLog::Trace(NULL,
+  TraceEventETWProvider::Trace(NULL,
                         0,
-                        TraceLog::EVENT_BEGIN,
+                        base::debug::TRACE_EVENT_PHASE_BEGIN,
                         kId,
                         NULL,
                         0);
@@ -263,9 +266,9 @@ TEST_F(TraceEventTest, TraceLog) {
               kId,
               kEmpty, 0);
 
-  TraceLog::Trace(NULL,
+  TraceEventETWProvider::Trace(NULL,
                         -1,
-                        TraceLog::EVENT_END,
+                        base::debug::TRACE_EVENT_PHASE_END,
                         kId,
                         NULL,
                         -1);
@@ -279,27 +282,27 @@ TEST_F(TraceEventTest, TraceLog) {
   PlayLog();
 }
 
-TEST_F(TraceEventTest, Macros) {
+TEST_F(TraceEventWinTest, Macros) {
   ExpectPlayLog();
 
   // The events should arrive in the same sequence as the expects.
   InSequence in_sequence;
 
-  TRACE_EVENT_BEGIN(kName, kId, kExtra);
+  TRACE_EVENT_BEGIN_ETW(kName, kId, kExtra);
   ExpectEvent(kTraceEventClass32,
               kTraceEventTypeBegin,
               kName, strlen(kName),
               kId,
               kExtra, strlen(kExtra));
 
-  TRACE_EVENT_END(kName, kId, kExtra);
+  TRACE_EVENT_END_ETW(kName, kId, kExtra);
   ExpectEvent(kTraceEventClass32,
               kTraceEventTypeEnd,
               kName, strlen(kName),
               kId,
               kExtra, strlen(kExtra));
 
-  TRACE_EVENT_INSTANT(kName, kId, kExtra);
+  TRACE_EVENT_INSTANT_ETW(kName, kId, kExtra);
   ExpectEvent(kTraceEventClass32,
               kTraceEventTypeInstant,
               kName, strlen(kName),