Recorded events cannot distinguish completed vs truncated SSE; mid-stream upstream failure records status=200 and returns an invalid second Response #67

New issue

Open

opened 2026-09-08 17:42:07 +00:00 by nsaspy · 0 comments

nsaspy commented

2026-09-08 17:42:07 +00:00

Owner

Summary

Two related capture-fidelity bugs on the HTTP streaming path:

Mid-stream upstream failure (llm_log/proxy.py:488-493, main @ HEAD): after downstream.prepare(request) has already sent the upstream's real status (e.g. 200) to the client, the except branch builds downstream = web.Response(status=502, ...). Returning a second response for an already-prepared request is invalid in aiohttp, and the recorded CaptureEvent uses response_status — which still holds the connect-time upstream status (200), not what the client ultimately received. The recorded event and the client experience disagree.
No stream-completeness signal: the proxy relays SSE chunks verbatim and records whatever accumulated. A stream the upstream ended silently (clean EOF mid-generation, no data: [DONE], no finish_reason) is recorded identically to a fully completed one — as status 200 with a big body.

Corpus evidence (24h slice, 2026-09-06T03:39Z → 09-07T03:39Z, 6,430 events)

5 events recorded as status=200 whose response bodies are provably incomplete SSE: end mid-reasoning delta, finish_reason:null, no [DONE], 121KB–716KB bodies (4c671736… Z.AI, e4a09d86… Modal, 28f4de87… GMICloud, aadcae1d… AtlasCloud, plus a zero-frame stream 4ea9686c… consisting only of : OPENROUTER PROCESSING comments).
No journal exceptions at those timestamps → clean upstream EOF, not client aborts (those take the raise at proxy.py:491-492 and are never recorded at all — 426 × ClientConnectionResetError in the period).
1 event (722235fc…) shows what proper failure looks like: OpenRouter in-stream error frame {"error":{"code":504,"message":"Upstream idle timeout exceeded","metadata":{"error_type":"timeout"}}} with finish_reason:"error".
23 events recorded as 502 with upstream body [Errno 104] Connection reset by peer (pre-connect resets).

Downstream consumers (failure detectors, the expert plane's outcome labeler #15) currently cannot tell "model finished" from "stream died halfway through a 716KB reasoning trace" without re-parsing bodies.

Suggested fix

Record stream-completeness on CaptureEvent (e.g. stream_completed: bool, plus final finish_reason if parseable) at relay end — cheap, deterministic.
In the mid-stream exception path: if the downstream response was already prepared, do not construct a second web.Response; write an SSE error frame / write_eof() if the transport is alive, and record the event with an explicit status_kind (e.g. upstream_midstream_error) instead of the connect-time status.
Keep the client-abort raise path, but consider recording a minimal aborted-request marker (see #61) so "client gave up because upstream stalled" is distinguishable later.

Regression fixtures

Upstream that ends the SSE body without [DONE] → event must be marked incomplete.
Upstream that dies mid-chunk with a live downstream transport → no second-response crash; event reflects the true terminal condition.

## Summary Two related capture-fidelity bugs on the HTTP streaming path: 1. **Mid-stream upstream failure** (`llm_log/proxy.py:488-493`, main @ HEAD): after `downstream.prepare(request)` has already sent the upstream's real status (e.g. 200) to the client, the except branch builds `downstream = web.Response(status=502, ...)`. Returning a second response for an already-prepared request is invalid in aiohttp, and the recorded CaptureEvent uses `response_status` — which still holds the **connect-time upstream status (200)**, not what the client ultimately received. The recorded event and the client experience disagree. 2. **No stream-completeness signal**: the proxy relays SSE chunks verbatim and records whatever accumulated. A stream the upstream ended *silently* (clean EOF mid-generation, no `data: [DONE]`, no `finish_reason`) is recorded identically to a fully completed one — as status 200 with a big body. ## Corpus evidence (24h slice, 2026-09-06T03:39Z → 09-07T03:39Z, 6,430 events) - 5 events recorded as `status=200` whose response bodies are provably incomplete SSE: end mid-`reasoning` delta, `finish_reason:null`, no `[DONE]`, 121KB–716KB bodies (`4c671736…` Z.AI, `e4a09d86…` Modal, `28f4de87…` GMICloud, `aadcae1d…` AtlasCloud, plus a zero-frame stream `4ea9686c…` consisting only of `: OPENROUTER PROCESSING` comments). - No journal exceptions at those timestamps → clean upstream EOF, not client aborts (those take the `raise` at proxy.py:491-492 and are never recorded at all — 426 × `ClientConnectionResetError` in the period). - 1 event (`722235fc…`) shows what proper failure looks like: OpenRouter in-stream error frame `{"error":{"code":504,"message":"Upstream idle timeout exceeded","metadata":{"error_type":"timeout"}}}` with `finish_reason:"error"`. - 23 events recorded as 502 with upstream body `[Errno 104] Connection reset by peer` (pre-connect resets). Downstream consumers (failure detectors, the expert plane's outcome labeler #15) currently cannot tell "model finished" from "stream died halfway through a 716KB reasoning trace" without re-parsing bodies. ## Suggested fix - Record stream-completeness on `CaptureEvent` (e.g. `stream_completed: bool`, plus final `finish_reason` if parseable) at relay end — cheap, deterministic. - In the mid-stream exception path: if the downstream response was already prepared, do not construct a second `web.Response`; write an SSE error frame / `write_eof()` if the transport is alive, and record the event with an explicit `status_kind` (e.g. `upstream_midstream_error`) instead of the connect-time status. - Keep the client-abort `raise` path, but consider recording a minimal aborted-request marker (see #61) so "client gave up because upstream stalled" is distinguishable later. ## Regression fixtures - Upstream that ends the SSE body without `[DONE]` → event must be marked incomplete. - Upstream that dies mid-chunk with a live downstream transport → no second-response crash; event reflects the true terminal condition.

nsaspy referenced this issue

2026-09-08 17:43:30 +00:00

Transport error classifier: distinguish client disconnects, upstream resets, router failures and model anomalies #56

nsaspy referenced this issue

2026-09-19 05:30:22 +00:00

Upstream exhaustion failover: route depleted sub-provider proxies through OpenRouter #88

nsaspy referenced this issue

2026-09-20 06:13:37 +00:00

Fix SSE stream integrity capture #107