fix(scripts): observe the final polling interval before declaring a timeout
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) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_013hzwzS8UvBsr4yZm7o7sev Signed-off-by: cliffhall <cliff@futurescale.com>
This commit is contained in:
parent
9cade95fd0
commit
6b4bf68b8b
2 changed files with 36 additions and 3 deletions
|
|
@ -69,15 +69,24 @@ export async function startAnnouncedChild({
|
||||||
child.on("exit", () => (exited = true));
|
child.on("exit", () => (exited = true));
|
||||||
child.on("close", () => (exited = true));
|
child.on("close", () => (exited = true));
|
||||||
|
|
||||||
const attempts = Math.max(1, Math.ceil(timeoutMs / pollMs));
|
// A deadline loop, not a fixed attempt count: state is re-read *after* every
|
||||||
for (let attempt = 0; attempt < attempts; attempt++) {
|
// 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);
|
const match = out.match(pattern);
|
||||||
if (match) return { child, match };
|
if (match) return { child, match };
|
||||||
if (spawnError) {
|
if (spawnError) {
|
||||||
throw new Error(`could not spawn the ${what}: ${spawnError.message}`);
|
throw new Error(`could not spawn the ${what}: ${spawnError.message}`);
|
||||||
}
|
}
|
||||||
if (exited) throw new Error(`${what} exited early:\n${out}`);
|
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(
|
throw new Error(
|
||||||
`${what} did not start within ${Math.round(timeoutMs / 1000)}s:\n${out}`,
|
`${what} did not start within ${Math.round(timeoutMs / 1000)}s:\n${out}`,
|
||||||
|
|
|
||||||
|
|
@ -70,6 +70,30 @@ test("scans stdout as well as stderr", async (t) => {
|
||||||
assert.equal(match[1], "4242");
|
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) => {
|
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
|
// 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
|
// not be the only thing that happens — the caller must already hold the
|
||||||
|
|
|
||||||
Loading…
Reference in a new issue