Fixed GPU tracing so the categories do not get mixed.

Because of how the chromium tracing macros work, it is not possible
to use the same line for multiple tracing categories. I have moved
the GPU categories to a separate trace arg "gl_categories" instead,
and changed the trace categories back to gpu.device and gpu.service.

GroupPushMarkerEXT calls can no longer be disabled by their category.
We currently use these to trace top level GPU traces which are
constructed before the tracing categories are initialized.

There were also some other issues related to having multiple channels
in the GPU Tracer. Now functions that query the current trace take
in a channel argument as well to differentiate the channels.

R=vmiura@chromium.org
BUG=None
TEST=trybots

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

Cr-Commit-Position: refs/heads/master@{#310426}

5 files changed, 62 insertions, 58 deletions

diff --git a/base/debug/trace_event.h b/base/debug/trace_event.h
index 62a9b1f..9754036 100644
--- a/base/debug/trace_event.h
+++ b/base/debug/trace_event.h
@@ -395,6 +395,11 @@
     INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
         TRACE_EVENT_PHASE_ASYNC_BEGIN, category_group, name, id, thread_id, \
         timestamp, TRACE_EVENT_FLAG_COPY)
+#define TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP1( \
+        category_group, name, id, thread_id, timestamp, arg1_name, arg1_val) \
+    INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
+        TRACE_EVENT_PHASE_ASYNC_BEGIN, category_group, name, id, thread_id, \
+        timestamp, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val)
 
 // Records a single END event for "name" immediately. If the category
 // is not enabled, then this does nothing.
@@ -439,6 +444,11 @@
     INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
         TRACE_EVENT_PHASE_ASYNC_END, category_group, name, id, thread_id, \
         timestamp, TRACE_EVENT_FLAG_COPY)
+#define TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP1( \
+        category_group, name, id, thread_id, timestamp, arg1_name, arg1_val) \
+    INTERNAL_TRACE_EVENT_ADD_WITH_ID_TID_AND_TIMESTAMP( \
+        TRACE_EVENT_PHASE_ASYNC_END, category_group, name, id, thread_id, \
+        timestamp, TRACE_EVENT_FLAG_COPY, arg1_name, arg1_val)
 
 // Records the value of a counter called "name" immediately. Value
 // must be representable as a 32 bit integer.
diff --git a/gpu/command_buffer/service/gles2_cmd_decoder.cc b/gpu/command_buffer/service/gles2_cmd_decoder.cc
index 9ad567a..7f9166e 100644
--- a/gpu/command_buffer/service/gles2_cmd_decoder.cc
+++ b/gpu/command_buffer/service/gles2_cmd_decoder.cc
@@ -1878,7 +1878,6 @@ class GLES2DecoderImpl : public GLES2Decoder,
   scoped_ptr<GPUStateTracer> gpu_state_tracer_;
   const unsigned char* cb_command_trace_category_;
   const unsigned char* gpu_decoder_category_;
-  const unsigned char* gpu_group_marker_category_;
   int gpu_trace_level_;
   bool gpu_trace_commands_;
   bool gpu_debug_commands_;
@@ -2396,8 +2395,6 @@ GLES2DecoderImpl::GLES2DecoderImpl(ContextGroup* group)
           TRACE_DISABLED_BY_DEFAULT("cb_command"))),
       gpu_decoder_category_(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
           TRACE_DISABLED_BY_DEFAULT("gpu_decoder"))),
-      gpu_group_marker_category_(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
-          TRACE_DISABLED_BY_DEFAULT("gpu_group_marker"))),
       gpu_trace_level_(2),
       gpu_trace_commands_(false),
       gpu_debug_commands_(false),
@@ -11006,17 +11003,13 @@ void GLES2DecoderImpl::DoPushGroupMarkerEXT(
   }
   std::string name = length ? std::string(marker, length) : std::string(marker);
   debug_marker_manager_.PushGroup(name);
