Skip to content

Forget a CLI probe killed by its own deadline - #71

Merged
khalilgharbaoui merged 2 commits into
masterfrom
btw-flake
Oct 1, 2026
Merged

khalilgharbaoui merged 2 commits into
masterfrom
btw-flake

Conversation

@khalilgharbaoui

Copy link
Copy Markdown
Owner

Root cause

test-side-question.ts "provider /btw uses native control response between normal turns on the same CLI process" is not flaky because of anything in /btw. It loses a race against detectCliVersion's own five-second execFile deadline, and the damage sticks because the answer is cached.

Timeline inside a failing run:

  1. Turn 1's prologue awaits detectCliVersion(cliPath). On a loaded machine that claude --version spawn overruns 5,000 ms, execFile kills it, the probe returns null and caches it per cliPath for the life of the process.
  2. Turn 1 still passes: an unknown version only drops optional flags.
  3. The /btw turn reads cliSupportsSideQuestion(null) === false, requestSideQuestion throws "/btw requires Claude Code CLI 2.1.258 or newer", the stream carries an error part and no text-delta, and answer is "".

Evidence

Deterministic, by making the fixture CLI burn 5.5 s on --version:

DEBUG turn done "Start the main conversation." elapsedMs 5129 parts stream-start,text-start,text-delta,text-end,finish
DEBUG error part: Error: /btw requires Claude Code CLI 2.1.258 or newer (the oldest verified version).
DEBUG turn done "/btw What changed?" elapsedMs 2 parts stream-start,error
AssertionError: actual: '', expected: 'Native aside after turn 1'
duration_ms 5533

against the reported 5723 ms and the same assertion.

Natural, which is what makes it a product bug and not a slow fixture: 40 concurrent copies of the file at a load average of 66 to 76 failed 6 of 40, and the plugin log carried exactly 6 failed to detect claude cli version lines, one per failing run. The slowest surviving turn took 5,874 ms.

The other two reports are the same class

Same trick, same shape, both confirmed:

spec injected result
test-skill-bridge.ts "a skill Claude already loads is not bridged..." 5.5 s on --help resolveSkillPluginDirs returns [], dies on dirs[0]! with ERR_INVALID_ARG_TYPE after 5,484 ms
test-startup-diagnostics.ts "detectOpencodeVersion reads the version from the opencode binary" sleep 6 before echo 1.18.5 reports undefined after 5,295 ms

One class: a fixed five-second child-process probe whose timeout degrades silently into a wrong value a spec asserts against.

The fix, and why at that layer

