Open Bug 1745512 Opened 3 years ago Updated 2 years ago

Significant performance impact when using Webpagetest and ES Modules

Categories

(Core :: JavaScript Engine, defect, P3)

Firefox 94
defect

Tracking

()

Performance Impact high
Tracking Status
firefox95 --- affected
firefox96 --- affected
firefox97 --- affected

People

(Reporter: richard.bull, Unassigned, NeedInfo)

References

Details

(Keywords: perf:pageload, reproducible)

Steps to reproduce:

  1. Setup WPT run using https://webpagetest.org/ and https://richallanb.github.io/esm-with-http2/es6-modules.html as target
  2. Select First & Repeat views under advanced tab and 5 runs
  3. Examine median Visually Complete metric

https://richallanb.github.io/esm-with-http2/es6-modules.html simply loads lodash-es using ESM. This page was built using a forked code from a bug reported a few years ago, https://bugzilla.mozilla.org/show_bug.cgi?id=1365187
Repo: https://github.com/richallanb/esm-with-http2

Actual results:

Significant performance gap between Chrome and Firefox

Expected results:

Firefox ESM performance should be somewhat comparable to Chrome ESM performance.
There's a large push to move to using ES Modules to serve javascript within our company (ServiceNow) and we've, so far, been unable to reliably measure performance on a day-to-day basis with Firefox using ESM.

Confirming a similar performance issue, tested based on the steps to reproduce provided by the reporter on MacOS 10.15.

Firefox Release Version 95.0.2 : 2.579s median
Firefox Beta 96.0b9: 4.279s median
Firefox Nightly 97.0a1: 4.349s median

Chrome Version 96.0.4664.110 : 2.436s median VC

Severity: -- → S3
Status: UNCONFIRMED → NEW
Component: Untriaged → JavaScript Engine
Ever confirmed: true
Product: Firefox → Core

It looks like, according to the numbers :tbabos provided, 95 might not be affected and we have a regression in 96? Am I reading that right?

Possible regression from the changes here: https://bugzilla.mozilla.org/show_bug.cgi?id=1311726 -- this is in 97 though, it wouldn't explain earlier regressions.

I've tested revisions up to 92, and it looks like this isn't a regression. In 92 we had significantly worse performance, this improved in 93. Since 93, I have measured an average of ~1.5s on my machine for modules, up to the current nightly. This is still twice the load time of chrome which came in at around 0.7s on my test machine. We have some improvement to do here.

At the moment, caching isn't turned on for modules, but work has already been done to enable it. That is the first thing that comes to mind for me. But there are likely other opportunities. cc arai and dpalmeiro in case they have other ideas.

Flags: needinfo?(dpalmeiro)
Flags: needinfo?(arai.unmht)

I can reproduce this locally using browsertime. It seems we are significantly slower on the reloads, but faster on the cold load. I think this is probably just a caching issue.

SpeedIndex                                                                          Chrome96                  Firefox94                     
-----------------------------------------------------------------------------------------------------------------------------------------
https://richallanb.github.io/esm-with-http2/es6-modules.html                     |    146.60 (+-  38)      |    93.00 (+-  28)   36.56% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=2   |    126.80 (+-  24)      |   421.40 (+- 197) -232.33% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=3   |     99.60 (+-  16)      |   318.20 (+- 219) -219.48% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=4   |    106.20 (+-  27)      |   350.60 (+- 251) -230.13% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=5   |    100.40 (+-  26)      |   341.80 (+- 232) -240.44% |


VisualComplete85                                                                    Chrome96                  Firefox94                     
-----------------------------------------------------------------------------------------------------------------------------------------
https://richallanb.github.io/esm-with-http2/es6-modules.html                     |    146.60 (+-  38)      |    93.00 (+-  28)   36.56% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=2   |    113.40 (+-  18)      |   420.40 (+- 200) -270.72% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=3   |     93.20 (+-  15)      |   313.40 (+- 225) -236.27% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=4   |     93.40 (+-  28)      |   346.80 (+- 257) -271.31% |
https://richallanb.github.io/esm-with-http2/es6-modules.html?browsertime_run=5   |     93.60 (+-  28)      |   340.00 (+- 235) -263.25% |

Flags: needinfo?(dpalmeiro)

I'm going to take a look into why the reloads are so slow though. That seems a bit odd.

(In reply to Denis Palmeiro [:denispal] from comment #4)

I can reproduce this locally using browsertime. It seems we are significantly slower on the reloads, but faster on the cold load. I think this is probably just a caching issue.

This follows some of the internal metrics we've been seeing with our various products. Thank you so much for looking into this. Is there anything else I/we can do to assist with the investigation?

(In reply to Denis Palmeiro [:denispal] from comment #5)

I'm going to take a look into why the reloads are so slow though. That seems a bit odd.

Took a look, and it's mostly just because Firefox's tab shows a loading gradient during refresh so it trips up the visual metrics and makes them seem worse than it actually is. So, this seems like mostly just a caching issue to help the reloads.

Whiteboard: [qf]
Flags: needinfo?(arai.unmht)
Whiteboard: [qf] → [qf:p1:pageload]

Denis: do you know when a fix for this is likely to land?

Priority: -- → P3

Matthew: any update on when this problem is likely to be fixed?

Performance Impact: --- → P1
Keywords: perf:pageload
Whiteboard: [qf:p1:pageload]

The Performance Priority Calculator has determined this bug's performance priority to be P1. If you'd like to request re-triage, you can reset the Performance flag to "?" or needinfo the triage sheriff.

Platforms: [x] Windows [x] macOS [x] Linux [x] Android
Page load impact: Some
[x] Able to reproduce locally
[x] Bug affects multiple sites

Keywords: reproducible

I had a look at this in the profiler, and most of the time is spent getting data from the networking layer. In the cold load case this is actually coming from the network. In later cases it's coming from the cache, but that doesn't seem to improve things that much. It's taking a couple of hundred milliseconds to load resources that are less the half a kilobyte.

Looking at main thread profile, most of the time is spent running JS and most of that is in the observe method in WebRequest.jsm: https://searchfox.org/mozilla-central/source/toolkit/components/extensions/webrequest/WebRequest.jsm#714-731

I don't know what this is doing but it seems like we shouldn't have to run JS to fetch resources from the cache.

Profile: https://share.firefox.dev/3qZW5pN

The severity field for this bug is set to S3. However, the Performance Impact field flags this bug as having a high impact on the performance.
:sdetar, could you consider increasing the severity of this performance-impacting bug? Alternatively, if you think the performance impact is lower than previously assessed, could you request a re-triage from the performance team by setting the Performance Impact flag to ??

For more information, please visit auto_nag documentation.

Flags: needinfo?(sdetar)
Flags: needinfo?(sdetar)

I seem to remember thinking this was something to do with service workers but I don't really know much about those. Do you know why getting data from the cache is so slow and if there's anything we can do about it? See comment 11 for details. Alternatively please redirect if I'm off base with this.

Flags: needinfo?(echuang)
You need to log in before you can comment on or make changes to this bug.