Implement sampling profiler (chromium side change)

Implement sampling profiler (chromium side change)

Trace-viewer side change is here: https://codereview.appspot.com/39310043

Screenshot of the profiler: http://haraken.info/null/sampling_tracing.png

Design document: https://docs.google.com/a/google.com/document/d/1j39sbA9ECTwFFlxbhSD1EvJnGfYeS5EUJ05yxuku6VY/edit

TBR=phajdan.jr
NOTRY=true

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=242671

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=243528

[haraken, 2013-12-11 04:56:48]

This is the first version of the sampling profiler.

Would you take a quick look at the CL? If it looks good, I'll add test cases.

FYI, trace-viewer side change is here: https://codereview.appspot.com/39310043/

[dsinclair, 2013-12-11 15:55:04]

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1352: // TODO(haraken): Don't call Platform::Join
from the UI thread.
Is this todo to be done before commit? Or for later?

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1700: // We enable all categories in sampling
tracing, since it doesn't make sense
Does this include disabled-by-default- categories? Do we really want those on
with the sampling profiler?

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1702: if (!(flags & TRACE_EVENT_FLAG_SAMPLING) &&
!*category_group_enabled)
If we always enable all categories then why does the EnableMonitoring call take
a category filter?

[Xianzhu, 2013-12-11 17:53:41]

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1662: return
static_cast<int>(subtle::NoBarrier_AtomicIncrement(&generation_, 1));
Thanks for fixing this!

Would it be even better to
- move logged_events_.reset(CreateTraceBuffer()) from the callsites - into this
function
- rename it (UseNextTraceBuffer?)
- remove the return value

[haraken, 2013-12-12 00:48:47]

Thanks for review!

I'll polish up the CL, add tests and ping you :)

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1352: // TODO(haraken): Don't call Platform::Join
from the UI thread.
On 2013/12/11 15:55:04, dsinclair wrote:
> Is this todo to be done before commit? Or for later?

Sure, I'll fix before commit.

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1662: return
static_cast<int>(subtle::NoBarrier_AtomicIncrement(&generation_, 1));
On 2013/12/11 17:53:42, Xianzhu wrote:
> Thanks for fixing this!
> 
> Would it be even better to
> - move logged_events_.reset(CreateTraceBuffer()) from the callsites - into
this
> function
> - rename it (UseNextTraceBuffer?)
> - remove the return value

Sure, will do!

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1700: // We enable all categories in sampling
tracing, since it doesn't make sense
On 2013/12/11 15:55:04, dsinclair wrote:
> Does this include disabled-by-default- categories? Do we really want those on
> with the sampling profiler?

I think the answer is yes. Given that the sampling profiler is a thing that
tells us a percentage distribution of all sampled events, it wouldn't make much
sense to filter out some sampled events. (i.e., technically it's possible to
filter out sampled events by categories, but I cannot come up with practical use
cases for the filtering.) WDYT?

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1702: if (!(flags & TRACE_EVENT_FLAG_SAMPLING) &&
!*category_group_enabled)
On 2013/12/11 15:55:04, dsinclair wrote:
> If we always enable all categories then why does the EnableMonitoring call
take
> a category filter?

I think that's because the monitoring mode is going to be used for other
purposes than sampling profiler in the future (system tracing, tcmalloc
monitoring, etc).

[haraken, 2013-12-12 01:54:52]

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1352: // TODO(haraken): Don't call Platform::Join
from the UI thread.
On 2013/12/12 00:48:47, haraken wrote:
> On 2013/12/11 15:55:04, dsinclair wrote:
> > Is this todo to be done before commit? Or for later?
> 
> Sure, I'll fix before commit.

Question: Would the right fix for this be to change TracingControllerImpl so
that it calls SetDisabled() from the FILE thread? Or should we allow
TracingControllerImpl to call SetDisabled() from the UI thread but execute only
Platform::Join() from the FILE thread?

[haraken, 2013-12-12 04:27:24]

