fix: give the shadow review its own wall-clock budget #459

Merged
joshtronic merged 1 commit from fix/453-review-timeout into master 2026-07-30 20:59:52 +00:00
Collaborator

Closes #453

#453 reported review call failed 19x on one PR with no cause. The cause is now in the journal, courtesy of #454 putting log() on stderr:

[agent] claude review: failed (rc=124)

124 is timeout(1).

What's actually wrong

claude_call defaults to 300s, and reviewer_effort escalates to max at rework round 3 — which outgrows it. Measured on igor#455, same PR, consecutive rounds:

round effort diff result
2 high 24,683 chars verdict in 77s
3 max 26,898 chars rc=124, twice → then verdict in 197s

So max on a diff near the 400-line scope cap runs ~2.5× high and varies enough to straddle 300s. The escalation fires exactly when a PR is hardest, so the reviewer becomes least able to return a verdict precisely when one is most needed.

And the consequence is worse than a slow review. A timeout leaves the head un-recorded, so do_review_tick re-picks the same PR next tick and every other PR in the fleet queues behind it. On 2026-07-30 that presented as a fleet-wide review outage for ~30 minutes until an attempt got lucky — joshing.you#162 sat unreviewed the whole time.

600s is ~3× the observed successful max-effort run, and the same budget the sports digest already uses for its long call. Hardcoded, not an env knob.

Deliberately not changed

The retry count, and any skip-after-N-failures guard. The loop self-healed on retry, so there's no evidence of a permanent block — only of a budget set below the work. A guard would be building for a failure that hasn't happened, and I'd rather find out than pre-empt it.

Tests

bin/test-review-timeout.sh. The behavioural half is the load-bearing one: it drives the real claude_call with a stubbed CLI that outlives its budget, and asserts the 7th argument is honoured at all. If it were ignored, the new constant would be decoration and the bug would survive the PR intact.

+ a call that outruns its budget fails
+ and is killed at the budget, not 30s later (2s)
+ the journal gets rc=124, so a timeout is diagnosable as a timeout

The rest are source assertions, including one that fails if the budget is ever set at or below claude_call's default — the shape that would look fixed while changing nothing. Mutation-checked both ways: setting it to 300, and dropping the argument at the call site.

check-sync clean, shellcheck clean.

🤖 Generated with Claude Code

https://claude.ai/code/session_01QfDyMfn2Go73gw21a92wNB

Closes #453 #453 reported `review call failed` 19x on one PR with no cause. The cause is now in the journal, courtesy of #454 putting `log()` on stderr: ``` [agent] claude review: failed (rc=124) ``` `124` is `timeout(1)`. ## What's actually wrong `claude_call` defaults to 300s, and `reviewer_effort` escalates to `max` at rework round 3 — which outgrows it. Measured on **igor#455, same PR, consecutive rounds**: | round | effort | diff | result | |---|---|---|---| | 2 | `high` | 24,683 chars | verdict in **77s** | | 3 | **`max`** | 26,898 chars | **rc=124, twice** → then verdict in **197s** | So `max` on a diff near the 400-line scope cap runs ~2.5× `high` and varies enough to straddle 300s. The escalation fires exactly when a PR is hardest, so the reviewer becomes least able to return a verdict precisely when one is most needed. **And the consequence is worse than a slow review.** A timeout leaves the head un-recorded, so `do_review_tick` re-picks the same PR next tick and every other PR in the fleet queues behind it. On 2026-07-30 that presented as a fleet-wide review outage for ~30 minutes until an attempt got lucky — joshing.you#162 sat unreviewed the whole time. 600s is ~3× the observed successful max-effort run, and the same budget the sports digest already uses for its long call. Hardcoded, not an env knob. ## Deliberately not changed The retry count, and any skip-after-N-failures guard. **The loop self-healed on retry**, so there's no evidence of a permanent block — only of a budget set below the work. A guard would be building for a failure that hasn't happened, and I'd rather find out than pre-empt it. ## Tests `bin/test-review-timeout.sh`. The behavioural half is the load-bearing one: it drives the real `claude_call` with a stubbed CLI that outlives its budget, and asserts the 7th argument is honoured **at all**. If it were ignored, the new constant would be decoration and the bug would survive the PR intact. ``` + a call that outruns its budget fails + and is killed at the budget, not 30s later (2s) + the journal gets rc=124, so a timeout is diagnosable as a timeout ``` The rest are source assertions, including one that fails if the budget is ever set at or below `claude_call`'s default — the shape that would look fixed while changing nothing. Mutation-checked both ways: setting it to 300, and dropping the argument at the call site. check-sync clean, shellcheck clean. 🤖 Generated with [Claude Code](https://claude.com/claude-code) https://claude.ai/code/session_01QfDyMfn2Go73gw21a92wNB
fix: give the shadow review its own wall-clock budget
All checks were successful
Lint / check-sync (push) Successful in 5s
Lint / check-sync (pull_request) Successful in 6s
8c088d2bf9
Closes #453

