Have all trace points emit to ETW.

base/debug/trace_event_win.cc

Index: base/debug/trace_event_win.cc
diff --git a/base/debug/trace_event_win.cc b/base/debug/trace_event_win.cc
index d5a21f49268f3b386a94e6d4d06d1fb57db1faeb..33ac35dc6755a307704b1e9cdd13f1423a1c0ad6 100644
--- a/base/debug/trace_event_win.cc
+++ b/base/debug/trace_event_win.cc
@@ -25,6 +25,8 @@ const GUID kTraceEventClass32 = {
 const GUID kTraceEventClass64 = {
     0x97be602d, 0x2930, 0x4ac3, 0x80, 0x46, 0xb6, 0x76, 0x3b, 0x63, 0x1d, 0xfe};
 
+// Number of fields associated with traced events.
+const int kTraceNumFields = 6 + 2 * kTraceMaxNumArgs;

[chrisha, 2013/09/09 16:41:12]

Where does this magic number come from? Link to documentation, or a more
detailed comment?

[fdoray, 2013/09/09 19:38:59]

Done.

 
 TraceEventETWProvider::TraceEventETWProvider() :
     EtwTraceProvider(kChromeTraceProviderName) {
@@ -40,28 +42,44 @@ bool TraceEventETWProvider::StartTracing() {
   return true;
 }
 
-void TraceEventETWProvider::TraceEvent(const char* name,
+void TraceEventETWProvider::TraceEvent(const char* category_group,
+                                       const char* name,
                                        size_t name_len,
                                        char type,
-                                       const void* id,
-                                       const char* extra,
-                                       size_t extra_len) {
+                                       unsigned long long id,
+                                       const std::string& thread_name,
+                                       int num_args,
+                                       const char** arg_names,
+                                       std::string* arg_values) {
   // Make sure we don't touch NULL.
   if (name == NULL)
     name = "";
-  if (extra == NULL)
-    extra = "";
+  if (category_group == NULL)
+    category_group = "";
 
   EtwEventType etw_type = 0;
   switch (type) {
     case TRACE_EVENT_PHASE_BEGIN:
+    case TRACE_EVENT_PHASE_ASYNC_BEGIN:
+    case TRACE_EVENT_PHASE_FLOW_BEGIN:
+    case TRACE_EVENT_PHASE_CREATE_OBJECT:
       etw_type = kTraceEventTypeBegin;
       break;
     case TRACE_EVENT_PHASE_END:
+    case TRACE_EVENT_PHASE_ASYNC_END:
+    case TRACE_EVENT_PHASE_FLOW_END:
+    case TRACE_EVENT_PHASE_DELETE_OBJECT:
       etw_type = kTraceEventTypeEnd;
       break;
 
     case TRACE_EVENT_PHASE_INSTANT:
+    case TRACE_EVENT_PHASE_INSTANT_OLD:
+    case TRACE_EVENT_PHASE_ASYNC_STEP:
+    case TRACE_EVENT_PHASE_FLOW_STEP:
+    case TRACE_EVENT_PHASE_METADATA:
+    case TRACE_EVENT_PHASE_COUNTER:
+    case TRACE_EVENT_PHASE_SAMPLE:
+    case TRACE_EVENT_PHASE_SNAPSHOT_OBJECT:
       etw_type = kTraceEventTypeInstant;
       break;
 
@@ -71,12 +89,26 @@ void TraceEventETWProvider::TraceEvent(const char* name,
       break;
   }
 
-  EtwMofEvent<5> event(kTraceEventClass32,
-                       etw_type,
-                       TRACE_LEVEL_INFORMATION);
-  event.SetField(0, name_len + 1, name);
-  event.SetField(1, sizeof(id), &id);
-  event.SetField(2, extra_len + 1, extra);
+  EtwMofEvent<kTraceNumFields> event(kTraceEventClass32,
+                                     etw_type,
+                                     TRACE_LEVEL_INFORMATION);
+  int field_index = 0;
+  event.SetField(field_index++, strlen(name) + 1, name);
+  event.SetField(field_index++, sizeof(id), &id);
+  event.SetField(field_index++, strlen(category_group) + 1, category_group);
+  event.SetField(field_index++, thread_name.size() + 1, thread_name.c_str());
+
+  for (int i = 0; i < kTraceMaxNumArgs; ++i) {
+    if (i < num_args) {
+      event.SetField(field_index++, strlen(arg_names[i]) + 1, arg_names[i]);
+      event.SetField(field_index++,
+                     arg_values[i].size() + 1,
+                     arg_values[i].c_str());
+    } else {
+      event.SetField(field_index++, 1, "");
+      event.SetField(field_index++, 1, "");
+    }
+  }

[chrisha, 2013/09/09 16:41:12]

Do we want to have some DCHECK or log message if num_args > kTraceMaxNumArgs?

[fdoray, 2013/09/09 19:38:59]

Done.

 
   // See whether we're to capture a backtrace.
   void* backtrace[32];
@@ -86,8 +118,8 @@ void TraceEventETWProvider::TraceEvent(const char* name,
                                         arraysize(backtrace),
                                         backtrace,
                                         &hash);
-    event.SetField(3, sizeof(depth), &depth);
-    event.SetField(4, sizeof(backtrace[0]) * depth, backtrace);
+    event.SetField(field_index++, sizeof(depth), &depth);
+    event.SetField(field_index++, sizeof(backtrace[0]) * depth, backtrace);
   }
 
   // Trace the event.
@@ -108,7 +140,50 @@ void TraceEventETWProvider::Trace(const char* name,
     if (extra_len == -1)
       extra_len = (extra == NULL) ? 0 : strlen(extra);
 

[fdoray, 2013/09/08 18:35:50]

This method is only used by TRACE_EVENT_*_ETW macros, which are going to
disappear according to crbug.com/81584.

-    provider->TraceEvent(name, name_len, type, id, extra, extra_len);
+    int num_args = 0;
+    const char* arg_names[1];
+    std::string arg_values[1];
+    if (extra_len) {
+      num_args = 1;
+      arg_names[0] = "extra";
+      arg_values[0] = extra;
+    }
+
+    provider->TraceEvent("ETW Macro", name, name_len, type,
+                         reinterpret_cast<unsigned long long>(id),
+                         std::string(), num_args, arg_names, arg_values);
+  }
+}
+
+void TraceEventETWProvider::TraceWithArgs(
+    const char* category_group,
+    const char* name,
+    char type,
+    unsigned long long id,

[fdoray, 2013/09/08 18:35:50]

This method is called from TraceLog::AddTraceEventWithThreadIdAndTimestamp,
where the type of |id| is unsigned long long. 

|id| cannot easily be truncated to void*:

id of MessageLoop::PostTask events -> MSB=task id unique in the pool,
LSB=pointer to the pool
id of IPC events -> MSB=0x0, LSB=unique id

I chose to output the 64 bits id to make sure that I wouldn't end up with
duplicated ids (as I did with my previous patch).

What do you think? Should I try to create a 32 bits id by adding the MSB and
LSB? Or can I keep the 64 bits id?

[chrisha, 2013/09/09 16:41:12]

The 64-bit ID seems fine, as long as we're consistent with it everywhere. Having
a mix of different ID sizes is what was confusing me originally.

+    const std::string& thread_name,
+    int num_args,
+    const char** arg_names,
+    const unsigned char* arg_types,
+    const unsigned long long* arg_values,
+    scoped_ptr<ConvertableToTraceFormat> convertable_values[]) {
+  TraceEventETWProvider* provider = TraceEventETWProvider::GetInstance();
+  if (provider && provider->IsTracing()) {
+    // Convert argument values to strings.
+    std::string arg_str_values[kTraceMaxNumArgs];
+    for (int i = 0; i < num_args; ++i) {
+      if (arg_types[i] == TRACE_VALUE_TYPE_CONVERTABLE) {
+        convertable_values[i]->AppendAsTraceFormat(&arg_str_values[i]);
+      } else {
+        base::debug::TraceEvent::TraceValue value;
+        value.as_uint = arg_values[i];
+        base::debug::TraceEvent::AppendValueAsJSON(arg_types[i],
+                                                   value,
+                                                   &arg_str_values[i]);
+      }
+    }
+
+    provider->TraceEvent(category_group, name, strlen(name), type, id,
+                         thread_name, num_args, arg_names, arg_str_values);
   }
 }