Product (src/cli-version.ts), because the caching really is a bug. detectCliVersion and detectCliSupportsFlag cached their null / false forever. Every version gate reads that one answer, so a single busy five seconds during a first turn silently and permanently withheld --thinking-display summarized, fast mode, --restricted (the read-only preset's first layer), --permission-prompts, /btw and the skill bridge's --plugin-dir from the whole opencode session, with one WARN in a log that is off by default as the only sign.

Now a probe our own deadline killed is not cached: killedByDeadline(err) is killed === true with a string signal and no string code (execFile sets killed only when this process killed the child; a maxBuffer overflow carries ERR_CHILD_PROCESS_STDIO_MAXBUFFER, a plain refusal carries a numeric exit code), and forgetDeadlineKill deletes the entry once the probe settles, only while the entry is still the one it created. Every other failure (missing binary, non-zero exit, unparseable output) describes the binary, repeats, and stays cached, so a broken binary is still one spawn per cliPath.

The deadline itself is kept. It bounds how long a wedged claude may hold opencode's first turn; raising it makes that case worse and still loses on a busy enough machine. Losing a probe now costs one extra spawn on a later turn.

Tests, because the deadline is the product's contract. The specs no longer race it:

  • test-side-question.ts and test-btw-command.ts resolve the fake CLI's version up front via warmCliVersion(), which asks again when a probe was killed, and assert it. /btw is gated on that answer, so a spec must not discover it mid-turn.
  • test-skill-bridge.ts resolves --plugin-dir support inside fakeCli for any fixture meant to advertise it; every later call reads the cache.
  • test-startup-diagnostics.ts resets and re-probes until the script answers.
  • The per-turn AbortSignal.timeout(5_000) in both /btw fixtures became TURN_HANG_STOP_MS = 30_000, named and commented as a hang-stop rather than a deadline. A real spawn reached 5,874 ms under load, so the old budget was itself the flake it was meant to catch; the node test timeouts (60 s) are the real backstop.
  • test-cli-probe-cache.ts (new) covers the rule. It was rewritten once for the same sin: its first version asserted spawn counts and, at load 112, the trivial exit 3 fixture was itself deadline-killed in 20 of 20 runs. It now asks again until the fixture answered for itself and reads "was this cached" off promise identity, which no load can change.

Files changed

  • src/cli-version.ts : killedByDeadline, forgetDeadlineKill, PROBE_TIMEOUT_MS, both probes evict a deadline kill and log deadlineKill.
  • test-cli-probe-cache.ts : new, 2 tests.
  • test-side-question.ts, test-btw-command.ts : warmCliVersion(), TURN_HANG_STOP_MS, test timeouts to 60 s.
  • test-skill-bridge.ts : fakeCli is async and resolves the flag probe.
  • test-startup-diagnostics.ts : reset-and-retry around detectOpencodeVersion.
  • package.json : new file appended at the end of the test list.
  • AGENTS.md, docs/agents-history.md : the rule and its evidence, (h #g181).

Checks

Load generation for every "under load" run below: 72 yes > /dev/null processes on 18 cores, killed afterwards.

Reproduction, before and after

run load avg result
master, 40 concurrent copies of the /btw spec 66 to 76 6 of 40 failed, 6 failed to detect claude cli version
master, full suite 55 986 of 986 passed (the flake did not fire that round)
fixed, 40 concurrent copies of the /btw spec 103 40 of 40 passed, 4 probes genuinely killed and absorbed
fixed, 20 concurrent runs of all 5 touched files (89 tests each) 116 20 of 20 passed, 206 probes killed and absorbed
fixed, full suite 100 988 of 988 passed, 2 probes killed and absorbed

Gate, on a quiet machine (npm run typecheck && npm test > /tmp/lane-btw.log 2>&1; echo EXIT=$?)

TYPECHECK_EXIT=0
ℹ tests 988
ℹ suites 0
ℹ pass 988
ℹ fail 0
ℹ cancelled 0
ℹ skipped 0
ℹ todo 0
ℹ duration_ms 25975.020292
EXIT=0

Not verified / deliberately left

  • An abort that arrives during doStream's prologue is dropped, and this PR does not fix it. detectCliVersion is awaited before the ReadableStream is built, and the abort listener is registered inside start; addEventListener("abort", ...) on an already-aborted signal never fires. That is why turn 1 above passed at 5,874 ms against a 5,000 ms signal. For /btw it is harmless, but for a normal turn an operator's stop during a slow prologue does not stop the CLI's turn. Fixing it changes abort semantics across the whole turn path and belongs in its own change. Recorded in (h #g181).
  • The two test-skill-bridge.ts failures and the test-startup-diagnostics.ts one were reproduced by injection, not observed naturally on this machine; I did not have their original failure output, only the names and the ~5 s timing.
  • detectOpencodeVersion keeps caching its own timeout. It is read once per process for a diagnostic line, so there is no second caller to benefit from eviction; only its spec changed.
  • No release, no tag, no publish. npm run build was not run (nothing here touches the build).

A 5s execFile deadline on 'claude --version' and '--help' cached its own
timeout, so one busy turn permanently withheld every version-gated flag,
the skill bridge and /btw from the opencode process. That is what made
test-side-question's native /btw spec flaky under load. Keep the
deadline, drop only the answer that described the machine, and make the
specs resolve their probes up front instead of racing them.
@khalilgharbaoui
khalilgharbaoui merged commit 1f2de0b into master Oct 1, 2026
@khalilgharbaoui
khalilgharbaoui deleted the btw-flake branch October 1, 2026 08:42
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant