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