feat(subagent): progress-aware idle watchdog for forked turns - #672
Conversation
Add a progress-aware idle watchdog to forked sub-agent turns: fire when a child produces no observable OutputEvent for an idle window (default 8 min), distinct from the blunt 45-min wall-clock. Round caps bound work done and the wall-clock bounds time elapsed; neither bounds time since the child last did anything observable — the missing signal that distinguishes a healthy child grinding for 40 min from a child stalled at minute 2 (the ~43-min zero-output /review hang under 429 throttling that motivated this). Mechanism: - New IdleWatchdog helper (one .unref()'d setTimeout, re-armed per event) wired alongside the existing SubagentProgressSink fire site in handle.ts. The only thing that resets the clock is a real OutputEvent (anti-gaming: no caller- facing heartbeat). - Pause-aware: on OAuth `paused` (resetsAt + slack) or a `rate_limit` event carrying retryAfterMs, EXTEND the deadline instead of firing — only unexplained silence counts. `resumed` collapses back to a normal window. - On fire, abort the SAME controller withTimeout targets. IdleWatchdogError extends TimeoutError, so the existing instanceof-TimeoutError own-budget classification, AbortGraph cascade, and partial-output preservation all apply unchanged: an idle-fire is `failed` (own budget) with partialOutput intact, NOT `cancelled`. Config: SUBAGENT_DEFAULT_IDLE_TIMEOUT_MS = 8 min (clears the ~363s transient-429 backoff this PR is deliberately blind to — the transient-429 stream signal is a separate follow-up — with ~2 min margin, while staying 5.6x tighter than the wall-clock). Env-tunable via AFK_SUBAGENT_IDLE_TIMEOUT_MS (registered in ENV_REGISTRY, category model; docs/env-registry regenerated); per-fork override via config.idleTimeoutMs; 0 disables (wall-clock still applies). Observability: new `idle_watchdog_fired` session phase added in lockstep to both the SessionPhaseName union and the SessionPhaseNameSchema Zod enum, with a union<->schema parity test. Scope: v1 = forked sub-agent turns only (top-level/daemon = fast-follow). Additive and backward-compatible. Tests: new idle-watchdog.test.ts (arm/fire/reset/extend/collapse/dispose/ disable, fake timers); subagent.test.ts integration (no-progress child aborts IdleWatchdogError-failed before the wall-clock; streaming child never cut off; paused->resumed completes; idleTimeoutMs:0 opt-out; env override + invalid fallback; partialOutput populated) + resolveSubagentIdleTimeoutMs unit tests; session-phase.test.ts round-trip + parity. Two pre-existing wall-clock tests gained idleTimeoutMs:0 to isolate the wall-clock bound from the new default.
|
The latest updates on your projects. Learn more about Vercel for GitHub.
|
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 8afb0b7e76
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| } | ||
| // `resumed` and every other event type are ordinary progress: collapse (or | ||
| // stay at) a normal idle window measured from now. | ||
| this.arm(this.idleTimeoutMs, event.type); |
There was a problem hiding this comment.
Avoid timing out legitimate in-flight tools
When the last event is a tool-start chunk, this normal idle re-arm can expire while the tool is still legitimately running. The Anthropic loop yields tool.use.start and then awaits executeBatch(calls) before any tool.output event is yielded (src/agent/providers/anthropic-direct/loop.ts:795-825,877), while bash explicitly allows silent commands up to 600000ms (src/agent/tools/handlers/bash.ts:50-56) and nested agent tool calls can also exceed 8 minutes. With the new 480000ms default, a subagent running e.g. a 9-minute silent bash/test command or waiting on a healthy nested agent is aborted as idle before the tool's own bound/result, so treat in-flight tool execution as a bounded wait or extend the watchdog until the matching tool result arrives.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 1456b15. Confirmed the blind window: both providers yield every tool.use.start (→ tool_use_detail chunk), then await the tool dispatch with zero intervening events, then yield every tool.output (→ tool_result chunk) — so an in-flight tool produces no progress signal on the parent stream. The watchdog now SUSPENDS the idle clock while ≥1 tool is in flight (tracked by toolUseId) and re-arms a normal window when the last in-flight tool of a batch returns. Tools carry their own bounds (bash ≤600000ms, nested agents their own wall-clock + idle watchdog); a tool that hangs with none is still caught by the un-resettable wall-clock ceiling. Regression-guarded by 5 new tests (all verified to fail with the suspend branch neutered).
griffinwork40
left a comment
There was a problem hiding this comment.
🤖 Automated review (hourly sweep), generated by the /review tool — a maintainer will follow up.
Merge decision: ✅ MERGE
Reviewed at head ref 8afb0b7. Full-regime review (2 parallel dimension agents + citation/absence verification pass) across security, api-compat, correctness, spec-compliance, test-coverage, and perf-observability. No blocking, critical, or high findings. Two low-severity items below; neither blocks merge.
Verified strengths (read against ref 8afb0b7)
- api-compat — clean. Every new symbol is additive (
IdleWatchdog,IdleWatchdogError,resolveSubagentIdleTimeoutMs,SUBAGENT_DEFAULT_IDLE_TIMEOUT_MS,AgentConfig.idleTimeoutMs); no exported signature changed or removed.IdleWatchdogError extends TimeoutError(src/utils/errors.ts:33) keeps the existinginstanceof TimeoutErrorclassification athandle.ts:255unchanged — idle-fires route to thefailed(own-budget) branch, notcancelled, matching the stated intent. - security — clean. Single
.unref()'d timer (idle-watchdog.ts:172),clearTimeouton every re-arm and indispose()under afinallycovering completion/break/throw (handle.tsdispose path) → no timer leak.fire()is guarded (if (this.fired || this.disposed) return) and checks!signal.abortedbefore aborting → no double-fire, no unsafe abort.onFirecallback errors are swallowed so a failing trace emit cannot suppress the abort. Error message carries only sub-agent id + timeout + event type, no payload → no secret exposure. - spec-compliance — no unmet clauses, no scope creep. Timer re-arm on real
OutputEvent, pause/resume deadline extension,dispose(),0-disables escape hatch, and theidle_watchdog_firedtrace phase added in lockstep to both theSessionPhaseNameunion AND the Zod enum (+ parity test) are all present. The 8-min-default behavioral change is handled exactly as documented — the two pre-existing wall-clock tests were isolated withidleTimeoutMs: 0. Anti-gaming property holds: only a provider-loopOutputEventre-arms the clock; there is no caller-facing heartbeat to spoof. - perf-observability — clean. The per-event re-arm is O(1) (
clearTimeout+setTimeout+.unref()), negligible even at high chunk rates; trace emission on fire is fire-and-forget and cannot delay the abort or the hot path. - test-coverage — claimed tests present at ref.
idle-watchdog.test.ts(18it()blocks — the PR's "16" is an undercount, not a defect), plus the newsubagent.test.tsidle/resolver cases and thesession-phase.test.tsparity test. Covers arm/fire/reset/extend(paused)/collapse(resumed)/dispose/0-disable/env-override/invalid-fallback/partialOutput.
Non-blocking findings
-
low · nit · correctness —
src/agent/subagent/idle-watchdog.ts:116(ref8afb0b7): theonEventdocstring lists event typestool_use/thinkingthat do not exist in theOutputEventunion (onlytool_use_detail, nested insidechunk). Comment-only; the catch-allarm(idleTimeoutMs, event.type)covers all remaining types correctly regardless.- Suggestion: drop
tool_use/thinkingfrom the comment's example list.
- Suggestion: drop
-
low · test-coverage —
src/agent/subagent/idle-watchdog.ts:151-154(ref8afb0b7):pausedWindowMsfloors a past-datedresetsAtviaMath.max(idleTimeoutMs, untilResetMs + slack), but no test inidle-watchdog.test.tsdrives aresetsAtin the past (verified: the past-datedresetsAtcases live inusage-limit.test.ts, a different unit). TheMath.maxfloor makes the behavior correct; the branch is just unproven here.- Suggestion: add a case with
resetsAt = new Date(Date.now() - 60_000)asserting a normal idle window is used.
- Suggestion: add a case with
What was NOT checked
- The suite was not executed — the "12753 passed / 0 failed" claim is unverified here (read-only review; citations verified against ref
8afb0b7, tests not run). - Background-mode forks (
SUBAGENT_BACKGROUND_TIMEOUT_MS) — intent scopes v1 to foreground forks; the background path was not traced. - Runtime timing accuracy of the pause-extension math under real (non-fake) timers.
docs/env-registry.{md,json}regeneration fidelity beyond the diff hunk.
Stated intent: PR #672 title + body — spec-compliance assessed against it.
…ts (#674) Detect when a FORKED subagent issues the same tool call with the same (normalized) arguments repeatedly within a sliding window, and emit a `suspected_loop` trace signal so we can measure whether real busy-loops occur in practice. Pure observability to gather data BEFORE deciding whether an enforcing loop-detector is ever warranted. OBSERVE-ONLY invariant: this NEVER aborts the fork, NEVER sets a failureClass, NEVER alters or delays a tool result, and NEVER changes control flow. The sole effect is a fire-and-forget trace emission on the witness side channel. - New src/agent/tools/suspected-loop-detector.ts: pure fingerprintToolCall (sha256 over tool name + key-order-normalized args), a bounded ring-buffer recurrence predicate, fixed constants (N=5 recurrences within M=20 rounds), and a per-fingerprint debounce so it emits at most once per detected loop. Mirrors the repeat/denial circuit-breaker fixed-constant + pure-helper style. - Wire per-dispatcher state on SessionToolDispatcher, evaluated on the sequential pre-execution path (execute() + executeBatch phase 1) after the repeat breaker. Scoped to FORKED children (parentSessionId set), like the denial breaker, so interactive sessions are unaffected. - Add `suspected_loop` to SessionPhaseName (types.ts) and SessionPhaseNameSchema (events.ts) in lockstep, mirroring idle_watchdog_fired; extend the union<->schema parity test. - Does NOT fire on distinct-arg fan-out (e.g. the /review per-citation trap) by design: that is budget-shaped and handled elsewhere. Tests: new suspected-loop-detector.test.ts (pure helpers + dispatcher integration asserting the observe-only invariant), plus dispatcher.test.ts coexistence tests and session-phase.test.ts parity/acceptance coverage.
Addresses codex P2 on #672: the progress-aware idle watchdog re-armed only on a real OutputEvent, but a forked child's tool call runs SILENTLY between its `tool_use_detail` chunk and its matching `tool_result` chunk — both providers yield every `tool.use.start`, `await` the tool dispatch with zero intervening events, then yield every `tool.output` (anthropic-direct/loop.ts, openai-compatible/query/dispatch-append.ts). With the 8-min default, a child running a single long silent tool (a >8-min `bash`/test/build/install, or a healthy nested `agent` turn that streams on its own child stream) produced no observable progress on the parent stream and was aborted as "idle" before the tool's own bound — the exact "healthy child grinding" case the watchdog exists to protect, a false positive that contradicts the feature's own thesis. Fix: track in-flight tool-use ids (Set, keyed by toolUseId) and SUSPEND the idle clock while ≥1 tool is executing; re-arm a normal window when the LAST in-flight tool of a (possibly parallel) batch returns. Tools carry their own bounds (bash ≤600000ms, nested agents their own wall-clock + idle watchdog, network tools their timeout); a tool that hangs with no bound of its own is still caught by the un-resettable wall-clock ceiling — the same guarantee as before this watchdog existed. The watchdog's true target (a stalled model SSE call under 429 throttling) happens during model streaming, not tool execution, so detection of that case is unchanged. Also drops the stale `tool_use`/`thinking` event-type names from the onEvent docstring (codex review low nit #1 — those are chunk sub-types, not OutputEvent types). Tests: 4 new IdleWatchdog unit cases (suspend on long silent tool; parallel batch stays suspended until last result; re-arm across successive tools; lastEventType="tool_result" on post-tool fire) + 1 subagent integration case (a 30s silent tool under a 5s idle window completes instead of idle-firing). All 5 verified load-bearing (fail with the suspend branch neutered). Full suite: 691 files, 12783 passed / 14 skipped / 0 failed; lint clean.
Addressed codex P2 — idle watchdog no longer times out legitimate in-flight tools (1456b15)Finding (valid, independently re-derived): the watchdog re-armed only on a real Fix: track in-flight tool-use ids (a
Also swept in review low-nit #1: dropped the stale Verification
Not addressed here: review low-nit #2 (a past-dated |
…ling (#797) * fix(subagent): credit provider-paused time against the wall-clock ceiling A fork parked by a provider-imposed pause longer than its wall-clock budget was GUARANTEED to die, no matter what the caller did. On 2026-07-31 a /forge run lost 1h49m of work this way: the provider parked the account at 01:16:47Z (HTTP 429, retryAfterMs 6792000, resetsAt 03:10:00Z — a ~113 min pause), the child forked at 02:26:21.307Z inheriting SUBAGENT_DEFAULT_TIMEOUT_MS, and it died at 03:11:21.307Z — exactly dispatch + 2,700,000 ms, 81 seconds AFTER the pause reset. It had spent 43m38s of its 45-minute budget parked and got ~81 seconds of actual working time. The idle watchdog did NOT fire at its 8-minute window, which proves the runtime recognized the pause and correctly extended the idle deadline. The wall clock ignored the very same signal and killed the child anyway. Callers cannot pre-compute a safe timeoutMs because the pause window is unknowable at dispatch; the only escape was timeoutMs: 0 (fully unbounded), which is worse. WHY THIS REVISES A SHIPPED DECISION .afk/plans/subagent-idle-watchdog.md:88 locked the wall-clock as the "un-resettable ceiling", and #672 deliberately built pause-awareness into IdleWatchdog alone so it would NOT touch withTimeout. This is a deliberate revision of that decision, not a gap-fill. It honors the PURPOSE of the invariant — a fork's lifetime must have a guaranteed finite, predictable upper bound — rather than its letter, which made "bound the child's WORKING time" inexpressible. The budget now bounds working time: effective ceiling = timeoutMs + min(provider-parked time, cap) Crediting parked time (rather than asking "is a pause in effect right now?") is load-bearing: in the incident the park ended 81s BEFORE the deadline, so a right-now check grants nothing and the child still dies. Properties preserved: - Only provider-reported pause signals (`paused` w/ resetsAt, `rate_limit` w/ retryAfterMs) grant credit — the same events IdleWatchdog consumes. Child content, tokens, thinking, and tool activity NEVER extend the ceiling, so it remains un-resettable by the child: it cannot author the only moving signal. - Each grant is bounded by the provider's own reported window, never open-ended; an unresumed park stops accruing at its stated end. - Total accumulated extension is capped by SUBAGENT_MAX_PAUSE_EXTENSION_MS (2h — the provider's own maximum subscription park, covering the observed ~113 min with headroom). Once exhausted the ceiling fires as it does today. Worst case with the default budget is 45min + 2h = 2h45m: finite, predictable. - On fire under pause the TimeoutError names the pause context instead of a bare "Operation timed out after 2700000ms". - With no pause events, behaviour and error message are byte-for-byte identical. Pause arithmetic is extracted to a shared pause-window module so the idle watchdog and the ceiling cannot drift apart (all 20 existing idle-watchdog tests pass unchanged). New concerns live in new files, keeping every source file under the 350 LOC limit. * fix(subagent): close an expired pause so credit never counts working time Adversarial review of the previous commit found a real defect. A pause was closed only on `resumed`, but `resumed` is emitted ONLY on the OAuth park path (`retry-layer.ts:415,512`) — a transient `rate_limit` NEVER has a matching `resumed`. Such a pause therefore stayed open forever, and because a later signal widens the window by the elapsed gap (`elapsedIntoPause + windowMs`), each new throttle retroactively credited the ordinary WORKING time between throttles: a 5s retry-after seen every 10 min credited the full 10 min, quietly inflating the effective budget toward `timeoutMs + cap`. Finiteness was never at risk (the absolute cap still bound it), but the budget's MEANING was: the whole point is to credit only time the provider actually said it was parked. A pause is now closed as soon as its own reported window has elapsed — checked on every pause signal and at the deadline — so credit can only ever reflect provider-stated park time. Verified: 4 x 5s throttles spread over 40 min now credit 140s (the reported windows incl. slack), not 40 min. Also from the same review: - Floor each grant at MIN_EXTENSION_GRANT_MS (1s). A deadline landing ~1ms after a pause opened would otherwise grant ~1ms at a time and re-arm the timer millions of times across a long park. Never exceeds the remaining cap, so the worst-case bound is unchanged. - `describe()` now reports a stale pause as `expired` rather than `still open`, so the error text cannot misreport a long-dead throttle. Independently re-derived and confirmed by the same review: worst-case total wait is timeoutMs + SUBAGENT_MAX_PAUSE_EXTENSION_MS (2h45m at the default); no child-authored event can grant extension; and the no-pause path is byte-for-byte identical to before. * test(cli): freeze the clock so the quota countdown assertion stops racing the runner The 'prints the quota line with its deadline once the binding window is hot' test builds a deadline of exactly Date.now() + 12*60_000 and asserts the rendered footer contains 'resets in 12m'. resetClause() in quota-footer.ts recomputes msLeft against a fresh now captured later, at render time, and formatResetCountdown() floors msRemaining/60_000 to whole minutes. Any wall-clock elapsed time between snapshot and render can push msLeft to 719_999ms, which floors to 11m instead of 12m — an exact-floor boundary assertion racing the test runner's speed. Freeze the clock in this describe block's beforeEach/afterEach so the deadline arithmetic is exact instead of racing the runner. This flake pre-existed on main and is unrelated to this PR's actual changes; the identical fix was already verified green on the sibling PR #793 branch. * feat(subagent): emit pause_extension_granted witness event on each ceiling grant PauseAwareCeiling granted bounded wall-clock extensions entirely off-observation: the only record that a fork's budget had been moved was the terminal timeout error string. Reconstructing "the child got N extensions totaling Xms across this park" required the error alone — exactly the forensics gap the next incident would need. Add a pause_extension_granted session_phase witness event, emitted fire-and-forget from the handle each time PauseAwareCeiling.onDeadline grants a non-zero extension. The ceiling exposes an onGrant observer (so it stays decoupled from the trace layer and pure/testable); the handle wires a callback that emits the event carrying grantMs, totalGrantedMs, remainingCapMs, grantCount, subagentId, and the pause description. - trace: add pause_extension_granted to SessionPhaseName union + Zod enum + parity-test map (the union<->schema parity test enforces all three move together). - pause-ceiling: new PauseExtensionGrantInfo interface + 3rd ctor param onGrant; invoked after grantedMs/grantCount update, wrapped so an observer fault can never strand the wait. No-pause path still grants nothing, never invokes onGrant (pinned by a new test). - handle: pass the observer, closing over traceWriter + this.id; mirrors the idle_watchdog_fired emit pattern. Tests: +2 unit tests (onGrant invoked with correct details on a grant; onGrant NOT invoked when no pause observed). pause-ceiling 16, session-phase 48, idle-watchdog 20 (unchanged), handle 6 — all green.
What
Adds a progress-aware idle watchdog to forked subagent turns. It fires when a child produces no observable
OutputEventfor an idle window (default 8 min,AFK_SUBAGENT_IDLE_TIMEOUT_MS), distinct from the blunt 45-min wall-clock (SUBAGENT_DEFAULT_TIMEOUT_MS). On fire it aborts the child's existing controller, so the current timeout→partial-output contract applies unchanged — the parent gets{ status: 'failed', error: IdleWatchdogError, partialOutput }instead of hanging.IdleWatchdog(src/agent/subagent/idle-watchdog.ts): one.unref()'d timer;onEventre-arms on eachOutputEvent; extends the deadline during recognized OAuthpaused/resumedwindows so a legitimate backoff never false-fires;dispose()on completion.IdleWatchdogError extends TimeoutError(src/utils/errors.ts) → the existinginstanceof TimeoutErrorclassification needs zero change; idle-fires classify asfailed(own-budget expiry), notcancelled.idle_watchdog_firedadded in lockstep to theSessionPhaseNameunion and the Zod enum, plus a union↔schema parity test.AFK_SUBAGENT_IDLE_TIMEOUT_MS(env-registry regenerated), per-forkconfig.idleTimeoutMs,0disables (escape hatch, matches every other timeout). Both bounds run concurrently via the existing race; the idle watchdog is the tighter first-to-fire, the wall-clock stays the un-resettable ceiling.Anti-gaming property: the only thing that resets the clock is a real
OutputEventfrom the provider loop — there is no caller-facing heartbeat to spoof.Why
A FULL
/reviewrun hung ~43 min producing zero output before the operator aborted. Root cause was not unbounded fan-out (round counts were already capped atREADONLY_AGENT_MAX_TOOL_USE_ITERATIONS = 50) — it was a child's model call stalling under HTTP 429 / provider throttling with no detection. The only bound on the whole child turn was the 45-min wall-clock. A code note atsubagent.tsalready anticipated this fix verbatim.Round-caps bound work done; wall-clock bounds time elapsed. Neither bounds time since the child last did anything observable — the missing signal that distinguishes "healthy child grinding for 40 min" from "child stalled at minute 2." This PR adds that signal.
Sibling load-reduction mitigations (#669 and the private mirror) lowered how often this class of stall triggers but explicitly disclaimed fixing the hang and named this work as the real fix. This is that fix.
Scope boundaries (deliberate)
3 × 120s + jitter ≈ 363s. 8 min (480s) clears that with ~2 min margin, so a transient backoff can never false-fire. Tightens toward ~5 min once the follow-up lands. Still 5.6× tighter than the wall-clock.retry-layer.tsto yield arate_limitOutputEventat wait-start). This PR is self-contained and does not depend on it.Test / verification
pnpm lint(tsc --noEmit, strict) — PASSpnpm scan:env:check— in sync (136 vars)pnpm audit:env:check— 0 violationspnpm test— 12753 passed / 14 skipped / 0 failed (690 files). The 8-min default is a behavioral change to every fork omittingidleTimeoutMs; two pre-existing wall-clock tests were isolated withidleTimeoutMs: 0and no other fork-based test regressed.idle-watchdog.test.ts(16 tests: arm/fire/reset/extend(paused)/collapse(resumed)/dispose/0-disable) + 10 newsubagent.test.tscases (no-event child idle-firesfailedbefore wall-clock; streaming child never cut off; paused→resumed→completes; env override + invalid-fallback;partialOutputpopulated).Additive, backward-compatible; opt-out via
idleTimeoutMs: 0/AFK_SUBAGENT_IDLE_TIMEOUT_MS=0; no migration. Rebased cleanly onto currentmain(only conflict was the generateddocs/env-registry.md, resolved by regeneration).Spec
Implemented from a shadow-verified spec (3 load-bearing claims independently re-derived from source; operator decisions locked). Follow-ups tracked there: daemon top-level idle watchdog; transient-429 stream signal; explicit SDK
maxRetries/timeoutinauth.ts.