790213 - Measure page load time with FX_ Telemetry

Status: RESOLVED FIXED

(Firefox :: General, defect)

Description

[Lawrence Mandel [:lmandel] (use needinfo)]

Measure page load time from the perspective of browser.js with Telemetry.

Comment 1

[:Margaret Leibovic]

Attachment: probe for time throbber is active

It's hard to measure exact page load times, but measuring the time the throbber is active should let us know about perceived page load times.

I'm not familiar with making these probes, so please correct me if there are better parameters we should use in Histograms.json.

Comment 2

[(dormant account)]

Comment on attachment 660804 [details] [diff] [review]
probe for time throbber is active

+  "FX_TAB_THROBBER_MS": {
+    "kind": "exponential",
+    "high": "10000",
+    "n_buckets": 20,
+    "description": "Firefox: Time while tab throbber is active (ms)"
+  },

I wonder if we should measure pageload in seconds. Seems like it can vary quite a bit

Comment 3

[Dão Gottwald [:dao]]

Comment on attachment 660804 [details] [diff] [review]
probe for time throbber is active

>+                    TelemetryStopwatch.start("FX_TAB_THROBBER_MS", this.mTelemetryObj);

Seems like you could use 'this' rather than 'this.mTelemetryObj'.

The throbber can flicker briefly and frequently and doesn't necessarily represent the time spent loading a page. It can also keep spinning while most resources the user cares about are loaded. So the average time spent spinning isn't necessarily meaningful. You could maybe still use it to identify trends, but then there's a risk of significant variations due to behavior changes on some high-profile site, advertising network outages or something like this.

Comment 4

[:Margaret Leibovic]

Attachment: alternate page load probe

Here's a different approach that measures load time using the progress start/stop of the top level content window. The documentation for STATE_IS_WINDOW is slightly confusing, but I think that's what we want to use.

Comment 5

[:Margaret Leibovic]

(In reply to Taras Glek (:taras) from comment #2)
> Comment on attachment 660804 [details] [diff] [review]
> probe for time throbber is active
> 
> +  "FX_TAB_THROBBER_MS": {
> +    "kind": "exponential",
> +    "high": "10000",
> +    "n_buckets": 20,
> +    "description": "Firefox: Time while tab throbber is active (ms)"
> +  },
> 
> I wonder if we should measure pageload in seconds. Seems like it can vary
> quite a bit

TelemetryStopwatch uses ms, and I really like the ease of using that. However, I agree page load times can be on the order of seconds, so maybe we can extend TelemetryStopwatch. Felipe, what do you think?

Comment 6

[Dão Gottwald [:dao]]

Comment on attachment 660830 [details] [diff] [review]
alternate page load probe

>+    // Collect telemetry data about tab load times.
>+    if (aWebProgress.DOMWindow == content &&
>+        aStateFlags & Ci.nsIWebProgressListener.STATE_IS_WINDOW) {
>+      if (aStateFlags & Ci.nsIWebProgressListener.STATE_START)
>+        TelemetryStopwatch.start("FX_TAB_LOAD_MS", aBrowser);
>+      else if (aStateFlags & Ci.nsIWebProgressListener.STATE_STOP)
>+        TelemetryStopwatch.finish("FX_TAB_LOAD_MS", aBrowser);
>+    }

Due to the DOMWindow == content check, it looks like wrong numbers could be recorded here, e.g. if you start loading a page, select a different tab, reload the previous tab from its context menu and switch to the tab before it finishes loading.

Comment 7

[:Margaret Leibovic]

Attachment: alternate page load probe (v2)

Good catch. Instead of using |content|, this patch checks DOMWindow.top. I tested this loading tabs in the foreground and background, and the data I got seemed reasonable (it definitely contained the correct number of top-level page loads).

Comment 8

[Dão Gottwald [:dao]]

Comment on attachment 663514 [details] [diff] [review]
alternate page load probe (v2)

When reloading a loading page, will we get STATE_STOP before the next STATE_START?

Comment 9

[:Margaret Leibovic]

(In reply to Dão Gottwald [:dao] from comment #8)
> Comment on attachment 663514 [details] [diff] [review]
> alternate page load probe (v2)
> 
> When reloading a loading page, will we get STATE_STOP before the next
> STATE_START?

I added some logging to check, we do get a STATE_STOP before the next STATE_START.

I just realized that this means we could get an artificially short load time if the user hits reload on a loading page. And I suppose the same thing could happen if the user hits stop. Are these things we can detect? Or do these happen infrequently enough that we don't care? If all we're really interested in is seeing if we regress/improve over time, it seems like these cases might not matter.

Comment 10

[Dão Gottwald [:dao]]

Comment on attachment 663514 [details] [diff] [review]
alternate page load probe (v2)

>+    // Collect telemetry data about tab load times.

>+    "description": "Firefox: Time taken to load a tab (ms)"

s/tab/page/

Please rename FX_TAB_LOAD_MS to FX_PAGE_LOAD_MS or FX_PAGE_LOAD_TIME_MS.

Comment 11

[:Margaret Leibovic]

https://hg.mozilla.org/integration/mozilla-inbound/rev/1efdcc6dc41b

Comment 12

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/1efdcc6dc41b

Comment 13

[alex_mayorga]

Is bug 795939 related?

Comment 14

[:Margaret Leibovic]

(In reply to alex_mayorga from comment #13)
> Is bug 795939 related?

Yeah, that's caused by code from this patch.