Repository navigation
fix(testing): treat a test-run timeout as not run, kill its process tree, make the limit configurable (#106) - #110
Conversation
A timed-out tool run was logged as a generic failure. ToolRun now carries status "timeout", timedOut: true and the timeoutMs that was exceeded, so every runner's provenance log tells a slow tool from a failing one. recordToolRun lets a runner that executes a command itself (to kill a whole process tree) land its run in the same log. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
A test run that hit the fixed 120 s limit raised an error, scored 0/20 for
execution (worse than --skip-tests), could score a previous run's coverage
file, and left npx/vitest/workers running because only /bin/sh was killed.
- Per-project status "timeout" ("timed out after N s") and a warning
test-run-timeout instead of the command-failed error; execution gets the
same 10/20 as --skip-tests; no coverage is read for a timed-out root, nor
the repo-level fallback. Check-level status derivation is unchanged.
- The limit is configurable: --test-timeout <ms> or .vcqa.json
checks.testing.settings.timeoutMs (flag wins; default 120000). The
effective value and its source are recorded in the check details.
- Test runs go through a small supervisor that starts the command in its
own process group and, on timeout, kills the whole group and waits for
it to be gone before returning.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
VibeCode QAPR #110 ( No workflow found. Add this to enable automatic PR scanning: name: VibeCode QA
on:
pull_request:
workflow_dispatch:
permissions:
contents: read
pull-requests: write
security-events: write
jobs:
scan:
runs-on: ubuntu-latest
steps:
- uses: actions/checkout@v4
- uses: vibecodeqa/action@v1
with:
fail-under: "70" |
serge-ivo
left a comment
There was a problem hiding this comment.
Adversarial review, round 1 (COMMENT only)
What I ran. I checked out head 6fbb074 in a throwaway worktree: build clean, lint 0 errors (62 warnings), 746/746 tests pass. I wrote repro scripts against the built dist/runners/exec-tree.js and compared them with main's dist/runners/exec.js. All on macOS.
The timeout classification, the test-run-timeout warning, skipping the stale coverage file, and the config/flag precedence all behave as described. The fixture test would fail on main for the right reason: main ignores settings.timeoutMs, so the run hangs past the test's own limit.
Findings
-
major, CONFIRMED:
src/runners/exec-tree.ts:29. Ctrl-C now orphans the test run; on main it does not. The command runsdetached, in its own process group, so the terminal's SIGINT no longer reaches it. The supervisor installs no signal handlers, so it dies on that SIGINT without signalling the group.
Repro: runrunWithTreeKill("echo $$ > pid; exec sleep 300", dir, 60000)from a Node script, thenkill -INT -<pgid of that script>.- PR:
sleep 300is still alive afterwards, reparented to PID 1 (PID 36423 PGID 36423 PPID 1). - main (
run()/execSync): the same repro leaves nothing running.
The same path applies when anything kills the CLI from outside. One example is the desktop monitor's 120 sexecFiletimeout on the whole CLI (src/monitor.tsx:175); I have not reproduced it there. This is the orphan class that #106 exists to remove.
Fix: in the supervisor, trapSIGINT/SIGTERM/SIGHUPand runsignalTree("SIGTERM")then SIGKILL before exiting. Also handle the parent dying outright: give the supervisor a stdin pipe from the parent, and kill the group on itsend/close.
- PR:
-
minor, CONFIRMED:
src/runners/testing.ts:79andsrc/cli.ts:68. A timeout above 2147483647 ms times out instantly.isValidTimeoutaccepts any positive integer. Node clamps an oversizedsetTimeoutto 1 ms (TimeoutOverflowWarning).
Repro:resolveTestTimeout({settings:{timeoutMs:3e9}})gives{ms:3000000000, source:'config'}.runWithTreeKill("sleep 1; echo done", cwd, 3e9)then returnstimedOut: trueafter 52 ms. Someone who writes a huge value to mean "no limit" gets every project marked timed out.
Fix: reject or clamp values above2**31-1, in both the flag and the setting. -
minor, CONFIRMED:
src/runners/exec-tree.ts:29and:83. A process outside the group that holds the inherited stdout turns a finished run into a "timeout" afterlimit + 30 s. stdout and stderr are inherited straight fromspawnSync's pipes. A test setup that spawns adetachedhelper (its own process group, so the group kill misses it) keeps the pipe open after the command exits, andspawnSyncwaits for the 30 s backstop.
Repro: a command that spawnssleep 45detached with inherited stdio, prints a report and exits.- PR:
{ ok: false, timedOut: true }after 33002 ms, with a 3000 ms limit. - main
run(): returns after 3002 ms.
The command itself finished in milliseconds and its stdout was complete, yet the project is reported as timed out.
Fix: pipe the child's stdio through the supervisor and close it when the child exits, and treat the supervisor's exit status as authoritative over the backstop'sETIMEDOUT.
- PR:
-
minor, CONFIRMED from code:
src/runners/testing.ts:1250. A timeout hides a command failure in another project.executionPointsreturns 10 wheneverexecutionis null and any project timed out. Take a monorepo where project A iscommand-failedand project B timed out: main scores execution 0, this PR scores 10.
Relatedly, when some projects do report, a timed-out project is dropped from the pass rate. A slow project with failing tests therefore stops counting against the score. That goes beyond the issue's rule ("execution scored as for--skip-tests").
Fix: give 10 only when every non-skipped project timed out. Otherwise keep the old rule. -
minor, CONFIRMED from code:
src/monitor.tsx:175. The monitor kills the whole CLI scan after 120 s, so achecks.testing.settings.timeoutMsabove 120000 can never take effect there. The scan is killed first, and with finding 1 the test group is orphaned.
Fix: derive the monitor timeout from the effective test timeout, or drop it when tests run. -
nit, PLAUSIBLE: output over 64 MB orphans the group.
spawnSynchitsmaxBuffer, getsENOBUFS, and SIGKILLs the supervisor. The group survives because the supervisor never runs its cleanup. Finding 1's fix (killing the group when the parent pipe closes) covers this too. -
nit, PLAUSIBLE: a full 10 s wait on every timeout in containers whose PID 1 does not reap. There, orphaned group members stay as zombies,
kill(-pgid, 0)keeps succeeding, and the supervisor waits out its 10 s ceiling. -
nit, CONFIRMED: docs and merge order.
README.md:256and theCLAUDE.mdflags list do not mention--test-timeout.- This PR conflicts with #109 in the
src/cli.tshelp block.
Verdict: fix finding 1 before merge. The PR's guarantee is that no process outlives the run, and Ctrl-C now breaks it where main did not.
run() and recordToolRun() each assembled ToolRun entries on their own: tool name, command, cwd, context, capped output, the not-found guess. Both now go through a single toolRunEntry() builder, with run() recording via recordToolRun(), so a run executed outside run() lands in the log in exactly the same shape. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
Running the test command in its own process group took it out of the terminal's reach: Ctrl-C killed the CLI and the supervisor, and left the test run alive under PID 1. The supervisor now tears the group down (SIGTERM, then SIGKILL, waiting until it is empty) on every abnormal end: - SIGINT, SIGTERM or SIGHUP to the supervisor, so Ctrl-C works again; - the parent dying, seen as EOF on a pipe only the parent holds open; - the parent giving up on its output (maxBuffer) or hitting the backstop: spawnSync now sends SIGTERM rather than SIGKILL, so the handler runs, and the relay also stops on a broken pipe. The command's stdout/stderr are now relayed by the supervisor instead of inherited. A process outside the group that keeps the pipe open (a detached helper) no longer holds a finished run open until the backstop and turns it into a "timeout": the supervisor stops relaying shortly after the command exits, and reports the exit code on fd 3, which wins over the backstop's ETIMEDOUT. A limit above 2^31-1 ms, which setTimeout would fire after 1 ms, is clamped to that maximum. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
Node fires a setTimeout above 2^31-1 ms after 1 ms, so a huge --test-timeout or checks.testing.settings.timeoutMs (someone meaning "no limit") marked every project as timed out at once. Both now accept a whole number of ms from 1 to 2147483647 (~24.8 days): the flag exits 2 with that range, and the setting falls back to the default with the existing invalid-setting info issue. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
…106) Execution got 10/20 whenever no project reported results and any project had timed out, so a monorepo with one timed-out project and one whose test command failed scored 10 where it used to score 0. The 10 points now need every non-skipped project to have timed out; otherwise the previous rule stands (pass rate over the projects that reported, else 0), and the failed command keeps its error. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
The monitor killed its scan subprocess after a fixed 120 s, so a checks.testing.settings.timeoutMs above that could never take effect there: the whole scan died first. When tests run, the limit is now 120 s plus the effective test timeout for each test project (capped at 2^31-1 ms); with --skip-tests it stays 120 s. Killing the scan no longer orphans a test run either, since the supervisor sees its parent go. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
|
Round-1 review addressed in six new commits; no force-push. Head is now 40b1884.
Left:
Verified at 40b1884: |
VibeCode QAPR #110 ( No workflow found. Add this to enable automatic PR scanning: name: VibeCode QA
on:
pull_request:
workflow_dispatch:
permissions:
contents: read
pull-requests: write
security-events: write
jobs:
scan:
runs-on: ubuntu-latest
steps:
- uses: actions/checkout@v4
- uses: vibecodeqa/action@v1
with:
fail-under: "70" |
serge-ivo
left a comment
There was a problem hiding this comment.
Adversarial review, round 2 (final, COMMENT only)
What I ran, at head 40b1884. I used a fresh worktree. Build is clean and lint shows 0 errors (62 warnings). pnpm test passes 66 files, 763/763, when run on its own. A merge of #110 with #111 builds and passes 780/780. I re-ran every round-1 repro against dist/ on macOS, then ran a signal matrix on Linux in Docker (node:22-bookworm, with and without --init). I also scanned a copy of a real project (@vibecodeqa/schema, with @vitest/coverage-v8 added so vitest runs and passes) with both main and this head, then diffed the normalized report.json.
Round-1 findings
| # | Status | Evidence |
|---|---|---|
| 1 major: Ctrl-C orphans the run | FIXED | runWithTreeKill("echo $$ > pid; exec sleep 300", …, 60000). I signalled either the parent's process group or the parent alone, with SIGINT, SIGTERM, SIGHUP and SIGKILL. Every case, on macOS and on Linux, left no sleep and no supervisor. |
| 2 timeout above 2^31-1 | FIXED | resolveTestTimeout({settings:{timeoutMs:3e9}}) returns {ms:120000, source:'default', invalidSetting:3e9}. runWithTreeKill("sleep 1; echo done", cwd, 3e9) returns ok after 1048 ms. --test-timeout 3000000000, 0 and abc all exit 2 with the range message. |
| 3 detached helper holding stdout | FIXED | The round-1 repro returns ok in 287 ms (main: 3004 ms). A setsid sleep 20 & helper returns in 16 ms. Only fds 0-2 reach the command (/proc/$$/fd on Linux, lsof on macOS), so the fd 3/4 pipes cannot hold the parent either. |
| 4 timeout credit hiding a failed project | FIXED | testExecutionPoints plus the two-project scan test. The test passes and asserts ["command-failed","timeout"]. A timed-out project is still left out of the pass rate when other projects report; the docs now say so. |
| 5 monitor's fixed 120 s | FIXED (code read; the wiring has no test) | — |
| 6 output over 64 MB | FIXED | The test passes. A 20 MB stdout relays intact (END marker present, same length as main). |
| 7 10 s wait when PID 1 does not reap | NOT FIXED (acknowledged) | CONFIRMED on Linux: with node as PID 1, a timed-out (sleep 30 &); (sleep 30 &); sleep 30 at a 1000 ms limit returns after 11047 ms. Under --init it returns after 1041 ms. Optional fix: once SIGKILL has gone to the group, stop polling after a short grace instead of waiting for zombies to be reaped. |
| 8 docs and merge order | FIXED (docs) / still open (merge) | git merge-tree pr109 pr110 now conflicts in README.md as well as src/cli.ts. |
Shared record helper. For non-test runners every ToolRun field comes out as on main. The diff of the normalized schema report, main against this head, contains only:
- the new
testTimeoutMs/testTimeoutSourcedetails; - timing-dependent order of the
slowesttests; - biome's internal
durationvalue.
All 39 check scores are identical (overall 87). On the failing path (exit 3, command not found) status, exitCode and notFound match main.
New findings
-
minor, CONFIRMED:
src/runners/exec-tree.ts:90. Ctrl-\ (SIGQUIT) still orphans the run; main does not. The trap list covers SIGINT, SIGTERM and SIGHUP. SIGQUIT's default action kills the supervisor before it can signal the group, and the fd-4 watch dies with it.
Repro: the same harness, withkill -QUIT -<pgid>.- PR:
sleepsurvives (PID 4250 PGID 4250 PPID 1). - main (
run()): nothing survives.
Fix: add
["SIGQUIT", 131]to the list. - PR:
-
nit, CONFIRMED:
src/runners/exec-tree.ts:112. A command killed by a signal is recorded as exit code 128, whatever the signal.code ?? (signal ? 128 : 1)maps SIGKILL, SIGTERM and SIGSEGV all to 128. On mainexitCodewasnullin that case.kill -9 $$givesexitCode 128; main givesnull.kill -TERM $$givesexitCode 128and empty output; main givesnullandError: Command failed: ….
An OOM-killed vitest (137) cannot be told apart from a crash.
Fix:128 + (os.constants.signals[signal] ?? 0), or recordnullas main did. -
nit, PLAUSIBLE: two new tests depend on timing. I ran the four suites (main, #109, #110, #111) at once on one machine. Two #110 tests failed there and passed on a serial re-run:
test-timeout.test.ts:93(a 2000 ms limit):pids.jsonwas never written before the limit hit.:210(1500 ms): the project meant to fail by command timed out instead, giving['timeout','timeout'].
The same heavy load also made main's
--json produces valid JSONtest time out, so this is weak evidence. A 2-vCPU CI runner still sits closer to that load than a dev laptop does.
Fix: give the project that must finish a generous limit, separate from the one that must time out.
Verdict: READY TO MERGE. The round-1 blocker is fixed and holds on both macOS and Linux. Finding 1 is a one-line change worth adding before merge. Findings 2 and 3 can follow. Resolve the #109 conflict (src/cli.ts help block and README.md flags table) without dropping either side's rows.
Ctrl-\ killed the supervisor by default action before it could signal the test group, leaving the run orphaned. SIGQUIT is now trapped like SIGINT, SIGTERM and SIGHUP (exit 131). A command killed by a signal was recorded as a flat 128; it is now 128 + the signal number (137 for SIGKILL, 143 for SIGTERM), so an OOM kill is distinguishable from a crash. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
The single-project timeout test used a 2 s limit and the two-project one 1.5 s; on a loaded machine the fake runner could miss writing its pid file, or the failing project could time out instead of failing. Both use 5 s; the 30 s sleepers still time out. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
|
Round-2 findings addressed in two new commits; no force-push. Head is now 128a770.
The #109 conflict is left to be resolved by merging Verified at 128a770: |
VibeCode QAPR #110 ( No workflow found. Add this to enable automatic PR scanning: name: VibeCode QA
on:
pull_request:
workflow_dispatch:
permissions:
contents: read
pull-requests: write
security-events: write
jobs:
scan:
runs-on: ubuntu-latest
steps:
- uses: actions/checkout@v4
- uses: vibecodeqa/action@v1
with:
fail-under: "70" |
# Conflicts: # README.md # src/cli.ts # src/core.ts # src/runners/exec.ts # src/runners/testing.ts
toolRunEntry passed a trimmed, capped copy of the output to record(), which now does its own processing and capping. Command and output are handed over whole, so runs recorded by runWithTreeKill are stored exactly like runs recorded by run(). Tests cover a successful run, a timed-out run, and output where a recognised value straddles the 8000-character cap. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88
VibeCode QAPR #110 ( No workflow found. Add this to enable automatic PR scanning: name: VibeCode QA
on:
pull_request:
workflow_dispatch:
permissions:
contents: read
pull-requests: write
security-events: write
jobs:
scan:
runs-on: ubuntu-latest
steps:
- uses: actions/checkout@v4
- uses: vibecodeqa/action@v1
with:
fail-under: "70" |
|
Merged main (782f54a) in and recorded tool runs through the shared recorder. Head is now adacab2. Both are new commits; no rebase or force-push.
Verified at adacab2: |
Closes #106.
Commits
62701d7fix(exec): record a run that hits its time limit as a timeout.ToolRun.statuscan now be"timeout", withtimedOutandtimeoutMsalongside it.run()the only change is in the catch block, which now records the timeout.recordToolRun()lets a runner that executes a command itself write to the same tool-run log.6fbb074fix(testing): treat a test-run timeout as not run, not failed.runWithTreeKill()(newsrc/runners/exec-tree.ts). The test command runs under a small Node supervisor in its own process group. On timeout the supervisor sends the group SIGTERM, then SIGKILL after 2 s, and waits until the group is gone. On a normal exit, leftover child processes are killed too. Windows usestaskkill /T /F(untested).timeout("timed out after N s") and atest-run-timeoutwarning, not an error.--skip-testswhen no project produced results. If other projects did, it is scored on their pass rate alone.--test-timeout <ms>overrideschecks.testing.settings.timeoutMs, which overrides the default of 120000. The programmatic equivalent isscan(cwd, { testTimeoutMs }).invalid-test-timeout-settinginfo issue.detailsastestTimeoutMs/testTimeoutSource.checks.<name>.settingsis added here as a plain object, with agetCheckSettings()helper.runTestingwas already over the complexity limit, and this change would have raised it. Two helpers were extracted, which brings it from 71 down to 58.Verification
pnpm build: clean.pnpm lint: 0 errors (62 warnings, same as the baseline on main).pnpm test: 65 files, 746/746 passing (main baseline 739, plus 7 new).src/runners/test-timeout.test.tsuses a fakevitestin localnode_modules, sonpxdownloads nothing. It sleeps past a 2 s limit and starts asleepgrandchild.timedOut: trueon the run record; project statustimeout; a warning and no error; execution scored the same as--skip-tests; a stale coverage file on disk is not read.scan()returns. A deliberately broken supervisor, which killed only its direct child, failed this assertion.--test-timeout 15000the same fixture passes, overriding a config limit of 2000.exec.test.ts: a real timeout is recorded astimeout; an ordinary failure is not.Not in this PR
--test-timeoutandsettings.timeoutMs. It will be linked on the issue.CLAUDE.mdflags list does not mention--test-timeoutyet.🤖 Generated with Claude Code
https://claude.ai/code/session_01SmtSK7qDTyXhimJ9grap88