Improvements to trace_event on Android and roll trace-viewer to r220

1. Output categories at the end of the events instead of prepending to the
   names. Trace-viewer supports the new format after r216 (for B events)
   and r220 (for C events). This change is still compatible with previous
   versions of trace-viewer though no category will be displayed.

2. Output event ids within the event names. Event ids are used to
   distinguish different sources of events (e.g. different layers, windows,
   etc.) This has been a missing feature of trace_event on Android since.

3. Output arguments in E events. Sometimes the E events may add some arguments
   in addition to the B events and need to be displayed. trace-viewer has
   already supported this.

BTW roll trace-viewer to r220 to include the changes to parse the new format.

BUG=none

Review URL: https://codereview.chromium.org/12570012

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@187898 0039d316-1c4b-4281-b951-d872f2087c98

3 files changed, 71 insertions, 40 deletions

diff --git a/base/debug/trace_event_android.cc b/base/debug/trace_event_android.cc
index 2901a34..c04ed91 100644
--- a/base/debug/trace_event_android.cc
+++ b/base/debug/trace_event_android.cc
@@ -7,6 +7,7 @@
 #include <fcntl.h>
 
 #include "base/debug/trace_event.h"
+#include "base/format_macros.h"
 #include "base/logging.h"
 #include "base/stringprintf.h"
 
