[Extensions] Add more fine-grained extension performance metrics

[Extensions] Add more fine-grained extension performance metrics

The previous batch of metrics (Extensions.Functions.Succeeded/Failed*)
have been baking long enough that we have some baseline stats for what a
fast or slow function looks like. Add buckets for <1ms, 1 - 5ms, 5 -
10ms, and >10ms that record the actual function that was called so that
we can analyze whether there is a problem with the functions taking
longest.

BUG=608561
Committed: https://crrev.com/9380ff2d3f2b42ca3def7ded5af3921cc8c7918c
Cr-Commit-Position: refs/heads/master@{#401708}

[Devlin, 2016-06-21 00:42:16]

rdevlin.cronin@chromium.org changed reviewers:
+ lazyboy@chromium.org, mpearson@chromium.org

[Devlin, 2016-06-21 00:42:18]

Mark and Istiaque, mind taking a look?

https://codereview.chromium.org/2079273005/diff/1/extensions/browser/extensio...
File extensions/browser/extension_function.cc (right):

https://codereview.chromium.org/2079273005/diff/1/extensions/browser/extensio...
extensions/browser/extension_function.cc:46:
UMA_HISTOGRAM_SPARSE_SLOWLY("Extensions.Functions.SucceededLessThan1ms",
I stole UMA_HISTOGRAM_SPARSE_SLOWLY from ExtensionFunctionDispatcher, where we
record which extension functions are called. [1]  I'm assuming that if it is the
right choice there, it's the right choice here, but reading the comments for the
macros, it seems like either SPARSE_SLOWLY or ENUMERATION would probably work. 
Mark, do you know if one is better than the other in one or both of these
places?

[1]
https://chromium.googlesource.com/chromium/src/+/7d873db838bd65a60ac84a236a48...

[lazyboy, 2016-06-21 01:01:40]

extension_function lgtm

[Mark P, 2016-06-22 21:48:01]

https://codereview.chromium.org/2079273005/diff/1/extensions/browser/extensio...
File extensions/browser/extension_function.cc (right):

https://codereview.chromium.org/2079273005/diff/1/extensions/browser/extensio...
extensions/browser/extension_function.cc:46:
UMA_HISTOGRAM_SPARSE_SLOWLY("Extensions.Functions.SucceededLessThan1ms",
On 2016/06/21 00:42:18, Devlin wrote:
> I stole UMA_HISTOGRAM_SPARSE_SLOWLY from ExtensionFunctionDispatcher, where we
> record which extension functions are called. [1]  I'm assuming that if it is
the
> right choice there, it's the right choice here, but reading the comments for
the
> macros, it seems like either SPARSE_SLOWLY or ENUMERATION would probably work.

> Mark, do you know if one is better than the other in one or both of these
> places?
> 
> [1]
>
https://chromium.googlesource.com/chromium/src/+/7d873db838bd65a60ac84a236a48...

Sparse is best used for histograms when not many distinct buckets are going to
be used _and_ the behavior isn't in a tight inner loop.  It's probably
reasonable here and in the code you cite.  Enumerated histograms take a lot more
memory because we preallocate all possible bucket (in this case all possible
extension function, oy).

https://codereview.chromium.org/2079273005/diff/1/tools/metrics/histograms/hi...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/2079273005/diff/1/tools/metrics/histograms/hi...
tools/metrics/histograms/histograms.xml:14219: +<histogram
name="Extensions.Functions.Failed1msTo5ms" enum="ExtensionFunctions">
Consider whether you might want to have one histogram name & description here:
"Extensions.Functions.Failed"
and then have the histogram suffixes 1msTo5ms, 5msto10ms, etc. to yield the four
histograms you want (e.g., Extensions.Functions.Failed.1msTo5ms) .  This would
be more compact.

ditto for success

[Devlin, 2016-06-22 22:40:53]

https://codereview.chromium.org/2079273005/diff/1/extensions/browser/extensio...
File extensions/browser/extension_function.cc (right):

https://codereview.chromium.org/2079273005/diff/1/extensions/browser/extensio...
extensions/browser/extension_function.cc:46:
UMA_HISTOGRAM_SPARSE_SLOWLY("Extensions.Functions.SucceededLessThan1ms",
On 2016/06/22 21:48:01, Mark P wrote:
> On 2016/06/21 00:42:18, Devlin wrote:
> > I stole UMA_HISTOGRAM_SPARSE_SLOWLY from ExtensionFunctionDispatcher, where
we
> > record which extension functions are called. [1]  I'm assuming that if it is
> the
> > right choice there, it's the right choice here, but reading the comments for
> the
> > macros, it seems like either SPARSE_SLOWLY or ENUMERATION would probably
work.
> 
> > Mark, do you know if one is better than the other in one or both of these
> > places?
> > 
> > [1]
> >
>
https://chromium.googlesource.com/chromium/src/+/7d873db838bd65a60ac84a236a48...
> 
> Sparse is best used for histograms when not many distinct buckets are going to
> be used _and_ the behavior isn't in a tight inner loop.  It's probably
> reasonable here and in the code you cite.  Enumerated histograms take a lot
more
> memory because we preallocate all possible bucket (in this case all possible
> extension function, oy).

Cool, so sounds like this is the right one. :)

https://codereview.chromium.org/2079273005/diff/1/tools/metrics/histograms/hi...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/2079273005/diff/1/tools/metrics/histograms/hi...
tools/metrics/histograms/histograms.xml:14219: +<histogram
name="Extensions.Functions.Failed1msTo5ms" enum="ExtensionFunctions">
On 2016/06/22 21:48:01, Mark P wrote:
> Consider whether you might want to have one histogram name & description here:
> "Extensions.Functions.Failed"
> and then have the histogram suffixes 1msTo5ms, 5msto10ms, etc. to yield the
four
> histograms you want (e.g., Extensions.Functions.Failed.1msTo5ms) .  This would
> be more compact.
> 
> ditto for success

Done.

[Mark P, 2016-06-23 19:05:22]

histograms.xml lgtm

https://codereview.chromium.org/2079273005/diff/20001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/2079273005/diff/20001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:92911: +  <suffix name="Over10ms"
label="Execution took over 10ms (glacial)."/>
love your commentary :-)

[Devlin, 2016-06-23 19:42:59]

The CQ bit was checked by rdevlin.cronin@chromium.org

[Devlin, 2016-06-23 19:43:00]

The patchset sent to the CQ was uploaded after l-g-t-m from lazyboy@chromium.org
Link to the patchset: https://codereview.chromium.org/2079273005/#ps20001
(title: "Mark's")

[commit-bot: I haz the power, 2016-06-23 19:43:35]

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

[commit-bot: I haz the power, 2016-06-23 20:41:27]

Committed patchset #2 (id:20001)

[commit-bot: I haz the power, 2016-06-23 20:43:29]

Description was changed from

==========
[Extensions] Add more fine-grained extension performance metrics

The previous batch of metrics (Extensions.Functions.Succeeded/Failed*)
have been baking long enough that we have some baseline stats for what a
fast or slow function looks like. Add buckets for <1ms, 1 - 5ms, 5 -
10ms, and >10ms that record the actual function that was called so that
we can analyze whether there is a problem with the functions taking
longest.

BUG=608561
==========

to

==========
[Extensions] Add more fine-grained extension performance metrics

The previous batch of metrics (Extensions.Functions.Succeeded/Failed*)
have been baking long enough that we have some baseline stats for what a
fast or slow function looks like. Add buckets for <1ms, 1 - 5ms, 5 -
10ms, and >10ms that record the actual function that was called so that
we can analyze whether there is a problem with the functions taking
longest.

BUG=608561

Committed: https://crrev.com/9380ff2d3f2b42ca3def7ded5af3921cc8c7918c
Cr-Commit-Position: refs/heads/master@{#401708}
==========

[commit-bot: I haz the power, 2016-06-23 20:43:30]

Patchset 2 (id:??) landed as
https://crrev.com/9380ff2d3f2b42ca3def7ded5af3921cc8c7918c
Cr-Commit-Position: refs/heads/master@{#401708}