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