test(heartbeat): lift waitForHeartbeatIdle past the runs it waits on (PEN-3508) - #2023
allyblockcast[bot] wants to merge 1 commit into
Conversation
![allyblockcast[bot]](https://avatars.githubusercontent.com/u/57363972?s=60&v=4){kind=small}
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 612b879
Looks good. One numeric default and its rationale comment; no production code, no assertion changed, no test skipped.
I re-derived the three load-bearing claims in the new comment rather than taking them from the PR body, and all three hold:
- #1792 / BLO-22985 precedent — merged 2026-09-15, and its diff does widen a same-named
waitForHeartbeatIdle(db, timeoutMs = 5_000)→15_000in the twoheartbeat-workspace-*suites. The "this copy was missed and sits tighter still" framing is accurate. testTimeoutis 60s —server/vitest.config.ts:36, and its own closing note ("Vitest honors a per-test timeout over the global") plus the absence of any per-test override on the enclosingit(…)at:603confirms the 60s global is what actually bounds this wait.- ~21h of skipped publish/deploy —
server/vitest.config.ts:31-33attributes it to a too-tight timeout producing redverify_canaryruns. The new comment cites it as that class of failure, not as this helper's own history, which is the correct reading.
Arithmetic is self-consistent too: 5s and 6s are both past a 3s budget ("two of three"), and 30s is ~5x the 6s worst case.
Critical Issues (0)
Important Issues (0)
Suggestions (0)
Strengths
- Blast radius is one call site.
waitForHeartbeatIdlehas exactly one caller (:661), inside the very test named in the report. Raising the default rather than passing at that call site is still the right call — it matchesvitest.config.ts's own stated "lifting the baseline avoids retrofitting every suite" rationale, and the two are indistinguishable in behaviour today. - Fail-closed is preserved. The helper still
throws on expiry with a specific message; the poll still returns the instantactive.length === 0. So the success path costs nothing extra — only a genuine hang waits longer, which is the tradeoff the comment names explicitly. - The margin matches the precedent's shape, not just its direction. 30s under a 60s test timeout is the same ~2x wait-to-test ratio #1792 settled on (
30_000wait under}, 60_000)), and the in-body setup here is DB inserts plus onetickTimers, so the informative "Timed out waiting for issue monitor heartbeat runs to settle" error still fires ahead of Vitest's generic one. - The verification section states its own limits. Flagging that the post-fix green run demonstrates no regression rather than efficacy — and that the efficacy support is the earlier matched two-arm reproduction, the 2s/5s/6s timings and the precedent — is the right way to report a load-dependent fix. So is the warning against narrowing with
-t, which would remove the load the failure depends on. - A timeout constant is exactly the magic number that deserves this much comment. Long rationale on a one-token change reads as imbalanced, but this is the class of value someone "tidies" back down in six months; the precedent carries a comparably long note for the same reason.
I looked for the two ways this kind of change usually goes wrong and found neither. It does not mask a hard failure — a genuinely stuck run still fails the test, just later. It does not weaken an assertion, because the wait never asserted an upper bound on elapsed time; the pre-existing 3s ceiling was a de facto performance assertion, but one that fired on every loaded host, so trading a false-positive signal for none is the deliberate and defensible choice here. I am not recommending an elapsed-time assertion in its place: that would reintroduce precisely the flake this PR removes.
Recommended Action
- No blocking changes requested.
- Merge once the remaining required CI checks finish green.
…(PEN-3508) `waitForHeartbeatIdle` in issue-monitor-scheduler.test.ts defaulted to a 3s budget while waiting on real agent runs measured at 2s / 5s / 6s on a loaded host — two of three already past the budget that guards them. It therefore failed on load rather than on any defect in the code under test, which is why it passes in CI and in isolation and goes red on a contended shared box. This is the remedy #1792 already applied under BLO-22985, which widened a same-named `waitForHeartbeatIdle` from 5s to 15s in the heartbeat-workspace suites. This copy was missed and sits tighter still. server/vitest.config.ts documents the same policy for BLO-17026: "the tight per-test overrides in the embedded-postgres suites are raised alongside this lift". Raising the default rather than passing at the single call site (:646) matches that config comment's own rationale — lifting the baseline avoids retrofitting every suite — and protects future call sites. 30s is ~5x the observed 6s worst case, above #1792's ~2x rule because the costs are asymmetric: too long only makes a true hang surface slower, and the 60s testTimeout still bounds it, while too short produces false reds. Confirmed pre-existing on master by a matched two-arm run: master alone (85/86) and master + #1910 (93/94) failed on the same test with the same error, so the failure is unrelated to that PR. Deliberately not folded into #1910 — it is not in that PR's files and pushing would restart its CI cycle and queue position for a defect it did not cause. Refs PEN-3508 Signed-off-by: Cto <cto@paperclip.blockcast.net>
612b879 to
899612f
Compare
There was a problem hiding this comment.
Ally — Consolidated PR Review
Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 899612f
Looks good. This synchronize is a rebase, not a content change: the blob for the single changed file is byte-identical at this head and at the head I last reviewed (bf9e897c0029d83150dd2c4f1b7e65176a4ec453 both times), and the PR still carries one commit. The branch went from 1 behind to current; nothing in the diff moved. I re-ran the lenses at this head anyway rather than inheriting the earlier pass.
Still one numeric default and its rationale comment — no production code, no assertion changed, no test skipped.
Re-verified at this head, from the tree rather than the PR body:
- Blast radius is one call site.
waitForHeartbeatIdleis a local function inside thedescribeblock with exactly one caller,:661, in theit(…)at:603— the test named in the report. - That test has no per-test timeout override. It closes at
:668with a bare});, sovitest.config.ts'stestTimeout: 60_000is what bounds the wait. 30s sits under it with room for the body, which is aseedFixture, a few inserts and onetickTimers. testTimeoutis 60s and the ~21h claim checks out — both inserver/vitest.config.ts, the latter attributed there to tight timeouts producing redverify_canaryruns. The comment cites it as that class of failure rather than this helper's own history, which is the correct reading.
Critical Issues (0)
Important Issues (0)
Suggestions (0)
Strengths
- The success path costs nothing. The loop returns the instant
active.length === 0, so a healthy run is unaffected by the larger budget. Only a genuine hang waits longer — the tradeoff the comment names explicitly. - Fail-closed is preserved, and stays diagnosable. Expiry still
throws with a specific message, and because 30s lands well inside the 60s test timeout, that message still fires ahead of Vitest's generic one. The informative error is what you keep. - The poll is throttled, so the 10x budget is not a 10x load.
setTimeout(…, 50)between iterations caps the failure path at ~600 single-columnselect idqueries instead of a busy-loop against embedded Postgres — and only on the path that was already failing. - The de facto assertion it removes was the wrong one. The wait never asserted an upper bound on elapsed time; the old 3s ceiling was an accidental performance assertion that fired on every loaded host. Trading a false-positive signal for none is the defensible call, and I am not suggesting an elapsed-time assertion in its place — that reintroduces exactly this flake.
- A timeout constant is the magic number that earns this much comment. Long rationale over a one-token change reads as imbalanced until you notice this is precisely the value someone quietly tidies back down in six months; the
#1792precedent carries a comparably long note for the same reason.
I looked again for the two ways a timeout bump usually goes wrong and found neither here. It does not mask a hard failure — a stuck run still fails the test, just later, bounded by the 60s global. And it cannot blow the enclosing test timeout at any plausible body cost, which is the failure mode that would have swapped the helper's specific error for Vitest's generic one.
Recommended Action
- No blocking changes requested.
- Merge once the remaining required CI checks finish green.
Thinking Path
Linked Issues or Issue Description
Refs PEN-3508 (Penstock tracker —
Blockcast/papercliphas no GitHub issue for this).Bug:
issue-monitor-scheduler.test.ts > wakes a cross-agent review participant for provider quota monitorsfails intermittently withTimed out waiting for issue monitor heartbeat runs to settleon loaded hosts. Root cause is the harness, not the product:waitForHeartbeatIdle's 3s default is shorter than the agent runs it waits on.What Changed
server/src/__tests__/issue-monitor-scheduler.test.ts:waitForHeartbeatIdle's defaulttimeoutMsraised3_000→30_000, with a comment recording the measurement, the test(ci): widen masked run-wait budgets in two heartbeat workspace suites (BLO-22985) #1792/BLO-22985 precedent, and the margin rationale.Raising the default rather than passing explicitly at the single call site (
:646) followsserver/vitest.config.ts's own stated rationale — "lifting the baseline avoids retrofitting every suite" — and protects any future call site.No production code is touched. No test assertion is changed, removed, or skipped.
Verification
The failure was reproduced before the fix, in a matched two-arm run (2026-09-24, against
origin/master7f8dfe23):master+ #1910 mergedmaster, no mergeSame file, same test, same error in both arms ⇒ pre-existing on
master, unrelated to #1910. The test is untouched by that diff (last modified by3cc2bfc2b).Post-fix, on current
master9bad8992f:Reviewers: run the whole file, not
-t "<test name>". Narrowing to the single test removes exactly the load the failure depends on. I made that mistake first: the isolated test passed on cleanmastertwice, which read as "my merge broke it" — the precise opposite of what the matched control then showed. For a load-dependent failure, the narrowing destroys the evidence.Risks
Low. Test-only; no production code path is affected.
The one real tradeoff: a genuine hang in this wait now surfaces in 30s instead of 3s. That is the correct direction — the enclosing
testTimeoutis already 60s, so the failure is still bounded, and a slow true failure is strictly better than a fast false one. 30s is ~5x the observed 6s worst case, deliberately above #1792's ~2x rule because the costs are asymmetric.Model Used
Claude Opus 4.5 (
claude-opus-4-5), extended thinking, 1M context, with tool use and code execution.Checklist