Home | History | Annotate | Download | only in service 
      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(scoped_refptr<Outputter> outputter,
     63                    const std::string& name,
     64                    int64 offset,
     65                    GpuTracerType tracer_type)
     66     : name_(name),
     67       outputter_(outputter),
     68       offset_(offset),
     69       start_time_(0),
     70       end_time_(0),
     71       tracer_type_(tracer_type),
     72       end_requested_(false) {
     73   memset(queries_, 0, sizeof(queries_));
     74   switch (tracer_type_) {
     75     case kTracerTypeARBTimer:
     76     case kTracerTypeDisjointTimer:
     77       glGenQueriesARB(2, queries_);
     78       break;
     79 
     80     default:
     81       tracer_type_ = kTracerTypeInvalid;
     82   }
     83 }
     84 
     85 GPUTrace::~GPUTrace() {
     86   switch (tracer_type_) {
     87     case kTracerTypeInvalid:
     88       break;
     89 
     90     case kTracerTypeARBTimer:
     91     case kTracerTypeDisjointTimer:
     92       glDeleteQueriesARB(2, queries_);
     93       break;
     94   }
     95 }
     96 
     97 void GPUTrace::Start() {
     98   TRACE_EVENT_COPY_ASYNC_BEGIN0(
     99       TRACE_DISABLED_BY_DEFAULT("gpu.service"), name().c_str(), this);
    100 
    101   switch (tracer_type_) {
    102     case kTracerTypeInvalid:
    103       break;
    104 
    105     case kTracerTypeDisjointTimer:
    106       // For the disjoint timer, GPU idle time does not seem to increment the
    107       // internal counter. We must calculate the offset before any query. The
    108       // good news is any device that supports disjoint timer will also support
    109       // glGetInteger64v, so we can query it directly unlike the ARBTimer case.
    110       // The "offset_" variable will always be 0 during normal use cases, only
    111       // under the unit tests will it be set to specific test values.
    112       if (offset_ == 0) {
    113         GLint64 gl_now = 0;
    114         glGetInteger64v(GL_TIMESTAMP, &gl_now);
    115         offset_ = base::TimeTicks::NowFromSystemTraceTime().ToInternalValue() -
    116                   gl_now / base::Time::kNanosecondsPerMicrosecond;
    117       }
    118       // Intentionally fall through to kTracerTypeARBTimer case.xs
    119     case kTracerTypeARBTimer:
    120       // GL_TIMESTAMP and GL_TIMESTAMP_EXT both have the same value.
    121       glQueryCounter(queries_[0], GL_TIMESTAMP);
    122       break;
    123   }
    124 }
    125 
    126 void GPUTrace::End() {
    127   end_requested_ = true;
    128   switch (tracer_type_) {
    129     case kTracerTypeInvalid:
    130       break;
    131 
    132     case kTracerTypeARBTimer:
    133     case kTracerTypeDisjointTimer:
    134       // GL_TIMESTAMP and GL_TIMESTAMP_EXT both have the same value.
    135       glQueryCounter(queries_[1], GL_TIMESTAMP);
    136       break;
    137   }
    138 
    139   TRACE_EVENT_COPY_ASYNC_END0(
    140       TRACE_DISABLED_BY_DEFAULT("gpu.service"), name().c_str(), this);
    141 }
    142 
    143 bool GPUTrace::IsAvailable() {
    144   if (tracer_type_ != kTracerTypeInvalid) {
    145     if (!end_requested_)
    146       return false;
    147 
    148     GLint done = 0;
    149     glGetQueryObjectiv(queries_[1], GL_QUERY_RESULT_AVAILABLE, &done);
    150     return !!done;
    151   }
    152 
    153   return true;
    154 }
    155 
    156 void GPUTrace::Process() {
    157   if (tracer_type_ == kTracerTypeInvalid)
    158     return;
    159 
    160   DCHECK(IsAvailable());
    161 
    162   GLuint64 begin_stamp = 0;
    163   GLuint64 end_stamp = 0;
    164 
    165   // TODO(dsinclair): It's possible for the timer to wrap during the start/end.
    166   // We need to detect if the end is less then the start and correct for the
    167   // wrapping.
    168   glGetQueryObjectui64v(queries_[0], GL_QUERY_RESULT, &begin_stamp);
    169   glGetQueryObjectui64v(queries_[1], GL_QUERY_RESULT, &end_stamp);
    170 
    171   start_time_ = (begin_stamp / base::Time::kNanosecondsPerMicrosecond) +
    172                 offset_;
    173   end_time_ = (end_stamp / base::Time::kNanosecondsPerMicrosecond) + offset_;
    174   outputter_->Trace(name(), start_time_, end_time_);
    175 }
    176 
    177 GPUTracer::GPUTracer(gles2::GLES2Decoder* decoder)
    178     : gpu_trace_srv_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
    179           TRACE_DISABLED_BY_DEFAULT("gpu.service"))),
    180       gpu_trace_dev_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
    181           TRACE_DISABLED_BY_DEFAULT("gpu.device"))),
    182       decoder_(decoder),
    183       timer_offset_(0),
    184       last_tracer_source_(kTraceGroupInvalid),
    185       tracer_type_(kTracerTypeInvalid),
    186       gpu_timing_synced_(false),
    187       gpu_executing_(false),
    188       process_posted_(false) {
    189   if (gfx::g_driver_gl.ext.b_GL_EXT_disjoint_timer_query) {
    190     tracer_type_ = kTracerTypeDisjointTimer;
    191     outputter_ = TraceOutputter::Create("GL_EXT_disjoint_timer_query");
    192   } else if (gfx::g_driver_gl.ext.b_GL_ARB_timer_query) {
    193     tracer_type_ = kTracerTypeARBTimer;
    194     outputter_ = TraceOutputter::Create("GL_ARB_timer_query");
    195   }
    196 }
    197 
    198 GPUTracer::~GPUTracer() {
    199 }
    200 
    201 bool GPUTracer::BeginDecoding() {
    202   if (gpu_executing_)
    203     return false;
    204 
    205   CalculateTimerOffset();
    206   gpu_executing_ = true;
    207 
    208   if (IsTracing()) {
    209     // Reset disjoint bit for the disjoint timer.
    210     if (tracer_type_ == kTracerTypeDisjointTimer) {
    211       GLint disjoint_value = 0;
    212       glGetIntegerv(GL_GPU_DISJOINT_EXT, &disjoint_value);
    213     }
    214 
    215     // Begin a Trace for all active markers
    216     for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
    217       for (size_t i = 0; i < markers_[n].size(); i++) {
    218         markers_[n][i].trace_ = CreateTrace(markers_[n][i].name_);
    219         markers_[n][i].trace_->Start();
    220       }
    221     }
    222   }
    223   return true;
    224 }
    225 
    226 bool GPUTracer::EndDecoding() {
    227   if (!gpu_executing_)
    228     return false;
    229 
    230   // End Trace for all active markers
    231   if (IsTracing()) {
    232     for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
    233       for (size_t i = 0; i < markers_[n].size(); i++) {
    234         if (markers_[n][i].trace_.get()) {
    235           markers_[n][i].trace_->End();
    236           if (markers_[n][i].trace_->IsEnabled())
    237             traces_.push_back(markers_[n][i].trace_);
    238           markers_[n][i].trace_ = 0;
    239         }
    240       }
    241     }
    242     IssueProcessTask();
    243   }
    244 
    245   gpu_executing_ = false;
    246 
    247   // NOTE(vmiura): glFlush() here can help give better trace results,
    248   // but it distorts the normal device behavior.
    249   return true;
    250 }
    251 
    252 bool GPUTracer::Begin(const std::string& name, GpuTracerSource source) {
    253   if (!gpu_executing_)
    254     return false;
    255 
    256   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
    257 
    258   // Push new marker from given 'source'
    259   last_tracer_source_ = source;
    260   markers_[source].push_back(TraceMarker(name));
    261 
    262   // Create trace
    263   if (IsTracing()) {
    264     scoped_refptr<GPUTrace> trace = CreateTrace(name);
    265     trace->Start();
    266     markers_[source].back().trace_ = trace;
    267   }
    268 
    269   return true;
    270 }
    271 
    272 bool GPUTracer::End(GpuTracerSource source) {
    273   if (!gpu_executing_)
    274     return false;
    275 
    276   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
    277 
    278   // Pop last marker with matching 'source'
    279   if (!markers_[source].empty()) {
    280     if (IsTracing()) {
    281       scoped_refptr<GPUTrace> trace = markers_[source].back().trace_;
    282       if (trace.get()) {
    283         trace->End();
    284         if (trace->IsEnabled())
    285           traces_.push_back(trace);
    286         IssueProcessTask();
    287       }
    288     }
    289 
    290     markers_[source].pop_back();
    291     return true;
    292   }
    293   return false;
    294 }
    295 
    296 bool GPUTracer::IsTracing() {
    297   return (*gpu_trace_srv_category != 0) || (*gpu_trace_dev_category != 0);
    298 }
    299 
    300 const std::string& GPUTracer::CurrentName() const {
    301   if (last_tracer_source_ >= 0 &&
    302       last_tracer_source_ < NUM_TRACER_SOURCES &&
    303       !markers_[last_tracer_source_].empty()) {
    304     return markers_[last_tracer_source_].back().name_;
    305   }
    306   return base::EmptyString();
    307 }
    308 
    309 scoped_refptr<GPUTrace> GPUTracer::CreateTrace(const std::string& name) {
    310   GpuTracerType tracer_type = *gpu_trace_dev_category ? tracer_type_ :
    311                                                         kTracerTypeInvalid;
    312 
    313   return new GPUTrace(outputter_, name, timer_offset_, tracer_type);
    314 }
    315 
    316 void GPUTracer::Process() {
    317   process_posted_ = false;
    318   ProcessTraces();
    319   IssueProcessTask();
    320 }
    321 
    322 void GPUTracer::ProcessTraces() {
    323   if (tracer_type_ == kTracerTypeInvalid) {
    324     traces_.clear();
    325     return;
    326   }
    327 
    328   TRACE_EVENT0("gpu", "GPUTracer::ProcessTraces");
    329 
    330   // Make owning decoder's GL context current
    331   if (!decoder_->MakeCurrent()) {
    332     // Skip subsequent GL calls if MakeCurrent fails
    333     traces_.clear();
    334     return;
    335   }
    336 
    337   // Check if disjoint operation has occurred, discard ongoing traces if so.
    338   if (tracer_type_ == kTracerTypeDisjointTimer) {
    339     GLint disjoint_value = 0;
    340     glGetIntegerv(GL_GPU_DISJOINT_EXT, &disjoint_value);
    341     if (disjoint_value)
    342       traces_.clear();
    343   }
    344 
    345   while (!traces_.empty() && traces_.front()->IsAvailable()) {
    346     traces_.front()->Process();
    347     traces_.pop_front();
    348   }
    349 
    350   // Clear pending traces if there were are any errors
    351   GLenum err = glGetError();
    352   if (err != GL_NO_ERROR)
    353     traces_.clear();
    354 }
    355 
    356 void GPUTracer::CalculateTimerOffset() {
    357   if (tracer_type_ != kTracerTypeInvalid) {
    358     if (*gpu_trace_dev_category == '\0') {
    359       // If GPU device category is off, invalidate timing sync.
    360       gpu_timing_synced_ = false;
    361       return;
    362     } else if (tracer_type_ == kTracerTypeDisjointTimer) {
    363       // Disjoint timers offsets should be calculated before every query.
    364       gpu_timing_synced_ = true;
    365       timer_offset_ = 0;
    366     }
    367 
    368     if (gpu_timing_synced_)
    369       return;
    370 
    371     TRACE_EVENT0("gpu", "GPUTracer::CalculateTimerOffset");
    372 
    373     // NOTE(vmiura): It would be better to use glGetInteger64v, however
    374     // it's not available everywhere.
    375     GLuint64 gl_now = 0;
    376     GLuint query;
    377 
    378     glGenQueriesARB(1, &query);
    379 
    380     glFinish();
    381     glQueryCounter(query, GL_TIMESTAMP);
    382     glFinish();
    383 
    384     glGetQueryObjectui64v(query, GL_QUERY_RESULT, &gl_now);
    385     glDeleteQueriesARB(1, &query);
    386 
    387     base::TimeTicks system_now = base::TimeTicks::NowFromSystemTraceTime();
    388 
    389     gl_now /= base::Time::kNanosecondsPerMicrosecond;
    390     timer_offset_ = system_now.ToInternalValue() - gl_now;
    391     gpu_timing_synced_ = true;
    392   }
    393 }
    394 
    395 void GPUTracer::IssueProcessTask() {
    396   if (traces_.empty() || process_posted_)
    397     return;
    398 
    399   process_posted_ = true;
    400   base::MessageLoop::current()->PostDelayedTask(
    401       FROM_HERE,
    402       base::Bind(&GPUTracer::Process, base::AsWeakPtr(this)),
    403       base::TimeDelta::FromMilliseconds(kProcessInterval));
    404 }
    405 
    406 }  // namespace gles2
    407 }  // namespace gpu
    408