@@ -15,6 +16,42 @@ namespace {
 int g_atrace_fd = -1;
 const char* kATraceMarkerFile = "/sys/kernel/debug/tracing/trace_marker";
 
+void WriteEvent(char phase,
+                const char* category,
+                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) {
+  std::string out = StringPrintf("%c|%d|%s", phase, getpid(), name);
+  if (flags & TRACE_EVENT_FLAG_HAS_ID)
+    base::StringAppendF(&out, "-%" PRIx64, static_cast<uint64>(id));
+  out += '|';
+
+  for (int i = 0; i < num_args; ++i) {
+    if (i)
+      out += ';';
+    out += arg_names[i];
+    out += '=';
+    base::debug::TraceEvent::TraceValue value;
+    value.as_uint = arg_values[i];
+    std::string::size_type value_start = out.length();
+    base::debug::TraceEvent::AppendValueAsJSON(arg_types[i], value, &out);
+    // Remove the quotes which may confuse the atrace script.
+    ReplaceSubstringsAfterOffset(&out, value_start, "\\\"", "'");
+    ReplaceSubstringsAfterOffset(&out, value_start, "\"", "");
+    // Replace chars used for separators with similar chars in the value.
+    std::replace(out.begin() + value_start, out.end(), ';', ',');
+    std::replace(out.begin() + value_start, out.end(), '|', '!');
+  }
+
+  out += '|';
+  out += category;
+  write(g_atrace_fd, out.c_str(), out.size());
+}
+
 }  // namespace
 
 namespace base {
@@ -40,52 +77,44 @@ void TraceLog::StopATrace() {
 void TraceLog::SendToATrace(char phase,
                             const char* category,
                             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) {
+                            const unsigned long long* arg_values,
+                            unsigned char flags) {
   if (g_atrace_fd == -1)
     return;
 
   switch (phase) {
     case TRACE_EVENT_PHASE_BEGIN:
-    case TRACE_EVENT_PHASE_INSTANT: {
-      std::string out = StringPrintf("B|%d|%s-%s", getpid(), category, name);
-      for (int i = 0; i < num_args; ++i) {
-        out += (i == 0 ? '|' : ';');
-        out += arg_names[i];
-        out += '=';
-        TraceEvent::TraceValue value;
-        value.as_uint = arg_values[i];
-        std::string::size_type value_start = out.length();
-        TraceEvent::AppendValueAsJSON(arg_types[i], value, &out);
-        // Remove the quotes which may confuse the atrace script.
-        ReplaceSubstringsAfterOffset(&out, value_start, "\\\"", "'");
-        ReplaceSubstringsAfterOffset(&out, value_start, "\"", "");
-        // Replace chars used for separators with similar chars in the value.
-        std::replace(out.begin() + value_start, out.end(), ';', ',');
-        std::replace(out.begin() + value_start, out.end(), '|', '!');
-      }
-      write(g_atrace_fd, out.c_str(), out.size());
-
-      if (phase != TRACE_EVENT_PHASE_INSTANT)
-        break;
-      // Fall through. Simulate an instance event with a pair of begin/end.
-    }
-    case TRACE_EVENT_PHASE_END: {
-      // Though a single 'E' is enough, here append pid and name so that
-      // unpaired events can be found easily.
-      std::string out = StringPrintf("E|%d|%s-%s", getpid(), category, name);
-      write(g_atrace_fd, out.c_str(), out.size());
+      WriteEvent('B', category, name, id,
+                 num_args, arg_names, arg_types, arg_values, flags);
+      break;
+
+    case TRACE_EVENT_PHASE_END:
+      // Though a single 'E' is enough, here append pid, name and category etc.
+      // so that unpaired events can be found easily.
+      WriteEvent('E', category, name, id,
+                 num_args, arg_names, arg_types, arg_values, flags);
       break;
-    }
+
+    case TRACE_EVENT_PHASE_INSTANT:
+      // Simulate an instance event with a pair of begin/end events.
+      WriteEvent('B', category, name, id,
+                 num_args, arg_names, arg_types, arg_values, flags);
+      write(g_atrace_fd, "E", 1);
+      break;
+
     case TRACE_EVENT_PHASE_COUNTER:
       for (int i = 0; i < num_args; ++i) {
         DCHECK(arg_types[i] == TRACE_VALUE_TYPE_INT);
-        std::string out = StringPrintf(
-            "C|%d|%s-%s-%s|%d",
-            getpid(), category, name,
-            arg_names[i], static_cast<int>(arg_values[i]));
+        std::string out = StringPrintf("C|%d|%s-%s",
+                                       getpid(), name, arg_names[i]);
+        if (flags & TRACE_EVENT_FLAG_HAS_ID)
+          StringAppendF(&out, "-%" PRIx64, static_cast<uint64>(id));
+        StringAppendF(&out, "|%d|%s",
+                      static_cast<int>(arg_values[i]), category);
         write(g_atrace_fd, out.c_str(), out.size());
       }
       break;
diff --git a/base/debug/trace_event_impl.cc b/base/debug/trace_event_impl.cc
index 0f520b9..d9d7007 100644
--- a/base/debug/trace_event_impl.cc
+++ b/base/debug/trace_event_impl.cc
@@ -875,9 +875,12 @@ void TraceLog::AddTraceEventWithThreadIdAndTimestamp(
     unsigned char flags) {
   DCHECK(name);
 
+  if (flags & TRACE_EVENT_FLAG_MANGLE_ID)
+    id ^= process_id_hash_;
+
 #if defined(OS_ANDROID)
-  SendToATrace(phase, GetCategoryName(category_enabled), name,
-               num_args, arg_names, arg_types, arg_values);
+  SendToATrace(phase, GetCategoryName(category_enabled), name, id,
+               num_args, arg_names, arg_types, arg_values, flags);
 #endif
 
   TimeTicks now = timestamp - time_offset_;
@@ -922,9 +925,6 @@ void TraceLog::AddTraceEventWithThreadIdAndTimestamp(
       }
     }
 
-    if (flags & TRACE_EVENT_FLAG_MANGLE_ID)
-      id ^= process_id_hash_;
-
     logged_events_.push_back(
         TraceEvent(thread_id,
                    now, phase, category_enabled, name, id,
diff --git a/base/debug/trace_event_impl.h b/base/debug/trace_event_impl.h
index 42c11dc..f7cb2cd 100644
--- a/base/debug/trace_event_impl.h
+++ b/base/debug/trace_event_impl.h
@@ -402,10 +402,12 @@ class BASE_EXPORT TraceLog {
   void SendToATrace(char phase,
                     const char* category,
                     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);
+                    const unsigned long long* arg_values,
+                    unsigned char flags);
   static void ApplyATraceEnabledFlag(unsigned char* category_enabled);
 #endif