On 2013/12/12 01:54:52, haraken wrote:
>
https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
> File base/debug/trace_event_impl.cc (right):
> 
>
https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
> base/debug/trace_event_impl.cc:1352: // TODO(haraken): Don't call
Platform::Join
> from the UI thread.
> On 2013/12/12 00:48:47, haraken wrote:
> > On 2013/12/11 15:55:04, dsinclair wrote:
> > > Is this todo to be done before commit? Or for later?
> > 
> > Sure, I'll fix before commit.
> 
> Question: Would the right fix for this be to change TracingControllerImpl so
> that it calls SetDisabled() from the FILE thread? Or should we allow
> TracingControllerImpl to call SetDisabled() from the UI thread but execute
only
> Platform::Join() from the FILE thread?

Uploaded a CL here: https://codereview.chromium.org/105893004/

[nduca, 2013-12-12 07:02:41]

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event.h...
base/debug/trace_event.h:960: #define TRACE_EVENT_FLAG_SAMPLING    
(static_cast<unsigned char>(1 << 3))
we might have to update Blink's TraceEvent.h too?

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:901: name, 0, 0, NULL, NULL, NULL, NULL,
TRACE_EVENT_FLAG_SAMPLING);
i'm a little confused on this side. what is the category_group typically? i
think maybe there's something im misunderstanding in the way the sampling thread
is implemented :$

[haraken, 2013-12-12 07:34:27]

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:901: name, 0, 0, NULL, NULL, NULL, NULL,
TRACE_EVENT_FLAG_SAMPLING);
On 2013/12/12 07:02:41, nduca wrote:
> i'm a little confused on this side. what is the category_group typically? i
> think maybe there's something im misunderstanding in the way the sampling
thread
> is implemented :$

(1) The sampling thread gets the current category group.
(2) The sampling thread checks if the category group is enabled or not. The
check is done in TraceLog::AddTraceEvent() (See the diff below).
(3) If it's not enabled, the sampling thread doesn't log the event.

Thus, if we specify "-*" for a category group, the sampling thread logs nothing.
The TRACE_EVENT_FALG_SAMPLING is necessary to tell that "this is a sampling
thread, so I want to log everything".

[dsinclair, 2013-12-12 15:19:31]

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:901: name, 0, 0, NULL, NULL, NULL, NULL,
TRACE_EVENT_FLAG_SAMPLING);
On 2013/12/12 07:34:28, haraken wrote:
> On 2013/12/12 07:02:41, nduca wrote:
> > i'm a little confused on this side. what is the category_group typically? i
> > think maybe there's something im misunderstanding in the way the sampling
> thread
> > is implemented :$
> 
> (1) The sampling thread gets the current category group.
> (2) The sampling thread checks if the category group is enabled or not. The
> check is done in TraceLog::AddTraceEvent() (See the diff below).
> (3) If it's not enabled, the sampling thread doesn't log the event.
> 
> Thus, if we specify "-*" for a category group, the sampling thread logs
nothing.
> The TRACE_EVENT_FALG_SAMPLING is necessary to tell that "this is a sampling
> thread, so I want to log everything".


If we really want everything then why not set hte category flag to "*" instead
of "-*" and then we don't need the TRACE_EVENT_FLAG_SAMPLING magic? Seems like
we're just building a path around the category flags that's special cased to
sampling?

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1700: // We enable all categories in sampling
tracing, since it doesn't make sense
On 2013/12/12 00:48:47, haraken wrote:
> On 2013/12/11 15:55:04, dsinclair wrote:
> > Does this include disabled-by-default- categories? Do we really want those
on
> > with the sampling profiler?
> 
> I think the answer is yes. Given that the sampling profiler is a thing that
> tells us a percentage distribution of all sampled events, it wouldn't make
much
> sense to filter out some sampled events. (i.e., technically it's possible to
> filter out sampled events by categories, but I cannot come up with practical
use
> cases for the filtering.) WDYT?


