Observability: truthful token accounting, failure records, and stream stall diagnostics

[cvvz]

Why

Three separate things the dashboard could not tell you, all traced back to the same root: usage and failure state were only ever read on the success path.

1. IN showed 2 for a request carrying a 348,483-token prompt.
2. A failed request left no trace at all — not in the dashboard, not in error.log. Diagnosing one required a packet capture.
3. A stalled stream could not be attributed. When a client reports Response stalled mid-stream, nothing recorded whether the upstream had gone quiet or the proxy had.

Chasing #3 turned up a real bug on the way (see Non-2xx guard below) and ended in a measured explanation of the stall, included at the bottom because it is what several of these fields exist to capture.

What changed

Token accounting

Anthropic's three input buckets — input_tokens, cache_read_input_tokens, cache_creation_input_tokens — are disjoint, so the real prompt size is their sum. Reading input_tokens alone reports single digits for a fully-cached Claude Code turn, because cache_control covers nearly the entire prompt including the newest message. That was the IN = 2.

The three protocols disagree on how they slice the total, so there are three extractors rather than one shared misreading:

Protocol	Semantics
Anthropic	three disjoint buckets, must be summed
OpenAI	prompt_tokens already contains its cached subset — summing double-counts
Responses API	Anthropic's key names, OpenAI's semantics — the trap that motivated splitting these apart

Cost now reprices the cached buckets (read 0.1x, write 1.25x) instead of charging every input token at the full rate. Premium requests come from the catalog's billing.multiplier; a model the catalog never priced is left out rather than assumed to cost a full request.

All ratio-valued fields were put on one 0–1 scale (ratio_2dp), which previously mixed percentages and fractions across the API surface.

Non-2xx guard on the passthrough path

is_streamable_status() now gates all five streaming functions. Four already had the check inline; stream_anthropic_direct — the one path Claude Code takes — did not. A non-2xx upstream was therefore parsed as SSE and reached the client as a 200 text/event-stream whose body was a JSON error object, yielding no events at all. To the client that is indistinguishable from a stalled stream, which is why the real status code never surfaced.

Extracting the predicate means "which statuses may be streamed" now has a single definition point, and is unit-tested.

Failure records

• StreamRecorder + Drop. axum drops the response body when a client disconnects, which drops the async_stream generator, which meant the store.add after the loop never ran — a client that gave up left zero evidence. Drop is the only guaranteed path, and RequestStore::add uses a sync Mutex, so it is callable from there.
• record_failure() covers the pre-flight failures (token refresh, rate gate, connect errors) that previously returned early without recording.
• failure_kind names which step broke: precondition_failed / connect_error / upstream_status / stream_interrupted / client_disconnected.
• Failure records keep the partial upstream body. That partial is the main evidence for why a client gave up.

Stream diagnostics

• upstream_idle_max_ms (via util::IdleTracker) — longest silence between two upstream chunks. This is the field that assigns blame: large means the upstream went quiet, small means it kept sending and the stall was downstream.

• keepalive_probes — how many keepalives actually went out during that silence, shared with the recorder through an Arc<AtomicU32>. Pairs with the above: long idle + probes sent means the proxy kept signalling and the client ignored it; long idle + zero probes means the keepalive itself failed.

• Keepalive correctness. Probes are now emitted unconditionally by holding back partial events so the downstream always sits on an event boundary (last_event_boundary). Previously a probe could be skipped exactly when the stream was mid-event — which is precisely during a stall.

• output_tokens_final. On an Anthropic stream the authoritative output_tokens arrives only in the closing message_delta. A record finalized before that carries the opening placeholder from message_start — 3, for a turn that went on to emit 35,899. The dashboard now renders — rather than presenting that placeholder as fact. Tri-state: Some(false) → —, Some(true) → the number, None → unchanged behaviour for paths that do not track it.

  stop_reason looks like it would serve as this predicate and does not: the OpenAI and translated paths leave it None on success too, so using it would blank out their healthy records.

• DirectStreamState collects the five mutable generator locals into one plain value, so the whole SSE-event rulebook is testable without standing up a stream.

Session tracking

session_id, parsed out of metadata.user_id (a nested JSON string). Several Claude Code instances can share one proxy; without it their records interleave with no way to tell them apart. Clickable in the dashboard to filter.

Dashboard

• Columns: Time · Session · Endpoint · Model · Status · In · New · Out · Idle · Probes · Duration
• In shows total prompt size plus cache hit share (905.9k (98%)); Idle highlights past 60s
• Failure rows tinted, failure_kind shown inline, "Failures only" filter
• Scroll position preserved across refresh (bodies used to jump back to the top mid-read), and copy buttons on request/response bodies
• Stats cards gained premium requests, cache hit rate, cache writes

Tooling

scripts/replay.py replays any captured request — at the upstream directly or back through the proxy — and times the SSE stream event by event. It has no stall watchdog, so it can answer the two questions a client cannot answer for itself: how long an upstream silence actually lasts, and what arrives once it ends.

What this bought, concretely

A reproducible Response stalled mid-stream that had been undiagnosable now records:

in=348,483  out=—  idle=300.0s  probes=19  status=499  client_disconnected

and the retained partial body pins the exact stopping point:

content_block_start   tool_use "Write"
content_block_delta   input_json_delta  partial_json:""
                      ← 300s of silence, then the client gave up

Replaying that same request straight at the upstream, with no watchdog, finished the story:

max_tokens	output_tokens	longest silence	ms/token	tool args	stop_reason
64000	35,899	329.5s	9.18	85,744 chars	tool_use
8000	8,000	78.3s	9.79	0	max_tokens

The upstream was never broken — it buffers input_json_delta until the tool-argument JSON is complete, then flushes it all at once (85,744 chars in 3.3s, far above generation speed). Silence scales linearly with output size at ~9.5ms/token, putting the 300s client threshold at roughly 31,500 output tokens. Zero ping events arrive from the upstream during any of it.

None of this is a proxy defect — it reproduces identically when bypassing the proxy entirely — but every number above came from a field this PR adds.

Testing

• cargo test — 126 passed, 0 failed
• cargo clippy --all-targets -- -D warnings — clean
• cargo build --release — clean
• Dashboard render paths exercised against the three output_tokens_final states

🤖 Generated with Claude Code

[MartinForReal]

@codex[agent] fix ci

[Codex]

@codex[agent] fix ci

Fixed in 40f26ae. CI was failing on cargo fmt --all --check; I applied rustfmt-only changes in src/server.rs and src/state.rs, and verified locally with fmt/clippy/build/test all passing.