Index: base/debug/trace_event.h |
=================================================================== |
--- base/debug/trace_event.h (revision 84493) |
+++ base/debug/trace_event.h (working copy) |
@@ -2,40 +2,15 @@ |
// 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_ |
@@ -43,401 +18,132 @@ |
#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__) |
+// 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 |
-// 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); \ |
- } |
- |
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 BASE_API TraceValue { |
+class BASE_API TraceLog { |
public: |
- enum Type { |
- TRACE_TYPE_UNDEFINED, |
- TRACE_TYPE_BOOL, |
- TRACE_TYPE_UINT, |
- TRACE_TYPE_INT, |
- TRACE_TYPE_DOUBLE, |
- TRACE_TYPE_POINTER, |
- TRACE_TYPE_STRING |
+ enum EventType { |
+ EVENT_BEGIN, |
+ EVENT_END, |
+ EVENT_INSTANT |
}; |
- 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); |
- |
- 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; |
- }; |
- |
- 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(); |
- // 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; |
+ // 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); |
- // 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 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 BASE_API 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_ |