Repository navigation
fix(*): send thought tokens as one frame and name what failed a turn - #571
Conversation
Two halves of one incident. A design run that stalled on the model stream reached its parent as `turn_failed (code -32099)` with no cause, and the parent restarted it as an npm crash. Behind that, the same run had put 58,675 `agent_thought_chunk` frames on the wire, one per token, averaging 5.7 characters; every frame is a blocking write on the client's pipe, and a client that stopped reading held the server on that write. The ACP translator now holds consecutive thought chunks of a session and sends them as one chunk when a 200ms window closes, when 512 characters are held, or when anything that has to follow them arrives -- a chunk of the answer, a tool call, a latch, the turn's ending, the session's release or the connection closing. Measured on the incident's frame log, this replays to 4,333 frames; a 100ms window gives 6,210 and a 1,024-character cap changes nothing, so the window is what does the work. Order on the wire is kept: held text always precedes what released it. The failure event carried `str(exc)`, which asyncio's TimeoutError leaves empty. It now carries the exception's class and its message when it has one (`ValueError: boom`, `TimeoutError`), and the per-chunk idle stall in the LiteLLM stream raises StreamIdleTimeoutError, a TimeoutError whose message says how long the stream was silent and which bound decided it, so every `except TimeoutError` arm and retry verdict keeps applying. Co-authored-by: Claude (claude-fable-5-1) <noreply@anthropic.com>
The mutation that removed the flush from end_turn left every test green: the guarantee that held text precedes the prompt response was pinned by nothing. It now has its own test. Co-authored-by: Claude (claude-fable-5-1) <noreply@anthropic.com>
gloryfromca
left a comment
There was a problem hiding this comment.
No blockers; this can merge as far as I am concerned.
Reviewed the full diff and relevant ACP/session callers, provider timeout propagation, scheduler failure handling, and the branch history. I also checked the repository rules and Runtime terminology/architecture guidance, backward compatibility, and the test changes for weakened coverage. The new coalescer preserves ordering at the subscription and prompt-response boundaries, separates sessions and speakers, and flushes on every lifecycle path that can finish or release a turn. The typed idle timeout remains a TimeoutError, while scheduler failures now retain both class and message.
Verification: uv run pytest tests/test_acp_updates.py tests/test_spine_scheduler_lane.py tests/test_litellm_provider_timeout.py -q -n 0 -> 230 passed in 11.11s. git diff --check github/main...HEAD also passed. The documented limitation that writes remain synchronous is an explicit scope boundary; this patch still materially reduces frame pressure without changing the wire schema.
|
Not a blocker. All three changes do what they say, the frozen-tier cost is 1. The new error's message is fed to the classifier's substring matcher, and a configured idle value can flip the bucket
The declared sibling is immune, and the reason is the thing to copy: The smoking gun is the comment on the arm this used to reach,
That parenthesis is the premise, and this PR is what makes it untrue. Nothing 2.
|
|
No blockers; suggestions only, and they are marked inline. This new evidence changes my prior clean stance to nonblocking. I checked all five observations:
Verification rerun: No new inline findings from me; the actionable suggestions are already captured in the numbered comment above. |
|
Not a blocker -- a correction to my own note above, on two points the Point 2's second option is wrong and should not be taken. I wrote "or reuse Point 3 overstated the cap. The comment's claim is that a 1,024-character The other three stand as written. |
Follow-ups from review of the coalescer and the failure text. StreamIdleTimeoutError's message carries the configured idle budget, and classify_error runs its substring branches before the TimeoutError arm, so a budget of 429 read as a rate limit and one of 500 as a server error: the same wrong-cause report the error exists to remove. It is now named by type beside the first-byte bound, before any substring runs, as stream_idle_timeout with the same retry and fallback verdict. describe_failure prefixed the class unconditionally, so an SDK error whose own message opens with its class name stuttered (`APIError: APIError: ...`). The prefix is added only when the message does not already name the class, decided on the text alone: the kernel does not import the provider layer's own prefix rule. The coalescer's flush guard drops two clauses that could never decide it (a latch and a stream-ending error both arrive on an update the first test catches), and gains the two tests the mutation pass showed missing: settling a turn from outside the stream sends the held text, and the window is measured from the first held chunk, so a steady trickle cannot hold it open. The stale "carries only str(exc)" comment in the scheduler and the changelog's omission of the up-to-200ms first-thought latency are corrected. Co-authored-by: Claude (claude-fable-5-1) <noreply@anthropic.com>
|
Thanks, both. All five checked and acted on in b6097ea (same branch, pushed).
Mutation at b6097ea, each alone, control restored between runs (267 tests across Focused suites at this head: |
gloryfromca
left a comment
There was a problem hiding this comment.
No blockers; this can merge as far as I am concerned.
Reviewed the delta from 1d89ce1aff05 and the affected classifier, scheduler, ACP lifecycle paths, callers, tests, history, and author response. I also rechecked the repository rules, Runtime terminology and architecture boundary, backward compatibility, and whether the new tests merely preserved green status. The classifier now identifies the idle timeout by type before substring matching, failure descriptions avoid duplicate class prefixes without importing the provider layer into the kernel, and the simplified thought-flush guard remains equivalent for every current latch and terminal event shape. The previously missing settle and fixed-window behaviors now have direct regression tests; the RPC-wire behavior remains explicitly outside this ACP-scoped change.
Verification on Python 3.12: uv run --frozen --python 3.12 pytest tests/test_acp_updates.py tests/test_spine_scheduler_lane.py tests/test_litellm_provider_timeout.py tests/test_error_classification.py tests/test_agent_loop_stream.py tests/test_cli_agent_commands.py -q -n 0 -> 347 passed in 15.64s. uv run --frozen --python 3.12 lint-imports -> 10 contracts kept, 0 broken. git diff --check github/main...HEAD passed.
…571) ## Summary Two halves of one incident, on 2026-09-20. A Raven-Design run (an ACP sub-agent) stalled on its model stream; the parent conversation was told `turn_failed (code -32099)` and nothing else, diagnosed it as an npm crash and restarted the run. Behind that, the same run had written 58,675 `agent_thought_chunk` frames, one per reasoning token, averaging 5.7 characters. Every frame is a synchronous write plus flush on the client's pipe, so when the client (the gateway, frozen by a synchronous `find`, PR #566) stopped reading, the server blocked on that write too. **Thought chunks are coalesced.** `UpdateTranslator` (the ACP server's outbound sink, `raven/acp/updates.py`) now holds consecutive `thinking.delta` updates per session and sends them as one `agent_thought_chunk` when: - a 200ms window closes (a loop timer, `THOUGHT_COALESCE_WINDOW_S`), or - the held text reaches 512 characters (`THOUGHT_COALESCE_MAX_CHARS`), or - anything that has to follow them arrives: a chunk of the answer, a tool call, a latch or an ending event, the session's release, the turn slot being dropped, or the connection closing. Order on the wire is kept: held text always precedes whatever released it, and a delegated agent's thought (a different `_meta` target) never joins the main agent's held text. The thresholds are measured, not chosen: replaying the incident's frame log, 200ms/512 gives 4,333 frames (13.5x fewer); a 100ms window gives 6,210; a 1,024-character cap changes nothing (4,331), so the window is what does the work. The median gap between consecutive thought frames in that log was 0.34ms, the p90 92ms. `agent_message_chunk` (the answer itself) is not coalesced: a reader watches it stream, and its frame count was 79. **A failed turn names what failed.** (Second round: the class is prefixed only when the message does not already open with it, so an SDK error that names itself does not stutter; and `StreamIdleTimeoutError` is classified by type, as `stream_idle_timeout`, before any substring branch can read the budget in its message as a 429 or a 500.) `Lane._run_turn` built `TurnFailed(error=str(exc))`, and `str()` of asyncio's bare `TimeoutError` is empty, so the ACP translator's `_error` had only the wire message to show. `describe_failure(exc)` now carries the exception class and its message when it has one (`ValueError: boom`, `TimeoutError`). And the stall itself is named at the source: the per-chunk idle `wait_for` in `LiteLLMProvider.chat_stream` raises `StreamIdleTimeoutError(idle=...)`, a `TimeoutError` subclass (so every `except TimeoutError` arm and retry verdict keeps applying, the same argument `FirstByteTimeoutError` makes) whose message reads `the model stream sent nothing for 180s (bound stream_idle_timeout=180s)`. Not changed: the frame writer is still a blocking write on the loop. Fewer frames make the stall far less likely, they do not make it impossible; moving the write off the loop would change the ordering guarantee `UpdateTranslator`'s docstring states and is not attempted here. The other providers' idle watchdogs (the Responses and Anthropic SSE paths) still raise a bare `TimeoutError`; they now surface as `TimeoutError` through `describe_failure` rather than as nothing, and giving them the same message is a follow-up. ## Type - [x] Fix - [ ] Feature - [ ] Docs - [ ] CI / tooling - [ ] Refactor - [ ] Other ## Verification At head b6097ea: ``` uv run pytest tests/test_acp_updates.py tests/test_spine_scheduler_lane.py tests/test_litellm_provider_timeout.py -q -n 0 # 233 passed uv run pytest <24 test files across acp, spine, providers, rpc spine, subagent acp> -q # 1048 passed (before the last test was added) uv run pytest -q --ignore=tests/integration # 23791 passed, 110 skipped at head b6097ea, in a throwaway worktree with COLORTERM=truecolor make lint-python lint-imports lint-types lint-deps # all pass make check-source-language check-large-files # exit 0 (COMMIT_RANGE=origin/main..HEAD) ``` Revert-to-red, each production file (pair) reverted to `origin/main` on its own with the tests kept: ``` raven/acp/updates.py reverted 6 failed raven/spine/scheduler.py reverted 2 failed raven/providers/{first_byte,litellm_provider}.py reverted 1 failed ``` Mutation, each mutant applied alone, control restored between runs: ``` no flush before an update that must follow the thoughts 3 failed window timer never armed 2 failed 512-character cap disabled 1 failed different speakers merged into one chunk 1 failed release_session keeps the held text 1 failed close keeps the held text 1 failed end_turn keeps the held text 1 failed (0 before the second commit added its test) describe_failure drops the class name 2 failed idle stall re-raised as a bare TimeoutError 1 failed control (nothing mutated) 230 passed ``` Second round (267 tests across `test_acp_updates.py`, `test_spine_scheduler_lane.py`, `test_error_classification.py`): ``` the three files reverted to the first-round head 4 failed idle stall classified by substring 3 failed describe_failure always prefixes 1 failed settle_turn keeps the held text 1 failed sliding window (timer re-armed per chunk) 1 failed control 267 passed ``` The two guard clauses the first round's mutation pass showed could not decide the flush (`or result.latch`, `or _ends_the_stream(event)`) were dropped rather than tested; the comment says why. One existing test changed: `test_reasoning_arrives_as_a_thought_chunk` asserted a lone thought went out immediately; it now sends two thoughts and an answer chunk and asserts one thought frame precedes the answer, which is the ordering rule this PR adds. - [x] Relevant tests pass locally - [x] Relevant lint / type checks pass locally - [x] User-facing docs or screenshots are updated when needed (CHANGELOG `Unreleased / Fixed`, two entries) ## Risk User-visible behaviour changes: - An ACP client sees reasoning text arrive in bursts of up to 200ms or 512 characters instead of per token, so the first thought token of a turn arrives up to 200ms later than before. Answer text, tool calls and endings are unchanged and never reordered relative to the thoughts that preceded them. - Every failure event (`error` on the wire, `turn_failed` in ACP) now starts with the exception class, e.g. `ValueError: boom` where it read `boom`. A client matching the old text exactly would need to match the suffix. - The mid-stream idle stall in the LiteLLM path raises `StreamIdleTimeoutError` instead of a bare `TimeoutError`. It is a `TimeoutError`, so `except TimeoutError` behaves as before; `classify_error` names it `stream_idle_timeout` (retryable, fallback) where it used to say `network`, and `_NON_AUTH_HINTS` has no entry for it, so the CLI renders its error line alone, as it does for `first_byte_timeout`. Rollback: revert the squash commit. No stored data or wire schema changes; the coalescer is process-local state. - [x] Security impact considered (held text is the model's own reasoning, already on this channel; `redact` is applied where it was before, in the failure text) - [x] Backward compatibility considered (frame shapes unchanged and schema-validated in the tests; exception hierarchy preserved) - [x] Rollback path is clear for risky changes ## Related Issues N/A --------- Co-authored-by: Claude (claude-fable-5-1) <noreply@anthropic.com>
Summary
Two halves of one incident, on 2026-09-20. A Raven-Design run (an ACP sub-agent) stalled on its model stream; the parent conversation was told
turn_failed (code -32099)and nothing else, diagnosed it as an npm crash and restarted the run. Behind that, the same run had written 58,675agent_thought_chunkframes, one per reasoning token, averaging 5.7 characters. Every frame is a synchronous write plus flush on the client's pipe, so when the client (the gateway, frozen by a synchronousfind, PR #566) stopped reading, the server blocked on that write too.Thought chunks are coalesced.
UpdateTranslator(the ACP server's outbound sink,raven/acp/updates.py) now holds consecutivethinking.deltaupdates per session and sends them as oneagent_thought_chunkwhen:THOUGHT_COALESCE_WINDOW_S), orTHOUGHT_COALESCE_MAX_CHARS), orOrder on the wire is kept: held text always precedes whatever released it, and a delegated agent's thought (a different
_metatarget) never joins the main agent's held text. The thresholds are measured, not chosen: replaying the incident's frame log, 200ms/512 gives 4,333 frames (13.5x fewer); a 100ms window gives 6,210; a 1,024-character cap changes nothing (4,331), so the window is what does the work. The median gap between consecutive thought frames in that log was 0.34ms, the p90 92ms.agent_message_chunk(the answer itself) is not coalesced: a reader watches it stream, and its frame count was 79.A failed turn names what failed. (Second round: the class is prefixed only when the message does not already open with it, so an SDK error that names itself does not stutter; and
StreamIdleTimeoutErroris classified by type, asstream_idle_timeout, before any substring branch can read the budget in its message as a 429 or a 500.)Lane._run_turnbuiltTurnFailed(error=str(exc)), andstr()of asyncio's bareTimeoutErroris empty, so the ACP translator's_errorhad only the wire message to show.describe_failure(exc)now carries the exception class and its message when it has one (ValueError: boom,TimeoutError). And the stall itself is named at the source: the per-chunk idlewait_forinLiteLLMProvider.chat_streamraisesStreamIdleTimeoutError(idle=...), aTimeoutErrorsubclass (so everyexcept TimeoutErrorarm and retry verdict keeps applying, the same argumentFirstByteTimeoutErrormakes) whose message readsthe model stream sent nothing for 180s (bound stream_idle_timeout=180s).Not changed: the frame writer is still a blocking write on the loop. Fewer frames make the stall far less likely, they do not make it impossible; moving the write off the loop would change the ordering guarantee
UpdateTranslator's docstring states and is not attempted here. The other providers' idle watchdogs (the Responses and Anthropic SSE paths) still raise a bareTimeoutError; they now surface asTimeoutErrorthroughdescribe_failurerather than as nothing, and giving them the same message is a follow-up.Type
Verification
At head b6097ea:
Revert-to-red, each production file (pair) reverted to
origin/mainon its own with the tests kept:Mutation, each mutant applied alone, control restored between runs:
Second round (267 tests across
test_acp_updates.py,test_spine_scheduler_lane.py,test_error_classification.py):The two guard clauses the first round's mutation pass showed could not decide the flush (
or result.latch,or _ends_the_stream(event)) were dropped rather than tested; the comment says why.One existing test changed:
test_reasoning_arrives_as_a_thought_chunkasserted a lone thought went out immediately; it now sends two thoughts and an answer chunk and asserts one thought frame precedes the answer, which is the ordering rule this PR adds.Unreleased / Fixed, two entries)Risk
User-visible behaviour changes:
erroron the wire,turn_failedin ACP) now starts with the exception class, e.g.ValueError: boomwhere it readboom. A client matching the old text exactly would need to match the suffix.StreamIdleTimeoutErrorinstead of a bareTimeoutError. It is aTimeoutError, soexcept TimeoutErrorbehaves as before;classify_errornames itstream_idle_timeout(retryable, fallback) where it used to saynetwork, and_NON_AUTH_HINTShas no entry for it, so the CLI renders its error line alone, as it does forfirst_byte_timeout.Rollback: revert the squash commit. No stored data or wire schema changes; the coalescer is process-local state.
redactis applied where it was before, in the failure text)Related Issues
N/A