gpu/command_buffer/service/gpu_tracer.cc

   1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "gpu/command_buffer/service/gpu_tracer.h"
   6
   7 #include <deque>
   8
   9 #include "base/bind.h"
  10 #include "base/debug/trace_event.h"
  11 #include "base/strings/string_util.h"
  12 #include "base/time/time.h"
  13 #include "gpu/command_buffer/common/gles2_cmd_utils.h"
  14
  15 namespace gpu {
  16 namespace gles2 {
  17
  18 static const unsigned int kProcessInterval = 16;
  19 static TraceOutputter* g_outputter_thread = NULL;
  20
  21 TraceMarker::TraceMarker(const std::string& name)
  22     : name_(name),
  23       trace_(NULL) {
  24 }
  25
  26 TraceMarker::~TraceMarker() {
  27 }
  28
  29 scoped_refptr<TraceOutputter> TraceOutputter::Create(const std::string& name) {
  30   if (!g_outputter_thread) {
  31     g_outputter_thread = new TraceOutputter(name);
  32   }
  33   return g_outputter_thread;
  34 }
  35
  36 TraceOutputter::TraceOutputter(const std::string& name)
  37     : named_thread_(name.c_str()), local_trace_id_(0) {
  38   named_thread_.Start();
  39   named_thread_.Stop();
  40 }
  41
  42 TraceOutputter::~TraceOutputter() { g_outputter_thread = NULL; }
  43
  44 void TraceOutputter::Trace(const std::string& name,
  45                            int64 start_time,
  46                            int64 end_time) {
  47   TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0(
  48       TRACE_DISABLED_BY_DEFAULT("gpu.device"),
  49       name.c_str(),
  50       local_trace_id_,
  51       named_thread_.thread_id(),
  52       start_time);
  53   TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0(
  54       TRACE_DISABLED_BY_DEFAULT("gpu.device"),
  55       name.c_str(),
  56       local_trace_id_,
  57       named_thread_.thread_id(),
  58       end_time);
  59   ++local_trace_id_;
  60 }
  61
  62 GPUTrace::GPUTrace(const std::string& name)
  63     : name_(name),
  64       outputter_(NULL),
  65       offset_(0),
  66       end_time_(0),
  67       end_requested_(false),
  68       enabled_(false) {
  69 }
  70
  71 GPUTrace::GPUTrace(scoped_refptr<Outputter> outputter,
  72                    const std::string& name,
  73                    int64 offset)
  74     : name_(name),
  75       outputter_(outputter),
  76       offset_(offset),
  77       start_time_(0),
  78       end_time_(0),
  79       end_requested_(false),
  80       enabled_(true) {
  81   glGenQueries(2, queries_);
  82 }
  83
  84 GPUTrace::~GPUTrace() {
  85   if (enabled_)
  86     glDeleteQueries(2, queries_);
  87 }
  88
  89 void GPUTrace::Start() {
  90   TRACE_EVENT_COPY_ASYNC_BEGIN0(
  91       TRACE_DISABLED_BY_DEFAULT("gpu.service"), name().c_str(), this);
  92   if (enabled_) {
  93     glQueryCounter(queries_[0], GL_TIMESTAMP);
  94   }
  95 }
  96
  97 void GPUTrace::End() {
  98   if (enabled_) {
  99     glQueryCounter(queries_[1], GL_TIMESTAMP);
 100     end_requested_ = true;
 101   }
 102
 103   TRACE_EVENT_COPY_ASYNC_END0(
 104       TRACE_DISABLED_BY_DEFAULT("gpu.service"), name().c_str(), this);
 105 }
 106
 107 bool GPUTrace::IsAvailable() {
 108   if (!enabled_)
 109     return true;
 110   else if (!end_requested_)
 111     return false;
 112
 113   GLint done = 0;
 114   glGetQueryObjectiv(queries_[1], GL_QUERY_RESULT_AVAILABLE, &done);
 115   return !!done;
 116 }
 117
 118 void GPUTrace::Process() {
 119   if (!enabled_)
 120     return;
 121
 122   DCHECK(IsAvailable());
 123
 124   GLuint64 timestamp;
 125
 126   // TODO(dsinclair): It's possible for the timer to wrap during the start/end.
 127   // We need to detect if the end is less then the start and correct for the
 128   // wrapping.
 129   glGetQueryObjectui64v(queries_[0], GL_QUERY_RESULT, &timestamp);
 130   start_time_ = (timestamp / base::Time::kNanosecondsPerMicrosecond) + offset_;
 131
 132   glGetQueryObjectui64v(queries_[1], GL_QUERY_RESULT, &timestamp);
 133   end_time_ = (timestamp / base::Time::kNanosecondsPerMicrosecond) + offset_;
 134
 135   glDeleteQueries(2, queries_);
 136   outputter_->Trace(name(), start_time_, end_time_);
 137 }
 138
 139 GPUTracer::GPUTracer(gles2::GLES2Decoder* decoder)
 140     : gpu_trace_srv_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
 141           TRACE_DISABLED_BY_DEFAULT("gpu.service"))),
 142       gpu_trace_dev_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
 143           TRACE_DISABLED_BY_DEFAULT("gpu.device"))),
 144       decoder_(decoder),
 145       timer_offset_(0),
 146       last_tracer_source_(kTraceGroupInvalid),
 147       enabled_(false),
 148       gpu_timing_synced_(false),
 149       gpu_executing_(false),
 150       process_posted_(false) {
 151   if (gfx::g_driver_gl.ext.b_GL_ARB_timer_query) {
 152     outputter_ = TraceOutputter::Create("GL_ARB_timer_query");
 153     enabled_ = true;
 154   }
 155 }
 156
 157 GPUTracer::~GPUTracer() {
 158 }
 159
 160 bool GPUTracer::BeginDecoding() {
 161   if (enabled_) {
 162     if (*gpu_trace_dev_category) {
 163       // Make sure timing is synced before tracing
 164       if (!gpu_timing_synced_) {
 165         CalculateTimerOffset();
 166         gpu_timing_synced_ = true;
 167       }
 168     } else {
 169       // If GPU device category is off, invalidate timing sync
 170       gpu_timing_synced_ = false;
 171     }
 172   }
 173
 174   if (gpu_executing_)
 175     return false;
 176
 177   gpu_executing_ = true;
 178
 179   if (IsTracing()) {
 180     // Begin a Trace for all active markers
 181     for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
 182       for (size_t i = 0; i < markers_[n].size(); i++) {
 183         markers_[n][i].trace_ = CreateTrace(markers_[n][i].name_);
 184         markers_[n][i].trace_->Start();
 185       }
 186     }
 187   }
 188   return true;
 189 }
 190
 191 bool GPUTracer::EndDecoding() {
 192   if (!gpu_executing_)
 193     return false;
 194
 195   // End Trace for all active markers
 196   if (IsTracing()) {
 197     for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
 198       for (size_t i = 0; i < markers_[n].size(); i++) {
 199         if (markers_[n][i].trace_.get()) {
 200           markers_[n][i].trace_->End();
 201           if (markers_[n][i].trace_->IsEnabled())
 202             traces_.push_back(markers_[n][i].trace_);
 203           markers_[n][i].trace_ = 0;
 204         }
 205       }
 206     }
 207     IssueProcessTask();
 208   }
 209
 210   gpu_executing_ = false;
 211
 212   // NOTE(vmiura): glFlush() here can help give better trace results,
 213   // but it distorts the normal device behavior.
 214   return true;
 215 }
 216
 217 bool GPUTracer::Begin(const std::string& name, GpuTracerSource source) {
 218   if (!gpu_executing_)
 219     return false;
 220
 221   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
 222
 223   // Push new marker from given 'source'
 224   last_tracer_source_ = source;
 225   markers_[source].push_back(TraceMarker(name));
 226
 227   // Create trace
 228   if (IsTracing()) {
 229     scoped_refptr<GPUTrace> trace = CreateTrace(name);
 230     trace->Start();
 231     markers_[source].back().trace_ = trace;
 232   }
 233
 234   return true;
 235 }
 236
 237 bool GPUTracer::End(GpuTracerSource source) {
 238   if (!gpu_executing_)
 239     return false;
 240
 241   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
 242
 243   // Pop last marker with matching 'source'
 244   if (!markers_[source].empty()) {
 245     if (IsTracing()) {
 246       scoped_refptr<GPUTrace> trace = markers_[source].back().trace_;
 247       if (trace.get()) {
 248         trace->End();
 249         if (trace->IsEnabled())
 250           traces_.push_back(trace);
 251         IssueProcessTask();
 252       }
 253     }
 254
 255     markers_[source].pop_back();
 256     return true;
 257   }
 258   return false;
 259 }
 260
 261 bool GPUTracer::IsTracing() {
 262   return (*gpu_trace_srv_category != 0) || (*gpu_trace_dev_category != 0);
 263 }
 264
 265 const std::string& GPUTracer::CurrentName() const {
 266   if (last_tracer_source_ >= 0 &&
 267       last_tracer_source_ < NUM_TRACER_SOURCES &&
 268       !markers_[last_tracer_source_].empty()) {
 269     return markers_[last_tracer_source_].back().name_;
 270   }
 271   return base::EmptyString();
 272 }
 273
 274 scoped_refptr<GPUTrace> GPUTracer::CreateTrace(const std::string& name) {
 275   if (enabled_ && *gpu_trace_dev_category)
 276     return new GPUTrace(outputter_, name, timer_offset_);
 277   else
 278     return new GPUTrace(name);
 279 }
 280
 281 void GPUTracer::Process() {
 282   process_posted_ = false;
 283   ProcessTraces();
 284   IssueProcessTask();
 285 }
 286
 287 void GPUTracer::ProcessTraces() {
 288   if (!enabled_) {
 289     while (!traces_.empty() && traces_.front()->IsAvailable()) {
 290       traces_.front()->Process();
 291       traces_.pop_front();
 292     }
 293     return;
 294   }
 295
 296   TRACE_EVENT0("gpu", "GPUTracer::ProcessTraces");
 297
 298   // Make owning decoder's GL context current
 299   if (!decoder_->MakeCurrent()) {
 300     // Skip subsequent GL calls if MakeCurrent fails
 301     traces_.clear();
 302     return;
 303   }
 304
 305   while (!traces_.empty() && traces_.front()->IsAvailable()) {
 306     traces_.front()->Process();
 307     traces_.pop_front();
 308   }
 309
 310   // Clear pending traces if there were are any errors
 311   GLenum err = glGetError();
 312   if (err != GL_NO_ERROR)
 313     traces_.clear();
 314 }
 315
 316 void GPUTracer::CalculateTimerOffset() {
 317   if (enabled_) {
 318     TRACE_EVENT0("gpu", "GPUTracer::CalculateTimerOffset");
 319
 320     // NOTE(vmiura): It would be better to use glGetInteger64v, however
 321     // it's not available everywhere.
 322     GLuint64 gl_now = 0;
 323     GLuint query;
 324     glFinish();
 325     glGenQueries(1, &query);
 326     glQueryCounter(query, GL_TIMESTAMP);
 327     glFinish();
 328     glGetQueryObjectui64v(query, GL_QUERY_RESULT, &gl_now);
 329     base::TimeTicks system_now = base::TimeTicks::NowFromSystemTraceTime();
 330
 331     gl_now /= base::Time::kNanosecondsPerMicrosecond;
 332     timer_offset_ = system_now.ToInternalValue() - gl_now;
 333     glDeleteQueries(1, &query);
 334   }
 335 }
 336
 337 void GPUTracer::IssueProcessTask() {
 338   if (traces_.empty() || process_posted_)
 339     return;
 340
 341   process_posted_ = true;
 342   base::MessageLoop::current()->PostDelayedTask(
 343       FROM_HERE,
 344       base::Bind(&GPUTracer::Process, base::AsWeakPtr(this)),
 345       base::TimeDelta::FromMilliseconds(kProcessInterval));
 346 }
 347
 348 }  // namespace gles2
 349 }  // namespace gpu