#453 reported `review call failed` 19x on one PR with no cause. The cause
is now in the journal, courtesy of #454 putting log() on stderr:

  [agent] claude review: failed (rc=124)

124 is timeout(1). claude_call defaults to 300s and reviewer_effort
escalates to `max` at rework round 3, which outgrows it. Measured on
igor#455, same PR, consecutive rounds:

  round 2  effort=high  24683 chars  -> verdict in  77s
  round 3  effort=max   26898 chars  -> rc=124, twice
                                     -> then verdict in 197s

So `max` on a diff near the 400-line scope cap runs ~2.5x `high` and
varies enough to straddle 300s. The escalation fires exactly when a PR is
hardest, so the reviewer becomes least able to return a verdict precisely
when one is most needed.

The consequence is worse than a slow review. A timeout leaves the head
un-recorded, so do_review_tick re-picks the same PR next tick and every
other PR in the fleet queues behind it. On 2026-07-30 that looked like a
fleet-wide review outage for ~30 minutes until an attempt got lucky --
joshing.you#162 sat unreviewed the whole time.

600s: ~3x the observed successful max-effort run, and the same budget the
sports digest already uses for its long call. Hardcoded, not an env knob.

Deliberately NOT changed: the retry count, and any skip-after-N-failures
guard. The loop self-healed on retry, so there is no evidence yet of a
permanent block -- only of a budget set below the work. Adding a guard now
would be building for a failure that has not happened.

bin/test-review-timeout.sh. The behavioural half is the load-bearing one:
it drives the real claude_call with a stubbed CLI that outlives its
budget, and asserts the 7th argument is honoured at all -- if it were
ignored the new constant would be decoration and the bug would survive
the PR. The rest are source assertions, including one that fails if the
budget is ever set at or below claude_call's default, which is the shape
that would look fixed while changing nothing. Mutation-checked both ways.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01QfDyMfn2Go73gw21a92wNB
Author
Collaborator

🤖 Review — APPROVE (automated)

CI for 8c088d2b: success

Bumps the shadow-review claude_call to a dedicated 600s budget (up from the 300s default) and adds bin/test-review-timeout.sh. CI green, scope tight (~110 lines, one issue), description matches the diff exactly.

What I checked

  • bin/tick.sh:1091-1108REVIEW_CALL_TIMEOUT_SECS=600 is defined at top level (between reviewer_effort and worker_effort), so it's in scope by the time do_review_tick runs at ~3047. No shadowing, no local, no env-override path that could reintroduce 300s.
  • bin/tick.sh:3050 — the 7th positional is the only change to the call; args 1–6 are untouched.
  • The behavioural test is genuinely load-bearing, not theatre: it drives the real claude_call with a sleep 30 stub CLI and a 2s budget, and asserts both the non-zero return and that it died at ~2s rather than 30s. That's the one assertion that would fail if claude_call ignored arg 7 — which matters, since lib/claude.sh isn't in this diff and I can't otherwise confirm the parameter exists. Combined with green CI, I'm satisfied it does.
  • The BUDGET > DEFAULT and BUDGET >= 400 source assertions close the "looks fixed, changes nothing" hole. Good instinct.
  • No security surface: no new input handling, no CI/workflow changes, no secrets.

