diff --git a/.changeset/dev-hmr-quiescence.md b/.changeset/dev-hmr-quiescence.md new file mode 100644 index 0000000000..d673520af4 --- /dev/null +++ b/.changeset/dev-hmr-quiescence.md @@ -0,0 +1,5 @@ +--- +'@workflow/next': patch +--- + +Dev HMR logging (`WORKFLOW_DEV_HMR_LOGS=1`) now also logs `workflow dev hmr: rebuild complete` when a rebuild finishes processing, so log readers can tell an idle pipeline from a rebuild in flight. diff --git a/packages/core/e2e/dev.test.ts b/packages/core/e2e/dev.test.ts index f5f3dc610b..bd5cf7841d 100644 --- a/packages/core/e2e/dev.test.ts +++ b/packages/core/e2e/dev.test.ts @@ -155,6 +155,7 @@ export function createDevTests(config?: DevTestConfig) { hot: 'workflow dev hmr: hot rebuild', full: 'workflow dev hmr: full rediscovery', }; + const hmrRebuildCompleteMessage = 'workflow dev hmr: rebuild complete'; const fetchWithTimeout = (pathname: string) => { if (!deploymentUrl) { @@ -193,10 +194,58 @@ export function createDevTests(config?: DevTestConfig) { .then(decodeDevServerLog) .catch(() => ''); }; - const readDevServerLogCursor = async () => - devServerLogPath && shouldAssertDevHmrLogs - ? (await readDevServerLog()).length - : undefined; + /** + * Wait until the dev server's HMR pipeline is quiescent: every rebuild + * the log says started (`hot rebuild` / `full rediscovery`) has logged + * `rebuild complete`, and no new HMR line has appeared for a short + * window (covering watcher latency for a just-landed write plus the + * flush debounce). + * + * Rebuilds are serialized and can take multi-second on CI, so a write + * from a previous case (or a teardown restore) can still be rebuilding + * — or sitting in the queue — when the next exact-count window would + * open. Draining here keeps those legitimate rebuild lines out of the + * next window instead of failing it with over-counts. + */ + const hmrQuiescenceQuietMs = 2_000; + const waitForHmrQuiescence = async () => { + if (!devServerLogPath || !shouldAssertDevHmrLogs) { + return; + } + let lastCounts = ''; + let quietSince = Date.now(); + await pollUntil({ + description: 'dev server HMR pipeline to go quiescent', + timeoutMs: hmrRediscoveryTimeoutMs, + intervalMs: 250, + check: async () => { + const log = await readDevServerLog(); + const hot = countLogMessage(log, hmrLogMessages.hot); + const full = countLogMessage(log, hmrLogMessages.full); + const skip = countLogMessage(log, hmrLogMessages.skip); + const complete = countLogMessage(log, hmrRebuildCompleteMessage); + const counts = `${hot}/${full}/${skip}/${complete}`; + if (counts !== lastCounts) { + lastCounts = counts; + quietSince = Date.now(); + } + expect(complete).toBeGreaterThanOrEqual(hot + full); + expect(Date.now() - quietSince).toBeGreaterThanOrEqual( + hmrQuiescenceQuietMs + ); + }, + }); + }; + + // Cursors open exact-count windows, so they only get taken once the + // pipeline is drained — every call site writes after taking its cursor. + const readDevServerLogCursor = async () => { + if (!devServerLogPath || !shouldAssertDevHmrLogs) { + return undefined; + } + await waitForHmrQuiescence(); + return (await readDevServerLog()).length; + }; const countLogMessage = (log: string, message: string) => log.split(message).length - 1; type ExpectedHmrLogCount = number | { min?: number; max?: number }; diff --git a/packages/next/src/builder-eager.ts b/packages/next/src/builder-eager.ts index 029601767c..c7ecae88f1 100644 --- a/packages/next/src/builder-eager.ts +++ b/packages/next/src/builder-eager.ts @@ -470,17 +470,32 @@ export async function getNextBuilderEager( } if (decision.kind === 'full') { logDevHmr('workflow dev hmr: full rediscovery'); - await fullRebuild(); - await refreshKnownFiles(); + try { + await fullRebuild(); + await refreshKnownFiles(); + } finally { + // Rebuilds log their classification when they start (above) + // and this line when their processing ends — in a finally, so + // it marks completion of processing, not success — letting a + // log reader tell "quiet" from "rebuild in flight with queued + // events behind it". The e2e HMR tests drain to that + // quiescence before counting lines. + logDevHmr('workflow dev hmr: rebuild complete'); + } return; } logDevHmr( `workflow dev hmr: hot rebuild${decision.refreshStepRegistrations ? ' with step registration refresh' : ''}` ); - await hotRebuild(decision.refreshStepRegistrations); - for (const [file, snapshot] of decision.snapshots) { - sourceSnapshots.set(file, snapshot); + try { + await hotRebuild(decision.refreshStepRegistrations); + for (const [file, snapshot] of decision.snapshots) { + sourceSnapshots.set(file, snapshot); + } + } finally { + // See the matching line on the full path above. + logDevHmr('workflow dev hmr: rebuild complete'); } };