Bugfix: watchRunHook race condition periodically breaks change detection triggered by writeModule (webpack@4)

[idpbond]

What's the problem this PR addresses?

Issue likely introduced by #66 whereby custom compiler hooks (eg watchRun, compilation) which implement a dynamic writeModule call will periodically (~half the time in the case of my watchRun) fail to trigger a rebuild of the virtual module. For me this didn't affect production builds, but presented when using the webpack dev server.

webpack-virtual-modules/src/index.ts

Line 266 in 6072912

fts.set(file, +virtualFiles[file].stats.mtime);

Above line will preserve the virtualFile's mtime, which makes sense in preventing every change from rebuilding every module, but also prevents writeModule calls from correctly triggering the necessary rebuilds down the line.

More specifically, the failure happens due to a check here:
https://github.com/webpack/webpack/blob/5d3004cccd3dd5af2721c39a7a8a27b12b3d0c19/lib/NormalModule.js#L533

Where timestamp is actually the last compilation's virtualFile's mtime.

How did you fix it?

While not the ideal/perfect solution, this change forces an update to the compiler.fileTimestamps reference of a virtualModule on which writeModule was called. As I see it: if you call writeModule you necessarily are "touching" the file (updating mtime)

[larixer]

@idpbond I appreciate that you came up with a clear description of the problem, thank you! CC: @non25
It looks like the fix is not good enough though, let us think about a better fix.

[idpbond]

@larixer 👍, this is my first foray into a webpack lifecycle. Just wanted to note that the timestamp discrepancy which causes missed rebuilds may ultimately come down to the fact that writeModule's mtime update/change triggering here:

webpack-virtual-modules/src/index.ts

Lines 170 to 171 in 6072912

	fileWatcher.directoryWatcher.setFileTime(filePath, time, false, false, null);
	fileWatcher.emit('change', time, null);

modifies the DirectoryWatcher.filesmap, but this map is not the condition upon which rebuilds are decided. Instead, rebuilds rely on the compiler.fileTimestamps, here: https://github.com/webpack/webpack/blob/5d3004cccd3dd5af2721c39a7a8a27b12b3d0c19/lib/NormalModule.js#L520

From some debugging I noticed that these were not the same map... hence #66 being necessary to prevent every-module rebuilds on any change, but with it comes a need to alert webpack to the changes writeModule has triggered.

I could be off in my observations and/or there is possibly a better way to fix it but I am not familiar enough with webpack internals/conventions to propose anything in particular.

Sidenote: I also found that changing the hook:

webpack-virtual-modules/src/index.ts

Line 275 in 6072912

compiler.hooks.watchRun.tapAsync('VirtualModulesPlugin', watchRunHook);