Non-blocking notes for the record

  • Worst-case tick duration doubles. do_review_tick still retries (for attempt in 1 2), so a pathological review can now occupy up to 1200s of wall clock inside one tick instead of 600s. If anything upstream (systemd TimeoutStopSec, a tick-level lock/watchdog, timer interval) sits below that, the failure mode changes from "review times out, retried next tick" to "tick killed mid-review", which is strictly worse. Worth a glance at the unit file; nothing in this diff tells me either way.
  • The head-of-line blocking is mitigated, not removed. The stated fleet-outage mechanism — a timeout leaves the head un-recorded, so do_review_tick re-picks the same PR forever — is unchanged; 600s just makes it much less likely to trigger. The PR is explicit about deferring the skip-after-N guard and gives a defensible reason (no evidence of a permanent block yet). Fine as a decision, but if #453's symptom recurs, that's the next thing to fix, not another budget bump.
  • Minor test flake risk: [ "$SECS" -le 6 ] against a 2s budget leaves ~4s of slack. Probably fine, but under a loaded runner this is the assertion that will go red first.
  • The call-site assertion greps for the exact literal claude_call "${AGENT_MODEL_REVIEW}:${rev_effort}"... — any reformatting of that line fails the test with a message that reads like a real regression. Acceptable tradeoff for catching a dropped argument, just be aware.

Nothing here blocks. Approving.


Independent review by the harness on claude-opus-5 (effort: high). The human reviewer is requested once Igor has reviewed; a human still merges.

### 🤖 Review — `APPROVE` _(automated)_ CI for `8c088d2b`: **success** Bumps the shadow-review `claude_call` to a dedicated 600s budget (up from the 300s default) and adds `bin/test-review-timeout.sh`. CI green, scope tight (~110 lines, one issue), description matches the diff exactly. **What I checked** - `bin/tick.sh:1091-1108` — `REVIEW_CALL_TIMEOUT_SECS=600` is defined at top level (between `reviewer_effort` and `worker_effort`), so it's in scope by the time `do_review_tick` runs at ~3047. No shadowing, no `local`, no env-override path that could reintroduce 300s. - `bin/tick.sh:3050` — the 7th positional is the only change to the call; args 1–6 are untouched. - The behavioural test is genuinely load-bearing, not theatre: it drives the *real* `claude_call` with a `sleep 30` stub CLI and a 2s budget, and asserts both the non-zero return and that it died at ~2s rather than 30s. That's the one assertion that would fail if `claude_call` ignored arg 7 — which matters, since `lib/claude.sh` isn't in this diff and I can't otherwise confirm the parameter exists. Combined with green CI, I'm satisfied it does. - The `BUDGET > DEFAULT` and `BUDGET >= 400` source assertions close the "looks fixed, changes nothing" hole. Good instinct. - No security surface: no new input handling, no CI/workflow changes, no secrets. **Non-blocking notes for the record** - *Worst-case tick duration doubles.* `do_review_tick` still retries (`for attempt in 1 2`), so a pathological review can now occupy up to 1200s of wall clock inside one tick instead of 600s. If anything upstream (systemd `TimeoutStopSec`, a tick-level lock/watchdog, timer interval) sits below that, the failure mode changes from "review times out, retried next tick" to "tick killed mid-review", which is strictly worse. Worth a glance at the unit file; nothing in this diff tells me either way. - *The head-of-line blocking is mitigated, not removed.* The stated fleet-outage mechanism — a timeout leaves the head un-recorded, so `do_review_tick` re-picks the same PR forever — is unchanged; 600s just makes it much less likely to trigger. The PR is explicit about deferring the skip-after-N guard and gives a defensible reason (no evidence of a permanent block yet). Fine as a decision, but if #453's symptom recurs, that's the next thing to fix, not another budget bump. - *Minor test flake risk:* `[ "$SECS" -le 6 ]` against a 2s budget leaves ~4s of slack. Probably fine, but under a loaded runner this is the assertion that will go red first. - The call-site assertion greps for the exact literal `claude_call "${AGENT_MODEL_REVIEW}:${rev_effort}"...` — any reformatting of that line fails the test with a message that reads like a real regression. Acceptable tradeoff for catching a dropped argument, just be aware. Nothing here blocks. Approving. --- <sub>Independent review by the harness on `claude-opus-5` (effort: high). The human reviewer is requested once Igor has reviewed; a human still merges.</sub> <!-- review sha=8c088d2bf98006c9b617929912c88cbd340f0654 verdict=APPROVE ci=success -->
igor added spent time 2026-07-30 19:50:18 +00:00
1 minute 7 seconds
joshtronic deleted branch fix/453-review-timeout 2026-07-30 20:59:52 +00:00
Sign in to join this conversation.
No reviewers
No milestone
No assignees
1 participant
Notifications
Total time spent: 1 minute 7 seconds
igor
1 minute 7 seconds
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
joshtronic/igor!459
No description provided.