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/location.h"
  11 #include "base/single_thread_task_runner.h"
  12 #include "base/strings/string_util.h"
  13 #include "base/thread_task_runner_handle.h"
  14 #include "base/time/time.h"
  15 #include "base/trace_event/trace_event.h"
  16 #include "gpu/command_buffer/common/gles2_cmd_utils.h"
  17 #include "gpu/command_buffer/service/context_group.h"
  18 #include "ui/gl/gl_bindings.h"
  19 #include "ui/gl/gl_version_info.h"
  20 #include "ui/gl/gpu_timing.h"
  21
  22 namespace gpu {
  23 namespace gles2 {
  24
  25 static const unsigned int kProcessInterval = 16;
  26 static const char* kGpuTraceSourceNames[] = {
  27   "GroupMarker", // kTraceGroupMarker = 0,
  28   "TraceCHROMIUM", // kTraceCHROMIUM = 1,
  29   "TraceCmd", // kTraceDecoder = 2,
  30 };
  31 static_assert(NUM_TRACER_SOURCES == arraysize(kGpuTraceSourceNames),
  32               "Trace source names must match enumeration.");
  33
  34 static TraceOutputter* g_outputter_thread = NULL;
  35
  36 TraceMarker::TraceMarker(const std::string& category, const std::string& name)
  37     : category_(category),
  38       name_(name),
  39       trace_(NULL) {
  40 }
  41
  42 TraceMarker::~TraceMarker() {
  43 }
  44
  45 scoped_refptr<TraceOutputter> TraceOutputter::Create(const std::string& name) {
  46   if (!g_outputter_thread) {
  47     g_outputter_thread = new TraceOutputter(name);
  48   }
  49   return g_outputter_thread;
  50 }
  51
  52 TraceOutputter::TraceOutputter(const std::string& name)
  53     : named_thread_(name.c_str()) {
  54   named_thread_.Start();
  55   named_thread_.Stop();
  56 }
  57
  58 TraceOutputter::~TraceOutputter() { g_outputter_thread = NULL; }
  59
  60 void TraceOutputter::TraceDevice(GpuTracerSource source,
  61                                  const std::string& category,
  62                                  const std::string& name,
  63                                  int64 start_time,
  64                                  int64 end_time) {
  65   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
  66   TRACE_EVENT_COPY_BEGIN_WITH_ID_TID_AND_TIMESTAMP2(
  67       TRACE_DISABLED_BY_DEFAULT("gpu.device"),
  68       name.c_str(),
  69       local_trace_device_id_,
  70       named_thread_.thread_id(),
  71       start_time,
  72       "gl_category",
  73       category.c_str(),
  74       "channel",
  75       kGpuTraceSourceNames[source]);
  76   TRACE_EVENT_COPY_END_WITH_ID_TID_AND_TIMESTAMP2(
  77       TRACE_DISABLED_BY_DEFAULT("gpu.device"),
  78       name.c_str(),
  79       local_trace_device_id_,
  80       named_thread_.thread_id(),
  81       end_time,
  82       "gl_category",
  83       category.c_str(),
  84       "channel",
  85       kGpuTraceSourceNames[source]);
  86   ++local_trace_device_id_;
  87 }
  88
  89 void TraceOutputter::TraceServiceBegin(GpuTracerSource source,
  90                                        const std::string& category,
  91                                        const std::string& name) {
  92   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
  93   TRACE_EVENT_COPY_NESTABLE_ASYNC_BEGIN_WITH_TTS2(
  94       TRACE_DISABLED_BY_DEFAULT("gpu.service"),
  95       name.c_str(), local_trace_service_id_,
  96       "gl_category", category.c_str(),
  97       "channel", kGpuTraceSourceNames[source]);
  98
  99   trace_service_id_stack_[source].push(local_trace_service_id_);
 100   ++local_trace_service_id_;
 101 }
 102
 103 void TraceOutputter::TraceServiceEnd(GpuTracerSource source,
 104                                      const std::string& category,
 105                                      const std::string& name) {
 106   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
 107   DCHECK(!trace_service_id_stack_[source].empty());
 108   const uint64 local_trace_id = trace_service_id_stack_[source].top();
 109   trace_service_id_stack_[source].pop();
 110
 111   TRACE_EVENT_COPY_NESTABLE_ASYNC_END_WITH_TTS2(
 112       TRACE_DISABLED_BY_DEFAULT("gpu.service"),
 113       name.c_str(), local_trace_id,
 114       "gl_category", category.c_str(),
 115       "channel", kGpuTraceSourceNames[source]);
 116 }
 117
 118 GPUTrace::GPUTrace(scoped_refptr<Outputter> outputter,
 119                    gfx::GPUTimingClient* gpu_timing_client,
 120                    const GpuTracerSource source,
 121                    const std::string& category,
 122                    const std::string& name,
 123                    const bool tracing_service,
 124                    const bool tracing_device)
 125     : source_(source),
 126       category_(category),
 127       name_(name),
 128       outputter_(outputter),
 129       service_enabled_(tracing_service),
 130       device_enabled_(tracing_device) {
 131   if (tracing_device &&
 132       gpu_timing_client->IsAvailable() &&
 133       gpu_timing_client->IsTimerOffsetAvailable()) {
 134     gpu_timer_ = gpu_timing_client->CreateGPUTimer();
 135   }
 136 }
 137
 138 GPUTrace::~GPUTrace() {
 139 }
 140
 141 void GPUTrace::Destroy(bool have_context) {
 142   if (gpu_timer_.get()) {
 143     gpu_timer_->Destroy(have_context);
 144   }
 145 }
 146
 147 void GPUTrace::Start() {
 148   if (service_enabled_) {
 149     outputter_->TraceServiceBegin(source_, category_, name_);
 150   }
 151   if (gpu_timer_.get()) {
 152     gpu_timer_->Start();
 153   }
 154 }
 155
 156 void GPUTrace::End() {
 157   if (gpu_timer_.get()) {
 158     gpu_timer_->End();
 159   }
 160   if (service_enabled_) {
 161     outputter_->TraceServiceEnd(source_, category_, name_);
 162   }
 163 }
 164
 165 bool GPUTrace::IsAvailable() {
 166   return !gpu_timer_.get() || gpu_timer_->IsAvailable();
 167 }
 168
 169 void GPUTrace::Process() {
 170   if (gpu_timer_.get()) {
 171     DCHECK(IsAvailable());
 172
 173     int64 start = 0;
 174     int64 end = 0;
 175     gpu_timer_->GetStartEndTimestamps(&start, &end);
 176     outputter_->TraceDevice(source_, category_, name_, start, end);
 177   }
 178 }
 179
 180 GPUTracer::GPUTracer(gles2::GLES2Decoder* decoder)
 181     : gpu_trace_srv_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
 182           TRACE_DISABLED_BY_DEFAULT("gpu.service"))),
 183       gpu_trace_dev_category(TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(
 184           TRACE_DISABLED_BY_DEFAULT("gpu.device"))),
 185       decoder_(decoder),
 186       gpu_executing_(false),
 187       process_posted_(false) {
 188   DCHECK(decoder_);
 189   gfx::GLContext* context = decoder_->GetGLContext();
 190   if (context) {
 191     gpu_timing_client_ = context->CreateGPUTimingClient();
 192   } else {
 193     gpu_timing_client_ = new gfx::GPUTimingClient();
 194   }
 195 }
 196
 197 GPUTracer::~GPUTracer() {
 198 }
 199
 200 void GPUTracer::Destroy(bool have_context) {
 201   for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
 202     for (size_t i = 0; i < markers_[n].size(); i++) {
 203       TraceMarker& marker = markers_[n][i];
 204       if (marker.trace_.get()) {
 205         marker.trace_->Destroy(have_context);
 206         marker.trace_ = 0;
 207       }
 208     }
 209   }
 210
 211   ClearFinishedTraces(have_context);
 212 }
 213
 214 bool GPUTracer::BeginDecoding() {
 215   if (gpu_executing_)
 216     return false;
 217
 218   if (!outputter_) {
 219     outputter_ = CreateOutputter(gpu_timing_client_->GetTimerTypeName());
 220   }
 221
 222   if (*gpu_trace_dev_category == '\0') {
 223     // If GPU device category is off, invalidate timing sync.
 224     gpu_timing_client_->InvalidateTimerOffset();
 225   }
 226
 227   gpu_executing_ = true;
 228   if (IsTracing()) {
 229     gpu_timing_client_->CheckAndResetTimerErrors();
 230     // Begin a Trace for all active markers
 231     for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
 232       for (size_t i = 0; i < markers_[n].size(); i++) {
 233         TraceMarker& trace_marker = markers_[n][i];
 234         trace_marker.trace_ =
 235             new GPUTrace(outputter_, gpu_timing_client_.get(),
 236                          static_cast<GpuTracerSource>(n),
 237                          trace_marker.category_, trace_marker.name_,
 238                          *gpu_trace_srv_category != 0,
 239                          *gpu_trace_dev_category != 0);
 240         trace_marker.trace_->Start();
 241       }
 242     }
 243   }
 244   return true;
 245 }
 246
 247 bool GPUTracer::EndDecoding() {
 248   if (!gpu_executing_)
 249     return false;
 250
 251   // End Trace for all active markers
 252   if (IsTracing()) {
 253     for (int n = 0; n < NUM_TRACER_SOURCES; n++) {
 254       if (!markers_[n].empty()) {
 255         for (int i = static_cast<int>(markers_[n].size()) - 1; i >= 0; --i) {
 256           TraceMarker& marker = markers_[n][i];
 257           if (marker.trace_.get()) {
 258             marker.trace_->End();
 259
 260             finished_traces_.push_back(marker.trace_);
 261             marker.trace_ = 0;
 262           }
 263         }
 264       }
 265     }
 266     IssueProcessTask();
 267   }
 268
 269   gpu_executing_ = false;
 270
 271   // NOTE(vmiura): glFlush() here can help give better trace results,
 272   // but it distorts the normal device behavior.
 273   return true;
 274 }
 275
 276 bool GPUTracer::Begin(const std::string& category, const std::string& name,
 277                       GpuTracerSource source) {
 278   if (!gpu_executing_)
 279     return false;
 280
 281   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
 282
 283   // Push new marker from given 'source'
 284   markers_[source].push_back(TraceMarker(category, name));
 285
 286   // Create trace
 287   if (IsTracing()) {
 288     scoped_refptr<GPUTrace> trace = new GPUTrace(
 289         outputter_, gpu_timing_client_.get(), source, category, name,
 290         *gpu_trace_srv_category != 0,
 291         *gpu_trace_dev_category != 0);
 292     trace->Start();
 293     markers_[source].back().trace_ = trace;
 294   }
 295
 296   return true;
 297 }
 298
 299 bool GPUTracer::End(GpuTracerSource source) {
 300   if (!gpu_executing_)
 301     return false;
 302
 303   DCHECK(source >= 0 && source < NUM_TRACER_SOURCES);
 304
 305   // Pop last marker with matching 'source'
 306   if (!markers_[source].empty()) {
 307     scoped_refptr<GPUTrace> trace = markers_[source].back().trace_;
 308     if (trace.get()) {
 309       if (IsTracing()) {
 310         trace->End();
 311       }
 312
 313       finished_traces_.push_back(trace);
 314       IssueProcessTask();
 315     }
 316
 317     markers_[source].pop_back();
 318     return true;
 319   }
 320   return false;
 321 }
 322
 323 bool GPUTracer::IsTracing() {
 324   return (*gpu_trace_srv_category != 0) || (*gpu_trace_dev_category != 0);
 325 }
 326
 327 const std::string& GPUTracer::CurrentCategory(GpuTracerSource source) const {
 328   if (source >= 0 &&
 329       source < NUM_TRACER_SOURCES &&
 330       !markers_[source].empty()) {
 331     return markers_[source].back().category_;
 332   }
 333   return base::EmptyString();
 334 }
 335
 336 const std::string& GPUTracer::CurrentName(GpuTracerSource source) const {
 337   if (source >= 0 &&
 338       source < NUM_TRACER_SOURCES &&
 339       !markers_[source].empty()) {
 340     return markers_[source].back().name_;
 341   }
 342   return base::EmptyString();
 343 }
 344
 345 scoped_refptr<Outputter> GPUTracer::CreateOutputter(const std::string& name) {
 346   return TraceOutputter::Create(name);
 347 }
 348
 349 void GPUTracer::PostTask() {
 350   base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
 351       FROM_HERE, base::Bind(&GPUTracer::Process, base::AsWeakPtr(this)),
 352       base::TimeDelta::FromMilliseconds(kProcessInterval));
 353 }
 354
 355 void GPUTracer::Process() {
 356   process_posted_ = false;
 357   ProcessTraces();
 358   IssueProcessTask();
 359 }
 360
 361 void GPUTracer::ProcessTraces() {
 362   if (!gpu_timing_client_->IsAvailable()) {
 363     ClearFinishedTraces(false);
 364     return;
 365   }
 366
 367   TRACE_EVENT0("gpu", "GPUTracer::ProcessTraces");
 368
 369   // Make owning decoder's GL context current
 370   if (!decoder_->MakeCurrent()) {
 371     // Skip subsequent GL calls if MakeCurrent fails
 372     ClearFinishedTraces(false);
 373     return;
 374   }
 375
 376   // Check if timers are still valid (e.g: a disjoint operation
 377   // might have occurred.)
 378   if (gpu_timing_client_->CheckAndResetTimerErrors()) {
 379     ClearFinishedTraces(true);
 380   }
 381
 382   while (!finished_traces_.empty()) {
 383     scoped_refptr<GPUTrace>& trace = finished_traces_.front();
 384     if (trace->IsDeviceTraceEnabled()) {
 385       if (!finished_traces_.front()->IsAvailable())
 386         break;
 387       finished_traces_.front()->Process();
 388     }
 389     finished_traces_.front()->Destroy(true);
 390     finished_traces_.pop_front();
 391   }
 392
 393   // Clear pending traces if there were are any errors
 394   GLenum err = glGetError();
 395   if (err != GL_NO_ERROR)
 396     ClearFinishedTraces(true);
 397 }
 398
 399 void GPUTracer::ClearFinishedTraces(bool have_context) {
 400   while (!finished_traces_.empty()) {
 401     finished_traces_.front()->Destroy(have_context);
 402     finished_traces_.pop_front();
 403   }
 404 }
 405
 406 void GPUTracer::IssueProcessTask() {
 407   if (finished_traces_.empty() || process_posted_)
 408     return;
 409
 410   process_posted_ = true;
 411   PostTask();
 412 }
 413
 414 }  // namespace gles2
 415 }  // namespace gpu