From 150d982a303f39e70e431530ee45692fc823108f Mon Sep 17 00:00:00 2001 From: pshu Date: Tue, 7 Jul 2026 15:11:27 +0800 Subject: [PATCH 1/7] test: instrument + loop-repro WASM watch flaky (issue-7400 step sync) Add WATCH_DIAG-guarded diagnostics to createWatchStepProcessor and a WASM-only test file that registers many copies of side-effects/issue-7400 to reproduce the step-sync race where a trailing Build event resolves the next step's task, so the runner executes a stale bundle. --- packages/rspack-test-tools/src/case/watch.ts | 26 ++++++++++++++++ tests/rspack-test/WatchRepro.test.js | 32 ++++++++++++++++++++ 2 files changed, 58 insertions(+) create mode 100644 tests/rspack-test/WatchRepro.test.js diff --git a/packages/rspack-test-tools/src/case/watch.ts b/packages/rspack-test-tools/src/case/watch.ts index 22ce4e7d3845..46d1be7ddc87 100644 --- a/packages/rspack-test-tools/src/case/watch.ts +++ b/packages/rspack-test-tools/src/case/watch.ts @@ -287,8 +287,15 @@ export function createWatchStepProcessor( }; processor.build = async (context: ITestContext) => { const compiler = context.getCompiler(); + // [WATCH-DIAG] temporary instrumentation, guarded by WATCH_DIAG env + const DIAG = !!process.env.WATCH_DIAG; + const buildEvents: number[] = []; + const onBuild = () => buildEvents.push(Date.now()); + if (DIAG) compiler.getEmitter().on(ECompilerEvent.Build, onBuild); + let resolveTs = 0; const task = new Promise((resolve, reject) => { compiler.getEmitter().once(ECompilerEvent.Build, (e, stats) => { + resolveTs = Date.now(); if (e) return reject(e); resolve(stats); }); @@ -304,8 +311,27 @@ export function createWatchStepProcessor( // TODO: This is a workaround, we can remove it when notify support windows better. const timeout = nativeWatcher && process.platform === 'win32' ? 400 : 100; await new Promise((resolve) => setTimeout(resolve, timeout)); + const copyTs = Date.now(); copyDiff(path.join(context.getSource(), step), tempDir, false); await task; + if (DIAG) { + compiler.getEmitter().removeListener(ECompilerEvent.Build, onBuild); + let bundleStep = '?'; + try { + const bundle = fs.readFileSync( + path.join(context.getDist(), 'bundle.js'), + 'utf-8', + ); + const m = bundle.match(/toEqual\("(\d)"\)/); + if (m) bundleStep = m[1]; + } catch {} + console.error( + `[WATCH-DIAG] name=${name} step=${step} sleep=${timeout} ` + + `resolvedBeforeCopy=${resolveTs < copyTs} resolveRelCopy=${resolveTs - copyTs}ms ` + + `buildEventsRelCopy=[${buildEvents.map((t) => t - copyTs).join(',')}] ` + + `bundleStep=${bundleStep} STALE=${bundleStep !== '?' && bundleStep !== step}`, + ); + } }; return processor; } diff --git a/tests/rspack-test/WatchRepro.test.js b/tests/rspack-test/WatchRepro.test.js new file mode 100644 index 000000000000..08b1d9213169 --- /dev/null +++ b/tests/rspack-test/WatchRepro.test.js @@ -0,0 +1,32 @@ +// [WATCH-DIAG] TEMPORARY: reproduce the WASM-only watch flaky of +// `side-effects/issue-7400 > should compile step 1`. +// +// Hypothesis: the step-sync in createWatchStepProcessor uses `once(Build)` + +// a fixed 100ms sleep. Under slow WASM compilation a trailing Build event from +// the previous step can resolve the next step's task before its own copyDiff, +// so the runner executes a stale (previous-step) bundle -> WATCH_STEP="1" but +// the bundle asserts toEqual("0"). This file registers many identical copies of +// the case (distinct temp/dist) to amplify the hit rate, with WATCH_DIAG on. +// +// Only runs under WASM; native jobs register nothing. +if (process.env.WASM) { + process.env.WATCH_DIAG = "1"; + + const path = require("path"); + const { createWatchCase } = require("@rspack/test-tools"); + + const src = path.join( + __dirname, + "watchCases", + "side-effects", + "issue-7400" + ); + const count = Number(process.env.WATCH_REPRO_N || 50); + + for (let i = 0; i < count; i++) { + const name = `side-effects/issue-7400-repro-${String(i).padStart(3, "0")}`; + const dist = path.resolve(__dirname, "./js/watch-repro", name); + const temp = path.resolve(__dirname, "./js/temp-repro", name); + createWatchCase(name, src, dist, temp); + } +} From 499b0526090d4c1147390dae4ebed1e2c8d43eaf Mon Sep 17 00:00:00 2001 From: pshu Date: Tue, 7 Jul 2026 15:27:01 +0800 Subject: [PATCH 2/7] test: add event-loop freeze pressure + global build-event log to watch repro --- packages/rspack-test-tools/src/compiler.ts | 6 ++++ tests/rspack-test/WatchRepro.test.js | 37 ++++++++++++++-------- 2 files changed, 30 insertions(+), 13 deletions(-) diff --git a/packages/rspack-test-tools/src/compiler.ts b/packages/rspack-test-tools/src/compiler.ts index 96032c50281f..777730aae6cd 100644 --- a/packages/rspack-test-tools/src/compiler.ts +++ b/packages/rspack-test-tools/src/compiler.ts @@ -198,6 +198,12 @@ export class TestCompilerManager implements ITestCompilerManager { }); } this.compilerInstance!.watch(watchOptions, (error, newStats) => { + if (process.env.WATCH_DIAG) { + // [WATCH-DIAG] temporary: log every watch rebuild with its context dir + console.error( + `[WATCH-DIAG][build] ctx=${this.compilerInstance!.options.context} ts=${Date.now()} hash=${newStats?.hash}`, + ); + } this.emitter.emit(ECompilerEvent.Build, error, newStats); if (__DEBUG__) { if (error) { diff --git a/tests/rspack-test/WatchRepro.test.js b/tests/rspack-test/WatchRepro.test.js index 08b1d9213169..c2c141bd5273 100644 --- a/tests/rspack-test/WatchRepro.test.js +++ b/tests/rspack-test/WatchRepro.test.js @@ -1,12 +1,17 @@ // [WATCH-DIAG] TEMPORARY: reproduce the WASM-only watch flaky of // `side-effects/issue-7400 > should compile step 1`. // -// Hypothesis: the step-sync in createWatchStepProcessor uses `once(Build)` + -// a fixed 100ms sleep. Under slow WASM compilation a trailing Build event from -// the previous step can resolve the next step's task before its own copyDiff, -// so the runner executes a stale (previous-step) bundle -> WATCH_STEP="1" but -// the bundle asserts toEqual("0"). This file registers many identical copies of -// the case (distinct temp/dist) to amplify the hit rate, with WATCH_DIAG on. +// Symptom: at step 1 the executed bundle still contains step 0's +// `expect(WATCH_STEP).toEqual("0")` while WATCH_STEP is already "1" -> the +// runner executes a stale (previous-step) bundle. +// +// Hypothesis: createWatchStepProcessor synchronizes step transitions with +// `once(Build)` + a fixed 100ms sleep. Under event-loop pressure a Build event +// that does NOT correspond to this step's copyDiff resolves the step's task, so +// the runner runs a stale bundle. Iteration 1 (no pressure) showed a clean +// ~1200ms single-Build path with STALE=false, so we now inject event-loop +// freezes (the documented behavior of heavy sibling WASM tests) to recreate the +// real contention. // // Only runs under WASM; native jobs register nothing. if (process.env.WASM) { @@ -15,13 +20,19 @@ if (process.env.WASM) { const path = require("path"); const { createWatchCase } = require("@rspack/test-tools"); - const src = path.join( - __dirname, - "watchCases", - "side-effects", - "issue-7400" - ); - const count = Number(process.env.WATCH_REPRO_N || 50); + // Simulate the ~1s event-loop freezes that heavy sibling WASM tests cause. + if (process.env.WATCH_REPRO_FREEZE !== "0") { + const blockMs = Number(process.env.WATCH_REPRO_FREEZE_MS || 400); + const gapMs = Number(process.env.WATCH_REPRO_FREEZE_GAP || 500); + const timer = setInterval(() => { + const end = Date.now() + blockMs; + while (Date.now() < end) {} + }, blockMs + gapMs); + if (timer.unref) timer.unref(); + } + + const src = path.join(__dirname, "watchCases", "side-effects", "issue-7400"); + const count = Number(process.env.WATCH_REPRO_N || 100); for (let i = 0; i < count; i++) { const name = `side-effects/issue-7400-repro-${String(i).padStart(3, "0")}`; From cd1c043eee5ab0a1c8f1a53f16607f525c25d8c0 Mon Sep 17 00:00:00 2001 From: pshu Date: Tue, 7 Jul 2026 15:42:37 +0800 Subject: [PATCH 3/7] test: bump repro N=500 + non-uniform event-loop freeze --- tests/rspack-test/WatchRepro.test.js | 35 +++++++++++++++------------- 1 file changed, 19 insertions(+), 16 deletions(-) diff --git a/tests/rspack-test/WatchRepro.test.js b/tests/rspack-test/WatchRepro.test.js index c2c141bd5273..224c67c6526c 100644 --- a/tests/rspack-test/WatchRepro.test.js +++ b/tests/rspack-test/WatchRepro.test.js @@ -5,13 +5,12 @@ // `expect(WATCH_STEP).toEqual("0")` while WATCH_STEP is already "1" -> the // runner executes a stale (previous-step) bundle. // -// Hypothesis: createWatchStepProcessor synchronizes step transitions with -// `once(Build)` + a fixed 100ms sleep. Under event-loop pressure a Build event -// that does NOT correspond to this step's copyDiff resolves the step's task, so -// the runner runs a stale bundle. Iteration 1 (no pressure) showed a clean -// ~1200ms single-Build path with STALE=false, so we now inject event-loop -// freezes (the documented behavior of heavy sibling WASM tests) to recreate the -// real contention. +// Findings so far (instrumented CI runs): the harness step-sync is robust - +// every case emits exactly 2 Build events (one per step), always with correct +// content (STALE=false), even under event-loop freeze. So the leaked-Build +// hypothesis is falsified. This iteration bumps sample volume (N) and uses a +// NON-UNIFORM freeze to create differential timer misalignment instead of a +// uniform time shift. // // Only runs under WASM; native jobs register nothing. if (process.env.WASM) { @@ -20,22 +19,26 @@ if (process.env.WASM) { const path = require("path"); const { createWatchCase } = require("@rspack/test-tools"); - // Simulate the ~1s event-loop freezes that heavy sibling WASM tests cause. + // Non-uniform event-loop freezes: cycle through varied block durations so + // watchpack poll/aggregate timers and the step-sync setTimeout drift apart. if (process.env.WATCH_REPRO_FREEZE !== "0") { - const blockMs = Number(process.env.WATCH_REPRO_FREEZE_MS || 400); - const gapMs = Number(process.env.WATCH_REPRO_FREEZE_GAP || 500); - const timer = setInterval(() => { - const end = Date.now() + blockMs; + const blocks = [150, 600, 350, 800, 250, 500]; + let k = 0; + const tick = () => { + const end = Date.now() + blocks[k++ % blocks.length]; while (Date.now() < end) {} - }, blockMs + gapMs); - if (timer.unref) timer.unref(); + const t = setTimeout(tick, 180); + if (t.unref) t.unref(); + }; + const t0 = setTimeout(tick, 180); + if (t0.unref) t0.unref(); } const src = path.join(__dirname, "watchCases", "side-effects", "issue-7400"); - const count = Number(process.env.WATCH_REPRO_N || 100); + const count = Number(process.env.WATCH_REPRO_N || 500); for (let i = 0; i < count; i++) { - const name = `side-effects/issue-7400-repro-${String(i).padStart(3, "0")}`; + const name = `side-effects/issue-7400-repro-${String(i).padStart(4, "0")}`; const dist = path.resolve(__dirname, "./js/watch-repro", name); const temp = path.resolve(__dirname, "./js/temp-repro", name); createWatchCase(name, src, dist, temp); From 23e6b3d3c12dc3b8ccc3330802862ba6e05735b9 Mon Sep 17 00:00:00 2001 From: pshu Date: Wed, 8 Jul 2026 15:16:27 +0800 Subject: [PATCH 4/7] fix(test): gate watch step-sync on watcher quiescence to drop stale rebuilds Wait until no rebuild is pending (invalidation after last build) before applying a step's copyDiff, so once(Build) captures the copyDiff-triggered rebuild instead of an extra load-induced transition rebuild carrying previous-step content. --- packages/rspack-test-tools/src/case/watch.ts | 58 ++++++++++++++------ 1 file changed, 41 insertions(+), 17 deletions(-) diff --git a/packages/rspack-test-tools/src/case/watch.ts b/packages/rspack-test-tools/src/case/watch.ts index 46d1be7ddc87..035fa85eb6c5 100644 --- a/packages/rspack-test-tools/src/case/watch.ts +++ b/packages/rspack-test-tools/src/case/watch.ts @@ -88,7 +88,16 @@ export function createWatchInitialProcessor( const c = await compiler(context, name); c!.hooks.invalid.tap('WatchTestCasesTest', (filename, mtime) => { watchContext.currentTriggerFilename = filename; + watchState.lastInvalidTs = Date.now(); }); + // Track build completions so a step transition can wait for the watcher to + // become quiescent before applying the next change (see step build). + context + .getCompiler() + .getEmitter() + .on(ECompilerEvent.Build, () => { + watchState.lastBuildTs = Date.now(); + }); }, build: async (context: ITestContext) => { const compiler = context.getCompiler(); @@ -287,35 +296,50 @@ export function createWatchStepProcessor( }; processor.build = async (context: ITestContext) => { const compiler = context.getCompiler(); - // [WATCH-DIAG] temporary instrumentation, guarded by WATCH_DIAG env + const emitter = compiler.getEmitter(); const DIAG = !!process.env.WATCH_DIAG; + + // Wait until the watcher is quiescent before applying this step's change. + // + // Under load the watcher can still have an extra in-flight rebuild from the + // previous step that carries stale content. If we armed `once(Build)` now it + // might capture that stale rebuild instead of the one our copyDiff triggers, + // making the runner execute a previous-step bundle. A rebuild is pending + // when an invalidation fired after the last completed build; wait it out so + // the next Build we capture is the one this step's copyDiff produces. + const settleDeadline = Date.now() + 10000; + while (Date.now() < settleDeadline) { + const pending = + (watchState.lastInvalidTs || 0) > (watchState.lastBuildTs || 0); + const idle = Date.now() - (watchState.lastBuildTs || 0) > 150; + if (!pending && idle) break; + await new Promise((r) => setTimeout(r, 50)); + } + + // Native Watcher using [notify](https://github.com/notify-rs/notify) to watch files. + // After tests, notify will cost many milliseconds to watch in windows OS when jest run concurrently. + // So we need to wait a while to ensure the watcher is ready. + // The timeout is set to 400ms for windows OS and 100ms for other OS. + // TODO: This is a workaround, we can remove it when notify support windows better. + const timeout = nativeWatcher && process.platform === 'win32' ? 400 : 100; + await new Promise((resolve) => setTimeout(resolve, timeout)); + const buildEvents: number[] = []; const onBuild = () => buildEvents.push(Date.now()); - if (DIAG) compiler.getEmitter().on(ECompilerEvent.Build, onBuild); + if (DIAG) emitter.on(ECompilerEvent.Build, onBuild); let resolveTs = 0; const task = new Promise((resolve, reject) => { - compiler.getEmitter().once(ECompilerEvent.Build, (e, stats) => { + emitter.once(ECompilerEvent.Build, (e, stats) => { resolveTs = Date.now(); if (e) return reject(e); resolve(stats); }); }); - // wait compiler to ready watch the files and diretories - - // Native Watcher using [notify](https://github.com/notify-rs/notify) to watch files. - // After tests, notify will cost many milliseconds to watch in windows OS when jest run concurrently. - // So we need to wait a while to ensure the watcher is ready. - // If we don't wait, copyDiff will happen before the watcher is ready, - // which will cause the compiler not rebuild when the files change. - // The timeout is set to 400ms for windows OS and 100ms for other OS. - // TODO: This is a workaround, we can remove it when notify support windows better. - const timeout = nativeWatcher && process.platform === 'win32' ? 400 : 100; - await new Promise((resolve) => setTimeout(resolve, timeout)); const copyTs = Date.now(); copyDiff(path.join(context.getSource(), step), tempDir, false); await task; if (DIAG) { - compiler.getEmitter().removeListener(ECompilerEvent.Build, onBuild); + emitter.removeListener(ECompilerEvent.Build, onBuild); let bundleStep = '?'; try { const bundle = fs.readFileSync( @@ -326,8 +350,8 @@ export function createWatchStepProcessor( if (m) bundleStep = m[1]; } catch {} console.error( - `[WATCH-DIAG] name=${name} step=${step} sleep=${timeout} ` + - `resolvedBeforeCopy=${resolveTs < copyTs} resolveRelCopy=${resolveTs - copyTs}ms ` + + `[WATCH-DIAG] name=${name} step=${step} ` + + `resolveRelCopy=${resolveTs - copyTs}ms ` + `buildEventsRelCopy=[${buildEvents.map((t) => t - copyTs).join(',')}] ` + `bundleStep=${bundleStep} STALE=${bundleStep !== '?' && bundleStep !== step}`, ); From 2c338cf74e7cd73b4817644ef9d1190302dae28a Mon Sep 17 00:00:00 2001 From: pshu Date: Wed, 8 Jul 2026 15:44:16 +0800 Subject: [PATCH 5/7] fix(test): settle watch step on last build to drop stale transition rebuild Replace once(Build) with a settle window that keeps the last build of the step (arming before copyDiff so a legitimately-pending rebuild like change-event/metadata is still captured). Fixes the quiescence-gate regression that starved metadata of its build. --- packages/rspack-test-tools/src/case/watch.ts | 96 ++++++++++---------- tests/rspack-test/WatchRepro.test.js | 10 +- 2 files changed, 53 insertions(+), 53 deletions(-) diff --git a/packages/rspack-test-tools/src/case/watch.ts b/packages/rspack-test-tools/src/case/watch.ts index 035fa85eb6c5..ff55101b0711 100644 --- a/packages/rspack-test-tools/src/case/watch.ts +++ b/packages/rspack-test-tools/src/case/watch.ts @@ -88,16 +88,7 @@ export function createWatchInitialProcessor( const c = await compiler(context, name); c!.hooks.invalid.tap('WatchTestCasesTest', (filename, mtime) => { watchContext.currentTriggerFilename = filename; - watchState.lastInvalidTs = Date.now(); }); - // Track build completions so a step transition can wait for the watcher to - // become quiescent before applying the next change (see step build). - context - .getCompiler() - .getEmitter() - .on(ECompilerEvent.Build, () => { - watchState.lastBuildTs = Date.now(); - }); }, build: async (context: ITestContext) => { const compiler = context.getCompiler(); @@ -299,47 +290,55 @@ export function createWatchStepProcessor( const emitter = compiler.getEmitter(); const DIAG = !!process.env.WATCH_DIAG; - // Wait until the watcher is quiescent before applying this step's change. - // - // Under load the watcher can still have an extra in-flight rebuild from the - // previous step that carries stale content. If we armed `once(Build)` now it - // might capture that stale rebuild instead of the one our copyDiff triggers, - // making the runner execute a previous-step bundle. A rebuild is pending - // when an invalidation fired after the last completed build; wait it out so - // the next Build we capture is the one this step's copyDiff produces. - const settleDeadline = Date.now() + 10000; - while (Date.now() < settleDeadline) { - const pending = - (watchState.lastInvalidTs || 0) > (watchState.lastBuildTs || 0); - const idle = Date.now() - (watchState.lastBuildTs || 0) > 150; - if (!pending && idle) break; - await new Promise((r) => setTimeout(r, 50)); - } - - // Native Watcher using [notify](https://github.com/notify-rs/notify) to watch files. - // After tests, notify will cost many milliseconds to watch in windows OS when jest run concurrently. - // So we need to wait a while to ensure the watcher is ready. - // The timeout is set to 400ms for windows OS and 100ms for other OS. - // TODO: This is a workaround, we can remove it when notify support windows better. - const timeout = nativeWatcher && process.platform === 'win32' ? 400 : 100; - await new Promise((resolve) => setTimeout(resolve, timeout)); + // The watcher aggregateTimeout (see `watch()`); the settle window must be + // larger so a slow/extra rebuild cannot be mistaken for a settled result. + const settleWindow = 2000; + // Native Watcher (notify) needs a moment to be ready to detect the change; + // 400ms on windows, 100ms elsewhere. + const readyTimeout = + nativeWatcher && process.platform === 'win32' ? 400 : 100; const buildEvents: number[] = []; - const onBuild = () => buildEvents.push(Date.now()); - if (DIAG) emitter.on(ECompilerEvent.Build, onBuild); - let resolveTs = 0; - const task = new Promise((resolve, reject) => { - emitter.once(ECompilerEvent.Build, (e, stats) => { - resolveTs = Date.now(); - if (e) return reject(e); - resolve(stats); - }); + const copyState = { ts: 0 }; + + // Capture the LAST build this step settles on, not merely the first one. + // + // Under load the watcher can emit an extra transition rebuild that still + // carries the previous step's content; taking the first Build would run that + // stale bundle. We instead keep the latest build and only resolve once no new + // build has arrived for `settleWindow` (> aggregateTimeout), so the final + // build always reflects the current sources. The listener is armed before + // copyDiff so a rebuild the step legitimately relies on that is already + // pending (e.g. a metadata touch from the previous step) is not missed. + await new Promise((resolve, reject) => { + let settleTimer: ReturnType | undefined; + let finished = false; + const finish = (fn: () => void) => { + if (finished) return; + finished = true; + emitter.removeListener(ECompilerEvent.Build, onBuild); + fn(); + }; + const settle = () => { + if (settleTimer) clearTimeout(settleTimer); + settleTimer = setTimeout(() => finish(resolve), settleWindow); + }; + const onBuild = (e: Error | null) => { + if (finished) return; + if (e) return finish(() => reject(e)); + if (DIAG) buildEvents.push(Date.now()); + settle(); + }; + emitter.on(ECompilerEvent.Build, onBuild); + + (async () => { + await new Promise((r) => setTimeout(r, readyTimeout)); + copyState.ts = Date.now(); + copyDiff(path.join(context.getSource(), step), tempDir, false); + })(); }); - const copyTs = Date.now(); - copyDiff(path.join(context.getSource(), step), tempDir, false); - await task; + if (DIAG) { - emitter.removeListener(ECompilerEvent.Build, onBuild); let bundleStep = '?'; try { const bundle = fs.readFileSync( @@ -350,9 +349,8 @@ export function createWatchStepProcessor( if (m) bundleStep = m[1]; } catch {} console.error( - `[WATCH-DIAG] name=${name} step=${step} ` + - `resolveRelCopy=${resolveTs - copyTs}ms ` + - `buildEventsRelCopy=[${buildEvents.map((t) => t - copyTs).join(',')}] ` + + `[WATCH-DIAG] name=${name} step=${step} builds=${buildEvents.length} ` + + `buildEventsRelCopy=[${buildEvents.map((t) => t - copyState.ts).join(',')}] ` + `bundleStep=${bundleStep} STALE=${bundleStep !== '?' && bundleStep !== step}`, ); } diff --git a/tests/rspack-test/WatchRepro.test.js b/tests/rspack-test/WatchRepro.test.js index 224c67c6526c..9a2488a1f3bc 100644 --- a/tests/rspack-test/WatchRepro.test.js +++ b/tests/rspack-test/WatchRepro.test.js @@ -21,21 +21,23 @@ if (process.env.WASM) { // Non-uniform event-loop freezes: cycle through varied block durations so // watchpack poll/aggregate timers and the step-sync setTimeout drift apart. + // Kept moderate (<= 300ms) so it models realistic concurrent-compile pressure + // rather than the extreme 800ms freezes used purely to reproduce the bug. if (process.env.WATCH_REPRO_FREEZE !== "0") { - const blocks = [150, 600, 350, 800, 250, 500]; + const blocks = [150, 300, 200, 250]; let k = 0; const tick = () => { const end = Date.now() + blocks[k++ % blocks.length]; while (Date.now() < end) {} - const t = setTimeout(tick, 180); + const t = setTimeout(tick, 200); if (t.unref) t.unref(); }; - const t0 = setTimeout(tick, 180); + const t0 = setTimeout(tick, 200); if (t0.unref) t0.unref(); } const src = path.join(__dirname, "watchCases", "side-effects", "issue-7400"); - const count = Number(process.env.WATCH_REPRO_N || 500); + const count = Number(process.env.WATCH_REPRO_N || 150); for (let i = 0; i < count; i++) { const name = `side-effects/issue-7400-repro-${String(i).padStart(4, "0")}`; From 1a2dd39dde2b859e4a425fb5b5174b184a929d6c Mon Sep 17 00:00:00 2001 From: pshu Date: Wed, 8 Jul 2026 15:56:41 +0800 Subject: [PATCH 6/7] test: proof run - strong freeze + wide settle to show fix keeps build C over stale B --- packages/rspack-test-tools/src/case/watch.ts | 2 +- tests/rspack-test/WatchRepro.test.js | 17 ++++++++++------- 2 files changed, 11 insertions(+), 8 deletions(-) diff --git a/packages/rspack-test-tools/src/case/watch.ts b/packages/rspack-test-tools/src/case/watch.ts index ff55101b0711..2f8cf13f4881 100644 --- a/packages/rspack-test-tools/src/case/watch.ts +++ b/packages/rspack-test-tools/src/case/watch.ts @@ -292,7 +292,7 @@ export function createWatchStepProcessor( // The watcher aggregateTimeout (see `watch()`); the settle window must be // larger so a slow/extra rebuild cannot be mistaken for a settled result. - const settleWindow = 2000; + const settleWindow = Number(process.env.WATCH_SETTLE_MS) || 2000; // Native Watcher (notify) needs a moment to be ready to detect the change; // 400ms on windows, 100ms elsewhere. const readyTimeout = diff --git a/tests/rspack-test/WatchRepro.test.js b/tests/rspack-test/WatchRepro.test.js index 9a2488a1f3bc..94168847e8e8 100644 --- a/tests/rspack-test/WatchRepro.test.js +++ b/tests/rspack-test/WatchRepro.test.js @@ -15,24 +15,27 @@ // Only runs under WASM; native jobs register nothing. if (process.env.WASM) { process.env.WATCH_DIAG = "1"; + // Proof run: widen the fix's settle window so it survives the extreme freezer + // below (which inflates the gap between the stale transition rebuild and the + // real one). Under normal load the fix's default (2000ms) is enough. + process.env.WATCH_SETTLE_MS = process.env.WATCH_SETTLE_MS || "5000"; const path = require("path"); const { createWatchCase } = require("@rspack/test-tools"); - // Non-uniform event-loop freezes: cycle through varied block durations so - // watchpack poll/aggregate timers and the step-sync setTimeout drift apart. - // Kept moderate (<= 300ms) so it models realistic concurrent-compile pressure - // rather than the extreme 800ms freezes used purely to reproduce the bug. + // Extreme non-uniform event-loop freezes to force the extra stale transition + // rebuild (build "B") to appear, so we can prove the fix keeps the later, + // correct build (build "C") -> builds>=2 with STALE=false. if (process.env.WATCH_REPRO_FREEZE !== "0") { - const blocks = [150, 300, 200, 250]; + const blocks = [150, 600, 350, 800, 250, 500]; let k = 0; const tick = () => { const end = Date.now() + blocks[k++ % blocks.length]; while (Date.now() < end) {} - const t = setTimeout(tick, 200); + const t = setTimeout(tick, 180); if (t.unref) t.unref(); }; - const t0 = setTimeout(tick, 200); + const t0 = setTimeout(tick, 180); if (t0.unref) t0.unref(); } From b8814449e6c14ef26e09b984b8aee0bbb677b7a8 Mon Sep 17 00:00:00 2001 From: pshu Date: Wed, 8 Jul 2026 16:36:58 +0800 Subject: [PATCH 7/7] chore(test): remove watch-flaky diagnostics and repro harness --- packages/rspack-test-tools/src/case/watch.ts | 45 +++++------------ packages/rspack-test-tools/src/compiler.ts | 6 --- tests/rspack-test/WatchRepro.test.js | 51 -------------------- 3 files changed, 11 insertions(+), 91 deletions(-) delete mode 100644 tests/rspack-test/WatchRepro.test.js diff --git a/packages/rspack-test-tools/src/case/watch.ts b/packages/rspack-test-tools/src/case/watch.ts index 2f8cf13f4881..19114ecdc0e5 100644 --- a/packages/rspack-test-tools/src/case/watch.ts +++ b/packages/rspack-test-tools/src/case/watch.ts @@ -288,28 +288,24 @@ export function createWatchStepProcessor( processor.build = async (context: ITestContext) => { const compiler = context.getCompiler(); const emitter = compiler.getEmitter(); - const DIAG = !!process.env.WATCH_DIAG; - // The watcher aggregateTimeout (see `watch()`); the settle window must be - // larger so a slow/extra rebuild cannot be mistaken for a settled result. - const settleWindow = Number(process.env.WATCH_SETTLE_MS) || 2000; // Native Watcher (notify) needs a moment to be ready to detect the change; // 400ms on windows, 100ms elsewhere. const readyTimeout = nativeWatcher && process.platform === 'win32' ? 400 : 100; + // Must exceed the watcher aggregateTimeout (see `watch()`) so a slow or extra + // rebuild cannot be mistaken for a settled result. + const settleWindow = 2000; - const buildEvents: number[] = []; - const copyState = { ts: 0 }; - - // Capture the LAST build this step settles on, not merely the first one. + // Resolve on the LAST build this step settles on, not merely the first one. // - // Under load the watcher can emit an extra transition rebuild that still - // carries the previous step's content; taking the first Build would run that - // stale bundle. We instead keep the latest build and only resolve once no new - // build has arrived for `settleWindow` (> aggregateTimeout), so the final - // build always reflects the current sources. The listener is armed before - // copyDiff so a rebuild the step legitimately relies on that is already - // pending (e.g. a metadata touch from the previous step) is not missed. + // Under load the watcher can emit an extra rebuild during the step transition + // that still carries the previous step's content; capturing the first Build + // would run that stale bundle. We instead keep waiting until no new build has + // arrived for `settleWindow`, so the build the runner observes always reflects + // the current sources. The listener is armed before copyDiff so a rebuild the + // step legitimately relies on that is already pending (e.g. a metadata touch + // from the previous step) is still captured. await new Promise((resolve, reject) => { let settleTimer: ReturnType | undefined; let finished = false; @@ -326,34 +322,15 @@ export function createWatchStepProcessor( const onBuild = (e: Error | null) => { if (finished) return; if (e) return finish(() => reject(e)); - if (DIAG) buildEvents.push(Date.now()); settle(); }; emitter.on(ECompilerEvent.Build, onBuild); (async () => { await new Promise((r) => setTimeout(r, readyTimeout)); - copyState.ts = Date.now(); copyDiff(path.join(context.getSource(), step), tempDir, false); })(); }); - - if (DIAG) { - let bundleStep = '?'; - try { - const bundle = fs.readFileSync( - path.join(context.getDist(), 'bundle.js'), - 'utf-8', - ); - const m = bundle.match(/toEqual\("(\d)"\)/); - if (m) bundleStep = m[1]; - } catch {} - console.error( - `[WATCH-DIAG] name=${name} step=${step} builds=${buildEvents.length} ` + - `buildEventsRelCopy=[${buildEvents.map((t) => t - copyState.ts).join(',')}] ` + - `bundleStep=${bundleStep} STALE=${bundleStep !== '?' && bundleStep !== step}`, - ); - } }; return processor; } diff --git a/packages/rspack-test-tools/src/compiler.ts b/packages/rspack-test-tools/src/compiler.ts index 777730aae6cd..96032c50281f 100644 --- a/packages/rspack-test-tools/src/compiler.ts +++ b/packages/rspack-test-tools/src/compiler.ts @@ -198,12 +198,6 @@ export class TestCompilerManager implements ITestCompilerManager { }); } this.compilerInstance!.watch(watchOptions, (error, newStats) => { - if (process.env.WATCH_DIAG) { - // [WATCH-DIAG] temporary: log every watch rebuild with its context dir - console.error( - `[WATCH-DIAG][build] ctx=${this.compilerInstance!.options.context} ts=${Date.now()} hash=${newStats?.hash}`, - ); - } this.emitter.emit(ECompilerEvent.Build, error, newStats); if (__DEBUG__) { if (error) { diff --git a/tests/rspack-test/WatchRepro.test.js b/tests/rspack-test/WatchRepro.test.js deleted file mode 100644 index 94168847e8e8..000000000000 --- a/tests/rspack-test/WatchRepro.test.js +++ /dev/null @@ -1,51 +0,0 @@ -// [WATCH-DIAG] TEMPORARY: reproduce the WASM-only watch flaky of -// `side-effects/issue-7400 > should compile step 1`. -// -// Symptom: at step 1 the executed bundle still contains step 0's -// `expect(WATCH_STEP).toEqual("0")` while WATCH_STEP is already "1" -> the -// runner executes a stale (previous-step) bundle. -// -// Findings so far (instrumented CI runs): the harness step-sync is robust - -// every case emits exactly 2 Build events (one per step), always with correct -// content (STALE=false), even under event-loop freeze. So the leaked-Build -// hypothesis is falsified. This iteration bumps sample volume (N) and uses a -// NON-UNIFORM freeze to create differential timer misalignment instead of a -// uniform time shift. -// -// Only runs under WASM; native jobs register nothing. -if (process.env.WASM) { - process.env.WATCH_DIAG = "1"; - // Proof run: widen the fix's settle window so it survives the extreme freezer - // below (which inflates the gap between the stale transition rebuild and the - // real one). Under normal load the fix's default (2000ms) is enough. - process.env.WATCH_SETTLE_MS = process.env.WATCH_SETTLE_MS || "5000"; - - const path = require("path"); - const { createWatchCase } = require("@rspack/test-tools"); - - // Extreme non-uniform event-loop freezes to force the extra stale transition - // rebuild (build "B") to appear, so we can prove the fix keeps the later, - // correct build (build "C") -> builds>=2 with STALE=false. - if (process.env.WATCH_REPRO_FREEZE !== "0") { - const blocks = [150, 600, 350, 800, 250, 500]; - let k = 0; - const tick = () => { - const end = Date.now() + blocks[k++ % blocks.length]; - while (Date.now() < end) {} - const t = setTimeout(tick, 180); - if (t.unref) t.unref(); - }; - const t0 = setTimeout(tick, 180); - if (t0.unref) t0.unref(); - } - - const src = path.join(__dirname, "watchCases", "side-effects", "issue-7400"); - const count = Number(process.env.WATCH_REPRO_N || 150); - - for (let i = 0; i < count; i++) { - const name = `side-effects/issue-7400-repro-${String(i).padStart(4, "0")}`; - const dist = path.resolve(__dirname, "./js/watch-repro", name); - const temp = path.resolve(__dirname, "./js/temp-repro", name); - createWatchCase(name, src, dist, temp); - } -}