Implement a new flow event API that allows binding flow events and regular events.

base/trace_event/trace_event_impl.cc

 // Copyright (c) 2012 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/trace_event/trace_event_impl.h"
 
 #include <algorithm>
 #include <cmath>
 
 #include "base/base_switches.h"
@@ skipping 390 matching lines @@
                              const char* metadata_name, const char* arg_name,
                              const T& value) {
   if (!trace_event)
     return;
 
   int num_args = 1;
   unsigned char arg_type;
   unsigned long long arg_value;
   ::trace_event_internal::SetTraceValue(value, &arg_type, &arg_value);
   trace_event->Initialize(
-      thread_id, TraceTicks(), ThreadTicks(), TRACE_EVENT_PHASE_METADATA,
-      &g_category_group_enabled[g_category_metadata], metadata_name,
-      trace_event_internal::kNoId, trace_event_internal::kNoId, num_args,
-      &arg_name, &arg_type, &arg_value, NULL, TRACE_EVENT_FLAG_NONE);
+      thread_id,
+      TraceTicks(),
+      ThreadTicks(),
+      TRACE_EVENT_PHASE_METADATA,
+      &g_category_group_enabled[g_category_metadata],
+      metadata_name,
+      trace_event_internal::kNoId,

[vmpstr, 2015/07/21 18:03:41]

nit: Can you put some inline comments with what the var is, something along the
lines of:

...,
trace_event_internal::kNoId, // id
trace_event_internal::kNoId, // context_id
trace_event_internal::kNoId, // bind_id

Same comment for the nulls below

+      trace_event_internal::kNoId,
+      trace_event_internal::kNoId,
+      num_args,
+      &arg_name,
+      &arg_type,
+      &arg_value,
+      NULL,
+      TRACE_EVENT_FLAG_NONE);
 }
 
 class AutoThreadLocalBoolean {
  public:
   explicit AutoThreadLocalBoolean(ThreadLocalBoolean* thread_local_boolean)
       : thread_local_boolean_(thread_local_boolean) {
     DCHECK(!thread_local_boolean_->Get());
     thread_local_boolean_->Set(true);
   }
   ~AutoThreadLocalBoolean() {
@@ skipping 160 matching lines @@
 
 void TraceEvent::Initialize(
     int thread_id,
     TraceTicks timestamp,
     ThreadTicks thread_timestamp,
     char phase,
     const unsigned char* category_group_enabled,
     const char* name,
     unsigned long long id,
     unsigned long long context_id,
+    unsigned long long bind_id,
     int num_args,
     const char** arg_names,
     const unsigned char* arg_types,
     const unsigned long long* arg_values,
     const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
     unsigned int flags) {
   timestamp_ = timestamp;
   thread_timestamp_ = thread_timestamp;
   duration_ = TimeDelta::FromInternalValue(-1);
   id_ = id;
   context_id_ = context_id;
   category_group_enabled_ = category_group_enabled;
   name_ = name;
   thread_id_ = thread_id;
   phase_ = phase;
   flags_ = flags;
+  bind_id_ = bind_id;
 
   // Clamp num_args since it may have been set by a third_party library.
   num_args = (num_args > kTraceMaxNumArgs) ? kTraceMaxNumArgs : num_args;
   int i = 0;
   for (; i < num_args; ++i) {
     arg_names_[i] = arg_names[i];
     arg_types_[i] = arg_types[i];
 
     if (arg_types[i] == TRACE_VALUE_TYPE_CONVERTABLE)
       convertable_values_[i] = convertable_values[i];
@@ skipping 221 matching lines @@
   }
 
   // If id_ is set, print it out as a hex string so we don't loose any
   // bits (it might be a 64-bit pointer).
   if (flags_ & TRACE_EVENT_FLAG_HAS_ID)
     StringAppendF(out, ",\"id\":\"0x%" PRIx64 "\"", static_cast<uint64>(id_));
 
   if (flags_ & TRACE_EVENT_FLAG_BIND_TO_ENCLOSING)
     StringAppendF(out, ",\"bp\":\"e\"");
 
+  if ((flags_ & TRACE_EVENT_FLAG_FLOW_OUT) ||
+      (flags_ & TRACE_EVENT_FLAG_FLOW_IN))
+    StringAppendF(out, ",\"bind_id\":\"0x%" PRIx64 "\"",

[vmpstr, 2015/07/21 18:03:41]

nit: can you put braces around the if (usually we do that for multi-line
statement, or maybe it's just me)

+                  static_cast<uint64>(bind_id_));
+
+  if (flags_ & TRACE_EVENT_FLAG_FLOW_IN)
+    StringAppendF(out, ",\"flow_in\":true");
+
+  if (flags_ & TRACE_EVENT_FLAG_FLOW_OUT)
+    StringAppendF(out, ",\"flow_out\":true");
+
   // Similar to id_, print the context_id as hex if present.
   if (flags_ & TRACE_EVENT_FLAG_HAS_CONTEXT_ID)
     StringAppendF(out, ",\"cid\":\"0x%" PRIx64 "\"",
                   static_cast<uint64>(context_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:
@@ skipping 345 matching lines @@
   CheckThisIsCurrentBuffer();
 
   event_count_++;
   ThreadTicks thread_now = ThreadNow();
   TraceTicks now = trace_log_->OffsetNow();
   TimeDelta overhead = now - event_timestamp;
   if (overhead.InMicroseconds() >= kOverheadReportThresholdInMicroseconds) {
     TraceEvent* trace_event = AddTraceEvent(NULL);
     if (trace_event) {
       trace_event->Initialize(
-          static_cast<int>(PlatformThread::CurrentId()), event_timestamp,
-          event_thread_timestamp, TRACE_EVENT_PHASE_COMPLETE,
+          static_cast<int>(PlatformThread::CurrentId()),
+          event_timestamp,
+          event_thread_timestamp,
+          TRACE_EVENT_PHASE_COMPLETE,
           &g_category_group_enabled[g_category_trace_event_overhead],
-          "overhead", ::trace_event_internal::kNoId,
-          ::trace_event_internal::kNoId, ::trace_event_internal::kZeroNumArgs,
-          NULL, NULL, NULL, NULL, 0);
+          "overhead",
+          trace_event_internal::kNoId,
+          trace_event_internal::kNoId,
+          trace_event_internal::kNoId,
+          trace_event_internal::kZeroNumArgs,
+          NULL,
+          NULL,
+          NULL,
+          NULL,

[vmpstr, 2015/07/21 18:03:41]

nit: For the functions that you're updating, can you also change NULL to
nullptr, while in the area?

+          TRACE_EVENT_FLAG_NONE);
       trace_event->UpdateDuration(now, thread_now);
     }
   }
   overhead_ += overhead;
 }
 
 void TraceLog::ThreadLocalEventBuffer::WillDestroyCurrentMessageLoop() {
   delete this;
 }
 
@@ skipping 778 matching lines @@
     unsigned long long id,
     int num_args,
     const char** arg_names,
     const unsigned char* arg_types,
     const unsigned long long* arg_values,
     const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
     unsigned int flags) {
   int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
   base::TraceTicks now = base::TraceTicks::Now();
   return AddTraceEventWithThreadIdAndTimestamp(
-      phase, category_group_enabled, name, id, ::trace_event_internal::kNoId,
-      thread_id, now, num_args, arg_names, arg_types, arg_values,
-      convertable_values, flags);
+      phase,
+      category_group_enabled,
+      name,
+      id,
+      trace_event_internal::kNoId,
+      trace_event_internal::kNoId,
+      thread_id,
+      now,
+      num_args,
+      arg_names,
+      arg_types,
+      arg_values,
+      convertable_values,
+      flags);
 }
 
 TraceEventHandle TraceLog::AddTraceEventWithContextId(
     char phase,
     const unsigned char* category_group_enabled,
     const char* name,
     unsigned long long id,
     unsigned long long context_id,
     int num_args,
     const char** arg_names,
     const unsigned char* arg_types,
     const unsigned long long* arg_values,
     const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
     unsigned int flags) {
   int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
   base::TraceTicks now = base::TraceTicks::Now();
   return AddTraceEventWithThreadIdAndTimestamp(
-      phase, category_group_enabled, name, id, context_id, thread_id, now,
-      num_args, arg_names, arg_types, arg_values, convertable_values,
+      phase,
+      category_group_enabled,
+      name,
+      id,
+      context_id,
+      trace_event_internal::kNoId,
+      thread_id,
+      now,
+      num_args,
+      arg_names,
+      arg_types,
+      arg_values,
+      convertable_values,
       flags | TRACE_EVENT_FLAG_HAS_CONTEXT_ID);
 }
 
+// Handle legacy calls to AddTraceEventWithThreadIdAndTimestamp
+// with kNoId as bind_id
+TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp(
+    char phase,
+    const unsigned char* category_group_enabled,
+    const char* name,
+    unsigned long long id,
+    int thread_id,
+    const TraceTicks& timestamp,
+    int num_args,
+    const char** arg_names,
+    const unsigned char* arg_types,
+    const unsigned long long* arg_values,
+    const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
+    unsigned int flags) {
+  return AddTraceEventWithThreadIdAndTimestamp(
+      phase,
+      category_group_enabled,
+      name,
+      id,
+      trace_event_internal::kNoId,
+      trace_event_internal::kNoId,
+      thread_id,
+      timestamp,
+      num_args,
+      arg_names,
+      arg_types,
+      arg_values,
+      convertable_values,
+      flags);
+}
+
 TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp(
     char phase,
     const unsigned char* category_group_enabled,
     const char* name,
     unsigned long long id,
     unsigned long long context_id,
+    unsigned long long bind_id,
     int thread_id,
     const TraceTicks& timestamp,
     int num_args,
     const char** arg_names,
     const unsigned char* arg_types,
     const unsigned long long* arg_values,
     const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
     unsigned int flags) {
   TraceEventHandle handle = { 0, 0, 0 };
   if (!*category_group_enabled)
     return handle;
 
   // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when
   // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) ->
   // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ...
   if (thread_is_in_trace_event_.Get())
     return handle;
 
   AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_);
 
   DCHECK(name);
   DCHECK(!timestamp.is_null());
 
-  if (flags & TRACE_EVENT_FLAG_MANGLE_ID)
+  if (flags & TRACE_EVENT_FLAG_MANGLE_ID) {
+    if ((flags & TRACE_EVENT_FLAG_FLOW_IN) ||
+        (flags & TRACE_EVENT_FLAG_FLOW_OUT))
+      bind_id = MangleEventId(bind_id);
     id = MangleEventId(id);
+  }
 
   TraceTicks offset_event_timestamp = OffsetTimestamp(timestamp);
   TraceTicks now = flags & TRACE_EVENT_FLAG_EXPLICIT_TIMESTAMP ?
       OffsetNow() : offset_event_timestamp;
   ThreadTicks thread_now = ThreadNow();
 
   // |thread_local_event_buffer_| can be null if the current thread doesn't have
   // a message loop or the message loop is blocked.
   InitializeThreadLocalEventBufferIfSupported();
   auto thread_local_event_buffer = thread_local_event_buffer_.Get();
@@ skipping 53 matching lines @@
 
     TraceEvent* trace_event = NULL;
     if (thread_local_event_buffer) {
       trace_event = thread_local_event_buffer->AddTraceEvent(&handle);
     } else {
       lock.EnsureAcquired();
       trace_event = AddEventToThreadSharedChunkWhileLocked(&handle, true);
     }
 
     if (trace_event) {
-      trace_event->Initialize(thread_id, offset_event_timestamp, thread_now,
-                              phase, category_group_enabled, name, id,
-                              context_id, num_args, arg_names, arg_types,
-                              arg_values, convertable_values, flags);
+      trace_event->Initialize(thread_id,
+                              offset_event_timestamp,
+                              thread_now,
+                              phase,
+                              category_group_enabled,
+                              name,
+                              id,
+                              context_id,
+                              bind_id,

[dsinclair, 2015/07/21 18:11:49]

Why did you unwrap this call?

[yuhaoz, 2015/07/21 18:22:34]

Simply because it looks clearer, especially with many arguments. There was a bug
(and subsequent CL) related to the order of these arguments. I was just trying
to make it clearer. Do you prefer to blend them into fewer lines?

[dsinclair, 2015/07/21 18:32:50]

I prefer the old way, personally. It also makes it a lot easier to change since
it will highlight just the difference.

+                              num_args,
+                              arg_names,
+                              arg_types,
+                              arg_values,
+                              convertable_values,
+                              flags);
 
 #if defined(OS_ANDROID)
       trace_event->SendToATrace();
 #endif
     }
 
     if (trace_options() & kInternalEchoToConsole) {
       console_message = EventToConsoleMessage(
           phase == TRACE_EVENT_PHASE_COMPLETE ? TRACE_EVENT_PHASE_BEGIN : phase,
           timestamp, trace_event);
@@ skipping 142 matching lines @@
     }
   }
 
   if (console_message.size())
     LOG(ERROR) << console_message;
 
   if (*category_group_enabled & ENABLED_FOR_EVENT_CALLBACK) {
     EventCallback event_callback = reinterpret_cast<EventCallback>(
         subtle::NoBarrier_Load(&event_callback_));
     if (event_callback) {
-      event_callback(now, TRACE_EVENT_PHASE_END, category_group_enabled, name,
-                     trace_event_internal::kNoId, trace_event_internal::kNoId,
-                     NULL, NULL, NULL, TRACE_EVENT_FLAG_NONE);
+      event_callback(now,
+                     TRACE_EVENT_PHASE_END,
+                     category_group_enabled,
+                     name,
+                     trace_event_internal::kNoId,

[dsinclair, 2015/07/21 18:11:49]

ditto

+                     trace_event_internal::kNoId,
+                     NULL,
+                     NULL,
+                     NULL,
+                     TRACE_EVENT_FLAG_NONE);
     }
   }
 }
 
 void TraceLog::SetWatchEvent(const std::string& category_name,
                              const std::string& event_name,
                              const WatchEventCallback& callback) {
   const unsigned char* category = GetCategoryGroupEnabled(
       category_name.c_str());
   AutoLock lock(lock_);
@@ skipping 202 matching lines @@
     const char* category_group, const char* name) {
   // The single atom works because for now the category_group can only be "gpu".
   DCHECK_EQ(strcmp(category_group, "gpu"), 0);
   static TRACE_EVENT_API_ATOMIC_WORD atomic = 0;
   INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO_CUSTOM_VARIABLES(
       category_group, atomic, category_group_enabled_);
   name_ = name;
   if (*category_group_enabled_) {
     event_handle_ =
         TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
-            TRACE_EVENT_PHASE_COMPLETE, category_group_enabled_, name, kNoId,
-            kNoId, static_cast<int>(base::PlatformThread::CurrentId()),
-            base::TraceTicks::Now(), 0, NULL, NULL, NULL, NULL,
+            TRACE_EVENT_PHASE_COMPLETE,
+            category_group_enabled_,
+            name,
+            trace_event_internal::kNoId,
+            trace_event_internal::kNoId,

[dsinclair, 2015/07/21 18:11:49]

ditto

+            trace_event_internal::kNoId,
+            static_cast<int>(base::PlatformThread::CurrentId()),
+            base::TraceTicks::Now(),
+            trace_event_internal::kZeroNumArgs,
+            NULL,
+            NULL,
+            NULL,
+            NULL,
             TRACE_EVENT_FLAG_NONE);
   }
 }
 
 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() {
   if (*category_group_enabled_) {
     TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_,
                                                 name_, event_handle_);
   }
 }
 
 }  // namespace trace_event_internal