summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--base/debug/trace_event.h16
-rw-r--r--base/debug/trace_event_impl.cc45
-rw-r--r--base/debug/trace_event_impl.h28
-rw-r--r--base/debug/trace_event_internal.h163
-rw-r--r--base/debug/trace_event_unittest.cc121
5 files changed, 295 insertions, 78 deletions
diff --git a/base/debug/trace_event.h b/base/debug/trace_event.h
index d173282..3459a94 100644
--- a/base/debug/trace_event.h
+++ b/base/debug/trace_event.h
@@ -44,6 +44,22 @@
#define TRACE_EVENT_API_ADD_TRACE_EVENT \
base::debug::TraceLog::GetInstance()->AddTraceEvent
+// Add a trace event to the platform tracing system.
+// void TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_TIMESTAMP(
+// char phase,
+// const unsigned char* category_enabled,
+// const char* name,
+// unsigned long long id,
+// int thread_id,
+// const TimeTicks& timestamp,
+// int num_args,
+// const char** arg_names,
+// const unsigned char* arg_types,
+// const unsigned long long* arg_values,
+// unsigned char flags)
+#define TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP \
+ base::debug::TraceLog::GetInstance()->AddTraceEventWithThreadIdAndTimestamp
+
// Defines atomic operations used internally by the tracing system.
#define TRACE_EVENT_API_ATOMIC_WORD base::subtle::AtomicWord
#define TRACE_EVENT_API_ATOMIC_LOAD(var) base::subtle::NoBarrier_Load(&(var))
diff --git a/base/debug/trace_event_impl.cc b/base/debug/trace_event_impl.cc
index 69e9c600..3c770c3 100644
--- a/base/debug/trace_event_impl.cc
+++ b/base/debug/trace_event_impl.cc
@@ -20,6 +20,7 @@
#include "base/sys_info.h"
#include "base/third_party/dynamic_annotations/dynamic_annotations.h"
#include "base/threading/platform_thread.h"
+#include "base/threading/thread_id_name_manager.h"
#include "base/threading/thread_local.h"
#include "base/time.h"
#include "base/utf_string_conversions.h"
@@ -623,14 +624,33 @@ void TraceLog::Flush(const TraceLog::OutputCallback& cb) {
}
void TraceLog::AddTraceEvent(char phase,
- const unsigned char* category_enabled,
- const char* name,
- unsigned long long id,
- int num_args,
- const char** arg_names,
- const unsigned char* arg_types,
- const unsigned long long* arg_values,
- unsigned char flags) {
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ int num_args,
+ const char** arg_names,
+ const unsigned char* arg_types,
+ const unsigned long long* arg_values,
+ unsigned char flags) {
+ int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
+ base::TimeTicks now = base::TimeTicks::NowFromSystemTraceTime();
+ AddTraceEventWithThreadIdAndTimestamp(phase, category_enabled, name, id,
+ thread_id, now, num_args, arg_names,
+ arg_types, arg_values, flags);
+}
+
+void TraceLog::AddTraceEventWithThreadIdAndTimestamp(
+ char phase,
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ int thread_id,
+ const TimeTicks& timestamp,
+ int num_args,
+ const char** arg_names,
+ const unsigned char* arg_types,
+ const unsigned long long* arg_values,
+ unsigned char flags) {
DCHECK(name);
#if defined(OS_ANDROID)
@@ -638,8 +658,9 @@ void TraceLog::AddTraceEvent(char phase,
num_args, arg_names, arg_types, arg_values);
#endif
- TimeTicks now = TimeTicks::NowFromSystemTraceTime() - time_offset_;
+ TimeTicks now = timestamp - time_offset_;
NotificationHelper notifier(this);
+
{
AutoLock lock(lock_);
if (*category_enabled != CATEGORY_ENABLED)
@@ -647,9 +668,8 @@ void TraceLog::AddTraceEvent(char phase,
if (logged_events_.size() >= kTraceEventBufferSize)
return;
- int thread_id = static_cast<int>(PlatformThread::CurrentId());
-
- const char* new_name = PlatformThread::GetName();
+ const char* new_name = ThreadIdNameManager::GetInstance()->
+ GetName(thread_id);
// Check if the thread name has been set or changed since the previous
// call (if any), but don't bother if the new name is empty. Note this will
// not detect a thread name change within the same char* buffer address: we
@@ -657,6 +677,7 @@ void TraceLog::AddTraceEvent(char phase,
if (new_name != g_current_thread_name.Get().Get() &&
new_name && *new_name) {
g_current_thread_name.Get().Set(new_name);
+
hash_map<int, std::string>::iterator existing_name =
thread_names_.find(thread_id);
if (existing_name == thread_names_.end()) {
diff --git a/base/debug/trace_event_impl.h b/base/debug/trace_event_impl.h
index 7e306e2..f152b0a4 100644
--- a/base/debug/trace_event_impl.h
+++ b/base/debug/trace_event_impl.h
@@ -258,14 +258,26 @@ class BASE_EXPORT TraceLog {
// If |copy| is set, |name|, |arg_name1| and |arg_name2| will be deep copied
// into the event; see "Memory scoping note" and TRACE_EVENT_COPY_XXX above.
void AddTraceEvent(char phase,
- const unsigned char* category_enabled,
- const char* name,
- unsigned long long id,
- int num_args,
- const char** arg_names,
- const unsigned char* arg_types,
- const unsigned long long* arg_values,
- unsigned char flags);
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ int num_args,
+ const char** arg_names,
+ const unsigned char* arg_types,
+ const unsigned long long* arg_values,
+ unsigned char flags);
+ void AddTraceEventWithThreadIdAndTimestamp(
+ char phase,
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ int thread_id,
+ const TimeTicks& timestamp,
+ int num_args,
+ const char** arg_names,
+ const unsigned char* arg_types,
+ const unsigned long long* arg_values,
+ unsigned char flags);
static void AddTraceEventEtw(char phase,
const char* name,
const void* id,
diff --git a/base/debug/trace_event_internal.h b/base/debug/trace_event_internal.h
index 9622411..7cd56d0 100644
--- a/base/debug/trace_event_internal.h
+++ b/base/debug/trace_event_internal.h
@@ -261,6 +261,23 @@
category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val, \
arg2_name, arg2_val)
+// Similar to TRACE_EVENT_BEGINx but with a custom |at| timestamp provided.
+// - |id| is used to match the _BEGIN event with the _END event.
+// Events are considered to match if their category, name and id values all
+// match. |id| must either be a pointer or an integer value up to 64 bits. If
+// it's a pointer, the bits will be xored with a hash of the process ID so
+// that the same pointer on two different processes will not collide.
+#define TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0(category, \
+ name, id, thread_id, timestamp) \
+ INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
+ TRACE_EVENT_PHASE_ASYNC_BEGIN, category, name, id, thread_id, \
+ timestamp, TRACE_EVENT_FLAG_NONE)
+#define TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0( \
+ category, name, id, thread_id, timestamp) \
+ INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
+ TRACE_EVENT_PHASE_ASYNC_BEGIN, category, name, id, thread_id, \
+ timestamp, TRACE_EVENT_FLAG_COPY)
+
// 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
@@ -288,6 +305,23 @@
category, name, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val, \
arg2_name, arg2_val)
+// Similar to TRACE_EVENT_ENDx but with a custom |at| timestamp provided.
+// - |id| is used to match the _BEGIN event with the _END event.
+// Events are considered to match if their category, name and id values all
+// match. |id| must either be a pointer or an integer value up to 64 bits. If
+// it's a pointer, the bits will be xored with a hash of the process ID so
+// that the same pointer on two different processes will not collide.
+#define TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0(category, \
+ name, id, thread_id, timestamp) \
+ INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
+ TRACE_EVENT_PHASE_ASYNC_END, category, name, id, thread_id, timestamp, \
+ TRACE_EVENT_FLAG_NONE)
+#define TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0( \
+ category, name, id, thread_id, timestamp) \
+ INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
+ TRACE_EVENT_PHASE_ASYNC_END, category, name, id, thread_id, timestamp, \
+ TRACE_EVENT_FLAG_COPY)
+
// Records the value of a counter called "name" immediately. Value
// must be representable as a 32 bit integer.
// - category and name strings must have application lifetime (statics or
@@ -540,7 +574,6 @@
category, name, id, TRACE_EVENT_FLAG_COPY, \
arg1_name, arg1_val, arg2_name, arg2_val)
-
// 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.
@@ -614,6 +647,24 @@
} \
} while (0)
+// Implementation detail: internal macro to create static category and add
+// event if the category is enabled.
+#define INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP(phase, category, \
+ name, id, thread_id, timestamp, flags, ...) \
+ do { \
+ INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \
+ if (*INTERNAL_TRACE_EVENT_UID(catstatic)) { \
+ unsigned char trace_event_flags = flags | TRACE_EVENT_FLAG_HAS_ID; \
+ trace_event_internal::TraceID trace_event_trace_id( \
+ id, &trace_event_flags); \
+ trace_event_internal::AddTraceEventWithThreadIdAndTimestamp( \
+ phase, INTERNAL_TRACE_EVENT_UID(catstatic), \
+ name, trace_event_trace_id.data(), \
+ thread_id, TimeTicks::FromInternalValue(timestamp), \
+ trace_event_flags, ##__VA_ARGS__); \
+ } \
+ } while (0)
+
// Notes regarding the following definitions:
// New values can be added and propagated to third party libraries, but existing
// definitions must never be changed, because third party libraries may use old
@@ -793,39 +844,92 @@ static inline void SetTraceValue(const std::string& arg,
*value = type_value.as_uint;
}
-// These AddTraceEvent template functions are defined here instead of in the
-// macro, because the arg_values could be temporary objects, such as
-// std::string. In order to store pointers to the internal c_str and pass
-// through to the tracing API, the arg_values must live throughout
-// these procedures.
+// These AddTraceEvent and AddTraceEventWithThreadIdAndTimestamp template
+// functions are defined here instead of in the macro, because the arg_values
+// could be temporary objects, such as std::string. In order to store
+// pointers to the internal c_str and pass through to the tracing API,
+// the arg_values must live throughout these procedures.
+
+static inline void AddTraceEventWithThreadIdAndTimestamp(char phase,
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ int thread_id,
+ const base::TimeTicks& timestamp,
+ unsigned char flags) {
+ TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
+ phase, category_enabled, name, id, thread_id, timestamp,
+ kZeroNumArgs, NULL, NULL, NULL, flags);
+}
static inline void AddTraceEvent(char phase,
- const unsigned char* category_enabled,
- const char* name,
- unsigned long long id,
- unsigned char flags) {
- TRACE_EVENT_API_ADD_TRACE_EVENT(
- phase, category_enabled, name, id,
- kZeroNumArgs, NULL, NULL, NULL, flags);
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ unsigned char flags) {
+ int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
+ base::TimeTicks now = base::TimeTicks::NowFromSystemTraceTime();
+ AddTraceEventWithThreadIdAndTimestamp(phase, category_enabled, name, id,
+ thread_id, now, flags);
}
template<class ARG1_TYPE>
-static inline void AddTraceEvent(char phase,
- const unsigned char* category_enabled,
- const char* name,
- unsigned long long id,
- unsigned char flags,
- const char* arg1_name,
- const ARG1_TYPE& arg1_val) {
+static inline void AddTraceEventWithThreadIdAndTimestamp(char phase,
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ int thread_id,
+ const base::TimeTicks& timestamp,
+ unsigned char flags,
+ const char* arg1_name,
+ const ARG1_TYPE& arg1_val) {
const int num_args = 1;
unsigned char arg_types[1];
unsigned long long arg_values[1];
SetTraceValue(arg1_val, &arg_types[0], &arg_values[0]);
- TRACE_EVENT_API_ADD_TRACE_EVENT(
- phase, category_enabled, name, id,
+ TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
+ phase, category_enabled, name, id, thread_id, timestamp,
num_args, &arg1_name, arg_types, arg_values, flags);
}
+template<class ARG1_TYPE>
+static inline void AddTraceEvent(char phase,
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ unsigned char flags,
+ const char* arg1_name,
+ const ARG1_TYPE& arg1_val) {
+ int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
+ base::TimeTicks now = base::TimeTicks::NowFromSystemTraceTime();
+ AddTraceEventWithThreadIdAndTimestamp(phase, category_enabled, name, id,
+ thread_id, now, flags, arg1_name,
+ arg1_val);
+}
+
+template<class ARG1_TYPE, class ARG2_TYPE>
+static inline void AddTraceEventWithThreadIdAndTimestamp(char phase,
+ const unsigned char* category_enabled,
+ const char* name,
+ unsigned long long id,
+ int thread_id,
+ const base::TimeTicks& timestamp,
+ unsigned char flags,
+ const char* arg1_name,
+ const ARG1_TYPE& arg1_val,
+ const char* arg2_name,
+ const ARG2_TYPE& arg2_val) {
+ const int num_args = 2;
+ const char* arg_names[2] = { arg1_name, arg2_name };
+ unsigned char arg_types[2];
+ unsigned long long arg_values[2];
+ SetTraceValue(arg1_val, &arg_types[0], &arg_values[0]);
+ SetTraceValue(arg2_val, &arg_types[1], &arg_values[1]);
+ TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
+ phase, category_enabled, name, id, thread_id, timestamp,
+ num_args, arg_names, arg_types, arg_values, flags);
+}
+
template<class ARG1_TYPE, class ARG2_TYPE>
static inline void AddTraceEvent(char phase,
const unsigned char* category_enabled,
@@ -836,15 +940,11 @@ static inline void AddTraceEvent(char phase,
const ARG1_TYPE& arg1_val,
const char* arg2_name,
const ARG2_TYPE& arg2_val) {
- const int num_args = 2;
- const char* arg_names[2] = { arg1_name, arg2_name };
- unsigned char arg_types[2];
- unsigned long long arg_values[2];
- SetTraceValue(arg1_val, &arg_types[0], &arg_values[0]);
- SetTraceValue(arg2_val, &arg_types[1], &arg_values[1]);
- TRACE_EVENT_API_ADD_TRACE_EVENT(
- phase, category_enabled, name, id,
- num_args, arg_names, arg_types, arg_values, flags);
+ int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
+ base::TimeTicks now = base::TimeTicks::NowFromSystemTraceTime();
+ AddTraceEventWithThreadIdAndTimestamp(phase, category_enabled, name, id,
+ thread_id, now, flags, arg1_name,
+ arg1_val, arg2_name, arg2_val);
}
// Used by TRACE_EVENTx macro. Do not use directly.
@@ -864,7 +964,6 @@ class TRACE_EVENT_API_CLASS_EXPORT TraceEndOnScopeClose {
p_data_ = &data_;
}
-
private:
// Add the end event if the category is still enabled.
void AddEventIfEnabled() {
diff --git a/base/debug/trace_event_unittest.cc b/base/debug/trace_event_unittest.cc
index c42cc5d..15e11a7 100644
--- a/base/debug/trace_event_unittest.cc
+++ b/base/debug/trace_event_unittest.cc
@@ -4,6 +4,8 @@
#include "base/debug/trace_event_unittest.h"
+#include <cstdlib>
+
#include "base/bind.h"
#include "base/command_line.h"
#include "base/debug/trace_event.h"
@@ -39,6 +41,10 @@ struct JsonKeyValue {
CompareOp op;
};
+static int kThreadId = 42;
+static int kAsyncId = 5;
+static const char kAsyncIdStr[] = "5";
+
class TraceEventTestFixture : public testing::Test {
public:
// This fixture does not use SetUp() because the fixture must be manually set
@@ -337,10 +343,10 @@ void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) {
"name1", "value1",
"name2", "value2");
- TRACE_EVENT_ASYNC_BEGIN0("all", "TRACE_EVENT_ASYNC_BEGIN0 call", 5);
- TRACE_EVENT_ASYNC_BEGIN1("all", "TRACE_EVENT_ASYNC_BEGIN1 call", 5,
+ TRACE_EVENT_ASYNC_BEGIN0("all", "TRACE_EVENT_ASYNC_BEGIN0 call", kAsyncId);
+ TRACE_EVENT_ASYNC_BEGIN1("all", "TRACE_EVENT_ASYNC_BEGIN1 call", kAsyncId,
"name1", "value1");
- TRACE_EVENT_ASYNC_BEGIN2("all", "TRACE_EVENT_ASYNC_BEGIN2 call", 5,
+ TRACE_EVENT_ASYNC_BEGIN2("all", "TRACE_EVENT_ASYNC_BEGIN2 call", kAsyncId,
"name1", "value1",
"name2", "value2");
@@ -349,19 +355,19 @@ void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) {
TRACE_EVENT_ASYNC_STEP1("all", "TRACE_EVENT_ASYNC_STEP1 call",
5, "step2", "name1", "value1");
- TRACE_EVENT_ASYNC_END0("all", "TRACE_EVENT_ASYNC_END0 call", 5);
- TRACE_EVENT_ASYNC_END1("all", "TRACE_EVENT_ASYNC_END1 call", 5,
+ TRACE_EVENT_ASYNC_END0("all", "TRACE_EVENT_ASYNC_END0 call", kAsyncId);
+ TRACE_EVENT_ASYNC_END1("all", "TRACE_EVENT_ASYNC_END1 call", kAsyncId,
"name1", "value1");
- TRACE_EVENT_ASYNC_END2("all", "TRACE_EVENT_ASYNC_END2 call", 5,
+ TRACE_EVENT_ASYNC_END2("all", "TRACE_EVENT_ASYNC_END2 call", kAsyncId,
"name1", "value1",
"name2", "value2");
- TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW0 call", 5, NULL);
- TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW1 call", 5, "value");
- TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW0 call", 5, NULL);
- TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW1 call", 5, "value");
- TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW0 call", 5, NULL);
- TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW1 call", 5, "value");
+ TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW0 call", kAsyncId, NULL);
+ TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW1 call", kAsyncId, "value");
+ TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW0 call", kAsyncId, NULL);
+ TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW1 call", kAsyncId, "value");
+ TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW0 call", kAsyncId, NULL);
+ TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW1 call", kAsyncId, "value");
TRACE_COUNTER1("all", "TRACE_COUNTER1 call", 31415);
TRACE_COUNTER2("all", "TRACE_COUNTER2 call",
@@ -371,6 +377,21 @@ void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) {
TRACE_COUNTER_ID1("all", "TRACE_COUNTER_ID1 call", 0x319009, 31415);
TRACE_COUNTER_ID2("all", "TRACE_COUNTER_ID2 call", 0x319009,
"a", 30000, "b", 1415);
+
+ TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0("all",
+ "TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call",
+ kAsyncId, kThreadId, 12345);
+ TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0("all",
+ "TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0 call",
+ kAsyncId, kThreadId, 23456);
+
+ TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0("all",
+ "TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call",
+ kAsyncId + 1, kThreadId, 34567);
+ TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0("all",
+ "TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0 call",
+ kAsyncId + 1, kThreadId, 45678);
+
} // Scope close causes TRACE_EVENT0 etc to send their END events.
if (task_complete_event)
@@ -451,15 +472,15 @@ void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) {
EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN0 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN1 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("name1");
EXPECT_SUB_FIND_("value1");
EXPECT_FIND_("TRACE_EVENT_ASYNC_BEGIN2 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("name1");
EXPECT_SUB_FIND_("value1");
EXPECT_SUB_FIND_("name2");
@@ -467,26 +488,26 @@ void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) {
EXPECT_FIND_("TRACE_EVENT_ASYNC_STEP0 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("step1");
EXPECT_FIND_("TRACE_EVENT_ASYNC_STEP1 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("step2");
EXPECT_SUB_FIND_("name1");
EXPECT_SUB_FIND_("value1");
EXPECT_FIND_("TRACE_EVENT_ASYNC_END0 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_FIND_("TRACE_EVENT_ASYNC_END1 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("name1");
EXPECT_SUB_FIND_("value1");
EXPECT_FIND_("TRACE_EVENT_ASYNC_END2 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("name1");
EXPECT_SUB_FIND_("value1");
EXPECT_SUB_FIND_("name2");
@@ -494,32 +515,32 @@ void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) {
EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW0 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("extra");
EXPECT_SUB_FIND_("NULL");
EXPECT_FIND_("TRACE_EVENT_BEGIN_ETW1 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("extra");
EXPECT_SUB_FIND_("value");
EXPECT_FIND_("TRACE_EVENT_END_ETW0 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("extra");
EXPECT_SUB_FIND_("NULL");
EXPECT_FIND_("TRACE_EVENT_END_ETW1 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("extra");
EXPECT_SUB_FIND_("value");
EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW0 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("extra");
EXPECT_SUB_FIND_("NULL");
EXPECT_FIND_("TRACE_EVENT_INSTANT_ETW1 call");
EXPECT_SUB_FIND_("id");
- EXPECT_SUB_FIND_("5");
+ EXPECT_SUB_FIND_(kAsyncIdStr);
EXPECT_SUB_FIND_("extra");
EXPECT_SUB_FIND_("value");
@@ -580,6 +601,54 @@ void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) {
EXPECT_TRUE((item && item->GetInteger("args.b", &value)));
EXPECT_EQ(1415, value);
}
+
+ EXPECT_FIND_("TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call");
+ {
+ int val;
+ EXPECT_TRUE((item && item->GetInteger("ts", &val)));
+ EXPECT_EQ(12345, val);
+ EXPECT_TRUE((item && item->GetInteger("tid", &val)));
+ EXPECT_EQ(kThreadId, val);
+ std::string id;
+ EXPECT_TRUE((item && item->GetString("id", &id)));
+ EXPECT_EQ(kAsyncId, atoi(id.c_str()));
+ }
+
+ EXPECT_FIND_("TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0 call");
+ {
+ int val;
+ EXPECT_TRUE((item && item->GetInteger("ts", &val)));
+ EXPECT_EQ(23456, val);
+ EXPECT_TRUE((item && item->GetInteger("tid", &val)));
+ EXPECT_EQ(kThreadId, val);
+ std::string id;
+ EXPECT_TRUE((item && item->GetString("id", &id)));
+ EXPECT_EQ(kAsyncId, atoi(id.c_str()));
+ }
+
+ EXPECT_FIND_("TRACE_EVENT_BEGIN_WITH_ID_TID_AND_TIMESTAMP0 call");
+ {
+ int val;
+ EXPECT_TRUE((item && item->GetInteger("ts", &val)));
+ EXPECT_EQ(34567, val);
+ EXPECT_TRUE((item && item->GetInteger("tid", &val)));
+ EXPECT_EQ(kThreadId, val);
+ std::string id;
+ EXPECT_TRUE((item && item->GetString("id", &id)));
+ EXPECT_EQ(kAsyncId + 1, atoi(id.c_str()));
+ }
+
+ EXPECT_FIND_("TRACE_EVENT_END_WITH_ID_TID_AND_TIMESTAMP0 call");
+ {
+ int val;
+ EXPECT_TRUE((item && item->GetInteger("ts", &val)));
+ EXPECT_EQ(45678, val);
+ EXPECT_TRUE((item && item->GetInteger("tid", &val)));
+ EXPECT_EQ(kThreadId, val);
+ std::string id;
+ EXPECT_TRUE((item && item->GetString("id", &id)));
+ EXPECT_EQ(kAsyncId + 1, atoi(id.c_str()));
+ }
}
void TraceManyInstantEvents(int thread_id, int num_events,