Loading tens of ES Modules in parallel makes JS interpreter stall for more than 10 seconds
Reported by
gilta...@gmail.com,
May 16 2017
|
|||||||||
Issue description
UserAgent: 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 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`.
What is the expected behavior?
Loading the module and seeing "IT WORKS" in less than a second, given that the network fetching, on localhost, should take 10s of milliseconds.
What went wrong?
It takes about 18 seconds to see "IT WORKS".
Did this work before? No
Chrome version: 60.0.3100.0 Channel: canary
OS Version: OS X 10.12.4
Flash Version:
Incredibly enough, this behavior was found also in Firefox (their Canary version), and to a lesser extent in Safari (Canary).
,
May 16 2017
,
May 16 2017
Thanks for the report (and repro case, which I can confirm on my local workstation). The majority of this slowdown seems to be algorithmic overhead in our module fetching logic.
,
May 16 2017
Progress update: The 2 CLs below should get us into a better state. Applying both would improve local benchmark scores by 4x, and I have more optimization ideas that I plan to work on next week. https://codereview.chromium.org/2890593002/ https://codereview.chromium.org/2889783002/
,
Jul 20 2017
Will investigate whether this has the same root cause as issue 740874 .
,
Jul 20 2017
This has all the same symptoms as issue 740874 , and I suspect has the same root cause: a module graph with lots of interconnections. E.g., _baseIteratee.js is imported the most (43 times); it imports five other modules, which themselves collectively import another 14 modules, which...import more stuff. So if we're creating a ModuleTreeLinker per path-to-a-module, it is indeed going to add up fast (I see a total of ~360,000 MTLs created overall).
,
Jul 20 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/b391a13c197f6c381a012c1fc6d5d71cb1a5650e commit b391a13c197f6c381a012c1fc6d5d71cb1a5650e Author: Kouhei Ueno <kouhei@chromium.org> Date: Thu Jul 20 12:13:58 2017 [ES6 modules] Reduce number of MTLs by not creating MTL for sub-graph fetch already handled somewhere else This CL makes unbundled moment.js benchmark [1] 19x faster (3.8s -> 200ms) [1] https://sgom.es/posts/2017-06-30-ecmascript-module-loading-can-we-unbundle-yet/ Before this CL, we instantiated ModuleTreeLinker per module graph edge (== import stmt). For module graphs which are close to fully connected, this resulted in exponential number of ModuleTreeLinker involved. Each ModuleTreeLinker comes w/ multiple postTask cost and memory cost, thus this resulted in slow performance and high peak memory usage. This CL drastically reduces the ModuleTreeLinker per module graph fetch, by creating one ModuleTreeLinker at most for each module graph node (== module script) involved. This CL introduces ModuleTreeReachedUrlSet, which is instantiated per top-level module graph fetch, and shared among all descendant sub-graph ModuleTreeLinkers. Before creating a new ModuleTreeLinker for descendant module graph fetch, ModuleTreeLinker::FetchDescendants now consults this ModuleTreeReachedUrlSet to find if there is an existing ModuleTreeLinker instance which it can delegate the sub-graph fetch. Credits: - nhiroki@ for the original algorithm. - adamk@, hiroshige@ for extensive analysis. - adamk@, ksakamoto@ for verifying the speed up. Bug: 722728 Change-Id: I7af4206ece3c5613a3085e7483eddbd652718981 Reviewed-on: https://chromium-review.googlesource.com/578531 Reviewed-by: Hiroki Nakagawa <nhiroki@chromium.org> Reviewed-by: Kinuko Yasuda <kinuko@chromium.org> Reviewed-by: Yutaka Hirano <yhirano@chromium.org> Commit-Queue: Kouhei Ueno <kouhei@chromium.org> Cr-Commit-Position: refs/heads/master@{#488207} [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/dom/Modulator.h [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/dom/ModulatorImpl.cpp [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/dom/ModulatorImpl.h [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/loader/BUILD.gn [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/loader/modulescript/ModuleTreeLinker.cpp [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/loader/modulescript/ModuleTreeLinker.h [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/loader/modulescript/ModuleTreeLinkerRegistry.cpp [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/loader/modulescript/ModuleTreeLinkerRegistry.h [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/loader/modulescript/ModuleTreeLinkerTest.cpp [add] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/loader/modulescript/ModuleTreeReachedUrlSet.h [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/testing/DummyModulator.cpp [modify] https://crrev.com/b391a13c197f6c381a012c1fc6d5d71cb1a5650e/third_party/WebKit/Source/core/testing/DummyModulator.h
,
Jul 20 2017
With this CL, this test case now loads in about 1.2 seconds on my workstation.
,
Jul 20 2017
Attaching the full trace, still seems like task batching could help this case.
,
Nov 14 2017
I believe this was fixed awhile ago. |
|||||||||
►
Sign in to add a comment |
|||||||||
Comment 1 by neis@chromium.org
, May 16 2017