Uh oh!
There was an error while loading. Please reload this page.
fix(test): remove the registration race behind the fleet.test.ts 5s timeout (#442) - #467
fix(test): remove the registration race behind the fleet.test.ts 5s timeout (#442)#467khaliqgant wants to merge 4 commits into
Conversation
…rship flaky (#442) `fleet.test.ts` › "keeps relay dispatch ownership until the remote PR is published and the issue is parked" fails as "Test timed out in 5000ms" on loaded runners, on `main` and on unrelated PRs. The 5s default was the messenger, not the cause. `CompletingRemoteFleetClient` is a `remote` placement, so dispatch calls `#awaitRemoteAgentRegistration` and polls until the spawned agent is roster-visible, up to a 30s wall-clock deadline. The fake emitted the implementer's exit from `spawn` on a bare `setTimeout(..., 0)`, and `FakeFleetClient.emitAgentExit` *removes* the agent from the roster before notifying listeners. So the timer and the registration probe raced over the same roster entry: - probe first -> registration observed, dispatch proceeds (test passed) - timer first -> agent gone, never observable, dispatch burns the full 30s deadline and exits 1 (test "timed out") The scheduler picked the winner, which is why an idle runner passed and a loaded one did not. Arm the exit in `spawn` but release it from an `isAgentRegistered` probe, which dispatch prefers over a roster read. The exit still arrives asynchronously on a timer -- the ordering this class exists to provide, rather than one the test body drives -- but now lands causally after registration instead of racing it. Measured in this worktree (load average ~145 on 8 cores): - before: 32237ms, then fails; at a 120s timeout it does not hang but fails `expect(code).toBe(0)` with 1 and a RemoteAgentRegistrationTimeoutError. - after: 1821ms, whole file 170/170 green at the unchanged 5s default. Note this means raising `testTimeout` would NOT have fixed the test: it only converts the timeout into a hard assertion failure, which is what issue #442 proposed. No production code changes; no assertion is weakened or removed. Refs #442 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Gv6gy7NUDmJs5SUcDvQNK2 Session-Id: 1612e900-d9b9-4c55-a8a2-63e3c781d255
Warning Review limit reachedNext included review available in 17 minutes. View limit detailsLimit details: You’ve used the included review currently available. You've used all free OSS reviews for now. Wait for the free limit to reset to keep reviewing this public repository. Review configuration: ⚙️ Run configurationConfiguration used: Organization UI Review profile: CHILL Plan: Team Run ID: 📒 Files selected for processing (1)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
Codex Review SummaryThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
@coderabbitai review Requested for exact head |
MITIGATION, not a fix -- recorded plainly because #442 asked for it to be. The preceding commit fixes the actual defect behind the named test: a registration race that burned a 30s wall-clock deadline. This commit addresses what remains, which the race fix does not explain -- #442's observation that each rerun fails a *different* test. Measured in this worktree on 8 cores at load average ~155, one run of src/cli/fleet.test.ts failed 10 distinct tests, every one of them between 4.3s and 10.4s. These CLI tests each drive a whole dispatch through real filesystem I/O; 2-10s apiece is what they genuinely cost. At Vitest's 5s default that is a coin toss on any busy runner, which is the harm #442 reports: `package` goes red on unrelated PRs and a real failure becomes indistinguishable from a flake. 20s is ~2x the slowest run observed under that load and 4x the default, and stays under REMOTE_AGENT_REGISTRATION_TIMEOUT_MS (30s) so a regression of the race fixed in the previous commit still fails fast rather than being absorbed by the larger budget. This buys headroom. It does not make any test cheaper, and it hides load sensitivity rather than removing it. The real cure is for these tests to stop doing seconds of real I/O each. Refs #442 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Gv6gy7NUDmJs5SUcDvQNK2 Session-Id: 1612e900-d9b9-4c55-a8a2-63e3c781d255
@coderabbitai review Requested for exact head |
There was a problem hiding this comment.
All reported issues were addressed across 1 file (changes from recent commits).
Reply with feedback, questions, or to request a fix.
Re-trigger cubic
Uh oh!
There was an error while loading. Please reload this page.
Uh oh!
There was an error while loading. Please reload this page.
… 30s (#442) Addresses both cubic P2s on the previous commit. Both were right. 1. The `testTimeout` was in the top-level `test` block, so it applied to all 117 files in the `include` list, not just `fleet.test.ts` -- weakening hung-test detection everywhere and contradicting this repo's convention, which is to configure no global `testTimeout` (documented in sweep-counters.test.ts) and use per-test budgets instead; there are 99 such per-test timeouts already. Moved to a file-scoped `vi.setConfig({ testTimeout })` and the global setting is gone. 2. 20s sat BELOW REMOTE_AGENT_REGISTRATION_TIMEOUT_MS (30s, factory.ts:459). I had chosen that so a regressed race would fail fast, but cubic's trade is the better one: a budget under 30s truncates the production deadline into a bare "Test timed out in 5000ms", which is precisely the failure mode that hid this bug for weeks. At 40s a regression instead reaches the deadline and fails as `expect(code).toBe(0)` with a RemoteAgentRegistrationTimeoutError on stderr -- the diagnostic failure rather than an opaque one. Still a mitigation, not a fix: it buys headroom and makes no test cheaper. Refs #442 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Gv6gy7NUDmJs5SUcDvQNK2 Session-Id: 1612e900-d9b9-4c55-a8a2-63e3c781d255
@coderabbitai review Requested for exact head |
) `CompletingRemoteFleetBase`'s comment said `CompletingRemoteFleetClient` "races completion against dispatch on a timer". That was an accurate description of the bug, and reads as though the race is the point -- an invitation to restore the bare `setTimeout(..., 0)` that #442 was. Comment-only. Refs #442 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Gv6gy7NUDmJs5SUcDvQNK2 Session-Id: 1612e900-d9b9-4c55-a8a2-63e3c781d255
@coderabbitai review Requested for exact head |
Fixes#442.
The 5s timeout was the messenger, not the cause
Running the test with a generous timeout instead of the 5s default is what exposed the real behaviour:
It does not hang. It runs ~32s and then fails an assertion, with this on the CLI's stderr:
This matters for the fix#442 proposed: raising
testTimeoutwould not have made this test pass. It only converts the timeout into a hard assertion failure. The 5s default was hiding a genuinely broken run, not creating one.Mechanism
CompletingRemoteFleetClientextendsCompletingRemoteFleetBase, which setsplacementLocality = 'remote'. For a remote placement,Factorywaits for the spawned agent to become roster-visible before owning it:factory.ts:11383→#awaitRemoteAgentRegistration(...)roster()every 500ms againstREMOTE_AGENT_REGISTRATION_TIMEOUT_MS = 30_000(factory.ts:459) — a real wall clock; no fake timers here. The 30s constant is exactly the ~32s observed.The fake emitted the implementer's exit straight out of
spawn:and
FakeFleetClient.emitAgentExit(src/testing/fakes.ts:418) deletes the agent from the roster before notifying listeners:Between
spawnreturning and the first registration poll there are real awaits (#dispatchLifecycleStillOwned, file I/O), so thesetTimeout(…, 0)macrotask and the registration probe raced the same roster entry:The scheduler picked the winner. That is why an idle runner passed, a loaded one failed, and it reproduced on bare
main.What changed
1.
dcb827f— the fix. Arm the exit inspawn, release it from anisAgentRegisteredprobe, which#awaitRemoteAgentRegistrationprefers over a roster read (factory.ts:11422). The exit still arrives asynchronously, without the test body saying when — the ordering this class exists to provide — but now lands causally after registration instead of racing it. Test-only; no production code touched, no assertion weakened, skipped or removed.2.
b578b6c— a MITIGATION, explicitly not a fix. File-scopedvi.setConfig({ testTimeout: 40_000 })infleet.test.ts. This covers a second, independent problem that the race fix does not explain: these CLI tests each drive a whole dispatch through real filesystem I/O and cost 2–10s apiece, so at the 5s default a loaded runner fails a rotating cast of them — #442's own "each rerun fails a different test" observation. Measured on 8 cores at load average ~155, one run failed 10 distinct tests, every one between 4.3s and 10.4s.It is scoped to this file, not global, because the repo deliberately configures no global
testTimeout(documented insweep-counters.test.ts) and uses per-test budgets — 99 of them. It is set above the 30s production deadline on purpose: a smaller budget would truncate a regressed race into a bare "Test timed out", which is the exact masking that hid this bug. It buys headroom and makes no test cheaper.3.
963e801— comment-only. The class comment described the race as intended behaviour, which invited its restoration.Evidence
Determinism — 20 sequential runs of the whole file, on 8 cores at load average 26–155:
The loop exit code is 2, not 0, and that is reported rather than smoothed over. Both failing iterations were different tests, each failing once, both as assertion failures, and neither uses the class this PR changes (
CompletingRemoteFleetClientis used by exactly one test — the named one):These are pre-existing ordering flakes of the #342 shape, not timeouts, and not introduced here. Raising the budget above 5s makes them surface as honest assertion failures instead of being masked as timeouts. They deserve their own issue rather than being absorbed into this one.
For the named test:
code===1at 120s)Mutation testing — the test is not vacuous. Two independent defects reintroduced into
factory.ts, both caught:#tryPublishImplementerPr→ earlyreturn {}) → RED; dispatch never sees a published PR.#finishDurableRelease→ always'issue-done') → RED in 3911ms:expected [ 'issue-done', 'issue-done' ] to deeply equal [ 'issue-human-review', … ]Both reverted; the diff touches only
src/cli/fleet.test.ts.Relationship to #342 / #353
expected 492 to be less than 250); no ordering fix addresses it.Residual
The 30s cliff is gone, which is what made this fail hard rather than slowly. What remains is that this file does seconds of real I/O per test and still harbours #342-shaped assertion races. The real cure is making these tests stop doing real I/O; the timeout only buys room.
🤖 Generated with Claude Code
https://claude.ai/code/session_01Gv6gy7NUDmJs5SUcDvQNK2