Upstream 500 after 447s is recorded as a non-error, and litellm keeps working 207s after the caller is gone #106

New issue

Closed

opened 2026-08-12 20:50:19 +00:00 by coilyco-ops · 0 comments

coilyco-ops commented

2026-08-12 20:50:19 +00:00

Member

Two defects in one trace

Trace 8ea6619aa21aacae118b2d310a658f11, 2026-08-12T20:03:18Z (SigNoz: http://ser8:30808/trace/8ea6619aa21aacae118b2d310a658f11).

1. The failure is invisible on the agent-proxy side

Service	Span	Duration	Status
agent-proxy	`POST /v1/chat/completions` (root)	239.9956s	`Unset`, `has_error: false`
agent-proxy	`request.chat`	239.9864s	`Unset`, `has_error: false`
agent-proxy	`resilience.attempt`	239.9872s	`Unset`, `has_error: false`
agent-proxy	`POST → litellm`	239.9866s	`Unset`, `has_error: false`
litellm	`Received Proxy Server Request`	447.2455s	`Error`, HTTP 500
litellm	`litellm_request`	447.2197s	`Error`, HTTP 500

Every agent-proxy span in this trace reports success. The upstream returned 500. The root span's response_status_code is empty.

This has a direct measurement consequence: agent-proxy's reported errorRate over 24h is 0.74%. If failures of this shape are recorded as non-errors, that number is not trustworthy, and neither is any alert built on it.

2. Upstream work continues long after the caller has left

agent-proxy's client span ends at 20:07:18.206 (239.99s in)
litellm's server span ends at 20:10:45.466 (447.25s in)
litellm emits Failed Proxy Server Request at 20:10:45.466

litellm kept generating for 207 seconds — 3m27s — after agent-proxy stopped waiting, then failed. That work is unbillable to any caller, occupies backend capacity, and by that point no one can receive the result.

This is the same shape as the orphaned MCP sessions in coilyco-gaming/sirens-echo#160: the caller detaches, the server keeps holding. Different protocol, same failure to propagate cancellation.

Why it matters together

The caller-side deadline (coilyco-gaming/sirens-echo#171) is being tuned on the assumption that giving up releases the work. It does not. Raising the deadline without propagating cancellation means slow requests hold backend capacity for longer, not that fewer are wasted — and under load that makes contention worse, not better.

Suspected cause, unverified

Client disconnect is not propagating as request cancellation to litellm, and agent-proxy is not recording the upstream status on the span when it stops waiting. I have not read the code; both are inferences from span data.

Acceptance

An upstream non-2xx is recorded as an error on the agent-proxy span, with the status code.
Caller disconnect propagates cancellation upstream, so litellm stops rather than running to completion for nobody.
errorRate for the service reflects upstream failures.

Origin

Found while resolving #105. The 240s request was picked as a queue.wait sample; the 447s upstream span was incidental and is the more serious finding.

## Two defects in one trace Trace `8ea6619aa21aacae118b2d310a658f11`, 2026-08-12T20:03:18Z (SigNoz: `http://ser8:30808/trace/8ea6619aa21aacae118b2d310a658f11`). ### 1. The failure is invisible on the agent-proxy side | Service | Span | Duration | Status | | --- | --- | --- | --- | | agent-proxy | `POST /v1/chat/completions` (root) | 239.9956s | `Unset`, **`has_error: false`** | | agent-proxy | `request.chat` | 239.9864s | `Unset`, `has_error: false` | | agent-proxy | `resilience.attempt` | 239.9872s | `Unset`, `has_error: false` | | agent-proxy | `POST → litellm` | 239.9866s | `Unset`, `has_error: false` | | litellm | `Received Proxy Server Request` | 447.2455s | **`Error`, HTTP 500** | | litellm | `litellm_request` | 447.2197s | **`Error`, HTTP 500** | Every agent-proxy span in this trace reports success. The upstream returned **500**. The root span's `response_status_code` is empty. This has a direct measurement consequence: agent-proxy's reported `errorRate` over 24h is **0.74%**. If failures of this shape are recorded as non-errors, that number is not trustworthy, and neither is any alert built on it. ### 2. Upstream work continues long after the caller has left - agent-proxy's client span ends at **20:07:18.206** (239.99s in) - litellm's server span ends at **20:10:45.466** (447.25s in) - litellm emits `Failed Proxy Server Request` at **20:10:45.466** litellm kept generating for **207 seconds — 3m27s — after agent-proxy stopped waiting**, then failed. That work is unbillable to any caller, occupies backend capacity, and by that point no one can receive the result. This is the same shape as the orphaned MCP sessions in `coilyco-gaming/sirens-echo#160`: the caller detaches, the server keeps holding. Different protocol, same failure to propagate cancellation. ## Why it matters together The caller-side deadline (`coilyco-gaming/sirens-echo#171`) is being tuned on the assumption that giving up releases the work. It does not. Raising the deadline without propagating cancellation means slow requests hold backend capacity for longer, not that fewer are wasted — and under load that makes contention worse, not better. ## Suspected cause, unverified Client disconnect is not propagating as request cancellation to litellm, and agent-proxy is not recording the upstream status on the span when it stops waiting. I have not read the code; both are inferences from span data. ## Acceptance - An upstream non-2xx is recorded as an error on the agent-proxy span, with the status code. - Caller disconnect propagates cancellation upstream, so litellm stops rather than running to completion for nobody. - `errorRate` for the service reflects upstream failures. ## Origin Found while resolving #105. The 240s request was picked as a `queue.wait` sample; the 447s upstream span was incidental and is the more serious finding.

coilyco-ops referenced this issue

2026-08-12 22:17:52 +00:00

A saturated backend is not a failed backend, so failover never fires and the caller is told nothing #108

coilyco-ops referenced this issue from coilyco-gaming/sirens-echo

2026-08-13 04:54:33 +00:00

Deep: deep-round turns fail at the model stage and report a backend outage that did not happen #258

coilyco-ops referenced this issue

2026-08-13 17:17:03 +00:00

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

coilyco-ops referenced this issue

2026-08-13 17:17:29 +00:00

A 400 is classified as a transport error, retried three times, and returned to the caller as 502 #114