Sirens Deep fails 20% of turns: tool-inflated context exhausts the fixed completion budget #86

Closed
opened 2026-08-10 23:23:22 +00:00 by coilyco-ops · 2 comments
Member

Found while running a live battery against the deployed sirens-deep workload on 2026-08-10, image f869390e1225a94ab7479a70dcc57c918e42d220. Predates the merge of #82, so re-measure against current main before fixing.

Symptom

POST /v1/turn returns HTTP 502 with {"reply":"there was an error generating your reply","error":"turn failed"}.

Across 75 generated turns in a 13 minute window:

  • overall - 60 ok, 15 failed, 20.0% error rate
  • trivial - 22 turns, 0 failed
  • identity - 14 turns, 0 failed
  • short - 18 turns, 1 failed
  • conversational - 14 turns, 8 failed, 57%
  • reasoning-heavy - 7 turns, 6 failed, 86%

The failure rate is inverted against usefulness. Deep passes every trivial and identity check and fails hardest on ordinary member questions like "I just joined the server and I am a bit lost, where should I start?"

Mechanism

Confirmed from Agent Proxy capture bodies, not inferred.

A passing turn:

prompt_tokens: 6161, completion_tokens: 72, finish_reason: "stop"

A failing turn:

prompt_tokens: 41753, completion_tokens: 900, finish_reason: "length", content: ""
prompt_tokens: 47215, completion_tokens: 900, finish_reason: "length", content: ""

The sequence is:

  1. The turn triggers MCP tool calls. One capture shows finish_reason: "tool_calls" with four parallel Eco calls (get_climate, get_government, get_economy, get_civics).
  2. Tool results reinject into context and inflate the prompt from about 6k to about 47k tokens.
  3. The model spends the entire fixed max_tokens: 900 completion budget on reasoning_content and emits empty content with finish_reason: "length".
  4. model.response.repair retries once, hits the same wall, and the turn fails with turn.stage.failed / error_type=model_failed.

Over a 30 minute window, captured responses split 59 stop, 20 length, 19 tool_calls.

So the trigger is not question difficulty. It is any question that makes Deep reach for a tool.

Why nothing upstream reports it

Agent Proxy and LiteLLM both log outcome=ok for every one of these. A truncated completion is a valid response at the transport layer. The only error signal is inside the worker, which is why the Agent Proxy service view showed 1 error while sirens-deep showed 11 over the same window.

Worth considering

Raising max_tokens alone treats the symptom, because a 47k prompt will find the new ceiling too. Options that address the cause:

  • Bound tool-result size before reinjection.
  • Cap the number of parallel tool calls per round.
  • Separate the reasoning budget from the answer budget, if the backend exposes that.
  • Treat finish_reason: length with empty content as a retryable condition with a raised budget rather than a repeat at the same budget.

Secondary observation

Latency degrades sharply under even 4-way concurrency. Single-threaded turns ran at p50 under 2s. Under the burst, successful turns reached p50 5.48s, p95 25.85s, and max 43.44s. A 43s reply is past useful for a chat bot regardless of the failure above.

Reproduce

curl -sS -X POST http://sirens-deep:8080/v1/turn -H 'Content-Type: application/json' \
  -d '{"content":"I just joined the server and I am a bit lost. Where should I start?"}'

Evidence is on the Sirens Deep Console dashboard on ser8 SigNoz.

