Resources added to root url load group via setTimeout can cause significant load time noise
Categories
(Core :: Performance, enhancement, P3)
Tracking
()
Tracking | Status | |
---|---|---|
firefox70 | --- | affected |
People
(Reporter: acreskey, Unassigned)
References
(Blocks 1 open bug)
Details
Attachments
(2 files, 1 obsolete file)
I was investigating page load performance noise, specifically large outliers.
The test was raptor-tp6m-amazon-geckoview-cold
on the Moto G5.
The most common load time (onLoad event) was around 1300ms.
But I would frequently see load times of close to 2000ms.
By looking into what was loaded in the slow cases I noticed that a batch of images were added to the root resource loadgroup prior to the load event firing.
In the fast case, these images were loaded after the load event firing.
So we are measuring the load timing for a superset of resources in the slow load case.
i.e. not comparing apples to apples.
The first resource in this batch is https://images-na.ssl-images-amazon.com/images/G/01/gateway/grid/test/all_beauty2x._CB518612027_.png
You can see it in the load group that's a child of the root url's loadgroup here:
With changes that I intend to land to the logging of LoadGroups, this will be easier to spot going forward.
[0x8732d780]: Adding request 0x873be844 https://www.amazon.com/ (count=0).
07-09 13:18:25.628 18116 18131 V AJC - loadgroup: LOADGROUP [0x86189480]: rootLoadGroup 0x8732d780 Adding request 0x86e90044 https://images-na.ssl-images-amazon.com/images/G/01/gateway/grid/test/all_beauty2x._CB518612027_.png (count=0).
Profiles:
Slow (all_beauty2x
and related images loaded before onload)
https://perfht.ml/2JfCaOQ
Fast (all_beauty2x
and related images loaded after onload)
https://perfht.ml/2JfbDku
smaug was able to pinpoint this down to a setTimeout call using innerHTML to create the image element, thus triggering the early load:
https://perfht.ml/2NJTv6v
Logging this so we can discuss.
Can we defer all setTimeouts until after pageload? (that would probably hurt some pages?)
By spec, do these new resources have to go in the loadgroup of the root url?
Comment 1•5 years ago
|
||
Bugbug thinks this bug is a enhancement, but please change it back in case of error.
Comment 2•5 years ago
|
||
I believe this is spec behavior for loads; these are dependent resources of the document (once the setTimeout fires and tries to add them). smaug: correct?
If so it's likely just the same sort of variability that the timeout deferral attacked, but if we get idle time we will run the timeouts, and that can add things to the load group. We could tweak the definition of "idle" during load, to require a longer idle period than normal; but at some point there will be negative consequences to doing so (perhaps not seen in load time, but in other ways)
Comment 3•5 years ago
•
|
||
Yes :)
"Fetching the image must delay the load event of the element's node document until the task that is queued by the networking task source once the resource has been fetched (defined below) has been run. "
https://html.spec.whatwg.org/#the-end see step 6 (currently step 6)
"Spin the event loop until there is nothing that delays the load event in the Document."
Clicking that 'delays the load event ' tells what all delays load event that way.
Reporter | ||
Comment 4•5 years ago
|
||
Thanks guys.
Right - if we delay the setTimeout() then we delay the requests for the images.
And this could regress visual completeness.
For this page those images happen to be way, way below the fold (attached).
Although there is also some JS that's requested.
More for curiosity, I'll try to attach Chrome on android to this recording to see what it does with that setTimeout() and those images.
Reporter | ||
Updated•5 years ago
|
Reporter | ||
Comment 5•5 years ago
|
||
InnerHTML images added via setTimeout().
Reporter | ||
Comment 6•5 years ago
|
||
So if I'm reading the Chrome profiler correctly, those images are loaded way after the load event. (Moto G5, Chrome 75).
But that's not telling me too much -- gecko does the same thing, roughly 9 times out of 10.
Updated•5 years ago
|
Reporter | ||
Comment 7•5 years ago
|
||
To see how many sites are affected by this behavior I made a comparison:
Left-hand-side is baseline (with the idle detection tweak from Bug 1541229)
Right-hand-side doesn't run the setTimeout()
in the idle cue (commented out). So the setTimeouts()
run at onload.
Main comparison view (some jobs still running):
https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=190b8f87707ac2e16c9d94003310fec1700a14ad&newProject=try&newRevision=8cd358ef99bf055bd288661057d37ebcae9185b5&framework=10
Some interesting results:
• You can see the removal of most of the bimodal amazon loads here
• Removal of big outliers on ebay
• Did not remove all the outliers on instagram
• A 25% 'improvement' on amazon loadtime and a 35% 'improvement' on google loadtime on pixel 2 (no idea what the visual impact is). And makes sense since we push off more work till after.
Reporter | ||
Comment 8•5 years ago
|
||
Of the first five tp6 cold pages (G5), three of them have a bimodal loading pattern.
Deferring the setTimeout() execution "fixes" all three.
I've attached a screenshot of the replicates compare for google, but amazon and instagram are similar (baseline on top, experiment on the bottom).
tp6m-amazon-geckoview-cold
In the amazon case, images are added to the DOM via a setTimeout.
Deferring the setTimeouts causes these images to be added after the load and we get rid of the longer ~1500ms load times.
tp6m-google-geckoview-cold
On google, the setTimeout() adds a script node, so more network resources are added to the load group.
Deferring the addition of the script removes the 2x loadtime loads.
tp6m-instagram-geckoview-cold
In this case it’s a notification screen that’s triggered by a setTimeout.
If this setTimeout runs before load then about a half dozen images are added to the load group.
Instagram is interesting in that it’s one case were deferring all the setTimeouts() actually delays the load event.
I haven’t run this test on every site. It does appear to remove most of the bimodal load event behaviour, but not all.
e.g.
tp6m-ebay-kleinanzeigen-search-geckoview-cold
Here something else is causing the occasional faster loads.
Reporter | ||
Comment 9•5 years ago
|
||
For curiosity's sake, :denispal ran a visual metrics test of the deferred time execution:
https://pastebin.com/raw/VFZSJpjm
Major improvements in loadtime, major regressions in visual metrics.
Reporter | ||
Comment 10•5 years ago
|
||
I'm thinking that this be closed as "wont-fix" -- any thoughts?
Reporter | ||
Comment 11•5 years ago
|
||
Closing as won't fix for now.
Description
•