Lazy compilation can fail when switching "routes" quickly

[tmeasday]

Bug report

What is the current behavior?

When using the experimental lazy compilation feature (in Storybook), when you change stories quickly (thus triggering many different lazy compilation jobs), sometimes the HMR for the lazy update can fail in various ways, which can lead to react-refresh errors or simply the whole app having to reload itself.

If the current behavior is a bug, please provide the steps to reproduce.

It is not entirely predictable, and I have not managed to reproduce outside of Storybook (yet), but this is a very very simple Storybook project and I think it is quite obvious the bug is in Webpack, but I am ready to be corrected ;)

https://github.com/tmeasday/storybook-lazy-compilation-webpack -- see the instructions from the repo.

The key point in this reproduction is that when a bunch of lazy updates are created on the server, the browser, which is otherwise doing nothing, will sometimes 404 on a hot-update.json request:

Note we have seen other (less reproducible) issues around HMR and lazy compilation, that you might see if you play with this repository, including:

• Sometimes the storybook fails to load initially with a HMR error. This definitely seems to be a timing issue with when the auto-launched browser loads relative to the initial entries compilation (it happens maybe 10% of the time or less when I simply run rm -rf node_modules/.cache/ && yarn storybook and let the browser launch).

• You can also trigger a bug by changing stories in the sidebar directly quickly while lazy compilation is going on (i.e. start SB, open up, change stories as fast as you can (you can use option-down and option-up to do this). However I cannot make this happen reliably enough to create a reproduction that would be useful. If you'd like to see what I mean I can likely get a screen recording of it happening at least.

What is the expected behavior?

Lazy compilation should be fairly transparent to the consumer, beyond import() requests taking a little longer than they otherwise might. If updates come over the wire from compilations triggered by other browsers, they should not fail.

Other relevant information:
webpack version: 5.70.0
Node.js version: 14.18.1
Operating System: MacOS
Additional tools: Storybook 6.5.0-alpha.48

NOTE

The tool we are using here to trigger the bug is the Storybook test runner, which opens the Storybook up in 4 separate, concurrent playwright instances, each of which will trigger a different dynamic (and thus lazy-compiled) import() statement.

[vankop]

do you using output.clean=true ?

[tmeasday]

No, I don't think so. You can see the full webpack config SB generates with yarn storybook --debug-webpack.

[tmeasday]

OK, I simplified the repro a lot and brought it out of Storybook!

https://github.com/tmeasday/webpack-lazy-compilation-repro-simple

1. yarn webpack serve
2. Open browser, ensure "preserve log" is on
3. Run all()
4. Notice logs:

GET http://localhost:8080/main.01ce74ce55d820aed88a.hot-update.json 404 (Not Found)
[HMR] Cannot find update. Need to do a full reload!
[HMR] (Probably because of restarting the webpack-dev-server)

The content of all():

window.all = async () => {
  import('./a');
  await new Promise((r) => setTimeout(r, 0));
  import('./b');
  await new Promise((r) => setTimeout(r, 0));
  import('./c');
};

Interestingly the issue doesn't occur if you remove the final call to import('./c')

[vankop]

@tmeasday still does not work with latest webpack?

[tmeasday]

Hey @vankop. Hmmm, OK, so the reproduction I just posted is fixed in 5.72.0. But the original issue posted at the top is not. 🤔 I'll keep trying to reproduce in pure webpack.

[tmeasday]

@vankop I am not quite sure what happened 6 days ago in my comment directly above, but I came back to this today and tried it again, and it the reproduction I posted definitely does occur in 5.72.0.

It is a pretty simple reproduction so hopefully it should make the problem clear :)

[tmeasday]

@vankop I dug into this a bit and I think I have some more context on what is going wrong here, in case it helps. Apologies in advance for my lack of understanding of how HMR stuff works in detail.

So, just to reiterate, what's happening in the failing repro above is that we are import()-ing three files with a very small delay between each import.

Actually the issue can happen even when even importing two files with a delay, but it doesn't happen every time. It's interesting to see what happen when it does work vs when it does.

---

When the lazy compilation works, on the terminal (with all logging turned on), I see:

[webpack-cli] Compiler is watching files for updates...
[LazyCompilationBackend] /Users/tom/GitHub/Repros/webpack-lazy-compilation-repro-simple/a.js is now in use and will be compiled.
[LazyCompilationBackend] /Users/tom/GitHub/Repros/webpack-lazy-compilation-repro-simple/b.js is now in use and will be compiled.
[webpack-cli] File 'null' was modified
[webpack-cli] Changed time is Wed Feb 13 54385 03:50:43 GMT+1100 (Australian Eastern Daylight Time) (timestamp is 1654061359843)
[webpack-dev-middleware] Compilation starting...
[webpack-cli] Compiler starting...
[webpack-cli] Compiler is using config: '/Users/tom/GitHub/Repros/webpack-lazy-compilation-repro-simple/webpack.config.js'
[webpack-cli] Compiler finished
[webpack-dev-middleware] Compilation finished