Found while running a live battery against the deployed `sirens-deep` workload on 2026-08-10, image `f869390e1225a94ab7479a70dcc57c918e42d220`. Predates the merge of #82, so re-measure against current `main` before fixing. ## Symptom `POST /v1/turn` returns HTTP 502 with `{"reply":"there was an error generating your reply","error":"turn failed"}`. Across 75 generated turns in a 13 minute window: * **overall** - 60 ok, 15 failed, 20.0% error rate * **trivial** - 22 turns, 0 failed * **identity** - 14 turns, 0 failed * **short** - 18 turns, 1 failed * **conversational** - 14 turns, **8 failed, 57%** * **reasoning-heavy** - 7 turns, 6 failed, 86% The failure rate is inverted against usefulness. Deep passes every trivial and identity check and fails hardest on ordinary member questions like "I just joined the server and I am a bit lost, where should I start?" ## Mechanism Confirmed from Agent Proxy capture bodies, not inferred. A passing turn: ``` prompt_tokens: 6161, completion_tokens: 72, finish_reason: "stop" ``` A failing turn: ``` prompt_tokens: 41753, completion_tokens: 900, finish_reason: "length", content: "" prompt_tokens: 47215, completion_tokens: 900, finish_reason: "length", content: "" ``` The sequence is: 1. The turn triggers MCP tool calls. One capture shows `finish_reason: "tool_calls"` with four parallel Eco calls (`get_climate`, `get_government`, `get_economy`, `get_civics`). 2. Tool results reinject into context and inflate the prompt from about 6k to about 47k tokens. 3. The model spends the entire fixed `max_tokens: 900` completion budget on `reasoning_content` and emits empty `content` with `finish_reason: "length"`. 4. `model.response.repair` retries once, hits the same wall, and the turn fails with `turn.stage.failed` / `error_type=model_failed`. Over a 30 minute window, captured responses split 59 `stop`, 20 `length`, 19 `tool_calls`. **So the trigger is not question difficulty. It is any question that makes Deep reach for a tool.** ## Why nothing upstream reports it Agent Proxy and LiteLLM both log `outcome=ok` for every one of these. A truncated completion is a valid response at the transport layer. The only error signal is inside the worker, which is why the Agent Proxy service view showed 1 error while `sirens-deep` showed 11 over the same window. ## Worth considering Raising `max_tokens` alone treats the symptom, because a 47k prompt will find the new ceiling too. Options that address the cause: * Bound tool-result size before reinjection. * Cap the number of parallel tool calls per round. * Separate the reasoning budget from the answer budget, if the backend exposes that. * Treat `finish_reason: length` with empty `content` as a retryable condition with a raised budget rather than a repeat at the same budget. ## Secondary observation Latency degrades sharply under even 4-way concurrency. Single-threaded turns ran at p50 under 2s. Under the burst, successful turns reached p50 5.48s, p95 25.85s, and max 43.44s. A 43s reply is past useful for a chat bot regardless of the failure above. ## Reproduce ``` curl -sS -X POST http://sirens-deep:8080/v1/turn -H 'Content-Type: application/json' \ -d '{"content":"I just joined the server and I am a bit lost. Where should I start?"}' ``` Evidence is on the `Sirens Deep Console` dashboard on ser8 SigNoz.
Author
Member

The failure-rate half is fixed on main by #100.

The diagnosis in this issue was exactly right, and it turned out the runtime could not even observe the condition: finish_reason was never read from the response, so a truncated completion and a finished-but-empty one were indistinguishable. That is why the repair retried at the same budget. Capturing it is the smallest part of the fix and the part that made the rest possible.

Two bounds landed, matching the "address the cause" options listed here:

  • Tool results are capped before re-injection, which is the Bound tool-result size before reinjection option. Only the copy entering the prompt is bounded and the model sees a truncation marker. The full result is kept for grounding validation, so bounding cannot make the runtime accept an action claim it should reject.
  • The completion budget escalates on a completion that is both truncated and empty, from 900 to a cap of 3600 across two raises, then fails with an error naming the truncation. This is the Treat finish_reason: length with empty content as a retryable condition with a raised budget option.

Raising alone would have treated the symptom, since a larger prompt finds the new ceiling too. Truncated output that is not empty is a usable answer and does not raise, which is covered by its own test.

Each half is negative-tested: disabling the escalation fails both budget tests, and disabling the bound fails the tool-result test.

Contract in docs/sirens-echo-budget.md.

Not closing. The secondary observation in this issue is unaddressed: latency degrading under 4-way concurrency, p50 5.48s, p95 25.85s, max 43.44s. That is a separate concern from the failure rate, and it wants fresh measurement against current main rather than a fix, because admission control and the serialized turn path both changed since those numbers were taken. Worth re-running the battery and either closing this or splitting the latency observation into its own issue.

The failure-rate half is fixed on `main` by https://forgejo.coilysiren.me/coilyco-gaming/sirens-echo/pulls/100. The diagnosis in this issue was exactly right, and it turned out the runtime could not even observe the condition: `finish_reason` was never read from the response, so a truncated completion and a finished-but-empty one were indistinguishable. That is why the repair retried at the same budget. Capturing it is the smallest part of the fix and the part that made the rest possible. Two bounds landed, matching the "address the cause" options listed here: * **Tool results are capped before re-injection**, which is the `Bound tool-result size before reinjection` option. Only the copy entering the prompt is bounded and the model sees a truncation marker. The full result is kept for grounding validation, so bounding cannot make the runtime accept an action claim it should reject. * **The completion budget escalates** on a completion that is both truncated and empty, from 900 to a cap of 3600 across two raises, then fails with an error naming the truncation. This is the `Treat finish_reason: length with empty content as a retryable condition with a raised budget` option. Raising alone would have treated the symptom, since a larger prompt finds the new ceiling too. Truncated output that is not empty is a usable answer and does not raise, which is covered by its own test. Each half is negative-tested: disabling the escalation fails both budget tests, and disabling the bound fails the tool-result test. Contract in `docs/sirens-echo-budget.md`. **Not closing.** The secondary observation in this issue is unaddressed: latency degrading under 4-way concurrency, p50 5.48s, p95 25.85s, max 43.44s. That is a separate concern from the failure rate, and it wants fresh measurement against current `main` rather than a fix, because admission control and the serialized turn path both changed since those numbers were taken. Worth re-running the battery and either closing this or splitting the latency observation into its own issue.
Author
Member

