Cache issue with `integrity: true` and `output.filename = '[name].[contenthash].js'` in watch mode

webdiscus commented 3 months ago

Discussed in https://github.com/webdiscus/html-bundler-webpack-plugin/discussions/108

^{Originally posted by **davidmurdoch** August 2, 2024} I'm not yet sure what the root cause is, so can't provide a useful reproduction just yet (unless you think the entire MetaMask extension codebase would be useful). The gist of it is that setting `integrity: true` while using `output.filename = '[name].[contenthash].js'` (and a whole bunch of other settings, of course) can cause webpack's `RealContentHashPlugin` to crash, but only in `watch` mode after adding a new `import` statement to a JS file. I get dozens of errors like this one: ``` ERROR in RealContentHashPlugin Some kind of unexpected caching problem occurred. An asset was cached with a reference to another asset (___TMP-MkdU/WRbjt/NNXkiQNR3q17wa4fOtY+KiTtnqypW0z1eFvW7BH039HDomjylasQP) that's not in the compilation anymore. Either the asset was incorrectly cached, or the referenced asset should also be restored from cache. Referenced by: - runtime.e3ef84e993c262751e40.js: ...fNgsj7glCQyfV",722:"___TMP-MkdU/WRbjt/NNXkiQNR3q17wa4fOtY+KiTtnqypW0z1eFvW7BH039HDomjylasQP"},(()=>{t.b=documen... - runtime.e3ef84e993c262751e40.js.map: ...glCQyfV\",\"722\":\"___TMP-MkdU/WRbjt/NNXkiQNR3q17wa4fOtY+KiTtnqypW0z1eFvW7BH039HDomjylasQP\"};","__webpack_req... ``` setting `output.filename = '[name].[contenthash].js'` to `output.filename = '[name].[fullhash].js'` does *not* cause the error. So it seems like there is some complication with having a complex dependency graph (maybe due to circular dependencies), integrity hashing, and `[contenthash]`. Do you have any idea where I should look to further debug this so I can hopefully provide a reasonable reproduction?

And I just noticed this plugin in Integrity.js:

