Trace_event upgrades

This CL covers a targeted set of upgrades to the trace_event system in order to improve our perf monitoring capabilities for GPU.

1. Add parameters to trace events, instead of just an ID paramter.

2. Add categories to trace events.

3. Make output of trace data driven by an output callback rather than hard-wired to a file/ETW. Allows WebUI to be written that hooks traced data for analysis/display.

4. Forward trace data from render and gpu processes up to the browser process.

We tried to preserve the old output-to-ETW behavior and the implicit "id" parameter. This is embodied in the TRACE_*_LEGACY macros.

[arv (Not doing code reviews), 2011-02-23 17:51:25]

I only looked at the js

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
File chrome/browser/resources/gpu_internals/tracing_controller.js (right):

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:6: this.overlay_ =
$('gpu-tracing-overlay');
I know we do this a lot in the options code but using a static (the DOM element)
in an instance always seems dirty to me. How about passing in an overlay
instance instead?

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:9:
this.tracingEnabled_ = false;
I would move this to the prototype.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:15: initUI :
function(mainTabs) {
no ws before :

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:20:
startButton.onclick = function() {
startButton.onclick = this.beginTracing.bind(this);

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:35:
if(this.tracingEnabled_) throw new Error("Tracing already begun.");
line break

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:35:
if(this.tracingEnabled_) throw new Error("Tracing already begun.");
new is not needed here

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:40:
console.log("Beginning to trace...");
Use single quotes

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:56:
this.currentlyBoundKeypressListener_ = this.onOverlayKeyPress_.bind(this);
I'm not sure this is cleaner but this can also be done as:

var self = this;
window.addEventListener('keypress', function f(e) {
  window.removeEventListener('keypress', f);
  self.onOverlayKeyPress_(e);
});

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:62: if(e.charCode
== 13) { // enter
if (e.keyIdentifier == 'Enter')

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:62: if(e.charCode
== 13) { // enter
Whitespace after if

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:70:
isGpuTracingEnabled : function() {
Maybe use a getter?

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:78:
getGpuTraceEvents : function() {
getter?

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:99:
if(!browserBridge.debugMode)
If else has curly braces then if should too

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:121:
this.endTracing();
this.endTracing.bind(this)

[scheib, 2011-02-23 21:34:09]

Ah, one more nit, is this include needed:

http://codereview.chromium.org/6551019/diff/1/chrome/browser/gpu_process_host.cc
File chrome/browser/gpu_process_host.cc (right):

http://codereview.chromium.org/6551019/diff/1/chrome/browser/gpu_process_host...
chrome/browser/gpu_process_host.cc:8: #include "base/command_line.h"
This include is the only change to this file -- is it needed?

[nduca, 2011-02-23 23:34:13]

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
File chrome/browser/resources/gpu_internals/tracing_controller.js (right):

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:6: this.overlay_ =
$('gpu-tracing-overlay');
I agree, it smells bad. I think there are two 'wrong' cases that are worth
distinguishing:
1. Where we are trying to decorate an existing DOM node that was part of the
original page
2. Where the component has some private dom nodes that are used internally to
it.

I'm guilty of both of these, to be sure. I think the TracingController is case
2...

I notice in things like Closure, dom structures private to a component are just
created by building the DOM in script, rather than by having some inlined HTML
in the original document.

So what about one of the following:
1. don't inline, generate the overlay's div on the fly [eew]
2. Still inline the private nodes as a template and deepCopy them into a Overlay
instance during TracingController's init.



On 2011/02/23 17:51:25, arv wrote:
> I know we do this a lot in the options code but using a static (the DOM
element)
> in an instance always seems dirty to me. How about passing in an overlay
> instance instead?

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:9:
this.tracingEnabled_ = false;
On 2011/02/23 17:51:25, arv wrote:
> I would move this to the prototype.

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:15: initUI :
function(mainTabs) {
On 2011/02/23 17:51:25, arv wrote:
> no ws before :

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:20:
startButton.onclick = function() {
On 2011/02/23 17:51:25, arv wrote:
> startButton.onclick = this.beginTracing.bind(this);

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:35:
if(this.tracingEnabled_) throw new Error("Tracing already begun.");
On 2011/02/23 17:51:25, arv wrote:
> new is not needed here

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:56:
this.currentlyBoundKeypressListener_ = this.onOverlayKeyPress_.bind(this);
Thats pretty neat. I dislike that less than I would have first thought. Closure
seems to put a wrapper around major EventTargets such that a fourth parameter
for the addEventListener is the binding context for the callback,e.g:
 addEventListener('foo', myMethod, false, this);

I can't think of a clean way to make this work in cr.js land, though. If
anything jumps out to you, I'm happy to code it up.

On 2011/02/23 17:51:25, arv wrote:
> I'm not sure this is cleaner but this can also be done as:
> 
> var self = this;
> window.addEventListener('keypress', function f(e) {
>   window.removeEventListener('keypress', f);
>   self.onOverlayKeyPress_(e);
> });

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:62: if(e.charCode
== 13) { // enter
On 2011/02/23 17:51:25, arv wrote:
> Whitespace after if

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:70:
isGpuTracingEnabled : function() {
On 2011/02/23 17:51:25, arv wrote:
> Maybe use a getter?

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:78:
getGpuTraceEvents : function() {
On 2011/02/23 17:51:25, arv wrote:
> getter?

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:99:
if(!browserBridge.debugMode)
On 2011/02/23 17:51:25, arv wrote:
> If else has curly braces then if should too

Done.

http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
chrome/browser/resources/gpu_internals/tracing_controller.js:121:
this.endTracing();
On 2011/02/23 17:51:25, arv wrote:
> this.endTracing.bind(this)

Done.

[arv (Not doing code reviews), 2011-02-24 18:25:31]

On Wed, Feb 23, 2011 at 15:34,  <nduca@chromium.org> wrote:
>
>
http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
> File chrome/browser/resources/gpu_internals/tracing_controller.js
> (right):
>
>
http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
> chrome/browser/resources/gpu_internals/tracing_controller.js:6:
> this.overlay_ = $('gpu-tracing-overlay');
> I agree, it smells bad. I think there are two 'wrong' cases that are
> worth distinguishing:
> 1. Where we are trying to decorate an existing DOM node that was part of
> the original page
> 2. Where the component has some private dom nodes that are used
> internally to it.
>
> I'm guilty of both of these, to be sure. I think the TracingController
> is case 2...
>
> I notice in things like Closure, dom structures private to a component
> are just created by building the DOM in script, rather than by having
> some inlined HTML in the original document.

Not true. The Closure UI framework has two methods, createDom (which
builds the DOM imperatively) and decorate which takes an existing DOM.

> So what about one of the following:
> 1. don't inline, generate the overlay's div on the fly [eew]
> 2. Still inline the private nodes as a template and deepCopy them into a
> Overlay instance during TracingController's init.

Another option is to not use document.getElementById(id) and instead
use element.querySelector(class)

-- 
erik

[nduca, 2011-02-24 21:55:06]

Oh! Didn't know that, thanks for keeping me honest. 

For the TraceController, I'm going to go for not using an html template at all
and just creating stuff in script.

On 2011/02/24 18:25:31, arv wrote:
> On Wed, Feb 23, 2011 at 15:34,  <mailto:nduca@chromium.org> wrote:
> >
> >
>
http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
> > File chrome/browser/resources/gpu_internals/tracing_controller.js
> > (right):
> >
> >
>
http://codereview.chromium.org/6551019/diff/1/chrome/browser/resources/gpu_in...
> > chrome/browser/resources/gpu_internals/tracing_controller.js:6:
> > this.overlay_ = $('gpu-tracing-overlay');
> > I agree, it smells bad. I think there are two 'wrong' cases that are
> > worth distinguishing:
> > 1. Where we are trying to decorate an existing DOM node that was part of
> > the original page
> > 2. Where the component has some private dom nodes that are used
> > internally to it.
> >
> > I'm guilty of both of these, to be sure. I think the TracingController
> > is case 2...
> >
> > I notice in things like Closure, dom structures private to a component
> > are just created by building the DOM in script, rather than by having
> > some inlined HTML in the original document.
> 
> Not true. The Closure UI framework has two methods, createDom (which
> builds the DOM imperatively) and decorate which takes an existing DOM.
> 
> > So what about one of the following:
> > 1. don't inline, generate the overlay's div on the fly [eew]
> > 2. Still inline the private nodes as a template and deepCopy them into a
> > Overlay instance during TracingController's init.
> 
> Another option is to not use document.getElementById(id) and instead
> use element.querySelector(class)
> 
> -- 
> erik

[scheib, 2011-02-24 22:04:30]

brettw, or sjl, 

We could use some review particularly on the trace_event* files. Brett, you're
senior, Steve, you expressed interest.

[arv (Not doing code reviews), 2011-02-25 00:51:29]

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
File chrome/browser/resources/gpu_internals/info_view.js (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/info_view.js:122: if(window.jstProcess)
ws after if, while, for etc. (I guess the only exception is after function)

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/info_view.js:122: if(window.jstProcess)
if (typeof jstProcess != 'undefined') {

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
File chrome/browser/resources/gpu_internals/raw_events_view.js (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/raw_events_view.js:16: RawEventsView =
cr.ui.define(gpu.Tab);
missing var

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/raw_events_view.js:28:
on_selected_change_ : function() {
no underscores

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/raw_events_view.js:50: var tmp = "Still
tracing.";
use singel quotes

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/raw_events_view.js:52:
dataElement.innerText = tmp;
dataelement.textContent = '...' +
    '...';

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/raw_events_view.js:54:
dataElement.innerText = "No trace data collected. Collect data first.";
In general use textContent. innerText does a lot of strange things with
whitespace. If you need prefermatted text use a pre element or use white-space:
pre.

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
File chrome/browser/resources/gpu_internals/tracing_controller.css (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.css:29: background:
rgb(255,0,0);
ws after comma

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.css:30: border-left:
1px solid black;
Sometimes it gets shorter to do:

border: 1px solid black;
border-bottom: 0;

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
File chrome/browser/resources/gpu_internals/tracing_controller.js (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.js:4: cr.define('gpu',
function() {
Can you add an empty line before this?

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.js:7:
this.overlay_.removeAttribute('id');
Prefer DOM properties where possible

this.overlay_.id = '';

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.js:54:
if(e.keyIdentifier == 'Enter') {
ws

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.js:94:
if(window.getTimelineTestData1){
ws

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.js:94:
if(window.getTimelineTestData1){
or

events = window.getTimelineTestData1 ? getTimelineTestData1() : [];

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/resources/gpu...
chrome/browser/resources/gpu_internals/tracing_controller.js:103: /* Called by
the browser when all processes ack tracing having completed. */
Use JSDoc

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/webui/gpu_int...
File chrome/browser/webui/gpu_internals_ui.cc (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/webui/gpu_int...
chrome/browser/webui/gpu_internals_ui.cc:426: const char* json_complete =
"['TRACE_ENDED']";
JSON always use double quotes... I looks like this might cause trouble

[Ken Russell (switch to Gerrit), 2011-02-25 00:56:36]

This mostly looks great to me though someone with more experience with the
tracing code needs to review those changes.

Please send this CL through the try servers.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.cc
File base/debug/trace_event.cc (right):

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.cc#ne...
base/debug/trace_event.cc:68: out += "]";
Are there more efficient ways of building up C++ strings than using the +
operator?

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:31: // The trace system will automaticlaly add to this
information the
typo: automaticlaly

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:60: #define UNIQUE_IDENTIFIER2(a,b)
UNIQUE_IDENTIFIER3(a,b) // __LINE__ eval forced
Is this forced evaluation of the __LINE__ macro guaranteed to be portable among
preprocessors?

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:64: // end of the current scope, with one associated
argument. If the
"with one associated argument" -- is this accurate?

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:85: // associated argument. If the category is not
enabled, then this
Same question here.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:186: static void AppendAsJSON(std::string& out,
The Google C++ style guide says that all reference arguments must be const.
http://google-styleguide.googlecode.com/svn/trunk/cppguide.xml#Reference_Argu...

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:188: void AppendAsJSON(std::string& out) const;
Same here.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:251: // there are a ton of things we can to reduce
thread synchronization.
Perhaps a TODO(nduca): here then?

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:262: class TraceEndOnScopeClose {
This class isn't supposed to be accessed externally, right? Is there any way of
hiding it, or at least adding a comment to that effect?

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:281: protected:
Why are these protected and not private?

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/renderer_host...
File chrome/browser/renderer_host/render_message_filter.h (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/renderer_host...
chrome/browser/renderer_host/render_message_filter.h:332: void
OnTraceDataCollectedRemotelyOnUIThread(const std::string& json_events);
The latter should be private if you need it at all. I think you can just call
TraceLog::GetInstance() from the IO thread and post the RunnableMethod against
it directly form within OnTraceDataCollectedRemotely. Look around in the source
base to see if there are other patterns like this.

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/renderer_host...
File chrome/browser/renderer_host/render_process_host.cc (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/browser/renderer_host...
chrome/browser/renderer_host/render_process_host.cc:96: // TODO(nduca): if a
process is crated while enabled,
crated -> created

http://codereview.chromium.org/6551019/diff/5001/chrome/renderer/render_threa...
File chrome/renderer/render_thread.cc (right):

http://codereview.chromium.org/6551019/diff/5001/chrome/renderer/render_threa...
chrome/renderer/render_thread.cc:233: // Forward GPU trace data unless we are in
single-process mode.
I'd avoid the reference to the GPU here -- the tracing mechanism is general.

http://codereview.chromium.org/6551019/diff/5001/chrome/renderer/render_threa...
chrome/renderer/render_thread.cc:309: // Clean up GPU_TRACE
Remove apparently obsolete comment.

[scheib, 2011-02-25 17:59:31]

rvargas, brettw suggested adding you as you've been a user of trace event, could
you take a look at the trace_event* files in this review?

[brettw, 2011-02-25 18:30:02]

Added Siggi who wrote most of the trace event code.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:59: #define UNIQUE_IDENTIFIER3(a,b) a##b
I don't think it's a good idea to leak these generic macro names.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:71: static base::debug::TraceCategory*
UNIQUE_IDENTIFIER(catstatic) = \
Is this static really necessary? Can you just call GetCategory every time and
avoid the UNIQUE_IDENTIFIER macros?

Keep in mind this expands to the following code.
  static bool initialized = false;
  static TraceCategory* foo;
  if (!initialized) {
    initialized = true;
    foo = base::debug::TraceLog::GetInstance()->GetCategory(category); 
  }

There is a race condition initializing the parameter. This is why we use
Singleton which contains code that avoids this. In your case, it's possible that
the race condition won't matter, but it still seems like a bad idea to do this
in a macro that may be used from multithreaded code.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:75: base::debug::TRACE_EVENT_PHASE_BEGIN, \
Indent wrapped lines 4 spaces. Same elsewhere.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:127: if
(base::subtle::Acquire_Load(&(UNIQUE_IDENTIFIER(catstatic))->enabled_)) \
Multi-line conditions should use {}

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:161: public:
Indent these one char.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:263: public:
Indent these one char.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:265: TraceCategory* category,
Params should be aligned (should be under the const).

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:267: : file_(file),
: should only be indented 4 spaces (4 fewer than now).

[Sigurður Ásgeirsson, 2011-02-25 19:54:42]

Sorry guys, I'm OOO for the next week. I'd be happy to take a look after I
come back...

On Fri, Feb 25, 2011 at 1:30 PM, <brettw@chromium.org> wrote:

> Added Siggi who wrote most of the trace event code.
>
>
> http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h
> File base/debug/trace_event.h (right):
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:59: #define UNIQUE_IDENTIFIER3(a,b) a##b
> I don't think it's a good idea to leak these generic macro names.
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:71: static base::debug::TraceCategory*
> UNIQUE_IDENTIFIER(catstatic) = \
> Is this static really necessary? Can you just call GetCategory every
> time and avoid the UNIQUE_IDENTIFIER macros?
>
> Keep in mind this expands to the following code.
>  static bool initialized = false;
>  static TraceCategory* foo;
>  if (!initialized) {
>    initialized = true;
>    foo = base::debug::TraceLog::GetInstance()->GetCategory(category);
>  }
>
> There is a race condition initializing the parameter. This is why we use
> Singleton which contains code that avoids this. In your case, it's
> possible that the race condition won't matter, but it still seems like a
> bad idea to do this in a macro that may be used from multithreaded code.
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:75: base::debug::TRACE_EVENT_PHASE_BEGIN, \
> Indent wrapped lines 4 spaces. Same elsewhere.
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:127: if
> (base::subtle::Acquire_Load(&(UNIQUE_IDENTIFIER(catstatic))->enabled_))
> \
> Multi-line conditions should use {}
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:161: public:
> Indent these one char.
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:263: public:
> Indent these one char.
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:265: TraceCategory* category,
> Params should be aligned (should be under the const).
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:267: : file_(file),
> : should only be indented 4 spaces (4 fewer than now).
>
> http://codereview.chromium.org/6551019/
>

[rvargas (doing something else), 2011-02-25 23:38:33]

It looks like this will break the current chrome frame usage.

Given that Siggi is out, maybe Robert or Tommi could take a real look.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.cc
File base/debug/trace_event.cc (right):

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.cc#ne...
base/debug/trace_event.cc:21: #define GPU_TRACE_MAX_EVENTS_TO_BUFFER 16384
?

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:37: // application. In Chrome's case, navigating to
about:gpu will turn on
Is this really going to be the case?.

[tommi (sloooow) - chröme, 2011-02-27 17:44:35]

From skimming over this change it feels like the logging system is being
bent to one specific client's needs.
Since the change is pretty huge for the logging system, is it an option to
put the changelist on ice
(maybe fix all the style issues in the meantime - please run: gcl lint)
until Siggi gets back?

On Fri, Feb 25, 2011 at 6:38 PM, <rvargas@chromium.org> wrote:

> It looks like this will break the current chrome frame usage.
>
> Given that Siggi is out, maybe Robert or Tommi could take a real look.
>
>
> http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.cc
> File base/debug/trace_event.cc (right):
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.cc#ne...
> base/debug/trace_event.cc:21: #define GPU_TRACE_MAX_EVENTS_TO_BUFFER
> 16384
>
> ?
>
> http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h
> File base/debug/trace_event.h (right):
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:37: // application. In Chrome's case,
> navigating to about:gpu will turn on
> Is this really going to be the case?.
>
>
> http://codereview.chromium.org/6551019/
>

[nduca, 2011-03-02 04:15:12]

Thanks for the feedback folks.

I'm fine waiting for Siggi's return to discuss things further.

I will do a spin of the current CL to make the feature additions non-breaking,
e.g. leave the TRACE_EVENT_BEGIN/END/INSTANT macros undisturbed. I hope this
will address the chrome frame concerns.

I sympathize with the comment that we are bending the trace system. That's
definitely the case. I guess my question is, do any of the "bends" seem wrong or
out-of-place?

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:37: // application. In Chrome's case, navigating to
about:gpu will turn on
On 2011/02/25 23:38:33, rvargas wrote:
> Is this really going to be the case?.
This is a bit of a typo. The real answer is that tracing is off until someone
enables it. That is either an about:gpu user making a recording [big red "Record
now" button that they press] or on windows, a developer connecting with an ETW
event consumer. If neither of those conditions is met, then tracing macros are
equivalent to a check of an enabled flag on a singleton.

http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
base/debug/trace_event.h:71: static base::debug::TraceCategory*
UNIQUE_IDENTIFIER(catstatic) = \
I should probably have been more clear in the code that we understand and
survive gracefully the race condition you mention. While I haven't polished this
implementation completely [we don't handle shutdown quite right but its fixable]
the idea is that a category pointers is itself a  singleton --- while you might
set the category pointer twice, you get back the same pointer both times.



On 2011/02/25 18:30:03, brettw wrote:
> Is this static really necessary? Can you just call GetCategory every time and
> avoid the UNIQUE_IDENTIFIER macros?
> 
> Keep in mind this expands to the following code.
>   static bool initialized = false;
>   static TraceCategory* foo;
>   if (!initialized) {
>     initialized = true;
>     foo = base::debug::TraceLog::GetInstance()->GetCategory(category); 
>   }
> 
> There is a race condition initializing the parameter. This is why we use
> Singleton which contains code that avoids this. In your case, it's possible
that
> the race condition won't matter, but it still seems like a bad idea to do this
> in a macro that may be used from multithreaded code.

[scheib, 2011-03-08 00:24:58]

Could we get a clarification of expected current usage?

siggi mentioned on another thread, "I'm fine with adding features to the
trace macros, and I don't think anyone's using the instrumentation currently
there."

rvargas mentioned "It looks like this will break the current chrome frame
usage."

Do we know explicitly that it will be one or the other? rvargas, are you
stating that it will break chrome frame, or that it might? If yes, where?

If no one is currently relying on existing behavior, let's move forward with
making improvements to the system without wasting effort trying to support
non-existent users. We put out a call for responses in January to chrome-dev
and haven't heard from anyone currently using existing instrumentation.

On Tue, Mar 1, 2011 at 8:15 PM, <nduca@chromium.org> wrote:

> Thanks for the feedback folks.
>
> I'm fine waiting for Siggi's return to discuss things further.
>
> I will do a spin of the current CL to make the feature additions
> non-breaking,
> e.g. leave the TRACE_EVENT_BEGIN/END/INSTANT macros undisturbed. I hope
> this
> will address the chrome frame concerns.
>
> I sympathize with the comment that we are bending the trace system. That's
> definitely the case. I guess my question is, do any of the "bends" seem
> wrong or
> out-of-place?
>
>
>
> http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h
> File base/debug/trace_event.h (right):
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:37: // application. In Chrome's case,
> navigating to about:gpu will turn on
> On 2011/02/25 23:38:33, rvargas wrote:
>
>> Is this really going to be the case?.
>>
> This is a bit of a typo. The real answer is that tracing is off until
> someone enables it. That is either an about:gpu user making a recording
> [big red "Record now" button that they press] or on windows, a developer
> connecting with an ETW event consumer. If neither of those conditions is
> met, then tracing macros are equivalent to a check of an enabled flag on
> a singleton.
>
>
>
>
http://codereview.chromium.org/6551019/diff/5001/base/debug/trace_event.h#new...
> base/debug/trace_event.h:71: static base::debug::TraceCategory*
> UNIQUE_IDENTIFIER(catstatic) = \
> I should probably have been more clear in the code that we understand
> and survive gracefully the race condition you mention. While I haven't
> polished this implementation completely [we don't handle shutdown quite
> right but its fixable] the idea is that a category pointers is itself a
> singleton --- while you might set the category pointer twice, you get
> back the same pointer both times.
>
>
>
>
> On 2011/02/25 18:30:03, brettw wrote:
>
>> Is this static really necessary? Can you just call GetCategory every
>>
> time and
>
>> avoid the UNIQUE_IDENTIFIER macros?
>>
>
>  Keep in mind this expands to the following code.
>>   static bool initialized = false;
>>   static TraceCategory* foo;
>>   if (!initialized) {
>>     initialized = true;
>>     foo = base::debug::TraceLog::GetInstance()->GetCategory(category);
>>
>
>    }
>>
>
>  There is a race condition initializing the parameter. This is why we
>>
> use
>
>> Singleton which contains code that avoids this. In your case, it's
>>
> possible that
>
>> the race condition won't matter, but it still seems like a bad idea to
>>
> do this
>
>> in a macro that may be used from multithreaded code.
>>
>
> http://codereview.chromium.org/6551019/
>

[rvargas (doing something else), 2011-03-08 01:01:31]

On 2011/03/08 00:24:58, scheib wrote:
> Could we get a clarification of expected current usage?
> 
> siggi mentioned on another thread, "I'm fine with adding features to the
> trace macros, and I don't think anyone's using the instrumentation currently
> there."
> 
> rvargas mentioned "It looks like this will break the current chrome frame
> usage."
> 
> Do we know explicitly that it will be one or the other? rvargas, are you
> stating that it will break chrome frame, or that it might? If yes, where?

I'm not familiar with what chrome frame is using, but a code search shows a few
files under src/chrome_frame using EVENT_TRACE_, and they are not touched by
this cl.

The only high level comment that I have at this time is that if we expect this
code to be used by different modules, stating that about:gpu is the place to
configure it sounds bad (and having a constant named gpu_xx). If the only
expected user is gpu tracing then base may not be the right place.

[Sigurður Ásgeirsson, 2011-03-08 14:02:53]

I have no objection to this change in principle, and it seems like a good idea
to allow in-browser viewing of the trace data. From experience with collating
trace data, I think you might be better off with something more unique than
string to match begin/end pairs. The original idea with the id parameter is to
allow passing in a per-process unique value, like e.g. a this pointer.
Like Rick, I question whether this is a case of premature generalization, e.g.
it seems that the specific goal here is to capture metrics for GPU rendering,
and the change looks pretty drastic in that context. Maybe it's a better idea to
create a parallel implementation out of base, and migrate it into base once
there's a demonstrated need from more users. This would also save you the effort
of making sure you can deal with multiple consumers in the short term (since
presumably a generic mechanism would need to be able to cater to multiple
sinks?).
Be mindful in implementation and testing of a general base mechanism, that there
are base users who don't tolerate leaking objects - Chrome Frame in particular.

Since this change touches widely, has hairy-*** threading behavior and does IPC,
I'd expect that you'd need some unittests at minimum. The change incidentally
neglects to update the trace_event_win_unittest.cc.

Also, I'd expect you to fix all users of the current tracing implementation to
either maintain their current usage, to migrate them to equivalent
functionality, or get their consent to drop the usage.

As you've noticed, the _win implementation is pretty standalone, and the sole
real user of that implementation (Chrome Frame, AFAICS) is also Windows only. If
you decide you want to supplant the existing trace event interface, is to change
the _LEGACY macros to _WIN, make Chrome Frame include the _win headers and
invoke the _WIN macros.

I'd be more than happy to do a detailed review of changes to the windows
implementation if you decide to go forward, but I don't currently have the time
to commit to reviewing a change of this scope in detail.

[nduca, 2011-03-08 22:36:00]

Neat points, a few thoughts in response:

0. A few of us GPU folks highly value tracing as a basic infrastructural
capability. We're willing to do the work to make a system worthy of that title.
In particular, I see no problem adding unit tests, supporting multiple
consumers, perhaps even having about:trace_event.

1. I think in keeping with the above goal, my aim would be to make the ETW
backend continue to work, since it ties into Sawbuck as well as provides 
infrastructure for chrome_frame_perf_test and Siggi's profile guided linking
work. Macro wise, I think the right thing to do is have only one set of macros
--- we will change all the instrumentation to use the new tracing macros.

2. With regard to trace events having strings on their end, that's a neat point.
I looked at the ETW-based perf test for chrome frame and I see how having
arguments on the end token makes parsing simpler for that type of use case. The
flip side of this is that for things like a timeline visualization, it opens up
a whole can of worms --- can you make begin-end pairs non-nested, e.g.:
   thread 1: BEGIN frame
   thread 1: BEGIN somethingElse
   thread 1: END frame
   thread 1: END somethingElse
I'm not religious on this one way or another, just thought I'd throw it out as
why I opted to not allow arguments on the end token.

[Sigurður Ásgeirsson, 2011-03-09 14:48:33]

On Tue, Mar 8, 2011 at 5:36 PM, <nduca@chromium.org> wrote:

> Neat points, a few thoughts in response:
>
> 0. A few of us GPU folks highly value tracing as a basic infrastructural
> capability. We're willing to do the work to make a system worthy of that
> title.
> In particular, I see no problem adding unit tests, supporting multiple
> consumers, perhaps even having about:trace_event.
>
> SGTM.


> 1. I think in keeping with the above goal, my aim would be to make the ETW
> backend continue to work, since it ties into Sawbuck as well as provides
> infrastructure for chrome_frame_perf_test and Siggi's profile guided
> linking
> work. Macro wise, I think the right thing to do is have only one set of
> macros
> --- we will change all the instrumentation to use the new tracing macros.
>
>
Sawbuck and ETW are pretty flexible to whatever scheme you come up with, and
I'll happily update the ETW integration and Sawbuck to suit. The only thing
I'd ask for, for that, is a way to crank up the trace level, and some way to
hook into the events as they occur. This should ideally not incur whatever
overhead is normally to the scheme, e.g. your X-process transport and
intermediate storage.


> 2. With regard to trace events having strings on their end, that's a neat
> point.
> I looked at the ETW-based perf test for chrome frame and I see how having
> arguments on the end token makes parsing simpler for that type of use case.
> The
> flip side of this is that for things like a timeline visualization, it
> opens up
> a whole can of worms --- can you make begin-end pairs non-nested, e.g.:
>   thread 1: BEGIN frame
>   thread 1: BEGIN somethingElse
>   thread 1: END frame
>   thread 1: END somethingElse
> I'm not religious on this one way or another, just thought I'd throw it out
> as
> why I opted to not allow arguments on the end token.
>
>
Oh, I think you misunderstand what I was trying to say. What I was trying to
say is that the ID parameter to the original macros is a void*, and if you
pass in a pointer to some variable or object, you're guaranteed the value is
unique within the process, which makes it trivial to match events. This
would allow the BEGIN/END macros to e.g. track lifetimes of heap-allocated
objects, whose lifetimes will likely be non-nested. In Sawbuck (or other ETW
viewers), you could then do interesting visualization of this data.
Imagine e.g. how it would have simplified tracking down the GMail DOM issue
if each DOM object traced on creation and deletion.


>
>
> http://codereview.chromium.org/6551019/
>

[scheib, 2011-03-10 19:54:24]

On Begin End arguments:

Q: is any system currently using the id values? (I couldn't find such in

Future Proposal: We accept multiple arguments on both Begin and End. An
analyzer matching Begin End pairs can use just the name, or if e.g. id
matching is ever desired, can check that all arguments provided in both
begin and end match.
e.g. all these are easy to match:
BEGIN("category", "name1")
BEGIN("category", "name2", "id", pointerA, "info at begin", infoBegin)
BEGIN("category", "name2", "id", pointerB)
END("category", "name1")
END("category", "name2", "id", pointerA)
END("category", "name2", "id", pointerB, "info at end", infoEnd)

Today Proposal: We don't have any use case needed parameters on the END
events yet, so we don't build that out yet.

 2. With regard to trace events having strings on their end, that's a neat
>> point.
>> I looked at the ETW-based perf test for chrome frame and I see how having
>> arguments on the end token makes parsing simpler for that type of use
>> case. The
>> flip side of this is that for things like a timeline visualization, it
>> opens up
>> a whole can of worms --- can you make begin-end pairs non-nested, e.g.:
>>   thread 1: BEGIN frame
>>   thread 1: BEGIN somethingElse
>>   thread 1: END frame
>>   thread 1: END somethingElse
>> I'm not religious on this one way or another, just thought I'd throw it
>> out as
>> why I opted to not allow arguments on the end token.
>>
>>
> Oh, I think you misunderstand what I was trying to say. What I was trying
> to say is that the ID parameter to the original macros is a void*, and if
> you pass in a pointer to some variable or object, you're guaranteed the
> value is unique within the process, which makes it trivial to match
> events. This would allow the BEGIN/END macros to e.g. track lifetimes of
> heap-allocated objects, whose lifetimes will likely be non-nested. In
> Sawbuck (or other ETW viewers), you could then do interesting visualization
> of this data.
> Imagine e.g. how it would have simplified tracking down the GMail DOM issue
> if each DOM object traced on creation and deletion.
>
>

[Sigurður Ásgeirsson, 2011-03-10 21:12:12]

On Thu, Mar 10, 2011 at 2:53 PM, Vincent Scheib <scheib@chromium.org> wrote:

> On Begin End arguments:
>
> Q: is any system currently using the id values? (I couldn't find such in
>
> In Chrome Frame this is used to track object lifetimes:

http://codesearch.google.com/codesearch/p?hl=en#OAMlx_jo-ck/src/chrome_frame/...
<http://codesearch.google.com/codesearch/p?hl=en#OAMlx_jo-ck/src/chrome_frame/...>


> Future Proposal: We accept multiple arguments on both Begin and End. An
> analyzer matching Begin End pairs can use just the name, or if e.g. id
> matching is ever desired, can check that all arguments provided in both
> begin and end match.
> e.g. all these are easy to match:
> BEGIN("category", "name1")
> BEGIN("category", "name2", "id", pointerA, "info at begin", infoBegin)
> BEGIN("category", "name2", "id", pointerB)
> END("category", "name1")
> END("category", "name2", "id", pointerA)
> END("category", "name2", "id", pointerB, "info at end", infoEnd)
>
> Today Proposal: We don't have any use case needed parameters on the END
> events yet, so we don't build that out yet.
>
>  2. With regard to trace events having strings on their end, that's a neat
>>> point.
>>> I looked at the ETW-based perf test for chrome frame and I see how having
>>> arguments on the end token makes parsing simpler for that type of use
>>> case. The
>>> flip side of this is that for things like a timeline visualization, it
>>> opens up
>>> a whole can of worms --- can you make begin-end pairs non-nested, e.g.:
>>>   thread 1: BEGIN frame
>>>   thread 1: BEGIN somethingElse
>>>   thread 1: END frame
>>>   thread 1: END somethingElse
>>> I'm not religious on this one way or another, just thought I'd throw it
>>> out as
>>> why I opted to not allow arguments on the end token.
>>>
>>>
>> Oh, I think you misunderstand what I was trying to say. What I was trying
>> to say is that the ID parameter to the original macros is a void*, and if
>> you pass in a pointer to some variable or object, you're guaranteed the
>> value is unique within the process, which makes it trivial to match
>> events. This would allow the BEGIN/END macros to e.g. track lifetimes of
>> heap-allocated objects, whose lifetimes will likely be non-nested. In
>> Sawbuck (or other ETW viewers), you could then do interesting visualization
>> of this data.
>> Imagine e.g. how it would have simplified tracking down the GMail DOM
>> issue if each DOM object traced on creation and deletion.
>>
>>

[scheib, 2011-03-10 23:51:39]

>
> 1. trace size increase...
> 2. what happens when beign and end arguments odn't match? are they required
> to match? if they don't match, and i parse this from events to slices
> [timeline_mode.js], then what are the slice's parameters?


Size should increases only if trace points spam more data than they need to?
If you don't need to send arguments at both begin and end, don't.

When b/e args don't match the person interpreting the data can decide what
that means. The proposals for id are that you can determine the b/e aren't
related. My pitch would that if any arvname matches and argv doesn't they
are unrelated.

timeline_mode.js [seems that it] handles purely nested b/e pairs only right
now. The proposal would be that we optionally could do slice detection by
scanning all unclosed begin events to find a match - nesting would not be
required. Nesting detection still possible by another method (close at an e,
if sub slice it's nested, if a parent slice eject all pending sub slices).
No need to implement that unless/until we have a need for it.


> Q: is any system currently using the id values? (I couldn't find such in
>>
>> In Chrome Frame this is used to track object lifetimes:
>
>
>
http://codesearch.google.com/codesearch/p?hl=en#OAMlx_jo-ck/src/chrome_frame/...
>

That code is producing the id values, but what code uses them?

[scheib, 2011-04-13 21:44:59]

I'm working through cleaning this up, and have some decisions to make: (I'm
hoping for a yes on each):

A- Can we leave ETW code as is? (on first land at least)
  - Record events with name, id, extra structure as they have been, vs
upgrading to arbitrary name/value pairs
  - why: limit changes, don't need to update SawBuck yet.

B- Have multiple trace_event macros, for status quo (id, extra) and new form
of arbitrary name/value pairs?
  - why: Easier to land sooner with multiple entry points, leaving only the
call sites that require* it to use the old style. Merging macros and
continuing support for void* requires serializing and parsing void* unless A
is decided "no" and we modify ETW code.
  - * - require means that a void* is used, or if C is yes then

C- If A && B, then if a "new style" macro is called can we ignore ETW?
  - why: allows us to leave the "very efficient when off" style macros with
static category pointers, and to not have a .h dependence on ETW. Else we
need to make a non inlined function call so we can check the status of ETW.
  - This one isn't a big deal - already have some code that can do it.
  - Long term, we may prefer ETW to trigger the "categories" when it is
enabled, leaving them working very efficiently when off.

[Sigurður Ásgeirsson, 2011-04-14 12:11:21]

On Wed, Apr 13, 2011 at 5:44 PM, Vincent Scheib <scheib@chromium.org> wrote:

> I'm working through cleaning this up, and have some decisions to make: (I'm
> hoping for a yes on each):
>
> A- Can we leave ETW code as is? (on first land at least)
>   - Record events with name, id, extra structure as they have been, vs
> upgrading to arbitrary name/value pairs
>   - why: limit changes, don't need to update SawBuck yet.
>
> SGTM.


> B- Have multiple trace_event macros, for status quo (id, extra) and new
> form of arbitrary name/value pairs?
>   - why: Easier to land sooner with multiple entry points, leaving only the
> call sites that require* it to use the old style. Merging macros and
> continuing support for void* requires serializing and parsing void* unless A
> is decided "no" and we modify ETW code.
>   - * - require means that a void* is used, or if C is yes then
>
> SGTM.


> C- If A && B, then if a "new style" macro is called can we ignore ETW?
>   - why: allows us to leave the "very efficient when off" style macros with
> static category pointers, and to not have a .h dependence on ETW. Else we
> need to make a non inlined function call so we can check the status of ETW.
>   - This one isn't a big deal - already have some code that can do it.
>   - Long term, we may prefer ETW to trigger the "categories" when it is
> enabled, leaving them working very efficiently when off.
>
> SGTM - since no one is using the new macros at the moment there's nothing
lost, and I'd be for trailing with ETW support as needed.