Closed Bug 1368524 Opened 7 years ago Closed 7 years ago

Add a telemetry probe for how long we spend processing NotifyObservers callbacks

Categories

(Core :: XPCOM, enhancement)

enhancement
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla55
Performance Impact low
Tracking Status
firefox55 --- fixed

People

(Reporter: nika, Assigned: nika)

Details

Attachments

(1 file, 1 obsolete file)

We should keep track of how long we spend running NotifyObservers callbacks synchronously, and look into making the egregious offenders run their callbacks in an idle callback or similar.
Comment on attachment 8872442 [details] [diff] [review]
Add a telemetry probe for how long we spend processing NotifyObservers callbacks, dr=bsmedberg

Review of attachment 8872442 [details] [diff] [review]:
-----------------------------------------------------------------

::: toolkit/components/telemetry/Histograms.json
@@ +13246,5 @@
>      "keyed": true,
>      "description": "Measures the number of milliseconds we spend processing sync IPC messages in the receiving process, keyed by message name. Note: only messages that take over 500 microseconds are included in this probe."
> +  },
> +  "NOTIFY_OBSERVERS_LATENCY_MS": {
> +    "record_in_processes": ["main", "content"],

Any reason why we should restrict this to these processes?

@@ +13252,5 @@
> +    "bug_numbers": [1368524],
> +    "expires_in_version": "60",
> +    "kind": "exponential",
> +    "low": 3,
> +    "high": 128,

Why such a low high value?
Attachment #8872442 - Flags: review?(ehsan) → review+
(In reply to :Ehsan Akhgari (needinfo please, extremely long backlog) from comment #2)
> Any reason why we should restrict this to these processes?

Most probes are only collected in main and content, and I wasn't even sure if observers ever fired in the gpu process. I can add it there if you would like.

> Why such a low high value?

I figured that we would want a lower range than the sync IPC work, as hopefully these shouldn't be running nearly as long.

I arbitrarily chose 128 as the threshold, as over that number the hangs should start appearing in BHR, but I can bump it up to say 512ms?
Flags: needinfo?(ehsan)
Attachment #8872442 - Attachment is obsolete: true
(In reply to Michael Layzell [:mystor] from comment #3)
> (In reply to :Ehsan Akhgari (needinfo please, extremely long backlog) from
> comment #2)
> > Any reason why we should restrict this to these processes?
> 
> Most probes are only collected in main and content, and I wasn't even sure
> if observers ever fired in the gpu process. I can add it there if you would
> like.

Doesn't matter I guess.

> > Why such a low high value?
> 
> I figured that we would want a lower range than the sync IPC work, as
> hopefully these shouldn't be running nearly as long.
> 
> I arbitrarily chose 128 as the threshold, as over that number the hangs
> should start appearing in BHR, but I can bump it up to say 512ms?

Yes please.  I applaud your faith in the current state of our code base though.  ;-)
Flags: needinfo?(ehsan)
Whiteboard: [qf] → [qf:p3]
Comment on attachment 8873069 [details] [diff] [review]
Add a telemetry probe for how long we spend processing NotifyObservers callbacks, dr=bsmedberg

It may be worth documenting that this bunches all the observer together.

Also why the 500ms threshold? I'd be interested in either have no threshold or setting a single-frame budget like 16ms as our base.

data-r=me
Attachment #8873069 - Flags: review?(benjamin) → review+
Pushed by michael@thelayzells.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/60b8fd06f8fb
Add a telemetry probe for how long we spend processing NotifyObservers callbacks, dr=bsmedberg, r=ehsan
It'd be nice to get this into 54 as well (but it may be too late...)
Flags: needinfo?(michael)
(In reply to :Ehsan Akhgari (needinfo please, extremely long backlog) from comment #8)
> It'd be nice to get this into 54 as well (but it may be too late...)

My request for the other probe was also turned down, so I don't think this one will make it.
Flags: needinfo?(michael)
https://hg.mozilla.org/mozilla-central/rev/60b8fd06f8fb
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Performance Impact: --- → P3
Whiteboard: [qf:p3]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: