Tests: stop two harness hangs from wedging a whole run

Two suites could hang forever and never print a tally, because the one
mechanism that could interrupt the wedged work was missing on both paths.

Hang 1 (bun run test / build-phase.test.mjs): the test's run() helper
spawned every child with spawnSync and no timeout. spawnSync blocks the
test worker's thread, so node's --test-timeout (an event-loop timer)
cannot interrupt a child that wedges (a fork/exec blocked on OS resources
under concurrency, a gate's comp-diff grandchild, or a stray browser
launch). Bound every child with spawnSync timeout + killSignal SIGKILL so
a wedge becomes a fast, named failure the next test survives.

Hang 2 (bun run test:skill-behavior): runTurn called generateText with no
client-side deadline, so a stalled provider stream kept the fetch (and the
whole node process) alive past the per-test timeout, producing no tally.
Attach a real AbortSignal (default 840s, under the 900s per-test cap):
on expiry the fetch aborts, the turn throws, and the scenario
fails-and-continues. The unref'd timer is cleared on completion.

Runner backstops: run-tests.mjs now spawns each command as a detached
process-group leader and enforces a per-suite wall-clock cap that SIGKILLs
the entire group (workers, grandchildren, browsers) on expiry, with
SIGINT/SIGTERM forwarded so Ctrl-C still reaps the tree. The core node
batch gets a finite --test-timeout (180s); skill-behavior gets a 60min
group cap. Env overrides: IMPECCABLE_TEST_WALL_CLOCK_MS,
IMPECCABLE_SKILL_BEHAVIOR_TURN_TIMEOUT_MS,
IMPECCABLE_BUILD_PHASE_RUN_TIMEOUT_MS.

Proof: bun run test green twice (~60s); scoped claude-sonnet-5
skill-behavior sweep terminates with a tally (20 tests, ~32min) where the
840s abort caught a wedged redesign turn and the sweep continued instead
of hanging.