The problem with having disabled-by-default- is they can have a lot more
overhead then regular trace events. There is, potentially, a bunch of work to
convert from the current format into a base::Value object which will be
converted later. So, my fear is that we'd end up throwing off the samping
information due to these events.

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1702: if (!(flags & TRACE_EVENT_FLAG_SAMPLING) &&
!*category_group_enabled)
On 2013/12/12 00:48:47, haraken wrote:
> On 2013/12/11 15:55:04, dsinclair wrote:
> > If we always enable all categories then why does the EnableMonitoring call
> take
> > a category filter?
> 
> I think that's because the monitoring mode is going to be used for other
> purposes than sampling profiler in the future (system tracing, tcmalloc
> monitoring, etc).


Why can't I use monitoring mode to say, tell me the relative percentage of time
we spend in cc. functions? If I'm just interested in optimizing cc I may want to
filter out everything else.

[haraken, 2013-12-12 15:32:17]

Thanks for review!

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:901: name, 0, 0, NULL, NULL, NULL, NULL,
TRACE_EVENT_FLAG_SAMPLING);
On 2013/12/12 15:19:31, dsinclair wrote:
> On 2013/12/12 07:34:28, haraken wrote:
> > On 2013/12/12 07:02:41, nduca wrote:
> > > i'm a little confused on this side. what is the category_group typically?
i
> > > think maybe there's something im misunderstanding in the way the sampling
> > thread
> > > is implemented :$
> > 
> > (1) The sampling thread gets the current category group.
> > (2) The sampling thread checks if the category group is enabled or not. The
> > check is done in TraceLog::AddTraceEvent() (See the diff below).
> > (3) If it's not enabled, the sampling thread doesn't log the event.
> > 
> > Thus, if we specify "-*" for a category group, the sampling thread logs
> nothing.
> > The TRACE_EVENT_FALG_SAMPLING is necessary to tell that "this is a sampling
> > thread, so I want to log everything".
> 
> 
> If we really want everything then why not set hte category flag to "*" instead
> of "-*" and then we don't need the TRACE_EVENT_FLAG_SAMPLING magic? Seems like
> we're just building a path around the category flags that's special cased to
> sampling?

Then there arises another problem: If we use "*", then normal tracing like
TRACE_EVENT0 starts logging :(

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1700: // We enable all categories in sampling
tracing, since it doesn't make sense
On 2013/12/12 15:19:31, dsinclair wrote:
> On 2013/12/12 00:48:47, haraken wrote:
> > On 2013/12/11 15:55:04, dsinclair wrote:
> > > Does this include disabled-by-default- categories? Do we really want those
> on
> > > with the sampling profiler?
> > 
> > I think the answer is yes. Given that the sampling profiler is a thing that
> > tells us a percentage distribution of all sampled events, it wouldn't make
> much
> > sense to filter out some sampled events. (i.e., technically it's possible to
> > filter out sampled events by categories, but I cannot come up with practical
> use
> > cases for the filtering.) WDYT?
> 
> 
> The problem with having disabled-by-default- is they can have a lot more
> overhead then regular trace events. There is, potentially, a bunch of work to
> convert from the current format into a base::Value object which will be
> converted later. So, my fear is that we'd end up throwing off the samping
> information due to these events.

Now I agree that we shouldn't enable all categories by default (See my comment
below), but I'm curious why it affects performance. The sampling thread is just
peeking global variables  with 1 ms intervals. So the number of samples is
always up to 1000 per 1 second.

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1702: if (!(flags & TRACE_EVENT_FLAG_SAMPLING) &&
!*category_group_enabled)
On 2013/12/12 15:19:31, dsinclair wrote:
> On 2013/12/12 00:48:47, haraken wrote:
> > On 2013/12/11 15:55:04, dsinclair wrote:
> > > If we always enable all categories then why does the EnableMonitoring call
> > take
> > > a category filter?
> > 
> > I think that's because the monitoring mode is going to be used for other
> > purposes than sampling profiler in the future (system tracing, tcmalloc
> > monitoring, etc).
> 
> 
> Why can't I use monitoring mode to say, tell me the relative percentage of
time
> we spend in cc. functions? If I'm just interested in optimizing cc I may want
to
> filter out everything else.