Re-measure request, with what landed since

The issue says to re-measure against current main before fixing. Two of the four options it lists are already implemented, so a re-measure would be measuring a different system than the one that produced the 20 percent.

Bound tool-result size before reinjection - done. boundToolResult in proxy.go caps one result at maxToolResultBytes (8 KB), walks back to a rune boundary, appends a truncation marker, and logs mcp.tool.result.bounded. The full result is retained for grounding, so the bound cannot make the runtime accept a claim it should reject.

Treat finish_reason: length with empty content as retryable with a raised budget - done. chatChoice.truncated() requires length and empty content and no tool calls, then the budget escalates 900 to 1800 to 3600 across budgetRaisesAllowed raises before failing with an error naming the truncation. Truncated-but-non-empty output is a usable answer and does not raise.

Both are documented in docs/sirens-echo-budget.md.

Cap the number of parallel tool calls per round - not implemented. The loop executes every call in message.ToolCalls for a round.

Separate the reasoning budget from the answer budget - not implemented, and depends on the backend exposing it.

The gap the two landed bounds leave

The 8 KB cap is per result, and there is no cumulative bound. Four parallel Eco calls can still add 32 KB in one round, and maxToolRounds is 6, so the ceiling across a turn is roughly 192 KB of tool text on top of the base prompt. That is far better than unbounded but it is not a bound on the thing the issue actually measured, which was total prompt size.

If a re-measure still shows truncation, a cumulative per-turn reinjection budget is the next mechanism, not a larger completion budget.

Adjacent, landed today

cc82ba7 bounds one MCP tool call at 45 seconds. Previously a tool call inherited only the turn budget, so a hung server spent all of it. That is a latency fix rather than a token fix, but it bears on the secondary observation about p95 25.85s and max 43.44s: at least one contributor to that tail could previously run to 180s.

Next owner

Ops for the re-measure, since it needs the live workload and the Sirens Deep Console dashboard. The reproduce command in the issue still applies. Return the split by category and the prompt_tokens on any failing turn, and if truncation persists I will implement the cumulative bound.

## Re-measure request, with what landed since The issue says to re-measure against current `main` before fixing. Two of the four options it lists are already implemented, so a re-measure would be measuring a different system than the one that produced the 20 percent. **Bound tool-result size before reinjection** - done. `boundToolResult` in `proxy.go` caps one result at `maxToolResultBytes` (8 KB), walks back to a rune boundary, appends a truncation marker, and logs `mcp.tool.result.bounded`. The full result is retained for grounding, so the bound cannot make the runtime accept a claim it should reject. **Treat `finish_reason: length` with empty content as retryable with a raised budget** - done. `chatChoice.truncated()` requires `length` *and* empty content *and* no tool calls, then the budget escalates 900 to 1800 to 3600 across `budgetRaisesAllowed` raises before failing with an error naming the truncation. Truncated-but-non-empty output is a usable answer and does not raise. Both are documented in `docs/sirens-echo-budget.md`. **Cap the number of parallel tool calls per round** - not implemented. The loop executes every call in `message.ToolCalls` for a round. **Separate the reasoning budget from the answer budget** - not implemented, and depends on the backend exposing it. ## The gap the two landed bounds leave The 8 KB cap is per result, and there is no cumulative bound. Four parallel Eco calls can still add 32 KB in one round, and `maxToolRounds` is 6, so the ceiling across a turn is roughly 192 KB of tool text on top of the base prompt. That is far better than unbounded but it is not a bound on the thing the issue actually measured, which was total prompt size. If a re-measure still shows truncation, a cumulative per-turn reinjection budget is the next mechanism, not a larger completion budget. ## Adjacent, landed today cc82ba7 bounds one MCP tool call at 45 seconds. Previously a tool call inherited only the turn budget, so a hung server spent all of it. That is a latency fix rather than a token fix, but it bears on the secondary observation about p95 25.85s and max 43.44s: at least one contributor to that tail could previously run to 180s. ## Next owner Ops for the re-measure, since it needs the live workload and the Sirens Deep Console dashboard. The reproduce command in the issue still applies. Return the split by category and the `prompt_tokens` on any failing turn, and if truncation persists I will implement the cumulative bound.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
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
coilyco-gaming/sirens-echo#86
No description provided.