Revert 84284 - Merge gpu_trace_event back into base/debug/trace_event.Initial land attempt at htt...

base/debug/trace_event.h

 // 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.
 
-// Trace events are for tracking application performance.
+// 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.
 //
-// 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.
+// 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.
 
 #ifndef BASE_DEBUG_TRACE_EVENT_H_
 #define BASE_DEBUG_TRACE_EVENT_H_
 #pragma once
 
 #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/callback.h"
+#include "base/memory/scoped_ptr.h"
 #include "base/memory/singleton.h"
-#include "base/string_util.h"
+#include "base/synchronization/lock.h"
+#include "base/time.h"
 #include "base/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( \
-      base::debug::TRACE_EVENT_PHASE_BEGIN, \
-      __FILE__, __LINE__, name, reinterpret_cast<const void*>(id), extra);
+#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)
 
-#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);
+#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);
 
-#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);
+// 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__)
 
-// 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); \
-  }
+// 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
 
 namespace base {
 
+class ProcessMetrics;
+
 namespace debug {
 
-// 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 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:
+  enum EventType {
+    EVENT_BEGIN,
+    EVENT_END,
+    EVENT_INSTANT
+  };
+
   static TraceLog* GetInstance();
 
-  // 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_; }
+  // Is tracing currently enabled.
+  static bool IsTracing();
+  // Start logging trace events.
+  static bool StartTracing();
+  // Stop logging trace events.
+  static void StopTracing();
 
-  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();
+  // 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);
 
  private:
   // This allows constructor and destructor to be private and usable only
   // by the Singleton class.
-  friend struct StaticMemorySingletonTraits<TraceLog>;
+  friend struct DefaultSingletonTraits<TraceLog>;
 
   TraceLog();
   ~TraceLog();
-  const TraceCategory* GetCategoryInternal(const char* name);
+  bool OpenLogFile();
+  void CloseLogFile();
+  bool Start();
+  void Stop();
+  void Heartbeat();
+  void Log(const std::string& msg);
 
-  // TODO(nduca): switch to per-thread trace buffers to reduce thread
-  // synchronization.
-  Lock lock_;
   bool enabled_;
-  OutputCallback output_callback_;
-  BufferFullCallback buffer_full_callback_;
-  std::vector<TraceEvent> logged_events_;
-
-  DISALLOW_COPY_AND_ASSIGN(TraceLog);
+  FILE* log_file_;
+  base::Lock file_lock_;
+  TimeTicks trace_start_time_;
+  scoped_ptr<base::ProcessMetrics> process_metrics_;
+  RepeatingTimer<TraceLog> timer_;
 };
 
-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_