Closed Bug 1353172 Opened 3 years ago Closed 2 years ago

Add telemetry for background page load time time

Categories

(WebExtensions :: General, enhancement, P1)

51 Branch
enhancement

Tracking

(firefox55 fixed)

RESOLVED FIXED
mozilla55
Tracking Status
firefox55 --- fixed

People

(Reporter: bsilverberg, Assigned: bsilverberg)

References

(Blocks 1 open bug)

Details

(Whiteboard: [metrics] triaged)

Attachments

(1 file)

This would measure the time between the start of the build function and when we get notification that the page is fully loaded.
I'm about to attach a patch to this bug. I made some guesses at some things in the patch, about which I would appreciate clarification. Specifically, I'm not sure about:

In Histograms.json:
- alert_emails - I added Kris, but do we also want Andy and/or me listed?
- expires_in_version -  I used "never" as I think we want to track this over time, with no particular end date, in case there are regressions. I'm not sure if the use of "never" is frowned upon and if we therefore need to specify a future version.
- high - I used 60000, which seems pretty high to me, so we might want to lower that a bit.


I did not make this a keyed histogram (keyed on addonId) as I think we just want to track overall performance of background pages, and are not concerned with looking at particular addons (at this time anyway). I have asked a question about whether we can generate aggregate metrics from a keyed histogram, and if we can then maybe we want to make this keyed now, which would allow us to track both general performance and addon specific performance if desired.
 
I included a test for the telemetry probe, which seems like a worthwhile thing to do, although it also seems like if it passes once there's no reason to ever expect it to regress, unless telemetry overall breaks, so maybe it's not a test we need.
I heard back from Georg about keyed histograms and aggregate data. It sounds like it's possible to get aggregate data about keyed histograms, but if we want the aggregates to be easily available we should request both keyed and aggregate data. Do you think we want keyed data for this one?
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

https://reviewboard.mozilla.org/r/131354/#review135498

This will also need data review from a data collection peer.

::: toolkit/components/extensions/ext-backgroundPage.js:39
(Diff revision 1)
>        this.url = this.extension.baseURI.resolve("_blank.html");
>      }
>    }
>  
>    async build() {
> +    TelemetryStopwatch.start("WEBEXT_BACKGROUND_PAGE_LOAD_MS");

This isn't going to work. If we load multiple add-ons at the same time, they'll wind up with overlapping stopwatches, and we'll just get bad data or errors. You need to pass an object as the second argument to keep the timers matched up.

::: toolkit/components/extensions/ext-backgroundPage.js:68
(Diff revision 1)
>        await Promise.all(context.listenerPromises);
>        context.listenerPromises = null;
>      }
>  
>      this.extension.emit("startup");
> +    TelemetryStopwatch.finish("WEBEXT_BACKGROUND_PAGE_LOAD_MS");

Please move this to directly after the promiseExtensionViewLoaded call.

::: toolkit/components/extensions/test/xpcshell/test_ext_background_telemetry.js:14
(Diff revision 1)
> +  let histogram = Services.telemetry.getHistogramById(HISTOGRAM);
> +  histogram.clear();
> +  equal(histogram.snapshot().sum, 0, `No data recorded for histogram: ${HISTOGRAM}.`);
> +
> +  await extension.startup();
> +  await extension.awaitMessage("loaded");
> +
> +  ok(histogram.snapshot().sum > 0, `Data recorded for histogram: ${HISTOGRAM}.`);

Please test with multiple extensions loaded at once.