Sounds reasonable. We want to have category filters for sampling tracing as
well.

However, what's the cleanest way to realize it? Currently a category group is
shared between normal tracing and sampling tracing. So we cannot say that "We
want to enable these categories only in sampling tracing". Probably do we want
to prepare a separate category group for sampling tracing?

[dsinclair, 2013-12-13 15:55:56]

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:901: name, 0, 0, NULL, NULL, NULL, NULL,
TRACE_EVENT_FLAG_SAMPLING);
On 2013/12/12 15:32:17, haraken wrote:
> On 2013/12/12 15:19:31, dsinclair wrote:
> > On 2013/12/12 07:34:28, haraken wrote:
> > > On 2013/12/12 07:02:41, nduca wrote:
> > > > i'm a little confused on this side. what is the category_group
typically?
> i
> > > > think maybe there's something im misunderstanding in the way the
sampling
> > > thread
> > > > is implemented :$
> > > 
> > > (1) The sampling thread gets the current category group.
> > > (2) The sampling thread checks if the category group is enabled or not.
The
> > > check is done in TraceLog::AddTraceEvent() (See the diff below).
> > > (3) If it's not enabled, the sampling thread doesn't log the event.
> > > 
> > > Thus, if we specify "-*" for a category group, the sampling thread logs
> > nothing.
> > > The TRACE_EVENT_FALG_SAMPLING is necessary to tell that "this is a
sampling
> > > thread, so I want to log everything".
> > 
> > 
> > If we really want everything then why not set hte category flag to "*"
instead
> > of "-*" and then we don't need the TRACE_EVENT_FLAG_SAMPLING magic? Seems
like
> > we're just building a path around the category flags that's special cased to
> > sampling?
> 
> Then there arises another problem: If we use "*", then normal tracing like
> TRACE_EVENT0 starts logging :(


Isn't adding the TRACE_EVENT_FLAG_SAMPLING the same as checking for phase ==
TRACE_EVENT_PHASE_SAMPLE? The flag seems redundant.

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1352: // TODO(haraken): Don't call Platform::Join
from the UI thread.
On 2013/12/12 01:54:52, haraken wrote:
> On 2013/12/12 00:48:47, haraken wrote:
> > On 2013/12/11 15:55:04, dsinclair wrote:
> > > Is this todo to be done before commit? Or for later?
> > 
> > Sure, I'll fix before commit.
> 
> Question: Would the right fix for this be to change TracingControllerImpl so
> that it calls SetDisabled() from the FILE thread? Or should we allow
> TracingControllerImpl to call SetDisabled() from the UI thread but execute
only
> Platform::Join() from the FILE thread?


I believe this was handled in a separate CL correct?

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1700: // We enable all categories in sampling
tracing, since it doesn't make sense
On 2013/12/12 15:32:17, haraken wrote:
> On 2013/12/12 15:19:31, dsinclair wrote:
> > On 2013/12/12 00:48:47, haraken wrote:
> > > On 2013/12/11 15:55:04, dsinclair wrote:
> > > > Does this include disabled-by-default- categories? Do we really want
those
> > on
> > > > with the sampling profiler?
> > > 
> > > I think the answer is yes. Given that the sampling profiler is a thing
that
> > > tells us a percentage distribution of all sampled events, it wouldn't make
> > much
> > > sense to filter out some sampled events. (i.e., technically it's possible
to
> > > filter out sampled events by categories, but I cannot come up with
practical
> > use
> > > cases for the filtering.) WDYT?
> > 
> > 
> > The problem with having disabled-by-default- is they can have a lot more
> > overhead then regular trace events. There is, potentially, a bunch of work
to
> > convert from the current format into a base::Value object which will be
> > converted later. So, my fear is that we'd end up throwing off the samping
> > information due to these events.
> 
> Now I agree that we shouldn't enable all categories by default (See my comment
> below), but I'm curious why it affects performance. The sampling thread is
just
> peeking global variables  with 1 ms intervals. So the number of samples is
> always up to 1000 per 1 second.


