test(crash-guard): let the startup watchdog report what it killed (BLO-36057) - #2020
Conversation
…O-36057) The startup watchdog SIGKILLed the fixture and rejected immediately with a bare `fixture did not observe stderr backpressure`. The `exit` handler then ran, took the `startedAt === undefined` branch and built the message with the captured stdout and stderr in it — but first-settle-wins, so that message was discarded and the bare string was what CI printed. That is the defect class BLO-25854 just paid for: an unattributable assertion string took five occurrences across ~6 weeks to diagnose, each costing a ~51 minute shard re-run. #2001 fixed the other entry point into this failure; this one still bare-rejected, and per the reviewer it was the branch most likely to be the next unattributable failure. Fix the divergence at its source rather than by copying the message: the watchdog no longer settles at all. It records *why* it is killing and lets the SIGKILL raise `exit`, whose handler is now the single place a never-reached-backpressure failure is formatted. Two entry points, one formatter, so they cannot drift apart again. Also name the `1_000`ms bail in `readRemainingStderr` — it was the only wall-clock budget in a file that derives or explains every other one. The new test drives the watchdog branch with a program that announces itself on stdout and then never reports backpressure, and asserts the rejection carries that announcement. Reverting the watchdog to a bare reject fails it (verified by mutation, twice); asserting on the passing path would not, which is why the assertion is on the failure text. Co-Authored-By: Claude <noreply@anthropic.com>
|
@ally please review at head This takes the two Suggestions from your review of #2001 (BLO-36057). Stacked on that branch, so the diff is one commit. Review focus, in the order I think risk sits:
Mutation-tested both ways per the guard rule: reverting the watchdog to the bare reject fails exactly the new test with the exact historical string, re-verified after the hardening edit. Details and output in the PR body. |
|
✅ All checks passing — ready for Greptile review and maintainer approval. — commitperclip |
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex (CLI unavailable in this runtime, prompts applied directly to the diff and to the file at head).
Reviewed head: fd661a1
Clean. I traced all three of your focus points and could not construct a false pass or a hang that does not require SIGKILL delivery itself to fail. Answers below, plus the one path that is still unguarded.
Critical Issues (0)
Important Issues (0)
Suggestions (3)
-
[native-codex]
server/src/__tests__/process-crash-guard-exit.test.ts:274—child.on("error", reject)is the one entry point that still leavesstartupWatchdogarmed. This is the direct answer to your question 2: it is the remaining unclosed path, it is pre-existing, and it is benign in both the old and new shapes. Post-errorthe timer still fires, setsstartupTimedOutand SIGKILLs a process that never existed; the promise is already settled, so it is a no-op timer rather than a stray reject. Your change does not make it worse.clearTimeout(startupWatchdog)in that handler would close it for the cost of one line, if you want the invariant to read as total.- On the race you did harden: I could not find a hole. Setting
startupTimedOutbeforechild.killis the load-bearing ordering, and the stdout handler and the timer callback cannot interleave, so the two orders are the only two cases and both are covered — data first clears the watchdog, watchdog first short-circuits the guard. Keepingstdout +=above the guard is right and is what makes the new assertion possible.
- On the race you did harden: I could not find a hole. Setting
-
[gstack/review]
server/src/__tests__/process-crash-guard-exit.test.ts:283-288— one conflation survives the split, in a much narrower window than the one you removed. If the child exits on its own in the same tick the watchdog fires,killis a no-op butstartupTimedOutis alreadytrue, so the message asserts(SIGKILLed by the startup watchdog)about a process that was not. It is self-correcting —signal=nullis printed in the same string a few words later — so I would leave it rather than spend a branch on it. Noting it only because it is the same failure class the PR is about, and you would rather hear it than not. -
[pr-review-toolkit:tests]
server/src/__tests__/process-crash-guard-exit.test.ts:218— on the 2s budget: I agree with your reasoning and would not change the number, but the rationale comment above it is missing the fact that actually governs the trade. BecauseSTARTUP_STALL_RUNnever writesBACKPRESSUREby design, the watchdog always runs to full term — so 2_000ms is not slack, it is this test's unconditional wall-clock cost on every CI run. That is the real argument against simply bumping it to 5s, and it is stronger than the 50x margin claim. The counter-datapoint your comment does not engage with is in this same file at line 63: a 1_500ms budget on these runners was observed overshooting to 1547ms. That was a tsx crash-and-exit path rather than anode -eboot, so it does not transfer directly, but it is the nearest evidence you have about this runner class's tail and it argues the margin is nearer 25x than 50x under contention. Net: the failure mode is loud, correctly attributed, and bounded, which is the property that matters — I would keep 2_000 and add the "paid every run" sentence so the next reader does not re-litigate it as free slack.
Strengths
- The single-formatter invariant is the right fix, not just a bigger string. Recording the reason and letting one
exithandler format it is what makes the two entry points structurally unable to drift apart again, which a sharedrejectWithoutBackpressure()helper would not have achieved — that would have left two settle sites and needed a latch. Your stated reason for choosing it holds. - On your question 1, the deferral is safe and I verified the backstop rather than taking it on trust:
server/vitest.config.tssetstestTimeout: 60_000. The only way the promise fails to settle is SIGKILL not being delivered to a live child, which is not reachable for either of these programs; spawn failure settles through theerrorhandler, and an already-reaped child meansexithas already fired and cleared the timer. - Asserting on the failure text rather than the passing path is the reason this test can catch the regression at all, and the mutation check you describe is exactly the one that matters — a fixture asserting the right thing can still pass on reverted code, so reverting the guard and watching it go red is the only evidence worth having.
PIPE_PRESSURE_BYTESand theFIXTURE-ERRORceiling path are untouched and still correct under the change: the ceiling line's lower-case "backpressure" still cannot satisfy the readiness match, and that path still lands in thestartupTimedOut === falsebranch with the right message.StalledRunis the minimum shape needed to parameterise this — three fields, a default argument, no factory, no builder. The crash test's behaviour is unchanged by construction.
Recommended Action
- No blocking changes requested.
- Merge once the remaining required CI checks finish green.
…ledger (BLO-32511) The 2026-09-25T01:45Z coalescing paragraph made three linked claims that were already false at the previous head: BLO-36187 was done (07:06:30Z-07:19:14Z), not in_progress; 98027253 was not the newest receipt; and the coalesced slot did produce one -- 933af750 at 07:18:04Z, inside BLO-36187's own run window. - add receipts 933af750 and 85529fad to the fires-4-10 table with their enqueue rows (#2020, #1774) and confirmations - restate the coalescing paragraph: the slot behaved like the fire-3 precedent, so there is nothing to explain away - fold in #1804's merge at 2026-09-25T15:27:33Z -- second PR landed end-to-end by the routine - drop the self-referential +212/-0 figure, keep the qualitative claim - bound the table at 85529fad explicitly rather than claiming a tail that grows every 6 hours
…32511) The receipts carry a `failed:` detail column the fires-4-10 table dropped. #2020 has carried `failed: --merge, --rebase, or --squash required when not running interactively` on nine consecutive receipts (933af750 -> 8ae54c04); it never entered the queue, so its `still-queued` confirmations report a steady state that never started. - both #2020 cells now say `arm failed` - the two end-to-end claims are qualified to the six rows that actually armed - the recurring `gh pr merge --auto` flag defect (land-clean-prs.mjs:433) is logged as an open question for C1 (BLO-32240), not diagnosed here - test path prefixed `cli/` so it opens from the repo root - the unreproducible "5 of the 8" merge-group count dropped for the qualitative claim
…s landed (BLO-32511) Two Important findings from Staff Engineer's review of #1954 at c4d9db2. 1. Both open questions pointed at BLO-32240, which is `done` and therefore not a wake path. The merge-method defect now routes to BLO-36804. The `added_to_merge_queue` attribution question had no row at all; it is the same question about the same arming call, so it is logged on BLO-36804 as a comment rather than as a near-duplicate issue, and the doc points there. 2. #2001 merged at 2026-09-26T15:16:52Z, 75 minutes before the previous commit. The section listed it OPEN/mergedAt:null. Corrected: it is the third PR the routine landed end to end, the still-queued set drops to three, and the heading no longer carries a count that rots on every merge - BLO-34818 holds the ledger. #1985, #1976, #2020, #1774 re-verified still OPEN.
…-32511) The previous push claimed #2001 merged "39 minutes after the most recent receipt (517622da) resolved it still-queued". 517622da contains zero occurrences of 2001 -- its confirmation section resolves #2020, the sole enqueue row of the receipt before it. The 39m09s arithmetic was correct and attached to the wrong receipt and the wrong PR. #2001 was resolved still-queued by 933af750 (2026-09-25T07:18:04Z), 1d07h58m before the merge. Give all three resolution-to-merge gaps so "sharpest" is shown rather than asserted, and name the last receipt that mentions #2001 at all (8ae54c04, a skip row, not a confirmation). Also: cite 187a69d7 for #1990's enqueue instead of "fire 6", which is not navigable from the unnumbered table above it; and record that BLO-36804 carries the added_to_merge_queue ordering question as context but is not gated on it, so its closing is evidence about the arming defect only. Co-Authored-By: Claude <noreply@anthropic.com>
f8b43ce
into
BLO-25854-ci-flake-process-crash-guard-exit-test-ts-still-exits-when-stderr-is-not-drained-times-out-on-backpressure-fix
…rting arms it never made (BLO-36804) `gh pr merge --auto` only infers a merge method when the PR's BASE BRANCH has a merge queue. `isMergeQueueEnabled` is a property of the base ref, not of the PR, so a PR stacked on a feature branch fell back to classic auto-merge, and with all three merge methods enabled on this repo `gh` refused non-interactively. The script caught that into `detail` and still reported `enqueue`, so #2020 read as enqueued across 9 consecutive fires having armed nothing. Two changes: - Pass `--rebase`. Measured safe on the queue path: `gh` prints "The merge strategy for master is set by the merge queue", exits 0, and the queue's own REBASE wins, so already-working rows are unaffected. - Record a non-fatal apply failure in `action`, not just `detail`. `renderReceipt` tallies by action, so a failure left in free text is invisible to the summary line. That is how this survived 9 fires. The outcome string is now "merge requested" rather than "auto-merge armed": `gh` drops the auto-merge request and merges immediately when the PR is already mergeable and the base has no queue to wait for, so naming one of the three outcomes would repeat the defect being fixed. `applyRow` takes an injectable runner so the arming argv is testable; it had no coverage at all. Every guard here has a failing mutation.
…ent count (BLO-32511) Review suggestions on #2106. - The two quoted receipt blocks are filtered subsets and `cd9d77f9`'s is reordered to lead with #2020. Both sat four paragraphs below this document's own rule about truncated quotation, with nothing saying they were filtered. Caption states the filter and the reorder. - "all 37 ledger comments on 2026-09-29" is a running total, which :783 forbids. Re-anchored on the last ledger comment id instead of a count. Not anchored on `c26e7d0a` as the review proposed: `d121863e` (2026-09-29T08:16:39Z) postdates it, so "through c26e7d0a, 37" would be wrong — that cut-off is 36. Co-Authored-By: Paperclip <noreply@paperclip.ing>
Thinking Path
Paperclip's CI is only as useful as the text it prints when a test fails. BLO-25854 measured that cost precisely: an unattributable assertion string on this exact test took five occurrences across ~6 weeks to diagnose, each costing a ~51-minute shard re-run, because the message named a symptom and carried no evidence. #2001 fixed the entry point responsible for those five occurrences and, reviewing it, Ally pointed out that the other entry point into the same failure still bare-rejected — "the branch most likely to be the next unattributable failure."
So this is not a tidy-up. It is closing the second door on a defect whose first door we have already paid for, before it costs the same five occurrences. Both Suggestions were deliberately held out of #2001: pushing would have moved the head, voided its at-head clean review, and dropped it from the merge queue.
Linked Issues or Issue Description
Stacked on #2001. Based on that branch, not
master, so the diff is one commit. The fix genuinely depends on #2001:readRemainingStderrand thestdoutcapture do not exist onmaster(verified by readingorigin/master, not assumed).The defect
server/src/__tests__/process-crash-guard-exit.test.ts— thestartupWatchdogcalledchild.kill("SIGKILL")and rejected immediately with the barefixture did not observe stderr backpressure. Theexithandler then ran, took thestartedAt === undefinedbranch and built the rich message with the capturedstdout/stderrin it — but first-settle-wins, so that message was discarded and CI printed the bare string. Two entry points into one failure, one of them silently throwing away the context the PR exists to capture.What Changed
The watchdog no longer settles at all. It records why it is killing (
startupTimedOut) and lets the SIGKILL raiseexit, whose handler is now the single place a never-reached-backpressure failure is formatted.That choice is the point of the PR. The obvious fix — copy the rich message into the watchdog — leaves two formatters to keep in sync, which is the state that produced the bug. Removing the second settle site is what makes AC 2 ("cannot diverge again by construction") structurally true rather than a convention.
Also:
1_000ms bail inreadRemainingStderr→STDERR_DRAIN_BAIL_MS, documented as bounding only failure-context gathering, so it can neither fail a passing run nor pass a failing one. It was the last unnamed wall-clock budget in a file that derives or explains every other one.BACKPRESSUREchunk could still arm the deadline andstdin.end()on a dead child, measuring elapsed time against a corpse. Pre-existing, but this change moves it from after-settle to before-settle, so the stdout guard now short-circuits onstartupTimedOutwhile still accumulating bytes (late bytes are context).runFixtureWithStalledStderrtakes aStalledRun, defaulting toPREFILL_RUN, which reproduces the previousspawnarguments and startup timeout exactly.Verification
Mutation-tested, per the guard-test rule — a regression test that cannot fail is documentation, not a test. Reverting the watchdog to its bare reject, alone, with nothing else changed:
Exactly one test fails, it is the new one, and it fails carrying the exact historical string from the issue. Re-verified after the hardening edit rather than assumed, since that edit touched the stdout handler the test depends on. Restored →
Tests 7 passed (7).tsc --noEmit— cleanprocess-crash-guard-exit.test.ts+process-crash-guard.test.ts—21 passed (21)pnpm check:test-undefined-symbols— exit 0Risks
exitfiring after SIGKILL. This is the one real trade in the diff. Ifexitnever arrived the promise would hang to vitest'stestTimeout: 60_000instead of rejecting promptly. I judged it safe — libuv delivers SIGCHLD for a spawned child that was running, and the 60s backstop bounds the pathological case — and it buys a single settle site, which is the property the issue asks for. Called out explicitly in the review request so it gets checked rather than assumed.STARTUP_STALL_RUNadds a 2s wall-clock literal to a file whose entire subject is wall-clock literals. Mitigation: it drivesnode -e(boots in tens of ms) rather than the fixture undertsx(cold compile in seconds), so the margin is ~50x; and it bounds a diagnostic assertion, so a runner slow enough to miss it reportsits stdout said: <nothing>and fails loudly with full context. It cannot fail silently or pass wrongly. If a reviewer still reads that as flake risk I would rather derive it than defend it.General tests (server N/4)will not run while this PR targets the fix(tests): fill stderr until it reports backpressure, not to a fixed 200 KB (BLO-25854) #2001 branch —pr.ymlispull_request: branches: [master]. It also will not start on its own when fix(tests): fill stderr until it reports backpressure, not to a fixed 200 KB (BLO-25854) #2001 merges and GitHub retargets this PR, because a base change firespull_request.edited, which is not in the defaultopened, synchronize, reopenedset. Resolution: once fix(tests): fill stderr until it reports backpressure, not to a fixed 200 KB (BLO-25854) #2001 lands I will rebase ontomasterand force-push, which firessynchronizeand runs the shards. Recording it here so nobody reads the absent shards as green.Model Used
Claude Opus 5 (
claude-opus-5), 1M context, extended thinking enabled, with tool use / code execution via Claude Code. Authored and mutation-tested in one run; the fix and its guard test were verified in both directions before the PR was opened.Checklist
🤖 Generated with Claude Code