Notice in particular the two messages .... is now in use and will be compiled. that come in around the same time. This message is logged right before the lazyCompilationBackend calls compiler.watching.invalidate().

The two modules do not actually get "used" at the same time, there is a 2ms gap between them, but for whatever reason the new compilation triggered by the invalidate hasn't actually started yet.

On the client, on the HMR socket we see a really straightforward set of messages for a single HMR update and it all works fine:

---

When it doesn't work, it is because the compilation starts before the second invalidation:

[webpack-cli] Compiler is watching files for updates...
[LazyCompilationBackend] /Users/tom/GitHub/Repros/webpack-lazy-compilation-repro-simple/a.js is now in use and will be compiled.
[webpack-cli] File 'null' was modified
[webpack-cli] Changed time is Sun Feb 10 54385 23:26:14 GMT+1100 (Australian Eastern Daylight Time) (timestamp is 1654061171174)
[webpack-dev-middleware] Compilation starting...
[webpack-cli] Compiler starting...
[webpack-cli] Compiler is using config: '/Users/tom/GitHub/Repros/webpack-lazy-compilation-repro-simple/webpack.config.js'
<w> [LazyCompilationBackend] Error: read ECONNRESET
<w>     at TCP.onStreamRead (internal/stream_base_commons.js:209:20) {
<w>   errno: -54,
<w>   code: 'ECONNRESET',
<w>   syscall: 'read'
<w> }
[LazyCompilationBackend] /Users/tom/GitHub/Repros/webpack-lazy-compilation-repro-simple/b.js is now in use and will be compiled.
[webpack-cli] File 'null' was modified
[webpack-cli] Changed time is Sun Feb 10 54385 23:26:32 GMT+1100 (Australian Eastern Daylight Time) (timestamp is 1654061171192)
[webpack-cli] Compiler starting...
[webpack-cli] Compiler is using config: '/Users/tom/GitHub/Repros/webpack-lazy-compilation-repro-simple/webpack.config.js'
[webpack-cli] Compiler finished
[webpack-dev-middleware] Compilation finished

In this case, notice the "Compilation starting..." message is logged before the "...b.js is now in use and will be compiled." message. Ultimately this leads to the following messages over the websocket:

(Here's where I get a bit more hazy) -- what this means is that there are actually two "changes" in compilation -- we go from an initial hash, to a second hash with a.js, to a third hash with a.js and b.js. However, the HMR mechanism tries to fetch the hot-update.json based on the initial hash, after the compilation of the third hash, and it no longer exists in the dev server.

I am not sure exactly what the root problem is. I suspect that maybe the lazy compilation backend shouldn't (or shouldn't be able to) invalidate the compilation while it is compiling. Perhaps somewhere in the pipeline there should be a queue of invalidations that blocks on previous compilations?

[tmeasday]

@vankop FYI I implemented a workaround on SB's end by putting some pipelining/throttling in our client side code to avoid overlapping import() calls: storybookjs/storybook#18432

To be clear, I don't think this is a great solution because
(a) it feels like it's the wrong place for the fix (it's crude as it doesn't really know when the compilation is done, it probably slows things down).
(b) it doesn't help if there is >1 client, which is the scenario from the original reproduction on this ticket (and is still an issue for us).

I wonder if the right solution is to add a similar throttle to this requestListener so that incoming requests are queued up and not handled until a previous compilation triggered by this invalidation is complete?

I tried it out and it did resolve the problem, although I did need to put a little delay in (>10ms <100ms) between one compilation finishing and the next one starting (I think because otherwise the HMR update gets invalidated before the browser has a chance to grab it, although I didn't dig in too much). I'm really unsure if this is the right approach or not (plus how I'd go about adding a test to webpack for it).

[webpack-bot]

This issue had no activity for at least three months.

It's subject to automatic issue closing if there is no activity in the next 15 days.

[webpack-bot]

Issue was closed because of inactivity.

If you think this is still a valid issue, please file a new issue with additional information.

[tmeasday]

As a note we are still working around this problem in Storybook in a way which probably isn't ideal for performance: https://github.com/storybookjs/storybook/blob/15dd0ad6891e964f807a22e3e3827c0e7f599a1b/code/lib/core-webpack/src/to-importFn.ts#L50-L55

[Rajdeepc]

@tmeasday Something which I am still facing too in my repo. Issue: storybookjs/storybook#22706
This is how it looks.
If you see in the video, whenever i click on any component it is downloading duplicate assets and resources and the page continuosly refreshes.
I am using

"storybook": "^7.0.12",
"webpack": "^5.83.1"

scrollstorybook.mov