I think this was my own confusion with how sampling worked. I'd forgotten that
sampling has it's own macros that are separate. So, as long as the non-sampling
macros aren't being forced to evaluate their arguments it should be fine.

https://codereview.chromium.org/109933006/diff/20001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1702: if (!(flags & TRACE_EVENT_FLAG_SAMPLING) &&
!*category_group_enabled)
On 2013/12/12 15:32:17, haraken wrote:
> On 2013/12/12 15:19:31, dsinclair wrote:
> > On 2013/12/12 00:48:47, haraken wrote:
> > > On 2013/12/11 15:55:04, dsinclair wrote:
> > > > If we always enable all categories then why does the EnableMonitoring
call
> > > take
> > > > a category filter?
> > > 
> > > I think that's because the monitoring mode is going to be used for other
> > > purposes than sampling profiler in the future (system tracing, tcmalloc
> > > monitoring, etc).
> > 
> > 
> > Why can't I use monitoring mode to say, tell me the relative percentage of
> time
> > we spend in cc. functions? If I'm just interested in optimizing cc I may
want
> to
> > filter out everything else.
> 
> Sounds reasonable. We want to have category filters for sampling tracing as
> well.
> 
> However, what's the cleanest way to realize it? Currently a category group is
> shared between normal tracing and sampling tracing. So we cannot say that "We
> want to enable these categories only in sampling tracing". Probably do we want
> to prepare a separate category group for sampling tracing?



I think I'm getting confused on how this works. Please correct me if I'm
mistaken.

The sampling mode is separate from the tracing mode. They are mutually exclusive
so you can't turn them both on at the same time.

If that's the case, then we should be able to use the category_filter as it will
only apply to the current mode (sampling or tracing) that is enabled.

Is the problem that both use AddTraceEvent and we don't want to log
non-PHASE_SAMPLE events when in sampling mode?

What am I missing?

[haraken, 2013-12-13 16:07:00]

> I think I'm getting confused on how this works. Please correct me if I'm
> mistaken.
> 
> The sampling mode is separate from the tracing mode. They are mutually
exclusive
> so you can't turn them both on at the same time.
> 
> If that's the case, then we should be able to use the category_filter as it
will
> only apply to the current mode (sampling or tracing) that is enabled.
> 
> Is the problem that both use AddTraceEvent and we don't want to log
> non-PHASE_SAMPLE events when in sampling mode?
> 
> What am I missing?

Good point.

- Both sampling mode and tracing mode use AddTraceEvent.

- However, currently AddTraceEvent doesn't care about phases. Consequently, if
we specify "*" for a category filter of the sampling mode, the tracing mode also
starts logging.

- The right fix to this issue is to add 'if (phase == TRACE_EVENT_PHASE_SAMPLE)'
to AddTraceEvent.

Let me try :)

[haraken, 2013-12-18 21:48:10]

- I removed the TRACE_EVENT_FLAG_SAMPLING flag.

- I removed the MONITORING_SAMPLING flag.

- I introduced TraceLog::Mode to distinguish whether we're in the recording mode
or in the monitoring mode.

However, I have one concern about the implementation as described below.

