From 6b4bf68b8ba96fce48751f2f7be4a022619cc8e0 Mon Sep 17 00:00:00 2001 From: cliffhall Date: Sun, 23 Aug 2026 13:02:38 -0400 Subject: [PATCH] fix(scripts): observe the final polling interval before declaring a timeout MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Copilot's suppressed round-3 comment is right. The attempt-counted loop read the output and then slept, so nothing ever observed the last interval: an announcement arriving at 29.9s of a 30s budget was reported as a timeout, and a spawn error or early exit landing in that window was misattributed the same way. Inherited from the original smoke, but wrong either way. Replace it with a deadline loop that re-reads state after every wait, the last one included, and clamp the final wait to the deadline so the budget is a real bound rather than one poll longer. The regression test sets pollMs === timeoutMs, which makes the distinction deterministic rather than a race: the attempt-counted loop gets exactly one check, at t≈0 before the child has finished starting, then throws; the deadline loop re-reads after the wait and sees the announcement. The child announces immediately, ~2s inside the window, so a loaded runner can't flip it. Verified both directions — the test fails against the old loop and passes against the new one — and `npm run test:scripts` was repeated to confirm it is stable under the full 116-test parallel run (an earlier margin-based version of this test was not). Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_013hzwzS8UvBsr4yZm7o7sev Signed-off-by: cliffhall --- scripts/lib/announced-child.mjs | 15 ++++++++++++--- scripts/lib/announced-child.test.mjs | 24 ++++++++++++++++++++++++ 2 files changed, 36 insertions(+), 3 deletions(-) diff --git a/scripts/lib/announced-child.mjs b/scripts/lib/announced-child.mjs index 50c8f529..11303a19 100644 --- a/scripts/lib/announced-child.mjs +++ b/scripts/lib/announced-child.mjs @@ -69,15 +69,24 @@ export async function startAnnouncedChild({ child.on("exit", () => (exited = true)); child.on("close", () => (exited = true)); - const attempts = Math.max(1, Math.ceil(timeoutMs / pollMs)); - for (let attempt = 0; attempt < attempts; attempt++) { + // A deadline loop, not a fixed attempt count: state is re-read *after* every + // wait, including the last one. Counting attempts and throwing straight after + // the final `delay` leaves the whole last polling interval unobserved, so an + // announcement landing at 29.9s of a 30s budget is reported as a timeout — + // and a spawn error or early exit in that window is misattributed the same + // way. The final wait is also clamped to the deadline so the budget is a + // real bound rather than one poll longer. + const deadline = Date.now() + timeoutMs; + for (;;) { const match = out.match(pattern); if (match) return { child, match }; if (spawnError) { throw new Error(`could not spawn the ${what}: ${spawnError.message}`); } if (exited) throw new Error(`${what} exited early:\n${out}`); - await delay(pollMs); + const remaining = deadline - Date.now(); + if (remaining <= 0) break; + await delay(Math.min(pollMs, remaining)); } throw new Error( `${what} did not start within ${Math.round(timeoutMs / 1000)}s:\n${out}`, diff --git a/scripts/lib/announced-child.test.mjs b/scripts/lib/announced-child.test.mjs index a47f6977..e6404c80 100644 --- a/scripts/lib/announced-child.test.mjs +++ b/scripts/lib/announced-child.test.mjs @@ -70,6 +70,30 @@ test("scans stdout as well as stderr", async (t) => { assert.equal(match[1], "4242"); }); +test("sees an announcement that lands inside the final polling interval", async (t) => { + // The off-by-one this guards: a fixed attempt count checks the output and + // then sleeps, so nothing ever observes the last interval — an announcement + // at 29.9s of a 30s budget reads as a timeout. + // + // Setting pollMs === timeoutMs makes that deterministic rather than a race: + // the attempt-counted loop gets exactly one check, at t≈0 before the child + // has even finished starting, and then throws. The deadline loop re-reads + // after the wait, so *any* announcement before the deadline is seen. The + // child announces immediately, ~2s inside the window on either side, so a + // loaded runner cannot flip the outcome. (Verified: this fails against the + // attempt-counted loop and passes against the deadline loop.) + const { match } = await startAnnouncedChild({ + command: process.execPath, + args: ["-e", 'console.error("listening at http://127.0.0.1:8080")'], + pattern: /listening at (http:\/\/\S+)/i, + onSpawn: killOnTeardown(t), + what: "probe", + timeoutMs: 2000, + pollMs: 2000, + }); + assert.equal(match[1], "http://127.0.0.1:8080"); +}); + test("a non-announcing child is still reachable and killable after the timeout", async (t) => { // The regression: a child that is alive but never announces. The throw must // not be the only thing that happens — the caller must already hold the