-  if (*gpu_group_marker_category_) {
-    gpu_tracer_->Begin(TRACE_DISABLED_BY_DEFAULT("gpu_group_marker"), name,
-                       kTraceGroupMarker);
-  }
+  gpu_tracer_->Begin(TRACE_DISABLED_BY_DEFAULT("gpu_group_marker"), name,
+                     kTraceGroupMarker);
 }
 
 void GLES2DecoderImpl::DoPopGroupMarkerEXT(void) {
   debug_marker_manager_.PopGroup();
-  if (*gpu_group_marker_category_) {
-    gpu_tracer_->End(kTraceGroupMarker);
-  }
+  gpu_tracer_->End(kTraceGroupMarker);
 }
 
 void GLES2DecoderImpl::DoBindTexImage2DCHROMIUM(
@@ -11124,8 +11117,6 @@ error::Error GLES2DecoderImpl::HandleTraceBeginCHROMIUM(
     return error::kInvalidArguments;
   }
 
-  TRACE_EVENT_COPY_ASYNC_BEGIN0(category_name.c_str(), trace_name.c_str(),
-                                this);
   if (!gpu_tracer_->Begin(category_name, trace_name, kTraceCHROMIUM)) {
     LOCAL_SET_GL_ERROR(
         GL_INVALID_OPERATION,
@@ -11136,16 +11127,11 @@ error::Error GLES2DecoderImpl::HandleTraceBeginCHROMIUM(
 }
 
 void GLES2DecoderImpl::DoTraceEndCHROMIUM() {
-  if (gpu_tracer_->CurrentCategory().empty() ||
-      gpu_tracer_->CurrentName().empty()) {
-    LOCAL_SET_GL_ERROR(
-        GL_INVALID_OPERATION,
-        "glTraceEndCHROMIUM", "no trace begin found");
+  if (!gpu_tracer_->End(kTraceCHROMIUM)) {
+    LOCAL_SET_GL_ERROR(GL_INVALID_OPERATION,
+                       "glTraceEndCHROMIUM", "no trace begin found");
     return;
   }
-  TRACE_EVENT_COPY_ASYNC_END0(gpu_tracer_->CurrentCategory().c_str(),
-                              gpu_tracer_->CurrentName().c_str(), this);
-  gpu_tracer_->End(kTraceCHROMIUM);
 }
 
 void GLES2DecoderImpl::DoDrawBuffersEXT(
diff --git a/gpu/command_buffer/service/gpu_tracer.cc b/gpu/command_buffer/service/gpu_tracer.cc
index 1f91696..2853e96c 100644
--- a/gpu/command_buffer/service/gpu_tracer.cc
+++ b/gpu/command_buffer/service/gpu_tracer.cc
@@ -56,29 +56,39 @@ void TraceOutputter::TraceDevice(const std::string& category,
                                  const std::string& name,
                                  int64 start_time,
                                  int64 end_time) {
-  TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0(category.c_str(),
-                                                    name.c_str(),
-                                                    local_trace_id_,
-                                                    named_thread_.thread_id(),
-                                                    start_time);
-  TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0(category.c_str(),
-                                                  name.c_str(),
-                                                  local_trace_id_,
-                                                  named_thread_.thread_id(),
-                                                  end_time);
+  TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP1(
+      TRACE_DISABLED_BY_DEFAULT("gpu.device"),
+      name.c_str(),
+      local_trace_id_,
+      named_thread_.thread_id(),
+      start_time,
+      "gl_category",
+      category.c_str());
+  TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP1(
+      TRACE_DISABLED_BY_DEFAULT("gpu.device"),
+      name.c_str(),
+      local_trace_id_,
+      named_thread_.thread_id(),
+      end_time,
+      "gl_category",
+      category.c_str());
   ++local_trace_id_;
 }
 
 void TraceOutputter::TraceServiceBegin(const std::string& category,
                                        const std::string& name,
                                        void* id) {
-  TRACE_EVENT_COPY_ASYNC_BEGIN0(category.c_str(), name.c_str(), id);
+  TRACE_EVENT_COPY_ASYNC_BEGIN1(TRACE_DISABLED_BY_DEFAULT("gpu.service"),
+                                  name.c_str(), this,
+                                  "gl_category", category.c_str());
 }
 
 void TraceOutputter::TraceServiceEnd(const std::string& category,
                                      const std::string& name,
                                      void* id) {
-  TRACE_EVENT_COPY_ASYNC_END0(category.c_str(), name.c_str(), id);
+  TRACE_EVENT_COPY_ASYNC_END1(TRACE_DISABLED_BY_DEFAULT("gpu.service"),
+                                name.c_str(), this,
+                                "gl_category", category.c_str());
 }
 
 GPUTrace::GPUTrace(scoped_refptr<Outputter> outputter,
@@ -199,7 +209,7 @@ void GPUTrace::Process() {
   start_time_ = (begin_stamp / base::Time::kNanosecondsPerMicrosecond) +
                 offset_;
   end_time_ = (end_stamp / base::Time::kNanosecondsPerMicrosecond) + offset_;
-  outputter_->TraceDevice(category(), name(), start_time_, end_time_);
+  outputter_->TraceDevice(category_, name_, start_time_, end_time_);
 }
 
 GPUTracer::GPUTracer(gles2::GLES2Decoder* decoder)
@@ -209,7 +219,6 @@ GPUTracer::GPUTracer(gles2::GLES2Decoder* decoder)
           TRACE_DISABLED_BY_DEFAULT("gpu.device"))),
       decoder_(decoder),
       timer_offset_(0),
-      last_tracer_source_(kTraceGroupInvalid),
       tracer_type_(kTracerTypeInvalid),
       gpu_timing_synced_(false),
       gpu_executing_(false),
@@ -276,10 +285,12 @@ bool GPUTracer::EndDecoding() {
   if (IsTracing()) {
     for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
       for (size_t i = 0; i < markers_[n].size(); i++) {
-        if (markers_[n][i].trace_.get()) {
-          markers_[n][i].trace_->End(*gpu_trace_srv_category != 0);
-          if (markers_[n][i].trace_->IsEnabled())
-            traces_.push_back(markers_[n][i].trace_);
+        TraceMarker& marker = markers_[n][i];
+        if (marker.trace_.get()) {
+          marker.trace_->End(*gpu_trace_srv_category != 0);
+          if (marker.trace_->IsEnabled())
+            traces_.push_back(marker.trace_);
+
           markers_[n][i].trace_ = 0;
         }
       }
@@ -302,7 +313,6 @@ bool GPUTracer::Begin(const std::string& category, const std::string& name,
   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
 
   // Push new marker from given 'source'
-  last_tracer_source_ = source;
   markers_[source].push_back(TraceMarker(category, name));
 
   // Create trace
@@ -343,20 +353,20 @@ bool GPUTracer::IsTracing() {
   return (*gpu_trace_srv_category != 0) || (*gpu_trace_dev_category != 0);
 }
 
-const std::string& GPUTracer::CurrentCategory() const {
-  if (last_tracer_source_ >= 0 &&
-      last_tracer_source_ < NUM_TRACER_SOURCES &&
-      !markers_[last_tracer_source_].empty()) {
-    return markers_[last_tracer_source_].back().category_;
+const std::string& GPUTracer::CurrentCategory(GpuTracerSource source) const {
+  if (source >= 0 &&
+      source < NUM_TRACER_SOURCES &&
+      !markers_[source].empty()) {
+    return markers_[source].back().category_;
   }
   return base::EmptyString();
 }
 
-const std::string& GPUTracer::CurrentName() const {
-  if (last_tracer_source_ >= 0 &&
-      last_tracer_source_ < NUM_TRACER_SOURCES &&
-      !markers_[last_tracer_source_].empty()) {
-    return markers_[last_tracer_source_].back().name_;
+const std::string& GPUTracer::CurrentName(GpuTracerSource source) const {
+  if (source >= 0 &&
+      source < NUM_TRACER_SOURCES &&
+      !markers_[source].empty()) {
+    return markers_[source].back().name_;
   }
   return base::EmptyString();
 }
diff --git a/gpu/command_buffer/service/gpu_tracer.h b/gpu/command_buffer/service/gpu_tracer.h
index 170756f..64f13cc 100644
--- a/gpu/command_buffer/service/gpu_tracer.h
+++ b/gpu/command_buffer/service/gpu_tracer.h
@@ -89,8 +89,8 @@ class GPU_EXPORT GPUTracer
 
   // Retrieve the name of the current open trace.
   // Returns empty string if no current open trace.
-  const std::string& CurrentCategory() const;
-  const std::string& CurrentName() const;
+  const std::string& CurrentCategory(GpuTracerSource source) const;
+  const std::string& CurrentName(GpuTracerSource source) const;
 
  protected:
   // Trace Processing.
@@ -117,7 +117,6 @@ class GPU_EXPORT GPUTracer
   gles2::GLES2Decoder* decoder_;
 
   int64 timer_offset_;
-  GpuTracerSource last_tracer_source_;
 
   GpuTracerType tracer_type_;
   bool gpu_timing_synced_;
@@ -186,9 +185,6 @@ class GPU_EXPORT GPUTrace
 
   bool IsEnabled() { return tracer_type_ != kTracerTypeInvalid; }
 
-  const std::string& category() { return category_; }
-  const std::string& name() { return name_; }
-
   void Start(bool trace_service);
   void End(bool tracing_service);
   bool IsAvailable();
diff --git a/gpu/command_buffer/service/gpu_tracer_unittest.cc b/gpu/command_buffer/service/gpu_tracer_unittest.cc
index 3333e85..ae4c970 100644
--- a/gpu/command_buffer/service/gpu_tracer_unittest.cc
+++ b/gpu/command_buffer/service/gpu_tracer_unittest.cc
@@ -527,9 +527,6 @@ class BaseGpuTracerTest : public BaseGpuTest {
 
       const GpuTracerSource source = static_cast<GpuTracerSource>(i);
       ASSERT_TRUE(tracer.Begin(source_category, source_trace_name, source));
-
-      ASSERT_EQ(source_category, tracer.CurrentCategory());
-      ASSERT_EQ(source_trace_name, tracer.CurrentName());
     }
 
     for (int i = 0; i < NUM_TRACER_SOURCES; ++i) {
@@ -550,6 +547,11 @@ class BaseGpuTracerTest : public BaseGpuTest {
                               GetTracerType() != kTracerTypeInvalid);
 
       const GpuTracerSource source = static_cast<GpuTracerSource>(i);
+
+      // Check if the current category/name are correct for this source.
+      ASSERT_EQ(source_category, tracer.CurrentCategory(source));
+      ASSERT_EQ(source_trace_name, tracer.CurrentName(source));
+
       ASSERT_TRUE(tracer.End(source));
     }