https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1783: phase == TRACE_EVENT_PHASE_SAMPLE) {

Concern 1: There is a threading race in mode_. mode_ is set by the FILE thread
and accessed by the UI thread. We don't want to use a lock to access mode_,
because AddTraceEvent() is always called by TRACE_EVENT macros and thus
performance-sensitive.

Concern 2: This implementation will slow down TRACE_EVENT macros. Imagine that
the monitoring mode is enabled for all categories. In this case, all TRACE_EVENT
macros (for the recording mode) start calling AddTraceEvent() and then reach
this check. Since this check returns false, AddTraceEvent() returns without
doing nothing. However, it would be heavy to execute AddTraceEvent() for all
TRACE_EVENT macros. (We want to enable the sampling profiler always on in the
future.)

[haraken, 2013-12-18 21:49:00]

On 2013/12/18 21:48:10, haraken wrote:
> - I removed the TRACE_EVENT_FLAG_SAMPLING flag.
> 
> - I removed the MONITORING_SAMPLING flag.
> 
> - I introduced TraceLog::Mode to distinguish whether we're in the recording
mode
> or in the monitoring mode.
> 
> However, I have one concern about the implementation as described below.
> 
>
https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
> File base/debug/trace_event_impl.cc (right):
> 
>
https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
> base/debug/trace_event_impl.cc:1783: phase == TRACE_EVENT_PHASE_SAMPLE) {
> 
> Concern 1: There is a threading race in mode_. mode_ is set by the FILE thread
> and accessed by the UI thread. We don't want to use a lock to access mode_,
> because AddTraceEvent() is always called by TRACE_EVENT macros and thus
> performance-sensitive.
> 
> Concern 2: This implementation will slow down TRACE_EVENT macros. Imagine that
> the monitoring mode is enabled for all categories. In this case, all
TRACE_EVENT
> macros (for the recording mode) start calling AddTraceEvent() and then reach
> this check. Since this check returns false, AddTraceEvent() returns without
> doing nothing. However, it would be heavy to execute AddTraceEvent() for all
> TRACE_EVENT macros. (We want to enable the sampling profiler always on in the
> future.)

Do you have any idea on this?

[Xianzhu, 2013-12-18 22:26:54]

https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1783: phase == TRACE_EVENT_PHASE_SAMPLE) {
On 2013/12/18 21:48:10, haraken wrote:
> 
> Concern 1: There is a threading race in mode_. mode_ is set by the FILE thread
> and accessed by the UI thread. We don't want to use a lock to access mode_,
> because AddTraceEvent() is always called by TRACE_EVENT macros and thus
> performance-sensitive.
> 

I think we can omit checking mode_ here because we should trust
*category_group_enabled which has been updated according to mode_ in
UpdateCategoryEnabledFlags().

> Concern 2: This implementation will slow down TRACE_EVENT macros. Imagine that
> the monitoring mode is enabled for all categories. In this case, all
TRACE_EVENT
> macros (for the recording mode) start calling AddTraceEvent() and then reach
> this check. Since this check returns false, AddTraceEvent() returns without
> doing nothing. However, it would be heavy to execute AddTraceEvent() for all
> TRACE_EVENT macros. (We want to enable the sampling profiler always on in the
> future.)

This doesn't look good. Currently the extra cost is less than 3~4 machine
instructions for each TRACE_EVENT macro when it doesn't actually generate
traces.

I think we should also add the check in the macros:
- in sampling macros, change "if (*category_group_enabled)" to "if
(*category_group_enabled & ENABLED_FOR_MONITORING)"
- in other macros, change to "if (*category_group_enabled &
(ENABLED_FOR_RECORDING | ENABLED_FOR_EVENT_CALLBACK))"
so that for recording macros, the extra cost is still near zero when recording
and event_callback are not enabled.

[haraken, 2013-12-18 22:40:21]

Thanks wang!

https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/40001/base/debug/trace_event_i...
base/debug/trace_event_impl.cc:1783: phase == TRACE_EVENT_PHASE_SAMPLE) {
On 2013/12/18 22:26:54, Xianzhu wrote:
> On 2013/12/18 21:48:10, haraken wrote:
> > 
> > Concern 1: There is a threading race in mode_. mode_ is set by the FILE
thread
> > and accessed by the UI thread. We don't want to use a lock to access mode_,
> > because AddTraceEvent() is always called by TRACE_EVENT macros and thus
> > performance-sensitive.
> > 
> 
> I think we can omit checking mode_ here because we should trust
> *category_group_enabled which has been updated according to mode_ in
> UpdateCategoryEnabledFlags().

Would you elaborate on how to do that?

(1) TRACE_EVENT macros are just checking *category_group_enabled. They are not
checking *category_group_enabled & ENABLED_FOR_XXX. We want to keep the current
check for performance.

(2) If we want to enable some categories in the monitoring mode, we need to
enable *category_group_enabled for the categories.

(3) Then TRACE_EVENT macros start falling back to AddTraceEvent().

Are you suggesting using two category_group_enabled, one for the recording mode
and the other for the monitoring mode?

> I think we should also add the check in the macros:
> - in sampling macros, change "if (*category_group_enabled)" to "if
> (*category_group_enabled & ENABLED_FOR_MONITORING)"
> - in other macros, change to "if (*category_group_enabled &
> (ENABLED_FOR_RECORDING | ENABLED_FOR_EVENT_CALLBACK))"
> so that for recording macros, the extra cost is still near zero when recording
> and event_callback are not enabled.