Prepared with AI assistance (Claude Code).
This commit is contained in:
Paul Bakaus
2026-09-01 11:09:44 -07:00
parent c55cd49895
commit 47f1871385
4 changed files with 130 additions and 23 deletions
+69 -20
View File
@@ -1,7 +1,13 @@
#!/usr/bin/env node
import { spawnSync } from 'node:child_process';
import { spawn } from 'node:child_process';
import { DEFAULT_SUITES, OPT_IN_SUITES, SUITES, expandSuites } from './test-suites.mjs';
// Global wall-clock backstop for any one command. Even with per-test timeouts
// and client-side network deadlines in place, a wedged tool or an orphaned
// grandchild can keep a runner alive forever; this cap guarantees the sweep
// terminates. Per-suite `wallClockMs` overrides it; the env var overrides both.
const DEFAULT_WALL_CLOCK_MS = Number(process.env.IMPECCABLE_TEST_WALL_CLOCK_MS) || 1_200_000;
const args = process.argv.slice(2);
if (args.includes('--help') || args.includes('-h')) {
@@ -23,19 +29,24 @@ try {
process.exit(1);
}
for (const suiteName of suites) {
const suite = SUITES[suiteName];
console.log(`\n## test:${suiteName}`);
console.log(suite.description);
for (const command of suite.commands) {
runCommand(command);
await main();
async function main() {
for (const suiteName of suites) {
const suite = SUITES[suiteName];
console.log(`\n## test:${suiteName}`);
console.log(suite.description);
for (const command of suite.commands) {
await runCommand(command);
}
}
}
function runCommand(command) {
async function runCommand(command) {
const env = { ...process.env, ...(command.env || {}) };
const wallClockMs = command.wallClockMs ?? DEFAULT_WALL_CLOCK_MS;
if (command.runner === 'bun') {
runProcess('bun', ['test', ...command.files], { env });
await runProcess('bun', ['test', ...command.files], { env, wallClockMs });
return;
}
@@ -50,24 +61,62 @@ function runCommand(command) {
if (command.timeoutMs) args.push(`--test-timeout=${command.timeoutMs}`);
if (command.forceExit) args.push('--test-force-exit');
args.push(...command.files);
runProcess(process.execPath, args, { env });
await runProcess(process.execPath, args, { env, wallClockMs });
return;
}
throw new Error(`Unsupported test runner "${command.runner}"`);
}
function runProcess(cmd, args, { env }) {
console.log(`$ ${formatCommand(cmd, args)}`);
const result = spawnSync(cmd, args, {
stdio: 'inherit',
env,
// Spawn as a detached process-group leader so the wall-clock cap can SIGKILL
// the entire tree — the runner, its per-file `node --test` workers, and any
// grandchildren or browsers they left open — not just the top process. A
// blocked spawnSync inside a test can't be reached by node's `--test-timeout`;
// this group kill is the guaranteed cleanup that lets the sweep always end.
function runProcess(cmd, args, { env, wallClockMs }) {
return new Promise((resolve) => {
console.log(`$ ${formatCommand(cmd, args)}`);
const child = spawn(cmd, args, { stdio: 'inherit', env, detached: true });
let timedOut = false;
// A detached child is its own group leader, so an interactive Ctrl-C on
// the runner no longer reaches it. Forward the interrupt to the group so
// the whole tree is torn down instead of orphaned.
const forward = (signal) => () => {
try { process.kill(-child.pid, signal); } catch { try { child.kill(signal); } catch { /* gone */ } }
};
const onInt = forward('SIGINT');
const onTerm = forward('SIGTERM');
process.on('SIGINT', onInt);
process.on('SIGTERM', onTerm);
const timer = wallClockMs
? setTimeout(() => {
timedOut = true;
console.error(
`\n[run-tests] wall-clock cap of ${wallClockMs}ms exceeded for "${formatCommand(cmd, args)}"; ` +
'killing the process group (SIGKILL).',
);
try { process.kill(-child.pid, 'SIGKILL'); }
catch { try { child.kill('SIGKILL'); } catch { /* already gone */ } }
}, wallClockMs)
: null;
const cleanup = () => {
if (timer) clearTimeout(timer);
process.off('SIGINT', onInt);
process.off('SIGTERM', onTerm);
};
child.on('error', (err) => {
cleanup();
console.error(err.message);
process.exit(1);
});
child.on('exit', (code, signal) => {
cleanup();
if (timedOut) process.exit(1);
if (signal) { console.error(`[run-tests] "${formatCommand(cmd, args)}" killed by signal ${signal}`); process.exit(1); }
if (code !== 0) process.exit(code || 1);
resolve();
});
});
if (result.error) {
console.error(result.error.message);
process.exit(1);
}
if (result.status !== 0) process.exit(result.status || 1);
}
function formatCommand(cmd, args) {
+14
View File
@@ -48,6 +48,13 @@ export const SUITES = {
},
{
runner: 'node',
// A finite per-test cap so an async hang is cancelled and reported
// rather than left running with `--test-timeout` unset (Infinity).
// Note: this timer lives in the event loop, so it cannot interrupt a
// test blocked in a synchronous spawnSync; the child bounds in
// tests/build-phase.test.mjs and the runner's wall-clock group-kill
// cover that case. The slowest core test is ~11s, so 180s is safe.
timeoutMs: 180000,
files: [
'tests/build-phase.test.mjs',
'tests/ci-test-plan.test.mjs',
@@ -255,6 +262,13 @@ export const SUITES = {
// path is graded, so the cap was selecting for the behavior the suite
// exists to forbid.
timeoutMs: 900000,
// Overall wall-clock safety cap for the whole sweep: if a provider
// call wedges past every inner guard (the harness's 840s per-turn
// AbortSignal and the 900s per-test timeout), the runner SIGKILLs the
// process group so the sweep still ends with a per-provider tally
// instead of hanging overnight. Sized well above a healthy two-provider
// sweep; override with IMPECCABLE_TEST_WALL_CLOCK_MS to scope it down.
wallClockMs: 3_600_000,
files: [
'tests/skill-behavior/scenarios.test.mjs',
'tests/skill-behavior/workflow-contract.test.mjs',
+21 -1
View File
@@ -33,8 +33,28 @@ function makeComp(w = 640, h = 400) {
return img;
}
// Every child here is spawned synchronously. spawnSync blocks the test
// worker's thread, so node's own `--test-timeout` (an event-loop timer) can
// never interrupt a child that wedges — under load a fork/exec can block on
// OS resources, and a gate's grandchild (comp-diff.mjs) or an accidental
// browser launch can stall. spawnSync's own `timeout`/`killSignal` is the one
// mechanism that can kill such a child, so bound every run: a wedge becomes a
// fast, named failure that the next test survives, never a suite-wide hang.
const RUN_TIMEOUT_MS = Number(process.env.IMPECCABLE_BUILD_PHASE_RUN_TIMEOUT_MS) || 120_000;
function run(script, args, cwd) {
return spawnSync(process.execPath, [script, ...args], { cwd, encoding: 'utf8' });
const res = spawnSync(process.execPath, [script, ...args], {
cwd,
encoding: 'utf8',
timeout: RUN_TIMEOUT_MS,
killSignal: 'SIGKILL',
});
if (res.error && (res.error.code === 'ETIMEDOUT' || res.signal === 'SIGKILL')) {
throw new Error(
`build-phase child timed out after ${RUN_TIMEOUT_MS}ms and was killed (SIGKILL): ` +
`node ${script} ${args.join(' ')}\nstdout so far:\n${res.stdout || ''}\nstderr so far:\n${res.stderr || ''}`,
);
}
return res;
}
describe('comp-spec', () => {
+26 -2
View File
@@ -347,13 +347,31 @@ export function makeTools(workspace, extraEnv = {}, simulatedUser = {}) {
* `priorMessages` lets multi-turn scenarios chain context from a previous
* call (append the SDK's response messages between turns).
*/
export async function runTurn({ workspace, model, userPrompt, priorMessages = [], maxSteps = 8, env = {}, simulatedUser = {} }) {
// A single turn (generateText) can drive up to ~30 tool-use steps against a
// frontier model; the thorough path was measured near 580s. generateText
// takes no timeout of its own, so a provider socket that stalls mid-stream
// keeps the fetch — and therefore the whole node process — alive indefinitely,
// past node's own `--test-timeout` (which cancels the test but not the open
// handle). We attach a real AbortSignal instead: on expiry the underlying
// fetch is aborted, the socket closes, the turn throws, and the scenario
// fails-and-continues so the sweep still produces a per-provider tally. The
// cap sits just under the 900s per-test timeout so a genuine slow-but-correct
// run is never killed. The timer is unref'd (it must not keep the loop alive
// after a healthy turn) and cleared on completion.
const TURN_TIMEOUT_MS = Number(process.env.IMPECCABLE_SKILL_BEHAVIOR_TURN_TIMEOUT_MS) || 840_000;
export async function runTurn({ workspace, model, userPrompt, priorMessages = [], maxSteps = 8, env = {}, simulatedUser = {}, timeoutMs = TURN_TIMEOUT_MS }) {
const { tools, trace } = makeTools(workspace, env, simulatedUser);
const messages = [
...priorMessages,
{ role: 'user', content: userPrompt },
];
let result;
const controller = new AbortController();
const timer = setTimeout(
() => controller.abort(new Error(`LLM turn exceeded ${timeoutMs}ms; aborting the provider call`)),
timeoutMs,
);
if (typeof timer.unref === 'function') timer.unref();
try {
result = await generateText({
model,
@@ -361,13 +379,19 @@ export async function runTurn({ workspace, model, userPrompt, priorMessages = []
messages,
tools,
stopWhen: [stepCountIs(maxSteps)],
// Real client-side deadline on the provider call: without it a stalled
// stream wedges the whole sweep with no tally.
abortSignal: controller.signal,
// Resolved from the model object so the 21 runTurn call sites stay
// unchanged. Reasoning models run at the provider default otherwise,
// which is not the tier this suite is meant to measure.
providerOptions: getProviderOptions(model?.modelId ?? ''),
});
} catch (err) {
throw new Error(`LLM behavior turn failed before completing: ${String(err)}`, { cause: err });
const reason = controller.signal.aborted ? ` (aborted after ${timeoutMs}ms client-side timeout)` : '';
throw new Error(`LLM behavior turn failed before completing${reason}: ${String(err)}`, { cause: err });
} finally {
clearTimeout(timer);
}
const generatedResponseMessages = result.responseMessages ?? result.response?.messages ?? [];
const responseMessages = [...messages, ...generatedResponseMessages];