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
TraceMarker(const std::string & name)21 TraceMarker::TraceMarker(const std::string& name)
22 : name_(name),
23 trace_(NULL) {
24 }
25
~TraceMarker()26 TraceMarker::~TraceMarker() {
27 }
28
Create(const std::string & name)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
TraceOutputter(const std::string & name)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
~TraceOutputter()42 TraceOutputter::~TraceOutputter() { g_outputter_thread = NULL; }
43
Trace(const std::string & name,int64 start_time,int64 end_time)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
GPUTrace(scoped_refptr<Outputter> outputter,const std::string & name,int64 offset,GpuTracerType tracer_type)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
~GPUTrace()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
Start()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
End()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
IsAvailable()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
Process()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
GPUTracer(gles2::GLES2Decoder * decoder)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
~GPUTracer()198 GPUTracer::~GPUTracer() {
199 }
200
BeginDecoding()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
EndDecoding()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
Begin(const std::string & name,GpuTracerSource source)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
End(GpuTracerSource source)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
IsTracing()296 bool GPUTracer::IsTracing() {
297 return (*gpu_trace_srv_category != 0) || (*gpu_trace_dev_category != 0);
298 }
299
CurrentName() const300 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
CreateTrace(const std::string & name)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
Process()316 void GPUTracer::Process() {
317 process_posted_ = false;
318 ProcessTraces();
319 IssueProcessTask();
320 }
321
ProcessTraces()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
CalculateTimerOffset()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
IssueProcessTask()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