Actually I tried this at first but found that it won't make sense to distinguish
ENABLED_FOR_RECORDING from ENABLED_FOR_MONITORING. Because the recording mode
and the monitoring mode are mutually exclusive, we can just use
category_group_enabled for a category filter of the mode that is currently
enabled.

[haraken, 2013-12-19 00:19:05]

Discussed with Wang offline.

PTAL.

- I removed the TRACE_EVENT_FLAG_SAMPLING flag.

- I removed the MONITORING_SAMPLING flag.

- I introduced TraceLog::Mode to distinguish whether we're in the recording mode
or in the monitoring mode.

- I introduced an ENABLED_FOR_MONITORING flag.

I'm planning to add tests when landing the trace-viewer side CL, but if you want
me to write some tests for this CL, please tell me.

[haraken, 2013-12-19 00:19:14]

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event....
base/debug/trace_event.h:734: base::debug::TraceLog::ENABLED_FOR_RECORDING) { \

I'll land the same fix to TraceEvent.h in Blink.

[Xianzhu, 2013-12-19 00:39:57]

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event....
base/debug/trace_event.h:734: base::debug::TraceLog::ENABLED_FOR_RECORDING) { \
We also need to check ENABLED_FOR_EVENT_CALLBACK here. Perhaps we can create an
internal macro to reduce the duplicated code.

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event_...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event_...
base/debug/trace_event_impl.cc:1275: if (options != old_options) {
Should we also print warning for re-enabling tracing with a different mode?

[haraken, 2013-12-19 00:53:58]

PTAL

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event....
base/debug/trace_event.h:734: base::debug::TraceLog::ENABLED_FOR_RECORDING) { \
On 2013/12/19 00:39:57, Xianzhu wrote:
> We also need to check ENABLED_FOR_EVENT_CALLBACK here. Perhaps we can create
an
> internal macro to reduce the duplicated code.

Done.

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event_...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/100001/base/debug/trace_event_...
base/debug/trace_event_impl.cc:1275: if (options != old_options) {
On 2013/12/19 00:39:57, Xianzhu wrote:
> Should we also print warning for re-enabling tracing with a different mode?

Done.

[Xianzhu, 2013-12-19 01:01:04]

trace_event part lgtm.

https://codereview.chromium.org/109933006/diff/120001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

https://codereview.chromium.org/109933006/diff/120001/base/debug/trace_event....
base/debug/trace_event.h:728: #define
TRACE_EVENT_CATEGORY_GROUP_ENABLED_FOR_RECORDING_MODE( \
Nit: I think this macro should be prefixed with INTERNAL_ because it is not
usable from outside. As it is internal, we can omit the parameter as the name
|category_group_enabled| is an internal hardcoded name (declared in
INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO).

[haraken, 2013-12-19 01:34:01]

Thanks for review!

https://codereview.chromium.org/109933006/diff/120001/base/debug/trace_event.h
File base/debug/trace_event.h (right):

https://codereview.chromium.org/109933006/diff/120001/base/debug/trace_event....
base/debug/trace_event.h:728: #define
TRACE_EVENT_CATEGORY_GROUP_ENABLED_FOR_RECORDING_MODE( \
On 2013/12/19 01:01:05, Xianzhu wrote:
> Nit: I think this macro should be prefixed with INTERNAL_ because it is not
> usable from outside. As it is internal, we can omit the parameter as the name
> |category_group_enabled| is an internal hardcoded name (declared in
> INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO).

Done.

[haraken, 2013-12-19 01:37:29]

dsinclair@: Would you take a look at base/debug/ as an OWNER?

jochen@: Would you rubber-stamp changes to chrome/, content/ and component/ as
an OWNER?

[jochen (gone - plz use gerrit), 2013-12-20 07:55:27]

lgtm

[dsinclair, 2013-12-20 14:42:29]

lgtm with nit.

Sorry for the review delay.

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
base/debug/trace_event_impl.cc:1198: if (mode_ == MONITORING_MODE &&
else if?

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
File base/debug/trace_event_impl.h (right):

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
base/debug/trace_event_impl.h:382: // These values must be in sync with macro
values in TraceEvent.h in Blink.
Has this change happened in blink already?

[haraken, 2013-12-25 07:52:30]

Thanks for review!

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
File base/debug/trace_event_impl.cc (right):

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
base/debug/trace_event_impl.cc:1198: if (mode_ == MONITORING_MODE &&
On 2013/12/20 14:42:29, dsinclair wrote:
> else if?

Done.

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
File base/debug/trace_event_impl.h (right):

https://codereview.chromium.org/109933006/diff/140001/base/debug/trace_event_...
base/debug/trace_event_impl.h:382: // These values must be in sync with macro
values in TraceEvent.h in Blink.
On 2013/12/20 14:42:29, dsinclair wrote:
> Has this change happened in blink already?

Not yet. I'll do it after landing this CL. Since no one is using the monitoring
mode, I think there is no harm in landing this CL first.

[commit-bot: I haz the power, 2013-12-25 07:52:44]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/haraken@chromium.org/109933006/190001

[commit-bot: I haz the power, 2013-12-25 08:09:26]

Retried try job too often on mac_rel for step(s) base_unittests, browser_tests,
interactive_ui_tests, net_unittests, unit_tests
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=mac_rel&nu...

[commit-bot: I haz the power, 2013-12-25 10:46:21]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/haraken@chromium.org/109933006/190001

[commit-bot: I haz the power, 2013-12-25 11:13:02]

Retried try job too often on ios_dbg_simulator for step(s) base_unittests,
compile, content_unittests, crypto_unittests, net_unittests, sql_unittests,
ui_unittests, url_unittests
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=ios_dbg_si...

[commit-bot: I haz the power, 2013-12-25 11:39:15]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/haraken@chromium.org/109933006/680001

[commit-bot: I haz the power, 2013-12-25 12:02:44]

Retried try job too often on linux_rel for step(s) base_unittests,
browser_tests, interactive_ui_tests, net_unittests, unit_tests
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=linux_rel&...

[commit-bot: I haz the power, 2013-12-25 12:03:45]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/haraken@chromium.org/109933006/250005

[commit-bot: I haz the power, 2013-12-25 12:35:23]

Retried try job too often on android_clang_dbg for step(s) slave_steps
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=android_cl...

[commit-bot: I haz the power, 2013-12-25 12:45:23]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/haraken@chromium.org/109933006/850002

[commit-bot: I haz the power, 2013-12-25 13:04:25]

Retried try job too often on chromium_presubmit for step(s) presubmit
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=chromium_p...

[commit-bot: I haz the power, 2013-12-28 05:55:25]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/haraken@chromium.org/109933006/850002

[haraken, 2013-12-28 05:56:15]

Given the previous trybot results, the patch set 12 looks safe to land except
for the presubmit errors. Landing with NOTRY=true.

[commit-bot: I haz the power, 2013-12-28 06:04:31]

Change committed as 242671

[haraken, 2013-12-28 08:23:34]

Reverted this change because it broke base_unittests in iOS. I need to land
https://codereview.chromium.org/105893004/ first.

[commit-bot: I haz the power, 2014-01-08 08:44:21]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/haraken@chromium.org/109933006/1420001

[commit-bot: I haz the power, 2014-01-08 12:17:06]

Change committed as 243528