if (isRealContentHash) {
          // triggers the RealContentHashPlugin.updateHash hook when it is enabled, in production mode
          compilation.updateAsset(
            childChunkFile,
            (source) => source,
            (assetInfo) => {
              return assetInfo
                ? {
                    ...assetInfo,
                    contenthash: Array.isArray(assetInfo.contenthash)
                      ? [...new Set([...assetInfo.contenthash, placeholder])]
                      : assetInfo.contenthash
                      ? [...new Set([assetInfo.contenthash, placeholder])]
                      : placeholder,
                  }
                : undefined;
            }
          );

In development mode I get a different error:

TypeError: Cannot read properties of undefined (reading 'length')
    at Integrity.processAssets (/home/david/code/metamask-extension2/node_modules/html-bundler-webpack-plugin/src/Plugin/Extras/Integrity.js:166:53)
    at fn (/home/david/code/metamask-extension2/node_modules/webpack/lib/Compilation.js:486:10)
    at _next4 (eval at create (/home/david/code/metamask-extension2/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:45:1)
    at eval (eval at create (/home/david/code/metamask-extension2/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:63:1)
    at eval (eval at create (/home/david/code/metamask-extension2/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:14:1)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)

An interesting finding:

When the bug occurs, placeholder is the value undefined, and when undefined is passed to oldSource.indexOf(placeholder) is is coerced to the string "undefined". So if oldSource contains the string "undefined" it matches, and it then makes it to the placeholder.length check and fails with the Cannot read properties of undefined (reading 'length') error from above.

When this issue occurs, placeholderByChunkId is an empty Map.

webdiscus commented 3 months ago

@davidmurdoch

Thank you for the issue report. I try to reproduce it.

webdiscus commented 3 months ago

@davidmurdoch

can you please help me to reproduce the issue?

Here ist the simple manual test. I can't reproduce the issue.

In both modes production and development, the test works after changes w/o any error - the integrity will be re-calculated for changed JS file and injected into HTML. Follow please the steps described in README in test directory.

davidmurdoch commented 3 months ago

I spent a few hours today on this, but still couldn't create a minimal reproduction. I do have reproduction steps if you want to try it on the whole MetaMask Extension:

git clone https://github.com/MetaMask/metamask-extension.git
cd metamask-extension
git checkout cache-repro
corepack enable # to automatically enable the correct version of yarn
yarn
yarn webpack --watch --env production --no-lavamoat --no-cache # no-cache only disables the filesystem cache

The last command compiles the application in watch mode (there may be some compilation warnings, but they are not related to this issue).

then open ./ui/contexts/metametrics.js and uncomment line 18:

- // import { abortTransactionSigning } from '../store/actions';
+ // import { abortTransactionSigning } from '../store/actions';

Then save the file. You will see a bunch of errors that start with:

ERROR in RealContentHashPlugin
Some kind of unexpected caching problem occurred.
An asset was cached with a reference to another asset

Once this happens it will not recover without restarting compilation.

If you set integrity to false OR change filename: '[name].[contenthash].js', to filename: '[name].[fullhash].js' in the file ./development/webpack/webpack.config.ts the error will not occur.

I've also discovered that if I remove the optimization.runtimeChunk option the compilation errors do not occur. However, if I just change the optimization.runtimeChunk.name function to always return the same string it outputs a different error.

    runtimeChunk: {
-      name: (chunk: Chunk) => (canBeChunked(chunk) ? 'runtime' : false),
+      name: (chunk: Chunk) => 'runtime',      
    },

The different error:

TypeError: Cannot read properties of undefined (reading 'replace')
    at quoteMeta (/home/david/code/metamask-extension/node_modules/webpack/lib/optimize/RealContentHashPlugin.js:65:13)
    at Function.from (<anonymous>)
    at /home/david/code/metamask-extension/node_modules/webpack/lib/optimize/RealContentHashPlugin.js:200:13
    at fn (/home/david/code/metamask-extension/node_modules/webpack/lib/Compilation.js:544:19)
    at _next5 (eval at create (/home/david/code/metamask-extension/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:46:17)
    at eval (eval at create (/home/david/code/metamask-extension/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:67:1)
    at fn (/home/david/code/metamask-extension/node_modules/webpack/lib/Compilation.js:500:9)
    at _next4 (eval at create (/home/david/code/metamask-extension/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:62:1)
    at eval (eval at create (/home/david/code/metamask-extension/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:80:1)
    at eval (eval at create (/home/david/code/metamask-extension/node_modules/tapable/lib/HookCodeFactory.js:33:10), <anonymous>:14:1)

So it appears the issue might be related to chunking + runtime file + integrity + contenthash + production mode.

Note: the reason for the canBeChunked check is that we have a few modules the security team at MetaMask won't allow to be split/chunked or packed with other modules.

I noticed that the plugin mini-css-extra-plugin used to have a similar issue, and it was solved here: https://github.com/webpack-contrib/mini-css-extract-plugin/pull/869/files#diff-bfe9874d239014961b1ae4e89875a6155667db834a410aaaa2ebe3cf89820556. Maybe there is a clue to what is going on in this diff?

Let me know if you have any ideas on how I could go about reducing the size of the reproduction steps to something more reasonable!

webdiscus commented 3 months ago

@davidmurdoch thank you for the instruction. I can reproduce the ERROR in RealContentHashPlugin. I try to fix it.

P.S. the compilation process hangs by 92% when the TerserPlugin is used. I have disabled the TerserPlugin, then works. Run on MacBook Pro M1 Max.

webdiscus commented 3 months ago

I have noticed that if the size of all compiled chunks is lower than 2 MB, then compilation after changes works fine. By chunks size >= 3.5 MB occurs the ERROR in RealContentHashPlugin after changes.

davidmurdoch commented 3 months ago

@davidmurdoch thank you for the instruction. I can reproduce the ERROR in RealContentHashPlugin. I try to fix it.

P.S. the compilation process hangs by 92% when the TerserPlugin is used. I have disabled the TerserPlugin, then works. Run on MacBook Pro M1 Max.

In production mode minification is enabled and it takes a bit longer to run. I haven't seen it hang forever, it just pauses for a few seconds for me. Did it get stuck for you with minification enabled?

davidmurdoch commented 3 months ago

I have noticed that if the size of all compiled chunks is lower than 2 MB, then compilation after changes works fine. By chunks size >= 3.5 MB occurs the ERROR in RealContentHashPlugin after changes.

The larger the chunk size the faster the extension loads in browsers. But Firefox doesn't allow extensions to contain any JavaScript files greater than 4Mb, which is the only reason we are using chunking.

Thanks for looking into this. Let me know if you figure out a way I can help narrow this down further.

webdiscus commented 3 months ago

@davidmurdoch

I found the problem and fixed. No error with RealContentHashPlugin after change any file. I will test it and prepare the next beta version in a few hours.

But, I have noticed, that when the watching wait over ~1-3 mins, Node.js crashes - Out of memory:

🦊 Watching for changes…

node:internal/event_target:1036
  process.nextTick(() => { throw err; });
                           ^
RangeError [Error]: WebAssembly.instantiate(): Out of memory: Cannot allocate Wasm memory for new instance
Emitted 'error' event on InternalWorker instance at:
    at [kOnErrorMessage] (node:internal/worker:323:10)
    at [kOnMessage] (node:internal/worker:334:37)
    at MessagePort.<anonymous> (node:internal/worker:229:57)
    at [nodejs.internal.kHybridDispatch] (node:internal/event_target:761:20)
    at exports.emitMessage (node:internal/per_context/messageport:23:28)

Node.js v20.0.0

This Out of memory occurs regardless of the size of the generated chunks. It occurs with all chunks > 10 MB and with 2MB (I have reduced amount of imported JS files)

My MacBook has 64 GB RAM.

davidmurdoch commented 3 months ago

Amazing, I look forward to reading and understanding how you found and fix this! Thank you once again!

And thanks for letting me know about that OOM issue. I haven't experienced it myself and it hasn't been reported by anyone else at MetaMask. I wonder if it is an issue with Node v20.0.0 that has since been fixed (we use v20.11.0 and later versions).

webdiscus commented 3 months ago

@davidmurdoch

the issue is fixed in 4.0.0-beta.1. This is the next major version that has been refactored and optimized for a month.

The issue occurs when using dynamic import, e.g.: React.lazy(() => import('./routes')). This is special very complex case where I used a cache of temporary integrity placeholders. Before runtime requirements in the new compilation I cleared the cache and it was the BUG. Sorry.

P.S. I have updated Node.js to v20.16.0 und now it works stable. After many changes and an hour of waiting, no more crashes.

davidmurdoch commented 3 months ago

Awesome debugging! I'm sorry I wasn't able to narrow down the bug reproduction for you.

Amazing work, as usual! Thanks again!

webdiscus commented 3 months ago

@davidmurdoch

You've already done everything necessary to reproduce the issue. You couldn't localize the problematic place, because the code is very large. Everything is fine, thank you!

Can you please confirm whether the beta version is working properly or not?

davidmurdoch commented 3 months ago

Hm, I'm still seeing the error, though not nearly as much as before:

ERROR in RealContentHashPlugin
Some kind of unexpected caching problem occurred.
An asset was cached with a reference to another asset (xxxxxx-xNSAkBHxK0JY8OiBZ2i8c5NujE5hCi/BqFC2sI7VBJipF4KcfSUT+MIeXXe89fFi) that's not in the compilation anymore.
Either the asset was incorrectly cached, or the referenced asset should also be restored from cache.
Referenced by:
 - runtime.9e43f37abe65764155e8.js: ..."",t.integrity={73:"xxxxxx-xNSAkBHxK0JY8OiBZ2i8c5NujE5hCi/BqFC2sI7VBJipF4KcfSUT+MIeXXe89fFi",463:"xxxxxx-2yN4xY...
 - runtime.9e43f37abe65764155e8.js.map: ...tegrity = {\"73\":\"xxxxxx-xNSAkBHxK0JY8OiBZ2i8c5NujE5hCi/BqFC2sI7VBJipF4KcfSUT+MIeXXe89fFi\",\"463\":\"xxxxxx-...

ERROR in RealContentHashPlugin
Some kind of unexpected caching problem occurred.
An asset was cached with a reference to another asset (xxxxxx-MkdU/WRbjt/NNXkiQNR3q17wa4fOtY+KiTtnqypW0z1eFvW7BH039HDomjylasQP) that's not in the compilation anymore.
Either the asset was incorrectly cached, or the referenced asset should also be restored from cache.
Referenced by:
 - runtime.9e43f37abe65764155e8.js: ...fNgsj7glCQyfV",722:"xxxxxx-MkdU/WRbjt/NNXkiQNR3q17wa4fOtY+KiTtnqypW0z1eFvW7BH039HDomjylasQP"},(()=>{t.b=documen...
 - runtime.9e43f37abe65764155e8.js.map: ...glCQyfV\",\"722\":\"xxxxxx-MkdU/WRbjt/NNXkiQNR3q17wa4fOtY+KiTtnqypW0z1eFvW7BH039HDomjylasQP\"};","__webpack_req...

🦊 MetaMask – production compiled with 2 errors and 3 warnings
🦊 Watching for changes…

On Ubuntu running Node v20.11.1

webdiscus commented 3 months ago

Thanks for the answer.

I used follow testing scenario:

import { abortTransactionSigning } from '../store/actions'; <= initial not commented
// import { abortTransactionSigning } from '../store/actions'; <= after change works fine
import { abortTransactionSigning } from '../store/actions'; <= after change works fine
// add some comment test: 1234 <= after change works fine

I have tested now:

// import { abortTransactionSigning } from '../store/actions'; <= initial commented
import { abortTransactionSigning } from '../store/actions'; <= after change occurs ERROR

I'll continue debugging it.

webdiscus commented 3 months ago

@davidmurdoch the issue in the above usage scenario has been fixed. Please try to use 4.0.0-beta.2.

davidmurdoch commented 3 months ago

Looks like that fixes it! 🚀

webdiscus commented 3 months ago

Ok, then I close this ticket.

webdiscus / html-bundler-webpack-plugin

Cache issue with `integrity: true` and `output.filename = '[name].[contenthash].js'` in watch mode #110

Discussed in https://github.com/webdiscus/html-bundler-webpack-plugin/discussions/108