Treat thinking as progress in stream timeout; trim replayed history #67

Merged
ryan merged 1 commits from fix/stream-stall-timeout into main 2026-10-12 19:14:31 -04:00
Owner

Problem

Long turns failed with "Simba took too long to respond" while the model was still generating. llama-server showed stop: cancel task at n_gen = 1287 (~30 t/s), with n_tokens = 27262 on a 32k slot.

Two causes:

  1. The 30 s "TTFT" guard ran from the turn's first model call to the first answer token. Thinking, tool execution, and the second call's prefill all counted against it, so any tool call plus some reasoning on a long conversation was cancelled.
  2. Replayed history was huge. LangGraph replays earlier tool results at full size (whole search hits, full notes, 12k-char attachments, images). TOOL_RESULT_MAX_CHARS only applied to the Postgres copy.

Fix

  • Stall timeout instead of TTFT: the turn is abandoned only when an in-flight model call produces no output for TTFT_TIMEOUT_SECONDS.
    • Any chunk resets the clock, thinking and empty chunks included.
    • Each model call starts a fresh clock.
    • Tool time between calls doesn't count.
    • Same env var and default (30), so no config change is needed.
  • blueprints/conversation/context.py trim_history:
    • Earlier turns' tool results and user messages are capped at 4000 chars, attachments included.
    • Earlier images become a [image from an earlier message] placeholder.
    • The current turn is untouched.
    • The 12-message window no longer starts with orphaned ToolMessages.
  • Observability: stream_request logs now include model_calls (per call: prefill_ms, ms, prompt_tokens, output_tokens) and max_prompt_tokens. Tokens come from stream_usage=True on the llama client.

Caveat

llama-server sends nothing during prompt prefill, so a cold prefill of a very long prompt still counts as silence. Trimming should keep prompts well below that; prefill_ms in the logs will show if it ever gets close.

Test plan

  • pytest tests/ -q: 284 passed. New tests:
    • long thinking isn't a stall
    • slow tools between calls don't count
    • a silent call is a stall
    • per-call token logging
    • history trimming (caps, images, orphaned tool results, originals unmutated)
  • After deploy: re-run a long, tool-heavy conversation; check make logs | grep stream_request for max_prompt_tokens and prefill_ms

🤖 Generated with Claude Code

## Problem Long turns failed with "Simba took too long to respond" while the model was still generating. llama-server showed `stop: cancel task` at `n_gen = 1287` (~30 t/s), with `n_tokens = 27262` on a 32k slot. Two causes: 1. **The 30 s "TTFT" guard** ran from the turn's *first* model call to the first *answer* token. Thinking, tool execution, and the second call's prefill all counted against it, so any tool call plus some reasoning on a long conversation was cancelled. 2. **Replayed history was huge.** LangGraph replays earlier tool results at full size (whole search hits, full notes, 12k-char attachments, images). `TOOL_RESULT_MAX_CHARS` only applied to the Postgres copy. ## Fix - **Stall timeout instead of TTFT:** the turn is abandoned only when an *in-flight* model call produces no output for `TTFT_TIMEOUT_SECONDS`. - Any chunk resets the clock, thinking and empty chunks included. - Each model call starts a fresh clock. - Tool time between calls doesn't count. - Same env var and default (30), so no config change is needed. - **`blueprints/conversation/context.py` `trim_history`:** - Earlier turns' tool results and user messages are capped at 4000 chars, attachments included. - Earlier images become a `[image from an earlier message]` placeholder. - The current turn is untouched. - The 12-message window no longer starts with orphaned `ToolMessage`s. - **Observability:** `stream_request` logs now include `model_calls` (per call: `prefill_ms`, `ms`, `prompt_tokens`, `output_tokens`) and `max_prompt_tokens`. Tokens come from `stream_usage=True` on the llama client. ## Caveat llama-server sends nothing during prompt prefill, so a cold prefill of a very long prompt still counts as silence. Trimming should keep prompts well below that; `prefill_ms` in the logs will show if it ever gets close. ## Test plan - [x] `pytest tests/ -q`: 284 passed. New tests: - long thinking isn't a stall - slow tools between calls don't count - a silent call is a stall - per-call token logging - history trimming (caps, images, orphaned tool results, originals unmutated) - [ ] After deploy: re-run a long, tool-heavy conversation; check `make logs | grep stream_request` for `max_prompt_tokens` and `prefill_ms` 🤖 Generated with [Claude Code](https://claude.com/claude-code)
ryan added 1 commit 2026-10-12 19:14:23 -04:00
The 30s time-to-first-token guard measured from the turn's first model call
to the first answer token, so thinking, tool execution and the second call's
prefill all counted against it. Long reasoning on a long conversation was
cancelled mid-generation (llama-server: stop: cancel task at n_gen=1287).

- stream_query: the timeout now fires only when an in-flight model call goes
  silent for TTFT_TIMEOUT_SECONDS. Any chunk (thinking or empty) resets the
  clock, each model call starts a fresh one, and time spent in tools between
  calls doesn't count.
- Trim replayed history (blueprints/conversation/context.py): tool results
  and user messages from earlier turns are capped at 4000 chars (attachments
  included) and their images replaced by a placeholder. The current turn is
  untouched. The window no longer starts with orphaned ToolMessages.
- Log per-call prefill time, duration and prompt/output tokens
  (stream_usage=True) plus max_prompt_tokens in the stream_request line.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
ryan merged commit 9e993f420f into main 2026-10-12 19:14:31 -04:00
Sign in to join this conversation.
No Reviewers
No Label
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: ryan/simbarag#67