To instead use something like compiler.hooks.thisCompilation buys more "breathing room", ie: fixing the issue (delaying the mtime reset of #66 ) for dynamic modules which rely on compliation and watchRun hooks (essentially, any hook that runs before [but not including] thisCompilation). But this is an incomplete solution.

[non25]

Here's some observations too:
I've put console.logs everywhere, where fileTimestamps are getting recreated from scratch.

> grep -nr 'fileTimestamps ='
lib/Watching.js:134:				this.compiler.fileTimestamps = fileTimestamps;
lib/Watching.js:153:			this.compiler.fileTimestamps = this.watcher.getFileTimestamps();
lib/WatchIgnorePlugin.js:77:				const fileTimestamps = watcher.getFileTimestamps();
lib/Compiler.js:142:		this.fileTimestamps = new Map();
lib/Compiler.js:241:		this.fileTimestamps = new Map();
lib/Compiler.js:586:		childCompiler.fileTimestamps = this.fileTimestamps;
lib/Compiler.js:625:		compilation.fileTimestamps = this.fileTimestamps;
lib/Compilation.js:526:		this.fileTimestamps = undefined;
lib/CachePlugin.js:53:				const fileTs = (compiler.fileTimestamps = new Map());

This led me here: https://github.com/webpack/webpack/blob/c572c15a413ef7d086b52ccc78d9512a192954d7/lib/Watching.js#L134

That was the only place where console.log fired during test run.

I wanted to get more info, so I put these right above L134.

console.log('old', this.compiler.fileTimestamps);
console.log('new', fileTimestamps);

And here's what I got:

old Map(3) {
  '/tmp/webpack-virtual-modules/entry.js' => 1607970518229,    <<< 1
  '/tmp/webpack-virtual-modules/dep_one.js' => 1607970518229,  <<< 1
  '/tmp/webpack-virtual-modules/dep_two.js' => 1607970518229   <<< 1
}

new Map(17) {
  '/tmp/webpack-virtual-modules/.eslintignore' => 1607964563336,
  '/tmp/webpack-virtual-modules/.eslintrc.json' => 1607964563336,
  '/tmp/webpack-virtual-modules/.gitignore' => 1607964563336,
  '/tmp/webpack-virtual-modules/.nycrc' => 1607964563336,
  '/tmp/webpack-virtual-modules/.pinyarn.js' => 1607964563336,
  '/tmp/webpack-virtual-modules/.pinyarn.json' => 1607964563336,
  '/tmp/webpack-virtual-modules/.pnp.js' => 1607964877779,
  '/tmp/webpack-virtual-modules/.yarnrc.yml' => 1607964690349,
  '/tmp/webpack-virtual-modules/LICENSE' => 1607964563336,
  '/tmp/webpack-virtual-modules/README.md' => 1607964563336,
  '/tmp/webpack-virtual-modules/babel.config.js' => 1607964563336,
  '/tmp/webpack-virtual-modules/jest.config.js' => 1607964563339,
  '/tmp/webpack-virtual-modules/package.json' => 1607964875296,
  '/tmp/webpack-virtual-modules/tsconfig.build.json' => 1607964563339,
  '/tmp/webpack-virtual-modules/tsconfig.json' => 1607964563339,
  '/tmp/webpack-virtual-modules/yarn.lock' => 1607964877393,
  'dep_one.js' => 1607970519304                                <<< 2
}

updated Map(20) {
  '/tmp/webpack-virtual-modules/.eslintignore' => 1607964563336,
  '/tmp/webpack-virtual-modules/.eslintrc.json' => 1607964563336,
  '/tmp/webpack-virtual-modules/.gitignore' => 1607964563336,
  '/tmp/webpack-virtual-modules/.nycrc' => 1607964563336,
  '/tmp/webpack-virtual-modules/.pinyarn.js' => 1607964563336,
  '/tmp/webpack-virtual-modules/.pinyarn.json' => 1607964563336,
  '/tmp/webpack-virtual-modules/.pnp.js' => 1607964877779,
  '/tmp/webpack-virtual-modules/.yarnrc.yml' => 1607964690349,
  '/tmp/webpack-virtual-modules/LICENSE' => 1607964563336,
  '/tmp/webpack-virtual-modules/README.md' => 1607964563336,
  '/tmp/webpack-virtual-modules/babel.config.js' => 1607964563336,
  '/tmp/webpack-virtual-modules/jest.config.js' => 1607964563339,
  '/tmp/webpack-virtual-modules/package.json' => 1607964875296,
  '/tmp/webpack-virtual-modules/tsconfig.build.json' => 1607964563339,
  '/tmp/webpack-virtual-modules/tsconfig.json' => 1607964563339,
  '/tmp/webpack-virtual-modules/yarn.lock' => 1607964877393,
  'dep_one.js' => 1607970519304,
  '/tmp/webpack-virtual-modules/entry.js' => 1607970518229,    <<< 3
  '/tmp/webpack-virtual-modules/dep_one.js' => 1607970518304,  <<< 3
  '/tmp/webpack-virtual-modules/dep_two.js' => 1607970518229   <<< 3
}

1: Provided by

webpack-virtual-modules/src/index.ts

Lines 262 to 268 in 6072912

	const virtualFiles = (compiler as any).inputFileSystem._virtualFiles;
	const fts = compiler.fileTimestamps as any;
	if (virtualFiles && fts && typeof fts.set === 'function') {
	Object.keys(virtualFiles).forEach((file) => {
	fts.set(file, +virtualFiles[file].stats.mtime);
	});
	}

after initial build

2: Provided by

webpack-virtual-modules/src/index.ts

Lines 170 to 171 in 6072912

	fileWatcher.directoryWatcher.setFileTime(filePath, time, false, false, null);
	fileWatcher.emit('change', time, null);

on recreation from scratch step.

3. Same as 1, but console.logd right after code in 1.

Timestamps are created here: https://github.com/webpack/webpack/blob/c572c15a413ef7d086b52ccc78d9512a192954d7/lib/node/NodeWatchFileSystem.js#L54

Would be nice if I could reproduce 'it doesn't rebuild' behavior, or even better - make test for it...

I tried to change hook as you said, tests passed.
Looks like thisCompilation runs after recreating fileTimestamps from scratch.

[n8tz]

Hi there !

Thanks ! this PR helps me figure out why the hell my "virtual globe index files" weren't rebuilt during the hot update.

In fact, for the same reasons i had the same problem while making my plugin compatible with webpack 5 ( layer-pack); The updated virtual files were not recompiled.

I tried this fix, but Wp5 uses advanced method to do this TS test. It uses a concept of "snapshots" to have a better caching strategy I guess.
The problem is, these snapshots objects seems difficult to access / edit, so I've changed my strategy to make it work:

I directly tap the closest hook I found; the compilation queue.
Then, basing the resolved resource from the original module, I directly marked the updated virtual modules to force theirs rebuilds.

It's probably not the best method i guess ( it test all the added modules ), but this one work in WP5 too.

So for inspiration i wrote this, maybe it will help :)

		compiler.hooks.compilation.tap('layer-pack', ( compilation, params ) => {
				let toBeRebuilt = [];
				
				// force rebuild in wp5
				compilation.buildQueue &&
				compilation.buildQueue.hooks &&
				compilation.buildQueue.hooks.beforeAdd
				           .tapAsync('layer-pack',
				                     ( module, cb ) => {
					                     if ( toBeRebuilt.includes(module.resource) ) {
						                     //console.info("Index was Updated ", module.resource, module._forceBuild)
						                     toBeRebuilt.splice(toBeRebuilt.indexOf(module.resource), 1);
						                     module._forceBuild = true;
					                     }
					                     cb()
				                     }
				           );
		//				... ( fill toBeRebuilt with the method that suit you're needs )

[larixer]

Closing, as the PR is stale