From c76faeaa3ef76c0cf7560b5fe55ebb58981db4db Mon Sep 17 00:00:00 2001 From: "simonjam@chromium.org" Date: Tue, 26 Mar 2013 07:42:42 +0000 Subject: Add a |scope| argument to TRACE_EVENT_INSTANT* and require its presence. The scope indicates how long the vertical line should be in the tracing UI. It can be global (full screen), process or thread (fill those tracks), or local (the original style for INSTANT). BUG=None Review URL: https://chromiumcodereview.appspot.com/12252058 git-svn-id: svn://svn.chromium.org/chrome/trunk/src@190577 0039d316-1c4b-4281-b951-d872f2087c98 --- base/debug/trace_event_impl.cc | 20 +++++ base/debug/trace_event_internal.h | 82 +++++++++++------- base/debug/trace_event_unittest.cc | 135 ++++++++++++++++++----------- base/test/trace_event_analyzer_unittest.cc | 51 ++++++----- 4 files changed, 184 insertions(+), 104 deletions(-) (limited to 'base') diff --git a/base/debug/trace_event_impl.cc b/base/debug/trace_event_impl.cc index d543d87..dc8256a 100644 --- a/base/debug/trace_event_impl.cc +++ b/base/debug/trace_event_impl.cc @@ -408,6 +408,26 @@ void TraceEvent::AppendAsJSON(std::string* out) const { // bits (it might be a 64-bit pointer). if (flags_ & TRACE_EVENT_FLAG_HAS_ID) StringAppendF(out, ",\"id\":\"%" PRIx64 "\"", static_cast(id_)); + + // Instant events also output their scope. + if (phase_ == TRACE_EVENT_PHASE_INSTANT) { + char scope = '?'; + switch (flags_ & TRACE_EVENT_FLAG_SCOPE_MASK) { + case TRACE_EVENT_SCOPE_GLOBAL: + scope = TRACE_EVENT_SCOPE_NAME_GLOBAL; + break; + + case TRACE_EVENT_SCOPE_PROCESS: + scope = TRACE_EVENT_SCOPE_NAME_PROCESS; + break; + + case TRACE_EVENT_SCOPE_THREAD: + scope = TRACE_EVENT_SCOPE_NAME_THREAD; + break; + } + StringAppendF(out, ",\"s\":\"%c\"", scope); + } + *out += "}"; } diff --git a/base/debug/trace_event_internal.h b/base/debug/trace_event_internal.h index 864315e..46495f4 100644 --- a/base/debug/trace_event_internal.h +++ b/base/debug/trace_event_internal.h @@ -182,10 +182,11 @@ #define UNSHIPPED_TRACE_EVENT1(category, name, arg1_name, arg1_val) (void)0 #define UNSHIPPED_TRACE_EVENT2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) (void)0 -#define UNSHIPPED_TRACE_EVENT_INSTANT0(category, name) (void)0 -#define UNSHIPPED_TRACE_EVENT_INSTANT1(category, name, arg1_name, arg1_val) \ - (void)0 -#define UNSHIPPED_TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, \ +#define UNSHIPPED_TRACE_EVENT_INSTANT0(category, name, scope) (void)0 +#define UNSHIPPED_TRACE_EVENT_INSTANT1(category, name, scope, \ + arg1_name, arg1_val) (void)0 +#define UNSHIPPED_TRACE_EVENT_INSTANT2(category, name, scope, \ + arg1_name, arg1_val, \ arg2_name, arg2_val) (void)0 #else #define UNSHIPPED_TRACE_EVENT0(category, name) \ @@ -195,13 +196,15 @@ #define UNSHIPPED_TRACE_EVENT2(category, name, arg1_name, arg1_val, \ arg2_name, arg2_val) \ TRACE_EVENT2(category, name, arg1_name, arg1_val, arg2_name, arg2_val) -#define UNSHIPPED_TRACE_EVENT_INSTANT0(category, name) \ - TRACE_EVENT_INSTANT0(category, name) -#define UNSHIPPED_TRACE_EVENT_INSTANT1(category, name, arg1_name, arg1_val) \ - TRACE_EVENT_INSTANT1(category, name, arg1_name, arg1_val) -#define UNSHIPPED_TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, \ +#define UNSHIPPED_TRACE_EVENT_INSTANT0(category, name, scope) \ + TRACE_EVENT_INSTANT0(category, name, scope) +#define UNSHIPPED_TRACE_EVENT_INSTANT1(category, name, scope, \ + arg1_name, arg1_val) \ + TRACE_EVENT_INSTANT1(category, name, scope, arg1_name, arg1_val) +#define UNSHIPPED_TRACE_EVENT_INSTANT2(category, name, scope, \ + arg1_name, arg1_val, \ arg2_name, arg2_val) \ - TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, \ + TRACE_EVENT_INSTANT2(category, name, scope, arg1_name, arg1_val, \ arg2_name, arg2_val) #endif @@ -210,28 +213,31 @@ // does nothing. // - category and name strings must have application lifetime (statics or // literals). They may not include " chars. -#define TRACE_EVENT_INSTANT0(category, name) \ +#define TRACE_EVENT_INSTANT0(category, name, scope) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, TRACE_EVENT_FLAG_NONE) -#define TRACE_EVENT_INSTANT1(category, name, arg1_name, arg1_val) \ + category, name, TRACE_EVENT_FLAG_NONE | scope) +#define TRACE_EVENT_INSTANT1(category, name, scope, arg1_name, arg1_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val) -#define TRACE_EVENT_INSTANT2(category, name, arg1_name, arg1_val, \ - arg2_name, arg2_val) \ + category, name, TRACE_EVENT_FLAG_NONE | scope, \ + arg1_name, arg1_val) +#define TRACE_EVENT_INSTANT2(category, name, scope, arg1_name, arg1_val, \ + arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, TRACE_EVENT_FLAG_NONE, arg1_name, arg1_val, \ - arg2_name, arg2_val) -#define TRACE_EVENT_COPY_INSTANT0(category, name) \ + category, name, TRACE_EVENT_FLAG_NONE | scope, \ + arg1_name, arg1_val, arg2_name, arg2_val) +#define TRACE_EVENT_COPY_INSTANT0(category, name, scope) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, TRACE_EVENT_FLAG_COPY) -#define TRACE_EVENT_COPY_INSTANT1(category, name, arg1_name, arg1_val) \ + category, name, TRACE_EVENT_FLAG_COPY | scope) +#define TRACE_EVENT_COPY_INSTANT1(category, name, scope, \ + arg1_name, arg1_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val) -#define TRACE_EVENT_COPY_INSTANT2(category, name, arg1_name, arg1_val, \ - arg2_name, arg2_val) \ + category, name, TRACE_EVENT_FLAG_COPY | scope, arg1_name, arg1_val) +#define TRACE_EVENT_COPY_INSTANT2(category, name, scope, \ + arg1_name, arg1_val, \ + arg2_name, arg2_val) \ INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_INSTANT, \ - category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val, \ - arg2_name, arg2_val) + category, name, TRACE_EVENT_FLAG_COPY | scope, \ + arg1_name, arg1_val, arg2_name, arg2_val) // Sets the current sample state to the given category and name (both must be // constant strings). These states are intended for a sampling profiler. @@ -694,7 +700,7 @@ // Phase indicates the nature of an event entry. E.g. part of a begin/end pair. #define TRACE_EVENT_PHASE_BEGIN ('B') #define TRACE_EVENT_PHASE_END ('E') -#define TRACE_EVENT_PHASE_INSTANT ('I') +#define TRACE_EVENT_PHASE_INSTANT ('i') #define TRACE_EVENT_PHASE_ASYNC_BEGIN ('S') #define TRACE_EVENT_PHASE_ASYNC_STEP ('T') #define TRACE_EVENT_PHASE_ASYNC_END ('F') @@ -708,10 +714,14 @@ #define TRACE_EVENT_PHASE_DELETE_OBJECT ('D') // Flags for changing the behavior of TRACE_EVENT_API_ADD_TRACE_EVENT. -#define TRACE_EVENT_FLAG_NONE (static_cast(0)) -#define TRACE_EVENT_FLAG_COPY (static_cast(1 << 0)) -#define TRACE_EVENT_FLAG_HAS_ID (static_cast(1 << 1)) -#define TRACE_EVENT_FLAG_MANGLE_ID (static_cast(1 << 2)) +#define TRACE_EVENT_FLAG_NONE (static_cast(0)) +#define TRACE_EVENT_FLAG_COPY (static_cast(1 << 0)) +#define TRACE_EVENT_FLAG_HAS_ID (static_cast(1 << 1)) +#define TRACE_EVENT_FLAG_MANGLE_ID (static_cast(1 << 2)) +#define TRACE_EVENT_FLAG_SCOPE_OFFSET (static_cast(1 << 3)) + +#define TRACE_EVENT_FLAG_SCOPE_MASK (static_cast( \ + TRACE_EVENT_FLAG_SCOPE_OFFSET | (TRACE_EVENT_FLAG_SCOPE_OFFSET << 1))) // Type values for identifying types in the TraceValue union. #define TRACE_VALUE_TYPE_BOOL (static_cast(1)) @@ -722,6 +732,16 @@ #define TRACE_VALUE_TYPE_STRING (static_cast(6)) #define TRACE_VALUE_TYPE_COPY_STRING (static_cast(7)) +// Enum reflecting the scope of an INSTANT event. Must fit within +// TRACE_EVENT_FLAG_SCOPE_MASK. +#define TRACE_EVENT_SCOPE_GLOBAL (static_cast(0 << 3)) +#define TRACE_EVENT_SCOPE_PROCESS (static_cast(1 << 3)) +#define TRACE_EVENT_SCOPE_THREAD (static_cast(2 << 3)) + +#define TRACE_EVENT_SCOPE_NAME_GLOBAL ('g') +#define TRACE_EVENT_SCOPE_NAME_PROCESS ('p') +#define TRACE_EVENT_SCOPE_NAME_THREAD ('t') + namespace trace_event_internal { // Specify these values when the corresponding argument of AddTraceEvent is not diff --git a/base/debug/trace_event_unittest.cc b/base/debug/trace_event_unittest.cc index 5fb9040..4e76203 100644 --- a/base/debug/trace_event_unittest.cc +++ b/base/debug/trace_event_unittest.cc @@ -326,9 +326,12 @@ void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) { "name1", "\"value1\"", "name2", "value\\2"); - TRACE_EVENT_INSTANT0("all", "TRACE_EVENT_INSTANT0 call"); - TRACE_EVENT_INSTANT1("all", "TRACE_EVENT_INSTANT1 call", "name1", "value1"); + TRACE_EVENT_INSTANT0("all", "TRACE_EVENT_INSTANT0 call", + TRACE_EVENT_SCOPE_GLOBAL); + TRACE_EVENT_INSTANT1("all", "TRACE_EVENT_INSTANT1 call", + TRACE_EVENT_SCOPE_PROCESS, "name1", "value1"); TRACE_EVENT_INSTANT2("all", "TRACE_EVENT_INSTANT2 call", + TRACE_EVENT_SCOPE_THREAD, "name1", "value1", "name2", "value2"); @@ -447,10 +450,25 @@ void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) { EXPECT_SUB_FIND_("value\\2"); EXPECT_FIND_("TRACE_EVENT_INSTANT0 call"); + { + std::string scope; + EXPECT_TRUE((item && item->GetString("s", &scope))); + EXPECT_EQ("g", scope); + } EXPECT_FIND_("TRACE_EVENT_INSTANT1 call"); + { + std::string scope; + EXPECT_TRUE((item && item->GetString("s", &scope))); + EXPECT_EQ("p", scope); + } EXPECT_SUB_FIND_("name1"); EXPECT_SUB_FIND_("value1"); EXPECT_FIND_("TRACE_EVENT_INSTANT2 call"); + { + std::string scope; + EXPECT_TRUE((item && item->GetString("s", &scope))); + EXPECT_EQ("t", scope); + } EXPECT_SUB_FIND_("name1"); EXPECT_SUB_FIND_("value1"); EXPECT_SUB_FIND_("name2"); @@ -695,6 +713,7 @@ void TraceManyInstantEvents(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", + TRACE_EVENT_SCOPE_THREAD, "thread", thread_id, "event", i); } @@ -737,7 +756,7 @@ void ValidateInstantEventPresentOnEveryThread(const ListValue& trace_parsed, void TraceCallsWithCachedCategoryPointersPointers(const char* name_str) { TRACE_EVENT0("category name1", name_str); - TRACE_EVENT_INSTANT0("category name2", name_str); + TRACE_EVENT_INSTANT0("category name2", name_str, TRACE_EVENT_SCOPE_THREAD); TRACE_EVENT_BEGIN0("category name3", name_str); TRACE_EVENT_END0("category name4", name_str); } @@ -851,11 +870,11 @@ TEST_F(TraceEventTestFixture, Categories) { // Test that categories that are used can be retrieved whether trace was // enabled or disabled when the trace event was encountered. - TRACE_EVENT_INSTANT0("c1", "name"); - TRACE_EVENT_INSTANT0("c2", "name"); + TRACE_EVENT_INSTANT0("c1", "name", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("c2", "name", TRACE_EVENT_SCOPE_THREAD); BeginTrace(); - TRACE_EVENT_INSTANT0("c3", "name"); - TRACE_EVENT_INSTANT0("c4", "name"); + TRACE_EVENT_INSTANT0("c3", "name", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("c4", "name", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); std::vector cats; TraceLog::GetInstance()->GetKnownCategories(&cats); @@ -876,8 +895,8 @@ TEST_F(TraceEventTestFixture, Categories) { included_categories.push_back("not_found823564786"); TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories, TraceLog::RECORD_UNTIL_FULL); - TRACE_EVENT_INSTANT0("cat1", "name"); - TRACE_EVENT_INSTANT0("cat2", "name"); + TRACE_EVENT_INSTANT0("cat1", "name", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat2", "name", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_TRUE(trace_parsed_.empty()); @@ -887,8 +906,8 @@ TEST_F(TraceEventTestFixture, Categories) { included_categories.push_back("inc"); TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories, TraceLog::RECORD_UNTIL_FULL); - TRACE_EVENT_INSTANT0("inc", "name"); - TRACE_EVENT_INSTANT0("inc2", "name"); + TRACE_EVENT_INSTANT0("inc", "name", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc2", "name", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_TRUE(FindMatchingValue("cat", "inc")); EXPECT_FALSE(FindNonMatchingValue("cat", "inc")); @@ -900,12 +919,15 @@ TEST_F(TraceEventTestFixture, Categories) { included_categories.push_back("inc_wildchar_?_end"); TraceLog::GetInstance()->SetEnabled(included_categories, empty_categories, TraceLog::RECORD_UNTIL_FULL); - TRACE_EVENT_INSTANT0("inc_wildcard_abc", "included"); - TRACE_EVENT_INSTANT0("inc_wildcard_", "included"); - TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "included"); - TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "not_inc"); - TRACE_EVENT_INSTANT0("cat1", "not_inc"); - TRACE_EVENT_INSTANT0("cat2", "not_inc"); + TRACE_EVENT_INSTANT0("inc_wildcard_abc", "included", + TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc_wildcard_", "included", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "included", + TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "not_inc", + TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat1", "not_inc", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat2", "not_inc", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_abc")); EXPECT_TRUE(FindMatchingValue("cat", "inc_wildcard_")); @@ -920,8 +942,8 @@ TEST_F(TraceEventTestFixture, Categories) { excluded_categories.push_back("not_found823564786"); TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories, TraceLog::RECORD_UNTIL_FULL); - TRACE_EVENT_INSTANT0("cat1", "name"); - TRACE_EVENT_INSTANT0("cat2", "name"); + TRACE_EVENT_INSTANT0("cat1", "name", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat2", "name", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_TRUE(FindMatchingValue("cat", "cat1")); EXPECT_TRUE(FindMatchingValue("cat", "cat2")); @@ -932,8 +954,8 @@ TEST_F(TraceEventTestFixture, Categories) { excluded_categories.push_back("inc"); TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories, TraceLog::RECORD_UNTIL_FULL); - TRACE_EVENT_INSTANT0("inc", "name"); - TRACE_EVENT_INSTANT0("inc2", "name"); + TRACE_EVENT_INSTANT0("inc", "name", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc2", "name", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_TRUE(FindMatchingValue("cat", "inc2")); EXPECT_FALSE(FindMatchingValue("cat", "inc")); @@ -945,12 +967,14 @@ TEST_F(TraceEventTestFixture, Categories) { excluded_categories.push_back("inc_wildchar_?_end"); TraceLog::GetInstance()->SetEnabled(empty_categories, excluded_categories, TraceLog::RECORD_UNTIL_FULL); - TRACE_EVENT_INSTANT0("inc_wildcard_abc", "not_inc"); - TRACE_EVENT_INSTANT0("inc_wildcard_", "not_inc"); - TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "not_inc"); - TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "included"); - TRACE_EVENT_INSTANT0("cat1", "included"); - TRACE_EVENT_INSTANT0("cat2", "included"); + TRACE_EVENT_INSTANT0("inc_wildcard_abc", "not_inc", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc_wildcard_", "not_inc", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc_wildchar_x_end", "not_inc", + TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("inc_wildchar_bla_end", "included", + TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat1", "included", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat2", "included", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_TRUE(FindMatchingValue("cat", "inc_wildchar_bla_end")); EXPECT_TRUE(FindMatchingValue("cat", "cat1")); @@ -966,13 +990,13 @@ TEST_F(TraceEventTestFixture, EventWatchNotification) { // Basic one occurrence. BeginTrace(); TraceLog::GetInstance()->SetWatchEvent("cat", "event"); - TRACE_EVENT_INSTANT0("cat", "event"); + TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 1); // Basic one occurrence before Set. BeginTrace(); - TRACE_EVENT_INSTANT0("cat", "event"); + TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); TraceLog::GetInstance()->SetWatchEvent("cat", "event"); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 1); @@ -982,7 +1006,7 @@ TEST_F(TraceEventTestFixture, EventWatchNotification) { TraceLog::GetInstance()->SetWatchEvent("cat", "event"); EndTraceAndFlush(); BeginTrace(); - TRACE_EVENT_INSTANT0("cat", "event"); + TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 0); @@ -991,21 +1015,21 @@ TEST_F(TraceEventTestFixture, EventWatchNotification) { int num_occurrences = 5; TraceLog::GetInstance()->SetWatchEvent("cat", "event"); for (int i = 0; i < num_occurrences; ++i) - TRACE_EVENT_INSTANT0("cat", "event"); + TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, num_occurrences); // Wrong category. BeginTrace(); TraceLog::GetInstance()->SetWatchEvent("cat", "event"); - TRACE_EVENT_INSTANT0("wrong_cat", "event"); + TRACE_EVENT_INSTANT0("wrong_cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 0); // Wrong name. BeginTrace(); TraceLog::GetInstance()->SetWatchEvent("cat", "event"); - TRACE_EVENT_INSTANT0("cat", "wrong_event"); + TRACE_EVENT_INSTANT0("cat", "wrong_event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 0); @@ -1013,7 +1037,7 @@ TEST_F(TraceEventTestFixture, EventWatchNotification) { BeginTrace(); TraceLog::GetInstance()->SetWatchEvent("cat", "event"); TraceLog::GetInstance()->CancelWatchEvent(); - TRACE_EVENT_INSTANT0("cat", "event"); + TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); EXPECT_EQ(event_watch_notification_, 0); } @@ -1268,20 +1292,20 @@ TEST_F(TraceEventTestFixture, ThreadNameChanges) { BeginTrace(); PlatformThread::SetName(""); - TRACE_EVENT_INSTANT0("drink", "water"); + TRACE_EVENT_INSTANT0("drink", "water", TRACE_EVENT_SCOPE_THREAD); PlatformThread::SetName("cafe"); - TRACE_EVENT_INSTANT0("drink", "coffee"); + TRACE_EVENT_INSTANT0("drink", "coffee", TRACE_EVENT_SCOPE_THREAD); PlatformThread::SetName("shop"); // No event here, so won't appear in combined name. PlatformThread::SetName("pub"); - TRACE_EVENT_INSTANT0("drink", "beer"); - TRACE_EVENT_INSTANT0("drink", "wine"); + TRACE_EVENT_INSTANT0("drink", "beer", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("drink", "wine", TRACE_EVENT_SCOPE_THREAD); PlatformThread::SetName(" bar"); - TRACE_EVENT_INSTANT0("drink", "whisky"); + TRACE_EVENT_INSTANT0("drink", "whisky", TRACE_EVENT_SCOPE_THREAD); EndTraceAndFlush(); @@ -1320,11 +1344,13 @@ TEST_F(TraceEventTestFixture, AtExit) { // so that it will be destroyed when this scope closes. ManualTestSetUp(); - TRACE_EVENT_INSTANT0("all", "not recorded; system not enabled"); + TRACE_EVENT_INSTANT0("all", "not recorded; system not enabled", + TRACE_EVENT_SCOPE_THREAD); BeginTrace(); - TRACE_EVENT_INSTANT0("all", "is recorded 1; system has been enabled"); + TRACE_EVENT_INSTANT0("all", "is recorded 1; system has been enabled", + TRACE_EVENT_SCOPE_THREAD); // Trace calls that will cache pointers to categories; they're valid here TraceCallsWithCachedCategoryPointersPointers( "is recorded 2; system has been enabled"); @@ -1347,12 +1373,14 @@ TEST_F(TraceEventTestFixture, AtExit) { 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_INSTANT0("all", "not recorded; system shutdown", + TRACE_EVENT_SCOPE_THREAD); 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_INSTANT0("new category 1!", "not recorded; system shutdown", + TRACE_EVENT_SCOPE_THREAD); TRACE_EVENT_BEGIN0("new category 2!", "not recorded; system shutdown"); TRACE_EVENT_END0("new category 3!", "not recorded; system shutdown"); @@ -1371,7 +1399,8 @@ TEST_F(TraceEventTestFixture, NormallyNoDeepCopy) { std::string name_string("event name"); BeginTrace(); - TRACE_EVENT_INSTANT0("category", name_string.c_str()); + TRACE_EVENT_INSTANT0("category", name_string.c_str(), + TRACE_EVENT_SCOPE_THREAD); // Modify the string in place (a wholesale reassignment may leave the old // string intact on the heap). @@ -1398,7 +1427,8 @@ TEST_F(TraceEventTestFixture, DeepCopy) { std::string val2("val2"); BeginTrace(); - TRACE_EVENT_COPY_INSTANT0("category", name1.c_str()); + TRACE_EVENT_COPY_INSTANT0("category", name1.c_str(), + TRACE_EVENT_SCOPE_THREAD); TRACE_EVENT_COPY_BEGIN1("category", name2.c_str(), arg1.c_str(), 5); TRACE_EVENT_COPY_END2("category", name3.c_str(), @@ -1462,12 +1492,12 @@ TEST_F(TraceEventTestFixture, TracingIsLazy) { BeginTrace(); int a = 0; - TRACE_EVENT_INSTANT1("category", "test", "a", a++); + TRACE_EVENT_INSTANT1("category", "test", TRACE_EVENT_SCOPE_THREAD, "a", a++); EXPECT_EQ(1, a); TraceLog::GetInstance()->SetDisabled(); - TRACE_EVENT_INSTANT1("category", "test", "a", a++); + TRACE_EVENT_INSTANT1("category", "test", TRACE_EVENT_SCOPE_THREAD, "a", a++); EXPECT_EQ(1, a); EndTraceAndFlush(); @@ -1595,14 +1625,15 @@ class TraceEventCallbackTest : public TraceEventTestFixture { TraceEventCallbackTest* TraceEventCallbackTest::s_instance; TEST_F(TraceEventCallbackTest, TraceEventCallback) { - TRACE_EVENT_INSTANT0("all", "before enable"); + TRACE_EVENT_INSTANT0("all", "before enable", TRACE_EVENT_SCOPE_GLOBAL); TraceLog::GetInstance()->SetEnabled(true, TraceLog::RECORD_UNTIL_FULL); - TRACE_EVENT_INSTANT0("all", "before callback set"); + TRACE_EVENT_INSTANT0("all", "before callback set", TRACE_EVENT_SCOPE_GLOBAL); TraceLog::GetInstance()->SetEventCallback(Callback); - TRACE_EVENT_INSTANT0("all", "event1"); - TRACE_EVENT_INSTANT0("all", "event2"); + TRACE_EVENT_INSTANT0("all", "event1", TRACE_EVENT_SCOPE_GLOBAL); + TRACE_EVENT_INSTANT0("all", "event2", TRACE_EVENT_SCOPE_GLOBAL); TraceLog::GetInstance()->SetEventCallback(NULL); - TRACE_EVENT_INSTANT0("all", "after callback removed"); + TRACE_EVENT_INSTANT0("all", "after callback removed", + TRACE_EVENT_SCOPE_GLOBAL); EXPECT_EQ(2u, collected_events_.size()); EXPECT_EQ("event1", collected_events_[0]); EXPECT_EQ("event2", collected_events_[1]); diff --git a/base/test/trace_event_analyzer_unittest.cc b/base/test/trace_event_analyzer_unittest.cc index 6004341..33cacbf 100644 --- a/base/test/trace_event_analyzer_unittest.cc +++ b/base/test/trace_event_analyzer_unittest.cc @@ -208,10 +208,10 @@ TEST_F(TraceEventAnalyzerTest, BooleanOperators) { BeginTracing(); { - TRACE_EVENT_INSTANT1("cat1", "name1", "num", 1); - TRACE_EVENT_INSTANT1("cat1", "name2", "num", 2); - TRACE_EVENT_INSTANT1("cat2", "name3", "num", 3); - TRACE_EVENT_INSTANT1("cat2", "name4", "num", 4); + TRACE_EVENT_INSTANT1("cat1", "name1", TRACE_EVENT_SCOPE_THREAD, "num", 1); + TRACE_EVENT_INSTANT1("cat1", "name2", TRACE_EVENT_SCOPE_THREAD, "num", 2); + TRACE_EVENT_INSTANT1("cat2", "name3", TRACE_EVENT_SCOPE_THREAD, "num", 3); + TRACE_EVENT_INSTANT1("cat2", "name4", TRACE_EVENT_SCOPE_THREAD, "num", 4); } EndTracing(); @@ -293,11 +293,15 @@ TEST_F(TraceEventAnalyzerTest, ArithmeticOperators) { BeginTracing(); { // These events are searched for: - TRACE_EVENT_INSTANT2("cat1", "math1", "a", 10, "b", 5); - TRACE_EVENT_INSTANT2("cat1", "math2", "a", 10, "b", 10); + TRACE_EVENT_INSTANT2("cat1", "math1", TRACE_EVENT_SCOPE_THREAD, + "a", 10, "b", 5); + TRACE_EVENT_INSTANT2("cat1", "math2", TRACE_EVENT_SCOPE_THREAD, + "a", 10, "b", 10); // Extra events that never match, for noise: - TRACE_EVENT_INSTANT2("noise", "math3", "a", 1, "b", 3); - TRACE_EVENT_INSTANT2("noise", "math4", "c", 10, "d", 5); + TRACE_EVENT_INSTANT2("noise", "math3", TRACE_EVENT_SCOPE_THREAD, + "a", 1, "b", 3); + TRACE_EVENT_INSTANT2("noise", "math4", TRACE_EVENT_SCOPE_THREAD, + "c", 10, "d", 5); } EndTracing(); @@ -349,10 +353,10 @@ TEST_F(TraceEventAnalyzerTest, StringPattern) { BeginTracing(); { - TRACE_EVENT_INSTANT0("cat1", "name1"); - TRACE_EVENT_INSTANT0("cat1", "name2"); - TRACE_EVENT_INSTANT0("cat1", "no match"); - TRACE_EVENT_INSTANT0("cat1", "name3x"); + TRACE_EVENT_INSTANT0("cat1", "name1", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat1", "name2", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat1", "no match", TRACE_EVENT_SCOPE_THREAD); + TRACE_EVENT_INSTANT0("cat1", "name3x", TRACE_EVENT_SCOPE_THREAD); } EndTracing(); @@ -393,7 +397,8 @@ TEST_F(TraceEventAnalyzerTest, Duration) { TRACE_EVENT0("noise", "name2"); // not searched for, just noise { TRACE_EVENT0("cat2", "name3"); // found by duration query - TRACE_EVENT_INSTANT0("noise", "name4"); // not searched for, just noise + // next event not searched for, just noise + TRACE_EVENT_INSTANT0("noise", "name4", TRACE_EVENT_SCOPE_THREAD); base::debug::HighResSleepForTraceTest(kSleepTime); TRACE_EVENT0("cat2", "name5"); // not found (duration too short) } @@ -426,7 +431,7 @@ TEST_F(TraceEventAnalyzerTest, BeginEndAssocations) { { TRACE_EVENT_END0("cat1", "name1"); // does not match out of order begin TRACE_EVENT0("cat1", "name2"); - TRACE_EVENT_INSTANT0("cat1", "name3"); + TRACE_EVENT_INSTANT0("cat1", "name3", TRACE_EVENT_SCOPE_THREAD); TRACE_EVENT_BEGIN0("cat1", "name1"); } EndTracing(); @@ -479,7 +484,7 @@ TEST_F(TraceEventAnalyzerTest, AsyncBeginEndAssocations) { TRACE_EVENT_ASYNC_END0("cat1", "name1", 0xA); // no match / out of order TRACE_EVENT_ASYNC_BEGIN0("cat1", "name1", 0xB); TRACE_EVENT_ASYNC_BEGIN0("cat1", "name1", 0xC); - TRACE_EVENT_INSTANT0("cat1", "name1"); // noise + TRACE_EVENT_INSTANT0("cat1", "name1", TRACE_EVENT_SCOPE_THREAD); // noise TRACE_EVENT0("cat1", "name1"); // noise TRACE_EVENT_ASYNC_END0("cat1", "name1", 0xB); TRACE_EVENT_ASYNC_END0("cat1", "name1", 0xC); @@ -559,12 +564,16 @@ TEST_F(TraceEventAnalyzerTest, CustomAssociations) { // to match up the begin/end pairs. BeginTracing(); { - TRACE_EVENT_INSTANT1("cat1", "end", "id", 1); // no begin match - TRACE_EVENT_INSTANT1("cat2", "begin", "id", 2); // end is cat4 - TRACE_EVENT_INSTANT1("cat3", "begin", "id", 3); // end is cat5 - TRACE_EVENT_INSTANT1("cat4", "end", "id", 2); - TRACE_EVENT_INSTANT1("cat5", "end", "id", 3); - TRACE_EVENT_INSTANT1("cat6", "begin", "id", 1); // no end match + // no begin match + TRACE_EVENT_INSTANT1("cat1", "end", TRACE_EVENT_SCOPE_THREAD, "id", 1); + // end is cat4 + TRACE_EVENT_INSTANT1("cat2", "begin", TRACE_EVENT_SCOPE_THREAD, "id", 2); + // end is cat5 + TRACE_EVENT_INSTANT1("cat3", "begin", TRACE_EVENT_SCOPE_THREAD, "id", 3); + TRACE_EVENT_INSTANT1("cat4", "end", TRACE_EVENT_SCOPE_THREAD, "id", 2); + TRACE_EVENT_INSTANT1("cat5", "end", TRACE_EVENT_SCOPE_THREAD, "id", 3); + // no end match + TRACE_EVENT_INSTANT1("cat6", "begin", TRACE_EVENT_SCOPE_THREAD, "id", 1); } EndTracing(); -- cgit v1.1