A reset upstream stream drops the turn into a silent non-streaming fallback, which the idle watchdog then kills at 900s #276

Merged

toasterson merged 1 commit from claude/wi-019faa3e-a-reset-upstream-stream-drops-the-turn-i into main 2026-07-29 18:16:40 +00:00

Conversation 0 Commits 1 Files changed 2 +137 -20

toasterson commented 2026-07-29 16:59:11 +00:00

Owner

Copy link

Anima work item 019faa3e-5966-7d22-923d-251ae96b6e30.

The chain, measured end to end on 2026-07-28 (workspace tecton, glm-5.2 via ollama.com)

time (UTC)	event
19:05:23	session starts; 33 shell_exec tool calls in 90s, inter-event gaps 3–19s
19:07:16	last narrative delta — the idle watchdog's clock starts here
19:07:37	WARN agentic_chat: streaming chat failed (chat backend "ollama" turn failed: Ollama server unreachable at https://ollama.com/api/chat: Network Error: Connection reset by peer (os error 104)); falling back to non-streaming agent_id="tecton"
19:07:37 → 19:22:16	zero messages emitted — the non-streaming path has no deltas by construction
19:22:16	watchdog fires: idle_secs=900 last_step="narrative" last_step_age_secs=900 stop_reason=Refusal, and the complete assistant message lands in the same second

Three stalls with this identical signature inside five minutes.

Two defects, one visible symptom

1. The fallback is a liveness black hole. chat_with_tools_streaming failing drops the round into chat_with_tools (src/agent/agentic_chat.rs:493-506). That path emits nothing until the whole response is complete — the code's own comment says so: "in which case nothing was streamed and we emit the result ourselves". So any long response after a stream reset is guaranteed to trip the idle watchdog, no matter how healthy the model is. The turn is then killed at the moment its answer arrives, and all the work in it is discarded.

The tracing::warn! on that path goes to the daemon log only — it is not a sink.emit, so it does not reset the watchdog and the operator sees nothing in the thread.

2. The upstream stream is being reset mid-generation. Connection reset by peer (os error 104) against https://ollama.com/api/chat on a long-lived streaming request. Not a quota or provider-health problem: the ollama.com account was at 43.5% of its 5h window, and in the same period the opencode lane — same API key, same model — ran 623 events at a 2s cadence. The distinguishing factor is request duration: tecton's generations are long enough for something (provider, or an intermediary) to drop the connection; opencode's finish first.

Ask

1. Make the fallback observable and alive. On entering the non-streaming fallback, sink.emit a System message naming the transport error. That resets the idle timer, puts the cause in the thread, and turns a silent 15-minute death into a visible one-line degradation.
2. Prefer a streaming retry over a silent downgrade. A reset connection is usually transient; retry the stream (bounded, with backoff) before abandoning liveness for the whole round.
3. Make the watchdog measure transport liveness, not emitted messages. Reset it on any chunk received from the provider, so "streaming something that yields no delta" is distinguishable from "the provider has gone silent". This is the general fix — it also covers tool-call payloads, which Ollama accumulates rather than streaming (src/agent/ollama.rs:519-521).
4. Investigate the resets separately. Capture the request duration at reset, check keep_alive, and determine whether an intermediary or ollama.com itself is dropping long streams. If it is duration-bound, that is a hard ceiling on how long any single akh turn can generate.

Notes

• reasoning_effort = "high" was set on tecton the same day and is a large, separate win (first useful step 140s → 8s; avg gap 123s → 9s; 33 tool calls in the first 90s vs 1 thought). It does not address this defect — all three stalls above happened with it enabled.
• Diagnosis was only possible after deploying 9da2ea8 ("Turns die quietly"), which added last_step to the stall line and StopReason::Refusal. The daemon had been running an image built 2h before that commit.
• Beware when investigating: docker logs only retains the current container's output. An earlier grep for these fallback warnings returned zero purely because the container had just been recreated.

Anima work item `019faa3e-5966-7d22-923d-251ae96b6e30`. ## The chain, measured end to end on 2026-07-28 (workspace `tecton`, glm-5.2 via ollama.com) | time (UTC) | event | |---|---| | 19:05:23 | session starts; 33 `shell_exec` tool calls in 90s, inter-event gaps 3–19s | | 19:07:16 | last `narrative` delta — the idle watchdog's clock starts here | | **19:07:37** | `WARN agentic_chat: streaming chat failed (chat backend "ollama" turn failed: Ollama server unreachable at https://ollama.com/api/chat: Network Error: Connection reset by peer (os error 104)); falling back to non-streaming agent_id="tecton"` | | 19:07:37 → 19:22:16 | **zero messages emitted** — the non-streaming path has no deltas by construction | | 19:22:16 | watchdog fires: `idle_secs=900 last_step="narrative" last_step_age_secs=900 stop_reason=Refusal`, and the complete assistant message lands in the same second | Three stalls with this identical signature inside five minutes. ## Two defects, one visible symptom **1. The fallback is a liveness black hole.** `chat_with_tools_streaming` failing drops the round into `chat_with_tools` (`src/agent/agentic_chat.rs:493-506`). That path emits nothing until the whole response is complete — the code's own comment says so: *"in which case nothing was streamed and we emit the result ourselves"*. So **any** long response after a stream reset is guaranteed to trip the idle watchdog, no matter how healthy the model is. The turn is then killed at the moment its answer arrives, and all the work in it is discarded. The `tracing::warn!` on that path goes to the daemon log only — it is not a `sink.emit`, so it does not reset the watchdog and the operator sees nothing in the thread. **2. The upstream stream is being reset mid-generation.** `Connection reset by peer (os error 104)` against `https://ollama.com/api/chat` on a long-lived streaming request. Not a quota or provider-health problem: the ollama.com account was at 43.5% of its 5h window, and in the same period the opencode lane — *same API key, same model* — ran 623 events at a 2s cadence. The distinguishing factor is request duration: tecton's generations are long enough for something (provider, or an intermediary) to drop the connection; opencode's finish first. ## Ask 1. **Make the fallback observable and alive.** On entering the non-streaming fallback, `sink.emit` a `System` message naming the transport error. That resets the idle timer, puts the cause in the thread, and turns a silent 15-minute death into a visible one-line degradation. 2. **Prefer a streaming retry over a silent downgrade.** A reset connection is usually transient; retry the stream (bounded, with backoff) before abandoning liveness for the whole round. 3. **Make the watchdog measure transport liveness, not emitted messages.** Reset it on any chunk received from the provider, so "streaming something that yields no delta" is distinguishable from "the provider has gone silent". This is the general fix — it also covers tool-call payloads, which Ollama accumulates rather than streaming (`src/agent/ollama.rs:519-521`). 4. **Investigate the resets separately.** Capture the request duration at reset, check `keep_alive`, and determine whether an intermediary or ollama.com itself is dropping long streams. If it is duration-bound, that is a hard ceiling on how long any single akh turn can generate. ## Notes - `reasoning_effort = "high"` was set on tecton the same day and is a large, separate win (first useful step 140s → 8s; avg gap 123s → 9s; 33 tool calls in the first 90s vs 1 thought). It does **not** address this defect — all three stalls above happened with it enabled. - Diagnosis was only possible after deploying `9da2ea8` ("Turns die quietly"), which added `last_step` to the stall line and `StopReason::Refusal`. The daemon had been running an image built 2h before that commit. - Beware when investigating: `docker logs` only retains the current container's output. An earlier grep for these fallback warnings returned zero purely because the container had just been recreated.

toasterson added 1 commit 2026-07-29 16:59:11 +00:00

A reset upstream stream drops the turn into a silent non-streaming fallback, which the idle watchdog then kills at 900s ... 302fb3478a

Anima implementation session.

toasterson changed title from WIP: A reset upstream stream drops the turn into a silent non-streaming fallback, which the idle watchdog then kills at 900s to A reset upstream stream drops the turn into a silent non-streaming fallback, which the idle watchdog then kills at 900s 2026-07-29 17:37:38 +00:00

toasterson merged commit 222b2f123b into main 2026-07-29 18:16:40 +00:00

toasterson referenced this pull request from a commit 2026-07-29 18:16:42 +00:00

Merge pull request #276: Make the silent non-streaming fallback observable and alive

toasterson referenced this pull request 2026-08-15 21:41:55 +00:00

Sessions on one akh still serialise on the per-workspace Agent mutex, so parallel ACP sessions remain impossible #318

Sign in to join this conversation.

Reviewers

No reviewers

Labels

Clear labels

No items

No labels

Milestone

Clear milestone

No items

No milestone

Projects

Clear projects

No items

No project

Assignees

Clear assignees

No assignees

1 participant

Notifications

Subscribe

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

toasterson/akh-medu!276

No description provided.