Streaming: no stall detection and insufficient logging to diagnose silent stream failures

Summary

Streaming responses can stop mid-answer and be terminated with no application-level error. The client receives a truncated answer that is indistinguishable from a complete one. A partner (Phala) reported 1,306 such events in a six-hour window on 2026-07-23; the failure mode is still live at roughly 0.03%/day.

This issue tracks the cloud-api side. The infrastructure side (an unset nginx proxy_timeout) is tracked separately in cvm-ansible-playbooks.

The core problem is that cloud-api has no independent stall detection on streaming responses, and — more importantly right now — insufficient logging to determine what is actually stalling.

---

What we did

• Reproduced both truncation mechanisms in a lab against the same nginx version, with timestamped raw-socket clients.
• Queried production L4, cloud-api and vllm-proxy logs via Loki (28-day retention; the original 2026-07-23 window has since aged out).
• Ran live streaming probes against production cloud-api across models and context sizes.
• Correlated interrupted-stream records against the 600s session band, nginx reload events, and backend health signals.

What we discovered

1. There is a real 600-second idle timer, and it is ours

An L4 SNI proxy in front of the API inherits nginx's stream default of 600s because proxy_timeout is never set. At layer 4 there is no HTTP session to report an error into, so it closes the TCP connection with a clean FIN — which to a client library is indistinguishable from a normal end of stream.

Confirmed across three independent upstreams over 48h (model_proxy 174, cloud_api 107, gateway 3), 27 distinct client IPs in two countries, including our own infrastructure at 600.000/600.001 to the millisecond.

2. But the 600s band is NOT mostly stream truncation — correction

Attributing each banded session by client:

Client	stalls/48h	distinct SNIs
15.204.46.198 (cpu02, our own host)	67	14
40.160.1.150 (cpu01, our own host)	66	13
66.220.6.107	57	1
78.48.80.6	34	5

38% is cloud-api's own bucket-pinned connections to model-proxy going idle and being reaped. A further 17% is client fan-out — 17 moments where 5 models stalled in the same second, every one a single client IP reading ~390KB from each and going quiet.

An earlier analysis treated 1,150 banded sessions as 1,150 truncated streams. That was wrong; the band is dominated by idle-connection reaping. This also explains why every backend hypothesis (saturation, preemption, KV pressure, crashes, nginx reloads, long context) came back negative — in that population the model was never the thing that stopped.

Relevant to cloud-api: the reaping forces reconnects, and per the fleet's own compose comments a reconnect can traverse model-proxy's L4 LB, land on a different backend, and 404 the signature lookup.

3. The blocking problem is observability

Completion stream error fires 425×/day. The full record:

{"message":"Completion stream error",
 "organization_id":"9227ad7e-…",
 "model":"zai-org/GLM-5.1-FP8",
 "error_type":"completion_error"}

No error text. No request_id. No duration. Not one of those 425 daily failures is diagnosable.

We reproduced a concrete failure and confirmed it leaves no usable trace — GLM-5.1 at ≥128K context:

HTTP 200 OK
data: {"error":{"message":"Failed to perform completion: Chutes stream chunk parse:
       missing field `id` at line 1 column 184","type":"server_error"}}
data: [DONE]

The string Chutes stream chunk parse appears nowhere in our logs. (At 96K the same request returns a clean HTTP 400, so the system can reject properly — the 128K fallback path is a defect.)

Two further gaps:

• An interrupted stream's request_id appears in exactly one log line fleet-wide (checked 6, all singletons). No cross-layer correlation is possible.
• Interrupted streams record tokens but no duration, so "user cancelled at 3s" is indistinguishable from "gateway timed out at 600s".

Provider failed, will try next provider already logs a full error_detail — the stream-error path simply omits it.

4. Most "incomplete streams" are our own probes

vllm-proxy logs ~3,979 incomplete streams/day. Comparing against completed requests: org_id populated on 0 of 2,000 interrupted vs 1,393 of 2,000 completed; p50 input 18 tokens vs 472; 83% produce <50 output tokens. Two prompt sizes (in=13, in=18) account for two-thirds. ~71% is probe traffic. Any alert built on the raw count will fire on health checks.

The residual real workload is 832/day, p50 input 62,360 tokens.

5. Measured threshold data for the watchdog

DeepSeek-V4-Flash at 400K context took 93.04s to first token and completed normally (300K → 40.0s). A watchdog installed after response headers with a 90s threshold would have killed a healthy request.

---

Proposed steps

P0 — logging (unblocks everything else)

• Add error_detail and request_id to Completion stream error in crates/api/src/routes/completions.rs, matching the existing Provider failed pattern.
• Add total_duration_ms and time-since-last-byte to the interrupted-stream path. total_duration_ms already exists on request completed; the interrupted path omits it.
• Tag or exclude probe traffic so the incomplete-stream metric measures customers rather than health checks.
• Ensure request_id is emitted on both sides of every stream outcome so records can be joined across cloud-api, inference-proxy and ingress.

Rationale: every remaining unknown is unknowable without this, and the watchdog threshold below stays a guess until a duration distribution exists. It is also the smallest change on this list.

P1 — stall detection

• Per-chunk stream idle watchdog emitting a typed Timeout so the existing error path produces a real, diagnosable error.
• SSE keepalive comments so a long generation is never mistaken for a stall by an intermediate hop.
• Threshold: 300s for the first item, 90s for subsequent — see the 93.04s measurement above. A single 90s value is unsafe because the watchdog installs after response headers and therefore covers post-header prefill.

Two known defects in the current draft implementation:

• The keepalive wrapper stops on seeing [DONE] in a buffer, but the real parser emits the DONE line and its blank terminator as separate events — so it drops the terminator and the inner stream never reaches EOF, where provider-signature finalization fires.
• Keepalive bytes are excluded from the gateway signature. Correct for the provider TEE signature (scope = backend bytes), wrong for the gateway signature, whose contract is the exact bytes the client received. Needs a decision: hash post-keepalive wire bytes, version the contract, or suppress keepalives on signed streams.

P2 — the large-context fallback path

• Return a clean 400 for oversized requests, as the 96K path already does, instead of falling back to a provider whose stream cannot be parsed.
• Harden the external-provider chunk parser against schema variation (absent id, extra fields such as prompt_text).

P3 — alerting, once P0 lands

• Streams closed without [DONE], excluding probe traffic
• Time since last streamed byte
• Stream error rate by model and cause

---

Related

• #952 — returns a real HTTP status when a stream fails before its first event. Fixes delivery for the large-context case above (the parse error is the first stream event), but not the logging.
• cvm-compose-files #183 — HTTP/2 keepalive contract, the second truncation mechanism.
• Original report: gist 47b3d64394bb7beead081099eea2d095

Still unresolved

What stalled the reported streams. Their events showed data flowing and then stopping — a different shape from idle-connection reaping — so the 600s band is not a valid proxy for them. The only population that records a stream dying with content already delivered is the interrupted-stream log, and it carries no duration. The 2026-07-23 window has aged out of Loki, so this cannot be answered retrospectively; P0 is what makes the next occurrence diagnosable.

Start with crates/api/src/routes/completions.rs and compare the Completion stream error path with the existing Provider failed logging and request completed fields. The smallest stated scope is P0: preserve error_detail, request_id, total_duration_ms, and time-since-last-byte, while emitting request_id on both stream outcomes. Confirm the related logging and probe-traffic paths before expanding into watchdog, parser, or alerting work.