summaryrefslogtreecommitdiffstats
path: root/base/debug
diff options
context:
space:
mode:
authorscheib@chromium.org <scheib@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>2011-05-06 20:30:09 +0000
committerscheib@chromium.org <scheib@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>2011-05-06 20:30:09 +0000
commit5ae1f730fffdc5b06423a92acc8e004ce4b6bc64 (patch)
tree7aafbabace87609d656457813309c2fb691f2049 /base/debug
parentff24f49bedc612731ed5632391ce4325698ae8dc (diff)
downloadchromium_src-5ae1f730fffdc5b06423a92acc8e004ce4b6bc64.zip
chromium_src-5ae1f730fffdc5b06423a92acc8e004ce4b6bc64.tar.gz
chromium_src-5ae1f730fffdc5b06423a92acc8e004ce4b6bc64.tar.bz2
Revert 84486 - 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=79509TEST=trace_event_win_unittest and about:gpuCommitted: http://src.chromium.org/viewvc/chrome?view=rev&revision=84284Review URL: http://codereview.chromium.org/6862002
TBR=scheib@chromium.org Review URL: http://codereview.chromium.org/6955006 git-svn-id: svn://svn.chromium.org/chrome/trunk/src@84494 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'base/debug')
-rw-r--r--base/debug/trace_event.cc452
-rw-r--r--base/debug/trace_event.h508
-rw-r--r--base/debug/trace_event_unittest.cc397
-rw-r--r--base/debug/trace_event_win.cc47
-rw-r--r--base/debug/trace_event_win.h46
-rw-r--r--base/debug/trace_event_win_unittest.cc49
6 files changed, 306 insertions, 1193 deletions
diff --git a/base/debug/trace_event.cc b/base/debug/trace_event.cc
index 58ff82f..c219cec 100644
--- a/base/debug/trace_event.cc
+++ b/base/debug/trace_event.cc
@@ -1,15 +1,16 @@
-// Copyright (c) 2011 The Chromium Authors. All rights reserved.
+// Copyright (c) 2010 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"
@@ -18,368 +19,149 @@
namespace base {
namespace debug {
-// 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 char* kEventTypeNames[] = {
+ "BEGIN",
+ "END",
+ "INSTANT"
};
-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
-
-////////////////////////////////////////////////////////////////////////////////
-//
-// TraceValue
-//
-////////////////////////////////////////////////////////////////////////////////
-
-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;
-}
-
-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;
- }
-}
-
-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;
- }
-}
-
-////////////////////////////////////////////////////////////////////////////////
-//
-// TraceEvent
-//
-////////////////////////////////////////////////////////////////////////////////
-namespace {
+static const FilePath::CharType* kLogFileName =
+ FILE_PATH_LITERAL("trace_%d.log");
-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 "?";
- }
+// static
+TraceLog* TraceLog::GetInstance() {
+ return Singleton<TraceLog, DefaultSingletonTraits<TraceLog> >::get();
}
-} // 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));
+// static
+bool TraceLog::IsTracing() {
+ return TraceLog::GetInstance()->enabled_;
}
-TraceEvent::~TraceEvent() {
+// static
+bool TraceLog::StartTracing() {
+ return TraceLog::GetInstance()->Start();
}
-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 += "]";
+// static
+void TraceLog::StopTracing() {
+ return TraceLog::GetInstance()->Stop();
}
-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);
- }
- *out += "}}";
+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);
}
-////////////////////////////////////////////////////////////////////////////////
-//
-// TraceLog
-//
-////////////////////////////////////////////////////////////////////////////////
-
-// static
-TraceLog* TraceLog::GetInstance() {
- return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get();
-}
+void TraceLog::Trace(const std::string& name,
+ EventType type,
+ const void* id,
+ const std::string& extra,
+ const char* file,
+ int line) {
+ if (!enabled_)
+ return;
-TraceLog::TraceLog()
- : enabled_(false) {
- logged_events_.reserve(1024);
+#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
}
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;
+ 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;
+ }
}
- return tracelog->GetCategoryInternal(name);
+ return true;
}
-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];
- }
-
- // 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::CloseLogFile() {
+ if (log_file_) {
+ file_util::CloseFile(log_file_);
}
}
-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) {
- AutoLock lock(lock_);
- output_callback_ = cb;
- logged_events_.clear();
-}
-
-void TraceLog::SetBufferFullCallback(const TraceLog::BufferFullCallback& cb) {
- AutoLock lock(lock_);
- buffer_full_callback_ = cb;
+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);
+ }
+ return enabled_;
}
-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::Stop() {
+ if (enabled_) {
+ enabled_ = false;
+ Log("];\n");
+ CloseLogFile();
+ timer_.Stop();
}
}
-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::Heartbeat() {
+ std::string cpu = StringPrintf("%.0f", process_metrics_->GetCPUUsage());
+ TRACE_EVENT_INSTANT("heartbeat.cpu", 0, cpu);
}
-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 : "");
- }
-}
+void TraceLog::Log(const std::string& msg) {
+ AutoLock lock(file_lock_);
-void TraceLog::Resurrect() {
- StaticMemorySingletonTraits<TraceLog>::Resurrect();
+ fprintf(log_file_, "%s", msg.c_str());
}
} // namespace debug
diff --git a/base/debug/trace_event.h b/base/debug/trace_event.h
index 9476d71..3b4afc5 100644
--- a/base/debug/trace_event.h
+++ b/base/debug/trace_event.h
@@ -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);
-
-#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); \
- }
+#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
namespace base {
-namespace debug {
-
-// Categories allow enabling/disabling of streams of trace events
-struct TraceCategory {
- const char* name;
- volatile bool enabled;
-};
-
-const size_t kTraceMaxNumArgs = 2;
+class ProcessMetrics;
-// 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
-};
+namespace debug {
-// 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
- };
-
- 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;
+ enum EventType {
+ EVENT_BEGIN,
+ EVENT_END,
+ EVENT_INSTANT
};
- 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_; }
-
- 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();
+ // 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);
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);
-};
-
-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_;
+ FILE* log_file_;
+ base::Lock file_lock_;
+ TimeTicks trace_start_time_;
+ scoped_ptr<base::ProcessMetrics> process_metrics_;
+ RepeatingTimer<TraceLog> timer_;
};
-} // 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
deleted file mode 100644
index 360468d..0000000
--- a/base/debug/trace_event_unittest.cc
+++ /dev/null
@@ -1,397 +0,0 @@
-// 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 bba4713..4929944 100644
--- a/base/debug/trace_event_win.cc
+++ b/base/debug/trace_event_win.cc
@@ -1,6 +1,7 @@
// 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"
@@ -26,26 +27,24 @@ const GUID kTraceEventClass64 = {
0x97be602d, 0x2930, 0x4ac3, 0x80, 0x46, 0xb6, 0x76, 0x3b, 0x63, 0x1d, 0xfe};
-TraceEventETWProvider::TraceEventETWProvider() :
- EtwTraceProvider(kChromeTraceProviderName) {
+TraceLog::TraceLog() : EtwTraceProvider(kChromeTraceProviderName) {
Register();
}
-TraceEventETWProvider* TraceEventETWProvider::GetInstance() {
- return Singleton<TraceEventETWProvider,
- StaticMemorySingletonTraits<TraceEventETWProvider> >::get();
+TraceLog* TraceLog::GetInstance() {
+ return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get();
}
-bool TraceEventETWProvider::StartTracing() {
+bool TraceLog::StartTracing() {
return true;
}
-void TraceEventETWProvider::TraceEvent(const char* name,
- size_t name_len,
- TraceEventPhase type,
- const void* id,
- const char* extra,
- size_t extra_len) {
+void TraceLog::TraceEvent(const char* name,
+ size_t name_len,
+ EventType type,
+ const void* id,
+ const char* extra,
+ size_t extra_len) {
// Make sure we don't touch NULL.
if (name == NULL)
name = "";
@@ -54,14 +53,14 @@ void TraceEventETWProvider::TraceEvent(const char* name,
EtwEventType etw_type = 0;
switch (type) {
- case TRACE_EVENT_PHASE_BEGIN:
+ case TraceLog::EVENT_BEGIN:
etw_type = kTraceEventTypeBegin;
break;
- case TRACE_EVENT_PHASE_END:
+ case TraceLog::EVENT_END:
etw_type = kTraceEventTypeEnd;
break;
- case TRACE_EVENT_PHASE_INSTANT:
+ case TraceLog::EVENT_INSTANT:
etw_type = kTraceEventTypeInstant;
break;
@@ -94,13 +93,13 @@ void TraceEventETWProvider::TraceEvent(const char* name,
Log(event.get());
}
-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();
+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();
if (provider && provider->IsTracing()) {
// Compute the name & extra lengths if not supplied already.
if (name_len == -1)
@@ -112,8 +111,8 @@ void TraceEventETWProvider::Trace(const char* name,
}
}
-void TraceEventETWProvider::Resurrect() {
- StaticMemorySingletonTraits<TraceEventETWProvider>::Resurrect();
+void TraceLog::Resurrect() {
+ StaticMemorySingletonTraits<TraceLog>::Resurrect();
}
} // namespace debug
diff --git a/base/debug/trace_event_win.h b/base/debug/trace_event_win.h
index 6e6bcb4..9049bdb 100644
--- a/base/debug/trace_event_win.h
+++ b/base/debug/trace_event_win.h
@@ -10,9 +10,29 @@
#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;
@@ -22,8 +42,14 @@ namespace debug {
// This EtwTraceProvider subclass implements ETW logging
// for the macros above on Windows.
-class BASE_API TraceEventETWProvider : public base::win::EtwTraceProvider {
+class BASE_API TraceLog : 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();
@@ -37,14 +63,14 @@ class BASE_API TraceEventETWProvider : public base::win::EtwTraceProvider {
// be used for length.
static void Trace(const char* name,
size_t name_len,
- TraceEventPhase type,
+ EventType 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,
- TraceEventPhase type,
+ EventType type,
const void* id,
const std::string& extra) {
return Trace(name, -1, type, id, extra.c_str(), extra.length());
@@ -53,7 +79,7 @@ class BASE_API TraceEventETWProvider : 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,
- TraceEventPhase type,
+ EventType type,
const void* id,
const char* extra) {
return Trace(name, -1, type, id, extra, -1);
@@ -61,7 +87,7 @@ class BASE_API TraceEventETWProvider : public base::win::EtwTraceProvider {
// Retrieves the singleton.
// Note that this may return NULL post-AtExit processing.
- static TraceEventETWProvider* GetInstance();
+ static TraceLog* GetInstance();
// Returns true iff tracing is turned on.
bool IsTracing() {
@@ -75,7 +101,7 @@ class BASE_API TraceEventETWProvider : public base::win::EtwTraceProvider {
// string will be used.
void TraceEvent(const char* name,
size_t name_len,
- TraceEventPhase type,
+ EventType type,
const void* id,
const char* extra,
size_t extra_len);
@@ -86,10 +112,10 @@ class BASE_API TraceEventETWProvider : public base::win::EtwTraceProvider {
private:
// Ensure only the provider can construct us.
- friend struct StaticMemorySingletonTraits<TraceEventETWProvider>;
- TraceEventETWProvider();
+ friend struct StaticMemorySingletonTraits<TraceLog>;
+ TraceLog();
- DISALLOW_COPY_AND_ASSIGN(TraceEventETWProvider);
+ DISALLOW_COPY_AND_ASSIGN(TraceLog);
};
// The ETW trace provider GUID.
diff --git a/base/debug/trace_event_win_unittest.cc b/base/debug/trace_event_win_unittest.cc
index 785943e..4c5ed45 100644
--- a/base/debug/trace_event_win_unittest.cc
+++ b/base/debug/trace_event_win_unittest.cc
@@ -1,4 +1,4 @@
-// Copyright (c) 2011 The Chromium Authors. All rights reserved.
+// Copyright (c) 2010 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,11 +9,8 @@
#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"
@@ -87,9 +84,9 @@ class TestEventConsumer: public EtwTraceConsumerBase<TestEventConsumer> {
TestEventConsumer* TestEventConsumer::current_ = NULL;
-class TraceEventWinTest: public testing::Test {
+class TraceEventTest: public testing::Test {
public:
- TraceEventWinTest() {
+ TraceEventTest() {
}
void SetUp() {
@@ -106,10 +103,10 @@ class TraceEventWinTest: 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.
- TraceEventETWProvider* tracelog = NULL;
+ TraceLog* tracelog = NULL;
if (!is_xp) {
- TraceEventETWProvider::Resurrect();
- tracelog = TraceEventETWProvider::GetInstance();
+ TraceLog::Resurrect();
+ tracelog = TraceLog::GetInstance();
ASSERT_TRUE(tracelog != NULL);
ASSERT_FALSE(tracelog->IsTracing());
}
@@ -144,8 +141,8 @@ class TraceEventWinTest: public testing::Test {
0));
if (is_xp) {
- TraceEventETWProvider::Resurrect();
- tracelog = TraceEventETWProvider::GetInstance();
+ TraceLog::Resurrect();
+ tracelog = TraceLog::GetInstance();
}
ASSERT_TRUE(tracelog != NULL);
EXPECT_TRUE(tracelog->IsTracing());
@@ -207,16 +204,16 @@ class TraceEventWinTest: public testing::Test {
} // namespace
-TEST_F(TraceEventWinTest, TraceLog) {
+TEST_F(TraceEventTest, TraceLog) {
ExpectPlayLog();
// The events should arrive in the same sequence as the expects.
InSequence in_sequence;
// Full argument version, passing lengths explicitly.
- TraceEventETWProvider::Trace(kName,
+ TraceLog::Trace(kName,
strlen(kName),
- base::debug::TRACE_EVENT_PHASE_BEGIN,
+ TraceLog::EVENT_BEGIN,
kId,
kExtra,
strlen(kExtra));
@@ -228,8 +225,8 @@ TEST_F(TraceEventWinTest, TraceLog) {
kExtra, strlen(kExtra));
// Const char* version.
- TraceEventETWProvider::Trace(static_cast<const char*>(kName),
- base::debug::TRACE_EVENT_PHASE_END,
+ TraceLog::Trace(static_cast<const char*>(kName),
+ TraceLog::EVENT_END,
kId,
static_cast<const char*>(kExtra));
@@ -240,8 +237,8 @@ TEST_F(TraceEventWinTest, TraceLog) {
kExtra, strlen(kExtra));
// std::string extra version.
- TraceEventETWProvider::Trace(static_cast<const char*>(kName),
- base::debug::TRACE_EVENT_PHASE_INSTANT,
+ TraceLog::Trace(static_cast<const char*>(kName),
+ TraceLog::EVENT_INSTANT,
kId,
std::string(kExtra));
@@ -253,9 +250,9 @@ TEST_F(TraceEventWinTest, TraceLog) {
// Test for sanity on NULL inputs.
- TraceEventETWProvider::Trace(NULL,
+ TraceLog::Trace(NULL,
0,
- base::debug::TRACE_EVENT_PHASE_BEGIN,
+ TraceLog::EVENT_BEGIN,
kId,
NULL,
0);
@@ -266,9 +263,9 @@ TEST_F(TraceEventWinTest, TraceLog) {
kId,
kEmpty, 0);
- TraceEventETWProvider::Trace(NULL,
+ TraceLog::Trace(NULL,
-1,
- base::debug::TRACE_EVENT_PHASE_END,
+ TraceLog::EVENT_END,
kId,
NULL,
-1);
@@ -282,27 +279,27 @@ TEST_F(TraceEventWinTest, TraceLog) {
PlayLog();
}
-TEST_F(TraceEventWinTest, Macros) {
+TEST_F(TraceEventTest, Macros) {
ExpectPlayLog();
// The events should arrive in the same sequence as the expects.
InSequence in_sequence;
- TRACE_EVENT_BEGIN_ETW(kName, kId, kExtra);
+ TRACE_EVENT_BEGIN(kName, kId, kExtra);
ExpectEvent(kTraceEventClass32,
kTraceEventTypeBegin,
kName, strlen(kName),
kId,
kExtra, strlen(kExtra));
- TRACE_EVENT_END_ETW(kName, kId, kExtra);
+ TRACE_EVENT_END(kName, kId, kExtra);
ExpectEvent(kTraceEventClass32,
kTraceEventTypeEnd,
kName, strlen(kName),
kId,
kExtra, strlen(kExtra));
- TRACE_EVENT_INSTANT_ETW(kName, kId, kExtra);
+ TRACE_EVENT_INSTANT(kName, kId, kExtra);
ExpectEvent(kTraceEventClass32,
kTraceEventTypeInstant,
kName, strlen(kName),