Prompt trimming orphans tool messages, so every trimmed request is rejected 400 by the backend #113

Closed
opened 2026-08-13 17:17:03 +00:00 by coilyco-ops · 1 comment
Member

🤖 Filed by Claude Code on Kai's behalf.

Trace 1a49200c3bebaed778ef2ac5b79d3d99, 2026-08-13T17:05:52Z (SigNoz: http://ser8:30808/trace/1a49200c3bebaed778ef2ac5b79d3d99).

A sirens-deep Discord turn ran 97.15s across 6 model rounds and delivered nothing — the progress message was deleted and no reply posted (discord.turn.failed, "discord_failure":"no_response").

The trim is the failure

Rounds 0–4 all returned 200. Round 5 is the only request agent-proxy trimmed, and it is the only one that failed.

17:07:07.391  event=request.prompt_trimmed
              original_token_count=48226  final_token_count=45985
              budget_tokens=47104  target_num_ctx=48128  headroom_tokens=1024
              dropped_message_count=5

Round 5 carried message_count=23 — round 4's 17, plus one assistant turn and five steam__get_store_app_details tool results. The trimmer dropped exactly 5 messages. DeepSeek then rejected the payload (litellm pod, 17:07:10.964):

litellm.exceptions.BadRequestError: litellm.BadRequestError: DeepseekException -
{"error":{"message":"Messages with role 'tool' must be a response to a preceding
message with 'tool_calls'","type":"invalid_request_error","param":null,
"code":"invalid_request_error"}}

This is a structural violation of the OpenAI message contract, not a capacity or availability problem. The trimmer selects messages to drop by token budget alone, without preserving the assistant(tool_calls)tool pairing that the dialect requires.

Round-by-round evidence

Round request_bytes message_count Trimmed Result
0 93,022 3 no 200
1 137,507 8 no 200
2 178,347 11 no 200
3 203,678 14 no 200
4 230,531 17 no 200
5 242,923 23 yes, 5 dropped 502 (400 upstream)

The context grows monotonically with tool results across the turn, so the first request to cross budget_tokens=47104 is the first to be trimmed and the first to die. A tool-heavy turn reaches that boundary reliably.

Recurrence: 7 days, 11 trims, and the ratio does not move

Day request.prompt_trimmed events Log lines containing must be a response to a preceding message Ratio
2026-08-11 8 192 24
2026-08-12 1 24 24
2026-08-13 (partial) 2 48 24

Exactly 24 log lines per trim event on all three days. I counted lines, not distinct failures, so treat this as strong correlation rather than proven identity — but the ratio is invariant across three days at three different volumes, and I found no instance of this 400 on a day with no trim.

Read: every trim fails. The feature has, so far as telemetry shows, never once produced a request the backend accepted.

What I am not claiming

I have not read the trimming code — docs/proxy-num-ctx.md exists in this repo but is not in my checkout, and I have no live access here. The mechanism (drop-by-token-budget without group awareness) is inferred from the message arithmetic and the backend's error text, not read from source.

What would change my read: a request.prompt_trimmed event that did not produce this 400. That would mean the trimmer is only sometimes wrong and something else selects the bad case.

Acceptance

  • Trimming drops whole assistant(tool_calls) + corresponding tool message groups atomically, never a partial group.
  • The trimmed message list is validated for tool-call pairing before dispatch, and a payload that cannot be made valid fails locally with a clear reason rather than as an opaque upstream 400.
  • A turn that crosses budget_tokens on a tool-heavy round completes rather than 400s.
  • The 7-day recurrence query above returns trims with no corresponding backend rejection.
  • Sibling filed alongside this: the same trace's 400 is classified as a transport error, retried 3×, and returned to the caller as 502.
  • #106 — upstream non-2xx recorded as a non-error; adjacent status-fidelity problem, different defect.
  • #108 — the other reason a sirens-echo turn dies; unrelated cause, same user-visible outcome.

🤖 Filed by Claude Code on Kai's behalf.

> 🤖 Filed by Claude Code on Kai's behalf. Trace `1a49200c3bebaed778ef2ac5b79d3d99`, 2026-08-13T17:05:52Z (SigNoz: `http://ser8:30808/trace/1a49200c3bebaed778ef2ac5b79d3d99`). A `sirens-deep` Discord turn ran 97.15s across 6 model rounds and delivered **nothing** — the progress message was deleted and no reply posted (`discord.turn.failed`, `"discord_failure":"no_response"`). ## The trim is the failure Rounds 0–4 all returned 200. Round 5 is the only request agent-proxy trimmed, and it is the only one that failed. ``` 17:07:07.391 event=request.prompt_trimmed original_token_count=48226 final_token_count=45985 budget_tokens=47104 target_num_ctx=48128 headroom_tokens=1024 dropped_message_count=5 ``` Round 5 carried `message_count=23` — round 4's 17, plus one assistant turn and **five** `steam__get_store_app_details` tool results. The trimmer dropped exactly 5 messages. DeepSeek then rejected the payload (litellm pod, 17:07:10.964): ``` litellm.exceptions.BadRequestError: litellm.BadRequestError: DeepseekException - {"error":{"message":"Messages with role 'tool' must be a response to a preceding message with 'tool_calls'","type":"invalid_request_error","param":null, "code":"invalid_request_error"}} ``` This is a structural violation of the OpenAI message contract, not a capacity or availability problem. The trimmer selects messages to drop by token budget alone, without preserving the `assistant(tool_calls)` ↔ `tool` pairing that the dialect requires. ## Round-by-round evidence | Round | `request_bytes` | `message_count` | Trimmed | Result | | --- | --- | --- | --- | --- | | 0 | 93,022 | 3 | no | 200 | | 1 | 137,507 | 8 | no | 200 | | 2 | 178,347 | 11 | no | 200 | | 3 | 203,678 | 14 | no | 200 | | 4 | 230,531 | 17 | no | 200 | | 5 | 242,923 | 23 | **yes, 5 dropped** | **502** (400 upstream) | The context grows monotonically with tool results across the turn, so the first request to cross `budget_tokens=47104` is the first to be trimmed and the first to die. A tool-heavy turn reaches that boundary reliably. ## Recurrence: 7 days, 11 trims, and the ratio does not move | Day | `request.prompt_trimmed` events | Log lines containing `must be a response to a preceding message` | Ratio | | --- | --- | --- | --- | | 2026-08-11 | 8 | 192 | 24 | | 2026-08-12 | 1 | 24 | 24 | | 2026-08-13 (partial) | 2 | 48 | 24 | Exactly 24 log lines per trim event on all three days. I counted lines, not distinct failures, so treat this as strong correlation rather than proven identity — but the ratio is invariant across three days at three different volumes, and I found no instance of this 400 on a day with no trim. **Read: every trim fails.** The feature has, so far as telemetry shows, never once produced a request the backend accepted. ## What I am not claiming I have not read the trimming code — `docs/proxy-num-ctx.md` exists in this repo but is not in my checkout, and I have no live access here. The mechanism (drop-by-token-budget without group awareness) is inferred from the message arithmetic and the backend's error text, not read from source. What would change my read: a `request.prompt_trimmed` event that did **not** produce this 400. That would mean the trimmer is only sometimes wrong and something else selects the bad case. ## Acceptance - Trimming drops whole `assistant(tool_calls)` + corresponding `tool` message groups atomically, never a partial group. - The trimmed message list is validated for tool-call pairing before dispatch, and a payload that cannot be made valid fails locally with a clear reason rather than as an opaque upstream 400. - A turn that crosses `budget_tokens` on a tool-heavy round completes rather than 400s. - The 7-day recurrence query above returns trims with no corresponding backend rejection. ## Related - Sibling filed alongside this: the same trace's 400 is classified as a transport error, retried 3×, and returned to the caller as 502. - #106 — upstream non-2xx recorded as a non-error; adjacent status-fidelity problem, different defect. - #108 — the other reason a `sirens-echo` turn dies; unrelated cause, same user-visible outcome. > 🤖 Filed by Claude Code on Kai's behalf.
Author
Member

🤖 Filed by Claude Code on Kai's behalf.

Pulled all 11 request.prompt_trimmed events over 7d. Three corrections and additions to the issue above.

Correction: the dates in my recurrence table are wrong

The day buckets were off by one. Actual event dates:

Day request.prompt_trimmed events
2026-08-10 8
2026-08-11 1
2026-08-13 2

There were no trim events on 2026-08-12. The 24:1 ratio holds per day and the conclusion is unchanged, but query the correct dates.

The trimmer does not converge — 7 of 11 trims left the prompt over budget

Every event, budget_tokens=47104 throughout:

Timestamp (UTC) original final dropped msgs Under budget?
08-10 22:02:43 53,714 2,744 3 yes — 95% of the prompt discarded
08-10 22:54:25 82,951 82,072 3 no — 74% over
08-10 22:54:43 176,381 171,203 4 no — 263% over
08-10 22:54:57 82,951 82,072 3 no
08-10 22:56:45 82,951 82,072 3 no
08-10 22:57:47 82,953 82,072 3 no
08-10 23:00:01 201,780 119,703 4 no — 154% over
08-10 23:02:42 81,748 33,893 4 yes
08-11 07:10:40 83,867 83,785 2 no — removed 82 tokens from a prompt 36,763 over
08-13 17:07:07 48,226 45,985 5 yes
08-13 17:09:02 51,422 44,127 5 yes

Dropping 3 messages yields anywhere from −879 to −50,970 tokens. The trimmer removes a small number of messages, logs success, and returns — without checking whether it reached budget_tokens. It is not a loop with a termination condition on the budget.

So there are two independent defects in the same function: it breaks tool pairing (this issue), and it does not achieve the thing it exists to achieve.

The budget itself is the deeper problem — filed separately

target_num_ctx=48128 is invariant across all 11 events and every logical model. num_ctx is an Ollama parameter; per DeepSeek's published pricing, deepseek-v4-flash has a 1M context window and 384K max output. Filed as its own issue.

That reframes this trace specifically: at original_token_count=48226, the request fit the model's window with roughly 95% to spare and should never have been trimmed at all. The trim was unnecessary, and it is what broke the request.

The 08-10 rows are the confirming evidence. Those prompts went upstream at 82K–171K tokens after trimming and came back with the tool-pairing error, not a context-length error. DeepSeek parsed a 171,203-token payload far enough to validate message structure. budget_tokens=47104 is not the provider's limit and never was.

🤖 Filed by Claude Code on Kai's behalf.

> 🤖 Filed by Claude Code on Kai's behalf. Pulled all 11 `request.prompt_trimmed` events over 7d. Three corrections and additions to the issue above. ## Correction: the dates in my recurrence table are wrong The day buckets were off by one. Actual event dates: | Day | `request.prompt_trimmed` events | | --- | --- | | 2026-08-10 | 8 | | 2026-08-11 | 1 | | 2026-08-13 | 2 | There were **no** trim events on 2026-08-12. The 24:1 ratio holds per day and the conclusion is unchanged, but query the correct dates. ## The trimmer does not converge — 7 of 11 trims left the prompt over budget Every event, `budget_tokens=47104` throughout: | Timestamp (UTC) | original | final | dropped msgs | Under budget? | | --- | --- | --- | --- | --- | | 08-10 22:02:43 | 53,714 | 2,744 | 3 | yes — 95% of the prompt discarded | | 08-10 22:54:25 | 82,951 | 82,072 | 3 | **no — 74% over** | | 08-10 22:54:43 | 176,381 | 171,203 | 4 | **no — 263% over** | | 08-10 22:54:57 | 82,951 | 82,072 | 3 | **no** | | 08-10 22:56:45 | 82,951 | 82,072 | 3 | **no** | | 08-10 22:57:47 | 82,953 | 82,072 | 3 | **no** | | 08-10 23:00:01 | 201,780 | 119,703 | 4 | **no — 154% over** | | 08-10 23:02:42 | 81,748 | 33,893 | 4 | yes | | 08-11 07:10:40 | 83,867 | 83,785 | 2 | **no — removed 82 tokens from a prompt 36,763 over** | | 08-13 17:07:07 | 48,226 | 45,985 | 5 | yes | | 08-13 17:09:02 | 51,422 | 44,127 | 5 | yes | Dropping 3 messages yields anywhere from −879 to −50,970 tokens. The trimmer removes a small number of messages, logs success, and returns — without checking whether it reached `budget_tokens`. It is not a loop with a termination condition on the budget. So there are two independent defects in the same function: it breaks tool pairing (this issue), and it does not achieve the thing it exists to achieve. ## The budget itself is the deeper problem — filed separately `target_num_ctx=48128` is invariant across all 11 events and every logical model. `num_ctx` is an Ollama parameter; per DeepSeek's published pricing, `deepseek-v4-flash` has a **1M** context window and 384K max output. Filed as its own issue. That reframes this trace specifically: at `original_token_count=48226`, **the request fit the model's window with roughly 95% to spare and should never have been trimmed at all.** The trim was unnecessary, and it is what broke the request. The 08-10 rows are the confirming evidence. Those prompts went upstream at 82K–171K tokens after trimming and came back with the *tool-pairing* error, not a context-length error. DeepSeek parsed a 171,203-token payload far enough to validate message structure. `budget_tokens=47104` is not the provider's limit and never was. > 🤖 Filed by Claude Code on Kai's behalf.
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-flight-deck/agent-proxy#113
No description provided.