New issue
Advanced search Search tips

Issue 608561 link

Starred by 1 user

Issue metadata

Status: Assigned
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux , Windows , Chrome , Mac
Pri: 2
Type: Bug



Sign in to add a comment

Gather metrics on extension function performance

Project Member Reported by rdevlin....@chromium.org, May 3 2016

Issue description

We have insight into how often extension functions run, but not how performant they are.  We should add UMA for this.

Unfortunately, UMA maps don't exist (and aren't on the roadmap), so we can't do something awesome like:
UMA_HISTOGRAM_TIMES_MAP(
    "Extension.FunctionElapsedTime",
    function_name,
    time_taken);

which would give us granular information about how much time each call takes.  However, at the advice of some of the metrics folks, we can use a general bucketing principal to help us out.  For instance, if we know that fast extensions run in less < 1x ms, we can make buckets for time t < 1x ms, 1x < t < 10x ms, 10x < t < 100x ms, etc, so that we can see what the worst offenders are.

Another hitch is that extension functions are sometimes asynchronous, so the synchronous execution and asynchronous execution may differ heavily.  And, with asynchronous execution, we also have to deal with things like user interaction, where most bets are off.  We'll have to account for this in our metrics.
 
Project Member

Comment 1 by bugdroid1@chromium.org, May 3 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/f46fe266479fc6e1b133a80ad4ff95f15e064be7

commit f46fe266479fc6e1b133a80ad4ff95f15e064be7
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Tue May 03 23:15:36 2016

[Extensions] Add coarse metrics for extension function performance

Add metrics for extension function performance for overall and
synchronous execution time.
After these stew awhile, I'll add bucketed metrics that can capture
specific extension metrics (see bug for more details).

BUG=608561

Review-Url: https://codereview.chromium.org/1939413002
Cr-Commit-Position: refs/heads/master@{#391389}

[modify] https://crrev.com/f46fe266479fc6e1b133a80ad4ff95f15e064be7/extensions/browser/extension_function.cc
[modify] https://crrev.com/f46fe266479fc6e1b133a80ad4ff95f15e064be7/extensions/browser/extension_function.h
[modify] https://crrev.com/f46fe266479fc6e1b133a80ad4ff95f15e064be7/extensions/browser/extension_function_dispatcher.cc
[modify] https://crrev.com/f46fe266479fc6e1b133a80ad4ff95f15e064be7/tools/metrics/histograms/histograms.xml

Project Member

Comment 2 by bugdroid1@chromium.org, Jun 22 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/b2b31390d6845f42b5966f854e90f69ff39705e0

commit b2b31390d6845f42b5966f854e90f69ff39705e0
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Wed Jun 22 23:39:13 2016

[Extensions] Add perf metrics for StartRequest()/HandleResponse()

StartRequest() and HandleResponse() are used in the renderer to start
and finish an extension function call. The most intensive part of this
involves receiving arguments from v8 and converting them to base::Values
(or vice versa). Add a timer to see how long this takes.

Depending on the data, we may also want to break this into buckets and
record the function enum to highlight particularly egregious functions,
as we do for function execution time.

BUG=608561

Review-Url: https://codereview.chromium.org/2088663002
Cr-Commit-Position: refs/heads/master@{#401462}

[modify] https://crrev.com/b2b31390d6845f42b5966f854e90f69ff39705e0/extensions/renderer/request_sender.cc
[modify] https://crrev.com/b2b31390d6845f42b5966f854e90f69ff39705e0/extensions/renderer/request_sender.h
[modify] https://crrev.com/b2b31390d6845f42b5966f854e90f69ff39705e0/extensions/renderer/send_request_natives.cc
[modify] https://crrev.com/b2b31390d6845f42b5966f854e90f69ff39705e0/tools/metrics/histograms/histograms.xml

Project Member

Comment 3 by bugdroid1@chromium.org, Jun 23 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/9380ff2d3f2b42ca3def7ded5af3921cc8c7918c

commit 9380ff2d3f2b42ca3def7ded5af3921cc8c7918c
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Thu Jun 23 20:41:07 2016

[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

Review-Url: https://codereview.chromium.org/2079273005
Cr-Commit-Position: refs/heads/master@{#401708}

[modify] https://crrev.com/9380ff2d3f2b42ca3def7ded5af3921cc8c7918c/extensions/browser/extension_function.cc
[modify] https://crrev.com/9380ff2d3f2b42ca3def7ded5af3921cc8c7918c/tools/metrics/histograms/histograms.xml

Project Member

Comment 4 by bugdroid1@chromium.org, Jun 29 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/95cbe926faeb42e0f4fcfa3c42c9cba95e77e4e5

commit 95cbe926faeb42e0f4fcfa3c42c9cba95e77e4e5
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Wed Jun 29 22:40:52 2016

[Extensions] Add metrics for API binding generation time

Extension API bindings are generated through some fancy javascript code,
but it's probably pretty slow by comparison to other mechanisms we're
looking at. Add UMA for the generation times so we have a better
picture.

BUG=608561

Review-Url: https://codereview.chromium.org/2102383002
Cr-Commit-Position: refs/heads/master@{#402969}

[modify] https://crrev.com/95cbe926faeb42e0f4fcfa3c42c9cba95e77e4e5/extensions/renderer/module_system.cc
[modify] https://crrev.com/95cbe926faeb42e0f4fcfa3c42c9cba95e77e4e5/tools/metrics/histograms/histograms.xml

Project Member

Comment 5 by bugdroid1@chromium.org, Oct 6 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/c6be58d620359b6c02b4b8b60a554dff2a928e6e

commit c6be58d620359b6c02b4b8b60a554dff2a928e6e
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Thu Oct 06 01:35:54 2016

[Extensions] Add metrics for execution time of binding.js

Add UMA for the time it takes for the BindingGeneratingNativeHandler
to create the JS object representing an API object. Since this tends to
be a fast process (but a repeated one), use microsecond accuracy.

BUG=608561

Review-Url: https://codereview.chromium.org/2395803003
Cr-Commit-Position: refs/heads/master@{#423384}

[modify] https://crrev.com/c6be58d620359b6c02b4b8b60a554dff2a928e6e/extensions/renderer/binding_generating_native_handler.cc
[modify] https://crrev.com/c6be58d620359b6c02b4b8b60a554dff2a928e6e/tools/metrics/histograms/histograms.xml

Project Member

Comment 6 by bugdroid1@chromium.org, Oct 27 2016

Labels: merge-merged-2840
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/c6be58d620359b6c02b4b8b60a554dff2a928e6e

commit c6be58d620359b6c02b4b8b60a554dff2a928e6e
Author: rdevlin.cronin <rdevlin.cronin@chromium.org>
Date: Thu Oct 06 01:35:54 2016

[Extensions] Add metrics for execution time of binding.js

Add UMA for the time it takes for the BindingGeneratingNativeHandler
to create the JS object representing an API object. Since this tends to
be a fast process (but a repeated one), use microsecond accuracy.

BUG=608561

Review-Url: https://codereview.chromium.org/2395803003
Cr-Commit-Position: refs/heads/master@{#423384}

[modify] https://crrev.com/c6be58d620359b6c02b4b8b60a554dff2a928e6e/extensions/renderer/binding_generating_native_handler.cc
[modify] https://crrev.com/c6be58d620359b6c02b4b8b60a554dff2a928e6e/tools/metrics/histograms/histograms.xml

Comment 7 by dimu@google.com, Nov 4 2016

Labels: -merge-merged-2840
[Automated comment] removing mislabelled merge-merged-2840
Cc: -asargent@chromium.org

Sign in to add a comment