Instrumenting OnExtensionAddListener observer invocation

Adding tracking to verify the theory that jankiness of ExtensionMessageFilter::OnExtensionAddListener is because of the observer invocation.

BUG=401560, 417106
Committed: https://crrev.com/a19e4877974a6a0cfc53f92c1496a8f995fe2614
Cr-Commit-Position: refs/heads/master@{#296804}

[vadimt, 2014-09-24 23:10:54]

vadimt@chromium.org changed reviewers:
+ isherman@chromium.org, mpcomplete@google.com

[vadimt, 2014-09-24 23:12:53]

vadimt@chromium.org changed reviewers:
- mpcomplete@google.com

[vadimt, 2014-09-24 23:20:27]

isherman@, could you look at this before I send this to file owners?

I introduce a new macro that will be used for digging into complex janky tasks.
The region instrumented with this macro should be placed inside a janky task,
and will be shown as a separate task in the internal tool, and will show the
part of jank introduced by that region. This jank will be subtracted from the
parent task.

[Ilya Sherman, 2014-09-24 23:38:01]

https://codereview.chromium.org/600213002/diff/1/base/profiler/scoped_profile.h
File base/profiler/scoped_profile.h (right):

https://codereview.chromium.org/600213002/diff/1/base/profiler/scoped_profile...
base/profiler/scoped_profile.h:51: TRACK_RUN_IN_IPC_HANDLER(scope_name)
It looks like all of the macros in this file could be replaced with this:

#define PASTE_LINE_NUMBER_ON_NAME(name, line) name##line

#define LINE_BASED_VARIABLE_NAME_FOR_PROFILING \
    PASTE_LINE_NUMBER_ON_NAME(some_profiler_variable_, __LINE__)

// Defines the containing scope as a profiled region. This allows developers to
// profile their code and see results on their about:profiler page, as well as
// on the UMA dashboard.
#define TRACK_RUN_IN_THIS_SCOPED_REGION(scope_name) \
    ::tracked_objects::ScopedProfile  LINE_BASED_VARIABLE_NAME_FOR_PROFILING(
        FROM_HERE_WITH_EXPLICIT_FUNCTION(#scope_name))


That is, we can delete TRACK_RUN_IN_THIS_SCOPED_REGION_FOR_DEVELOPER_BUILDS,
since it's unused; and we can rename TRACK_RUN_IN_IPC_HANDLER to the more
general name TRACK_RUN_IN_THIS_SCOPED_REGION.

When renaming the macro, it looks like the #include in
https://code.google.com/p/chromium/codesearch#chromium/src/ppapi/proxy/dispat...
can just be removed.

https://codereview.chromium.org/600213002/diff/1/extensions/browser/event_rou...
File extensions/browser/event_router.cc (right):

https://codereview.chromium.org/600213002/diff/1/extensions/browser/event_rou...
extensions/browser/event_router.cc:243: // crbug.com/417106 is fixed.
nit: Please prepend "http://" to the link, to increase the likelihood of
linkification.

[vadimt, 2014-09-25 00:21:21]

https://codereview.chromium.org/600213002/diff/1/base/profiler/scoped_profile.h
File base/profiler/scoped_profile.h (right):

https://codereview.chromium.org/600213002/diff/1/base/profiler/scoped_profile...
base/profiler/scoped_profile.h:51: TRACK_RUN_IN_IPC_HANDLER(scope_name)
On 2014/09/24 23:38:01, Ilya Sherman wrote:
> It looks like all of the macros in this file could be replaced with this:
> 
> #define PASTE_LINE_NUMBER_ON_NAME(name, line) name##line
> 
> #define LINE_BASED_VARIABLE_NAME_FOR_PROFILING \
>     PASTE_LINE_NUMBER_ON_NAME(some_profiler_variable_, __LINE__)
> 
> // Defines the containing scope as a profiled region. This allows developers
to
> // profile their code and see results on their about:profiler page, as well as
> // on the UMA dashboard.
> #define TRACK_RUN_IN_THIS_SCOPED_REGION(scope_name) \
>     ::tracked_objects::ScopedProfile  LINE_BASED_VARIABLE_NAME_FOR_PROFILING(
>         FROM_HERE_WITH_EXPLICIT_FUNCTION(#scope_name))
> 
> 
> That is, we can delete TRACK_RUN_IN_THIS_SCOPED_REGION_FOR_DEVELOPER_BUILDS,
> since it's unused; and we can rename TRACK_RUN_IN_IPC_HANDLER to the more
> general name TRACK_RUN_IN_THIS_SCOPED_REGION.
> 
> When renaming the macro, it looks like the #include in
>
https://code.google.com/p/chromium/codesearch#chromium/src/ppapi/proxy/dispat...
> can just be removed.

Done.

[Ilya Sherman, 2014-09-25 17:28:43]

LGTM % a nit.  Thanks, Vadim :)

https://codereview.chromium.org/600213002/diff/20001/base/profiler/scoped_pro...
File base/profiler/scoped_profile.h (right):

https://codereview.chromium.org/600213002/diff/20001/base/profiler/scoped_pro...
base/profiler/scoped_profile.h:27: // tools.
Optional nit: Suggested rephrasing:

// Defines the containing scope as a profiled region. This allows developers to
// profile their code and see results on their about:profiler page, as well as
// on the UMA dashboard.

[vadimt, 2014-09-25 17:51:02]

https://codereview.chromium.org/600213002/diff/20001/base/profiler/scoped_pro...
File base/profiler/scoped_profile.h (right):

https://codereview.chromium.org/600213002/diff/20001/base/profiler/scoped_pro...
base/profiler/scoped_profile.h:27: // tools.
On 2014/09/25 17:28:42, Ilya Sherman wrote:
> Optional nit: Suggested rephrasing:
> 
> // Defines the containing scope as a profiled region. This allows developers
to
> // profile their code and see results on their about:profiler page, as well as
> // on the UMA dashboard.

Done.

[vadimt, 2014-09-25 18:06:36]

vadimt@chromium.org changed reviewers:
+ brettw@chromium.org, dmichael@chromium.org, yoz@chromium.org

[vadimt, 2014-09-25 18:06:36]

yoz@chromium.org: Please provide OWNER's approval for:
extensions/browser/event_router.cc

brettw@chromium.org: Please provide OWNER's approval for:
base/profiler/scoped_profile.h

dmichael@chromium.org: Please provide OWNER's approval for:
ipc/ipc_message_macros.h
ppapi/host/dispatch_host_message.h
ppapi/proxy/dispatch_reply_message.h

The changes were LGTM'd by isherman@, who knows and understands scoped prodiles.

[dmichael (off chromium), 2014-09-25 18:08:42]

ppapi lgtm

[Yoyo Zhou, 2014-09-25 19:40:43]

event_router LGTM

[brettw, 2014-09-25 19:51:01]

LGTM with a change

https://codereview.chromium.org/600213002/diff/40001/extensions/browser/event...
File extensions/browser/event_router.cc (right):

https://codereview.chromium.org/600213002/diff/40001/extensions/browser/event...
extensions/browser/event_router.cc:244:
TRACK_RUN_IN_THIS_SCOPED_REGION(EventRouter_OnListenerAdded_ObserverCall);
I'm OK renaming the macro since the old one didn't do anything IPC-related. But
that macro is only necessary in the context of other macros where you need
automatic naming (since the IPC macros will be expanded in some unknown scope
with unknown variables).

In this case, I think it's clearer just to instantiate a ScopedProfile directly
and give it a regular variable name.

[vadimt, 2014-09-25 20:06:52]

https://codereview.chromium.org/600213002/diff/40001/extensions/browser/event...
File extensions/browser/event_router.cc (right):

https://codereview.chromium.org/600213002/diff/40001/extensions/browser/event...
extensions/browser/event_router.cc:244:
TRACK_RUN_IN_THIS_SCOPED_REGION(EventRouter_OnListenerAdded_ObserverCall);
1. We have a server-side source parser (I'll send a link internally soon). We
use it to match tasks received from the client against the code. That parser
benefits from the simplicity of the macro (macro name + param), as compared to
more complex Scoped_profile + variable + FROM_HERE + parameter construct.

2. I want to make tracking easy to use for (I hope!) a number of people who will
come to investigate their jankiness. It's much easier for a layperson to use the
macro than the more complex ScopedProfile construct. Automatic variable naming,
then, makes sense because we could imagine tracking 2 nested regions in the same
block of code, even though this would be an extremely rate scenario.

I'm taking a risk to submit this to CQ right now. If you disagree, I'll stop CQ,
or pinky-promise to submit a follow-up correction.

Thanks for understanding!

[vadimt, 2014-09-25 20:06:58]

The CQ bit was checked by vadimt@chromium.org

[commit-bot: I haz the power, 2014-09-25 20:08:22]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/600213002/40001

[brettw, 2014-09-25 20:16:59]

The CQ bit was unchecked by brettw@chromium.org

[brettw, 2014-09-25 20:19:32]

I disagree. ScopedProfile is not complicated. It's a class that takes a single
argument in the constructor. Such scoper classes are common and easy to
understand. When you wrap that in a macro, what is happening becomes less clear
since then I have to go read the macro, and then read the class.

There is no benefit to the automatic cariable naming in the nested case, since
presumably then you're measuring different things and can provide naming to go
with it. Such appropriate names actually increase readaility

[vadimt, 2014-09-25 20:39:20]

Done. Please confirm that you like it.
Note that I have to use FROM_HERE_WITH_EXPLICIT_FUNCTION so that
EventRouter_OnListenerAdded_ObserverCall shown in about://profiler. I.e. if I
used a mnemonic variable name + FROM_HERE, I wouldn't see the mnemonic name in
about://profiler. I'd see "EventRouter::OnListenerRemoved", which may be a task
name itself.

[brettw, 2014-09-25 20:41:21]

lgtm

[vadimt, 2014-09-25 20:44:44]

The CQ bit was checked by vadimt@chromium.org

[commit-bot: I haz the power, 2014-09-25 20:46:18]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/600213002/60001

[commit-bot: I haz the power, 2014-09-25 22:09:07]

Committed patchset #4 (id:60001) as 33e296684a245011f71d6371e33ca5b5f62e37aa

[commit-bot: I haz the power, 2014-09-25 22:09:41]

Patchset 4 (id:??) landed as
https://crrev.com/a19e4877974a6a0cfc53f92c1496a8f995fe2614
Cr-Commit-Position: refs/heads/master@{#296804}