src/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 scoped_refptr<TraceOutputter> TraceOutputter::Create(const std::string& name) {
  22   if (!g_outputter_thread) {
  23     g_outputter_thread = new TraceOutputter(name);
  24   }
  25   return g_outputter_thread;
  26 }
  27
  28 TraceOutputter::TraceOutputter(const std::string& name)
  29     : named_thread_(name.c_str()), local_trace_id_(0) {
  30   named_thread_.Start();
  31   named_thread_.Stop();
  32 }
  33
  34 TraceOutputter::~TraceOutputter() { g_outputter_thread = NULL; }
  35
  36 void TraceOutputter::Trace(const std::string& name,
  37                            int64 start_time,
  38                            int64 end_time) {
  39   TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP0(
  40       TRACE_DISABLED_BY_DEFAULT("gpu.device"),
  41       name.c_str(),
  42       local_trace_id_,
  43       named_thread_.thread_id(),
  44       start_time);
  45   TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP0(
  46       TRACE_DISABLED_BY_DEFAULT("gpu.device"),
  47       name.c_str(),
  48       local_trace_id_,
  49       named_thread_.thread_id(),
  50       end_time);
  51   ++local_trace_id_;
  52 }
  53
  54 GPUTrace::GPUTrace(const std::string& name)
  55     : name_(name),
  56       outputter_(NULL),
  57       offset_(0),
  58       end_time_(0),
  59       end_requested_(false),
  60       enabled_(false) {
  61 }
  62
  63 GPUTrace::GPUTrace(scoped_refptr<Outputter> outputter,
  64                    const std::string& name,
  65                    int64 offset)
  66     : name_(name),
  67       outputter_(outputter),
  68       offset_(offset),
  69       start_time_(0),
  70       end_time_(0),
  71       end_requested_(false),
  72       enabled_(true) {
  73   glGenQueries(2, queries_);
  74 }
  75
  76 GPUTrace::~GPUTrace() {
  77   if (enabled_)
  78     glDeleteQueries(2, queries_);
  79 }
  80
  81 void GPUTrace::Start() {
  82   TRACE_EVENT_COPY_ASYNC_BEGIN0(
  83       TRACE_DISABLED_BY_DEFAULT("gpu.service"), name().c_str(), this);
  84   if (enabled_) {
  85     glQueryCounter(queries_[0], GL_TIMESTAMP);
  86   }
  87 }
  88
  89 void GPUTrace::End() {
  90   if (enabled_) {
  91     glQueryCounter(queries_[1], GL_TIMESTAMP);
  92     end_requested_ = true;
  93   }
  94
  95   TRACE_EVENT_COPY_ASYNC_END0(
  96       TRACE_DISABLED_BY_DEFAULT("gpu.service"), name().c_str(), this);
  97 }
  98
  99 bool GPUTrace::IsAvailable() {
 100   if (!enabled_)
 101     return true;
 102   else if (!end_requested_)
 103     return false;
 104
 105   GLint done = 0;
 106   glGetQueryObjectiv(queries_[1], GL_QUERY_RESULT_AVAILABLE, &done);
 107   return !!done;
 108 }
 109
 110 void GPUTrace::Process() {
 111   if (!enabled_)
 112     return;
 113
 114   DCHECK(IsAvailable());
 115
 116   GLuint64 timestamp;
 117
 118   // TODO(dsinclair): It's possible for the timer to wrap during the start/end.
 119   // We need to detect if the end is less then the start and correct for the
 120   // wrapping.
 121   glGetQueryObjectui64v(queries_[0], GL_QUERY_RESULT, &timestamp);
 122   start_time_ = (timestamp / base::Time::kNanosecondsPerMicrosecond) + offset_;
 123
 124   glGetQueryObjectui64v(queries_[1], GL_QUERY_RESULT, &timestamp);
 125   end_time_ = (timestamp / base::Time::kNanosecondsPerMicrosecond) + offset_;
 126
 127   glDeleteQueries(2, queries_);
 128   outputter_->Trace(name(), start_time_, end_time_);
 129 }
 130
 131 struct TraceMarker {
 132   TraceMarker(const std::string& name, GpuTracerSource source)
 133       : name_(name), source_(source) {}
 134
 135   std::string name_;
 136   GpuTracerSource source_;
 137   scoped_refptr<GPUTrace> trace_;
 138 };
 139
 140 class GPUTracerImpl
 141     : public GPUTracer,
 142       public base::SupportsWeakPtr<GPUTracerImpl> {
 143  public:
 144   GPUTracerImpl()
 145       : gpu_trace_srv_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
 146             TRACE_DISABLED_BY_DEFAULT("gpu.service"))),
 147         gpu_trace_dev_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
 148             TRACE_DISABLED_BY_DEFAULT("gpu.device"))),
 149         gpu_executing_(false),
 150         process_posted_(false) {}
 151   virtual ~GPUTracerImpl() {}
 152
 153   // Implementation of gpu::gles2::GPUTracer
 154   virtual bool BeginDecoding() OVERRIDE;
 155   virtual bool EndDecoding() OVERRIDE;
 156   virtual bool Begin(const std::string& name, GpuTracerSource source) OVERRIDE;
 157   virtual bool End(GpuTracerSource source) OVERRIDE;
 158   virtual const std::string& CurrentName() const OVERRIDE;
 159   virtual bool IsTracing() OVERRIDE {
 160     return (*gpu_trace_srv_category != 0) || (*gpu_trace_dev_category != 0);
 161   }
 162   virtual void CalculateTimerOffset() {}
 163
 164   // Process any completed traces.
 165   virtual void Process();
 166   virtual void ProcessTraces();
 167
 168  protected:
 169   // Create a new trace.
 170   virtual scoped_refptr<GPUTrace> CreateTrace(const std::string& name);
 171
 172   const unsigned char* gpu_trace_srv_category;
 173   const unsigned char* gpu_trace_dev_category;
 174
 175  protected:
 176   void IssueProcessTask();
 177
 178   std::vector<TraceMarker> markers_;
 179   std::deque<scoped_refptr<GPUTrace> > traces_;
 180
 181   bool gpu_executing_;
 182   bool process_posted_;
 183
 184   DISALLOW_COPY_AND_ASSIGN(GPUTracerImpl);
 185 };
 186
 187 class GPUTracerARBTimerQuery : public GPUTracerImpl {
 188  public:
 189   explicit GPUTracerARBTimerQuery(gles2::GLES2Decoder* decoder);
 190   virtual ~GPUTracerARBTimerQuery();
 191
 192   // Implementation of GPUTracerImpl
 193   virtual void ProcessTraces() OVERRIDE;
 194
 195  protected:
 196   // Implementation of GPUTracerImpl.
 197   virtual bool BeginDecoding() OVERRIDE;
 198   virtual bool EndDecoding() OVERRIDE;
 199   virtual scoped_refptr<GPUTrace> CreateTrace(const std::string& name) OVERRIDE;
 200   virtual void CalculateTimerOffset() OVERRIDE;
 201
 202   scoped_refptr<Outputter> outputter_;
 203
 204   bool gpu_timing_synced_;
 205   int64 timer_offset_;
 206
 207   gles2::GLES2Decoder* decoder_;
 208
 209   DISALLOW_COPY_AND_ASSIGN(GPUTracerARBTimerQuery);
 210 };
 211
 212 bool GPUTracerImpl::BeginDecoding() {
 213   if (gpu_executing_)
 214     return false;
 215
 216   gpu_executing_ = true;
 217
 218   if (IsTracing()) {
 219     // Begin a Trace for all active markers
 220     for (size_t i = 0; i < markers_.size(); i++) {
 221       markers_[i].trace_ = CreateTrace(markers_[i].name_);
 222       markers_[i].trace_->Start();
 223     }
 224   }
 225   return true;
 226 }
 227
 228 bool GPUTracerImpl::EndDecoding() {
 229   if (!gpu_executing_)
 230     return false;
 231
 232   // End Trace for all active markers
 233   if (IsTracing()) {
 234     for (size_t i = 0; i < markers_.size(); i++) {
 235       if (markers_[i].trace_) {
 236         markers_[i].trace_->End();
 237         if (markers_[i].trace_->IsEnabled())
 238           traces_.push_back(markers_[i].trace_);
 239         markers_[i].trace_ = 0;
 240       }
 241     }
 242     IssueProcessTask();
 243   }
 244
 245   gpu_executing_ = false;
 246   return true;
 247 }
 248
 249 bool GPUTracerImpl::Begin(const std::string& name, GpuTracerSource source) {
 250   if (!gpu_executing_)
 251     return false;
 252
 253   // Push new marker from given 'source'
 254   markers_.push_back(TraceMarker(name, source));
 255
 256   // Create trace
 257   if (IsTracing()) {
 258     scoped_refptr<GPUTrace> trace = CreateTrace(name);
 259     trace->Start();
 260     markers_.back().trace_ = trace;
 261   }
 262   return true;
 263 }
 264
 265 bool GPUTracerImpl::End(GpuTracerSource source) {
 266   if (!gpu_executing_)
 267     return false;
 268
 269   // Pop last marker with matching 'source'
 270   for (int i = markers_.size() - 1; i >= 0; i--) {
 271     if (markers_[i].source_ == source) {
 272       // End trace
 273       if (IsTracing()) {
 274         scoped_refptr<GPUTrace> trace = markers_[i].trace_;
 275         if (trace) {
 276           trace->End();
 277           if (trace->IsEnabled())
 278             traces_.push_back(trace);
 279           IssueProcessTask();
 280         }
 281       }
 282
 283       markers_.erase(markers_.begin() + i);
 284       return true;
 285     }
 286   }
 287   return false;
 288 }
 289
 290 void GPUTracerImpl::Process() {
 291   process_posted_ = false;
 292   ProcessTraces();
 293   IssueProcessTask();
 294 }
 295
 296 void GPUTracerImpl::ProcessTraces() {
 297   while (!traces_.empty() && traces_.front()->IsAvailable()) {
 298     traces_.front()->Process();
 299     traces_.pop_front();
 300   }
 301 }
 302
 303 const std::string& GPUTracerImpl::CurrentName() const {
 304   if (markers_.empty())
 305     return base::EmptyString();
 306   return markers_.back().name_;
 307 }
 308
 309 scoped_refptr<GPUTrace> GPUTracerImpl::CreateTrace(
 310       const std::string& name) {
 311   return new GPUTrace(name);
 312 }
 313
 314 void GPUTracerImpl::IssueProcessTask() {
 315   if (traces_.empty() || process_posted_)
 316     return;
 317
 318   process_posted_ = true;
 319   base::MessageLoop::current()->PostDelayedTask(
 320       FROM_HERE,
 321       base::Bind(&GPUTracerImpl::Process, base::AsWeakPtr(this)),
 322       base::TimeDelta::FromMilliseconds(kProcessInterval));
 323 }
 324
 325 GPUTracerARBTimerQuery::GPUTracerARBTimerQuery(gles2::GLES2Decoder* decoder)
 326     : timer_offset_(0), decoder_(decoder) {
 327   outputter_ = TraceOutputter::Create("GL_ARB_timer_query");
 328 }
 329
 330 GPUTracerARBTimerQuery::~GPUTracerARBTimerQuery() {
 331 }
 332
 333 scoped_refptr<GPUTrace> GPUTracerARBTimerQuery::CreateTrace(
 334     const std::string& name) {
 335   if (*gpu_trace_dev_category)
 336     return new GPUTrace(outputter_, name, timer_offset_);
 337   return GPUTracerImpl::CreateTrace(name);
 338 }
 339
 340 bool GPUTracerARBTimerQuery::BeginDecoding() {
 341   if (*gpu_trace_dev_category) {
 342     // Make sure timing is synced before tracing
 343     if (!gpu_timing_synced_) {
 344       CalculateTimerOffset();
 345       gpu_timing_synced_ = true;
 346     }
 347   } else {
 348     // If GPU device category is off, invalidate timing sync
 349     gpu_timing_synced_ = false;
 350   }
 351
 352   return GPUTracerImpl::BeginDecoding();
 353 }
 354
 355 bool GPUTracerARBTimerQuery::EndDecoding() {
 356   bool ret = GPUTracerImpl::EndDecoding();
 357
 358   // NOTE(vmiura_: glFlush() here can help give better trace results,
 359   // but it distorts the normal device behavior.
 360   return ret;
 361 }
 362
 363 void GPUTracerARBTimerQuery::ProcessTraces() {
 364   TRACE_EVENT0("gpu", "GPUTracerARBTimerQuery::ProcessTraces");
 365
 366   // Make owning decoder's GL context current
 367   if (!decoder_->MakeCurrent()) {
 368     // Skip subsequent GL calls if MakeCurrent fails
 369     traces_.clear();
 370     return;
 371   }
 372
 373   while (!traces_.empty() && traces_.front()->IsAvailable()) {
 374     traces_.front()->Process();
 375     traces_.pop_front();
 376   }
 377
 378   // Clear pending traces if there were are any errors
 379   GLenum err = glGetError();
 380   if (err != GL_NO_ERROR)
 381     traces_.clear();
 382 }
 383
 384 void GPUTracerARBTimerQuery::CalculateTimerOffset() {
 385   TRACE_EVENT0("gpu", "GPUTracerARBTimerQuery::CalculateTimerOffset");
 386
 387   // NOTE(vmiura): It would be better to use glGetInteger64v, however
 388   // it's not available everywhere.
 389   GLuint64 gl_now = 0;
 390   GLuint query;
 391   glFinish();
 392   glGenQueries(1, &query);
 393   glQueryCounter(query, GL_TIMESTAMP);
 394   glFinish();
 395   glGetQueryObjectui64v(query, GL_QUERY_RESULT, &gl_now);
 396   base::TimeTicks system_now = base::TimeTicks::NowFromSystemTraceTime();
 397
 398   gl_now /= base::Time::kNanosecondsPerMicrosecond;
 399   timer_offset_ = system_now.ToInternalValue() - gl_now;
 400   glDeleteQueries(1, &query);
 401 }
 402
 403 GPUTracer::GPUTracer() {}
 404
 405 GPUTracer::~GPUTracer() {}
 406
 407 scoped_ptr<GPUTracer> GPUTracer::Create(gles2::GLES2Decoder* decoder) {
 408   if (gfx::g_driver_gl.ext.b_GL_ARB_timer_query) {
 409     return scoped_ptr<GPUTracer>(new GPUTracerARBTimerQuery(decoder));
 410   }
 411   return scoped_ptr<GPUTracer>(new GPUTracerImpl());
 412 }
 413
 414 }  // namespace gles2
 415 }  // namespace gpu