Closed
Bug 1365187
Opened 8 years ago
Closed 7 years ago
Loading a large module graph takes a very long time
Categories
(Core :: JavaScript Engine, defect, P3)
Tracking
()
RESOLVED
FIXED
mozilla59
| Tracking | Status | |
|---|---|---|
| firefox59 | --- | fixed |
People
(Reporter: gil, Assigned: jonco)
References
Details
(Keywords: triage-deferred)
Attachments
(2 files, 2 obsolete files)
|
(deleted),
patch
|
jonco
:
review+
|
Details | Diff | Splinter Review |
|
(deleted),
patch
|
smaug
:
review+
|
Details | Diff | Splinter Review |
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36
Steps to reproduce:
Steps to reproduce the problem:
1. Create the following HTML:
```
<!DOCTYPE html>
<body>
<h1 id="output">It doesn't work...</h1>
<script>
console.time('benchmark')
</script>
<script type="module">
import _ from './node_modules/lodash-es/lodash.default.js'
const $ = document.querySelector.bind(document)
$('#output').textContent = _.toUpper('it works')
console.timeEnd('benchmark')
</script>
</body>
```
2. To make it work, you need to `npm install lodash-es@4.17.4`
3. Now serve the file from a web server.
4. lodash imports tens of modules, but the network fetching itself only takes a few seconds.
4. It takes about 18 seconds to see "IT WORKS". Most of the time, as seen in the "Performance" tab in devtools, is the browser sitting idle.
5. A blog post describing this in detail can be found in https://hackernoon.com/native-es-modules-ready-for-prime-time-87c64d294d3c
6. A github repo that implements the above steps (and more), can be found in https://github.com/giltayar/esm-with-http2. Just `npm install && npm run build` and then open `http://localhost:3000/es6-modules.html`.
Actual results:
It takes about 30 seconds to see "IT WORKS", and the browser is unresposive at that time.
Expected results:
Loading the module and seeing "IT WORKS" in less than a second, given that the network fetching, on localhost, should take 10s of milliseconds.
|
||
Comment 1•8 years ago
|
||
Thanks for the CC! I'm not the right person to triage this (although, per bug 568953 and bug 1240072 seems like it should be Core::Javascript Engine)
Component: Untriaged → JavaScript Engine
Flags: needinfo?(gandalf)
Product: Firefox → Core
|
||
Updated•8 years ago
|
Flags: needinfo?(jcoppeard)
|
Assignee | |
Comment 2•8 years ago
|
||
I've reproduced this. The test loads 641 modules and takes around 10 seconds.
|
|
Assignee | |
Comment 3•8 years ago
|
||
I'm not really familiar with lodash, but it seems that lodash-es is generated in a form where every method is in a separate module. That's probably make sense if you're going to bundle your modules because you may be able to only include methods that are actually used. But it doesn't make as much sense if you're serving your modules over the web as they then have to be transferred individually over http.
(for more info see: https://www.npmjs.com/package/lodash-es and https://lodash.com/custom-builds)
(In reply to Jon Coppeard (:jonco) from comment #2)
> I've reproduced this. The test loads 641 modules and takes around 10
> seconds.
On my computer it's around 30 seconds, but given that most of the time is CPU time, then it probably heavily depends on the strength of the CPU.
The point is that loading those files _bundled_ takes tens of milliseconds, and not because of network time. So something is eating up CPU.
(In reply to Jon Coppeard (:jonco) from comment #3)
> I'm not really familiar with lodash, but it seems that lodash-es is
> generated in a form where every method is in a separate module. That's
> probably make sense if you're going to bundle your modules because you may
> be able to only include methods that are actually used. But it doesn't make
> as much sense if you're serving your modules over the web as they then have
> to be transferred individually over http.
>
> (for more info see: https://www.npmjs.com/package/lodash-es and
> https://lodash.com/custom-builds)
That's true, but as I said in an earlier comment, the time it takes is not network time (I checked).
The whole point of this exercise for me was to see how I can optimize the network part (using http/2 and push mode), but I can't get to that if the parsing and loading time is *so* big. I believe the goal should be for the parsing and execution of these modules to take around the time it takes to parse and executing the same amount of code when it is bundled (and that time is measured in milliseconds).
And this is not an edge case. In the current world of frontend using npm packages - applications *do* use hundreds of small modules.
|
|
Assignee | |
Comment 6•8 years ago
|
||
(In reply to gil from comment #5)
I'm not suggesting that this is not a bug or unworthy of investigation.
How are you measuring network time out of interest?
|
|
Assignee | |
Comment 7•8 years ago
|
||
(In reply to Jon Coppeard (:jonco) from comment #6)
> (In reply to gil from comment #5)
> I'm not suggesting that this is not a bug or unworthy of investigation.
>
> How are you measuring network time out of interest?
I just looked at the Network tab.
|
|
Assignee | |
Comment 9•8 years ago
|
||
What is happening is that the script loader is creating a module load request for every module import found via every path from the root module in the module graph (not just for every imported module). For this particular module graph this creates ~360000 import requests. It's implemented like this because it's following the algorithm given in the spec, but it should be possible to do something equivalent that doesn't have this behaviour.
|
|
Assignee | |
Comment 10•8 years ago
|
||
Currently when we go to fetch a dependency of a module we create a new module load request, fetch the module, then recursively fetch its dependencies in the same way. If the module is currently being fetched then we wait for that fetch to finish, but we still go on to fetch its dependencies (which will already have been fetched).
This is wasteful and traverses all paths from the root module to all leaves in the module dependency graph. Instead we can check whether the module is currently fetching and if so wait for it and its dependencies to finish loading. We don't need to attempt to load it's dependencies after this point.
The patch changes ScriptLoader::StartFetchingModuleDependencies to do this.
|
||
Updated•8 years ago
|
Attachment #8870064 -
Flags: review?(bugs) → review+
|
||
Comment 11•8 years ago
|
||
Pushed by jcoppeard@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/1a261952f14a
When fetching a dependent module wait for any ongoing fetch of the module and its dependents to finish rather than creating a new load request r=smaug
|
||
Comment 12•8 years ago
|
||
Backed out for frequent Win7 test_linkErrorInCommon2.html failures.
https://hg.mozilla.org/mozilla-central/rev/96e18bec9fc8
https://treeherder.mozilla.org/logviewer.html#?job_id=101350016&repo=mozilla-inbound
TEST-START | dom/base/test/jsmodules/test_linkErrorInCommon2.html
GECKO(3516) | JavaScript error: , line 0: attempt to re-instantiate module after failure
GECKO(3516) | JavaScript error: chrome://mochitests/content/chrome/dom/base/test/jsmodules/module_missingImport.js, line 0: TypeError: Resolved module not found in map: ./module_simple1.js
TEST-INFO | started process screenshot
TEST-INFO | screenshot: exit 0
Buffered messages logged at 14:21:49
TEST-PASS | dom/base/test/jsmodules/test_linkErrorInCommon2.html | Check no modules were executed
Buffered messages finished
TEST-UNEXPECTED-FAIL | dom/base/test/jsmodules/test_linkErrorInCommon2.html | Check that an error was reported
testError@chrome://mochitests/content/chrome/dom/base/test/jsmodules/test_linkErrorInCommon2.html:20:5
onload@chrome://mochitests/content/chrome/dom/base/test/jsmodules/test_linkErrorInCommon2.html:1:1
GECKO(3516) | MEMORY STAT | vsize 788MB | vsizeMaxContiguous 890MB | residentFast 231MB | heapAllocated 87MB
TEST-OK | dom/base/test/jsmodules/test_linkErrorInCommon2.html | took 84ms
Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
|
||
Updated•7 years ago
|
Keywords: triage-deferred
Priority: -- → P3
|
||
Comment 13•7 years ago
|
||
es modules makes ff 58.0b7 crash. every time.
It worked fine with version 55. Tell me if you want example.
|
|
Assignee | |
Comment 14•7 years ago
|
||
(In reply to capocyril from comment #13)
Yes please do provide a test case if you're seeing crashes (and possibly file a new bug).
|
|
Assignee | |
Updated•7 years ago
|
Summary: Loading tens of ES Modules in parallel makes JS interpreter stall for more than 10 seconds → Loading a large module graph takes a very long time
|
|
Assignee | |
Updated•7 years ago
|
Attachment #8870064 -
Attachment is obsolete: true
|
|
Assignee | |
Comment 15•7 years ago
|
||
The spec algorithm was updated to one that, although equivalent, does not have this behaviour:
https://github.com/whatwg/html/pull/2971
|
|
||
Comment 16•7 years ago
|
||
Correction: es modules makes ff 58.0b7 crash. almost every time on localhost http://localhost:8080/ with my setup. Sometimes it works I don't know why. There are no errors. It seems to work when served from a normal https server. It worked fine with version ff v55. I HAVE TO USE OPERA for now for dev. Hypothesis: Race condition or not https ?
Also make it possible to serve from file:///
PS: How to edit a previous comment ?
|
|
Assignee | |
Comment 17•7 years ago
|
||
(In reply to capocyril from comment #16)
Thanks for letting us know. Please can you file a new bug and include a test case, and if possible details of the crash?
Flags: needinfo?(capocyril)
|
|
Assignee | |
Comment 18•7 years ago
|
||
Patch to simplify the module map interface to use URLs rather than load requests. This was part of the previous patch on this bug. Carrying r+.
Attachment #8935757 -
Flags: review+
|
|
Assignee | |
Comment 19•7 years ago
|
||
Patch to update the module loader to use the new algorithm in the spec to avoid requesting the same module more than once when loading a module graph.
Originally this used a ancestor list and avoided re-requesting any ancestor module to the one being considered. This doesn't prevent a previously loaded module from being requested on a different path through the graph. The STR in this bug show how this can result in an N^2 blowup in requested modules.
The new approach maintains a visited set that applies to the whole graph and doesn't request the same module more than once.
Note that requesting a module more than once doesn't mean we actually issue more than one fetch - it just causes more internal bookkeeping.
Attachment #8935778 -
Flags: review?(bugs)
|
|
||
Comment 20•7 years ago
|
||
Comment on attachment 8935778 [details] [diff] [review]
bug1365187-visited-set
>- ModuleLoadRequest(nsIScriptElement* aElement,
>+ // Create a top-level module load request.
>+ ModuleLoadRequest(nsIURI *aURI,
>+ nsIScriptElement* aElement,
> ValidJSVersion aValidJSVersion,
> CORSMode aCORSMode,
> const SRIMetadata& aIntegrity,
> ScriptLoader* aLoader);
>
>+ // Create a module load request for an imported module.
>+ ModuleLoadRequest(nsIURI *aURI,
Nit, * goes with the type. Here and in the ctor above.
>+ // Set of module URLs visited while fetching the module graph this request is
>+ // part of.
>+ nsTHashtable<nsURIHashKey>* mVisitedSet;
Hmm, lifetime management of this is rather worrisome. As you note somewhere, we probably need to make this refcounted.
> void
> ModuleScript::SetErrorToRethrow(const JS::Value& aError)
> {
> MOZ_ASSERT(!aError.isUndefined());
> MOZ_ASSERT(!HasErrorToRethrow());
>
> mErrorToRethrow = aError;
>+ HoldJSObjects(this);
I don't understand this call. Why/how is this related to this bug?
Some clarifications and mVisitedSet handling fixed, then I'd r+, but I think I should re-read this, so r- still.
Attachment #8935778 -
Flags: review?(bugs) → review-
|
|
Assignee | |
Comment 21•7 years ago
|
||
Sorry I should have fixed that before requesting review. I updated the patch to reference count the set.
I removed the HoldJSObject part, that should have been in a different bug.
Attachment #8935778 -
Attachment is obsolete: true
Attachment #8936492 -
Flags: review?(bugs)
|
|
||
Updated•7 years ago
|
Attachment #8936492 -
Flags: review?(bugs) → review+
|
|
||
Comment 22•7 years ago
|
||
Pushed by jcoppeard@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ebcc9ceb0842
Simplify module map interface r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/9eca4461d079
Keep track of which modules in a graph have been fetched using a visited set r=smaug
|
||
Comment 23•7 years ago
|
||
| bugherder | ||
https://hg.mozilla.org/mozilla-central/rev/ebcc9ceb0842
https://hg.mozilla.org/mozilla-central/rev/9eca4461d079
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
status-firefox59:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla59
|
|
||
Comment 24•7 years ago
|
||
| bugherder | ||
|
|
||
Comment 26•7 years ago
|
||
The bug I was experiencing is no longer there with version 59.0b2 !
However I see that <script nomodule> are downloaded (not executed) in the network tab (F12)
Flags: needinfo?(capocyril)
|
|
Assignee | |
Comment 27•7 years ago
|
||
(In reply to capocyril from comment #26)
Good to hear that. The problem with <script nomodule> is bug 1382020.
You need to log in
before you can comment on or make changes to this bug.
Description
•