::: toolkit/components/telemetry/Histograms.json:11353
(Diff revision 1)
>      "kind": "enumerated",
>      "n_values": 99,
>      "description": "Count of which display items are being used by type id"
> +  },
> +  "WEBEXT_BACKGROUND_PAGE_LOAD_MS": {
> +    "alert_emails": ["kmaglione@mozilla.com"],

Please send these to dev-addons or dev-addons-internal.
Attachment #8859323 - Flags: review?(kmaglione+bmo)
(In reply to Bob Silverberg [:bsilverberg] from comment #3)
> I heard back from Georg about keyed histograms and aggregate data. It sounds
> like it's possible to get aggregate data about keyed histograms, but if we
> want the aggregates to be easily available we should request both keyed and
> aggregate data. Do you think we want keyed data for this one?

For this histogram, let's just start with the regular histogram and consider adding a keyed histogram if the data turns out to be noisy.
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

https://reviewboard.mozilla.org/r/131354/#review135498

Yes. I was planning on adding an f? for that once the patch looked ready to go, so I wanted to get through the code review first. Also, it was brought to my attention late last week that we need to go through a step to complete an "Analysis Plan" before moving forward with any patches, so that is also underway.
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

Flagging bsmedberg for data collection review.
Attachment #8859323 - Flags: feedback?(benjamin)
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

https://reviewboard.mozilla.org/r/131354/#review138060

::: toolkit/components/telemetry/Histograms.json:11407
(Diff revision 2)
> +    "bug_numbers": [1353172],
> +    "expires_in_version": "never",
> +    "kind": "exponential",
> +    "high": 60000,
> +    "n_buckets": 20,
> +    "description": "The amount of time it takes to load a WebExtensions background page, from when the build function is called to when the page is fully loaded."

What is your definition of "fully loaded"? The onload event or DOMContentLoaded (or something else)?

Related to the expiration and opt-in status: do you have an analysis plan for this data? In particular, I'd like to see the purpose/questions you're trying to answer by collecting this. It's not clear to me whether this is intended to watch for Firefox regressions, or addon regressions, or something else. Since prerelease users are not typical addon users, why is limiting this to prerelease valuable?

high=60000 with 20 buckets makes for some very large buckets. Here's your bucket list:

0, 1, 2, 4, 7, 13, 24, 44, 80, 146, 267, 487, 889, 1.62k, 2.96k, 5.41k, 9.87k, 18.01k, 32.87k, 60k

Are you sure buckets that wide are useful to you for answering the questions you have?
Flags: needinfo?(bob.silverberg)
(In reply to Benjamin Smedberg [:bsmedberg] from comment #9)
> Comment on attachment 8859323 [details]
> Bug 1353172 - Add telemetry for background page load time time,
> 
> https://reviewboard.mozilla.org/r/131354/#review138060
> 
> ::: toolkit/components/telemetry/Histograms.json:11407
> (Diff revision 2)
> > +    "bug_numbers": [1353172],
> > +    "expires_in_version": "never",
> > +    "kind": "exponential",
> > +    "high": 60000,
> > +    "n_buckets": 20,
> > +    "description": "The amount of time it takes to load a WebExtensions background page, from when the build function is called to when the page is fully loaded."
> 
> What is your definition of "fully loaded"? The onload event or
> DOMContentLoaded (or something else)?
> 

Looking at [1], I believe it is DOMContentLoaded, but Kris can correct me if I am wrong.

> Related to the expiration and opt-in status: do you have an analysis plan
> for this data? In particular, I'd like to see the purpose/questions you're
> trying to answer by collecting this. It's not clear to me whether this is
> intended to watch for Firefox regressions, or addon regressions, or
> something else. Since prerelease users are not typical addon users, why is
> limiting this to prerelease valuable?

Yes, I have just finished putting together an analysis plan. It's attached to bug 1352992, and I just requested an implementation review from you on it. As discussed in the plan, we do want to collect this data for the release population, so I guess I didn't create the correct object in Histograms.json for that. I think I need "releaseChannelCollection": "opt-out", so I will update that.

> 
> high=60000 with 20 buckets makes for some very large buckets. Here's your
> bucket list:
> 
> 0, 1, 2, 4, 7, 13, 24, 44, 80, 146, 267, 487, 889, 1.62k, 2.96k, 5.41k,
> 9.87k, 18.01k, 32.87k, 60k
> 
> Are you sure buckets that wide are useful to you for answering the questions
> you have?

I'm not sure about that. I'll defer that to Kris.

[1] http://searchfox.org/mozilla-central/source/toolkit/components/extensions/ExtensionPageChild.jsm#341
Flags: needinfo?(bob.silverberg) → needinfo?(kmaglione+bmo)
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

Oops, I didn't mean to remove the f? for data review. I guess MozReview did that for me.
Attachment #8859323 - Flags: feedback?(benjamin)
I'm going to hold on this while I understand the other doc better. In this particular case for example, I doubt that you'd ever be able to do regression testing against this number, because of the huge variability between addons and the content they load.
The primary purpose of this telemetry won't be for detecting regressions. It's mostly about investigating the current state of things so that we can decide what kinds of optimizations to work on in the coming months.

In particular, we're considering the possibility of implementing something similar to Chrome's "event page" concept, where background pages are destroyed when inactive, and recreated when they next need to process an event. Similarly, I'm looking into delaying most of the extension startup process until the extension absolutely needs to run (e.g., to process an HTTP request).

In order to decide how to prioritize this work, we need to know how long it takes background pages to startup in the wild. Once we have a good sense of that, and if further work seems feasible, I plan to add additional telemetry to determine how many events background pages process, and the mean time between events, so that we can get an idea of how much there is to gain by various types of optimizations.
Flags: needinfo?(kmaglione+bmo)
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

Kris has added information about why we want to collect this data in the short term, to aid us in decision making. Re-flagging for data review.
Attachment #8859323 - Flags: feedback?(benjamin)
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

https://reviewboard.mozilla.org/r/131354/#review143082

::: toolkit/components/telemetry/Histograms.json:13006
(Diff revision 4)
> +    "expires_in_version": "60",
> +    "kind": "exponential",
> +    "releaseChannelCollection": "opt-out",
> +    "high": 60000,
> +    "n_buckets": 100,
> +    "description": "The amount of time it takes to load a WebExtensions background page, from when the build function is called to when the page is fully loaded."

s/fully loaded/finished processing the onload event/
Attachment #8859323 - Flags: review+
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

data-r=me with that change
Attachment #8859323 - Flags: feedback?(benjamin)
Comment on attachment 8859323 [details]
Bug 1353172 - Add telemetry for background page load time time,

https://reviewboard.mozilla.org/r/131354/#review147146
Attachment #8859323 - Flags: review?(kmaglione+bmo) → review+
Pushed by bsilverberg@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9975e1fd9faa
Add telemetry for background page load time time, r=bsmedberg,kmag
https://hg.mozilla.org/mozilla-central/rev/9975e1fd9faa
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Depends on: 1425957
Product: Toolkit → WebExtensions
You need to log in before you can comment on or make changes to this bug.