mirror of
https://github.com/headroomlabs-ai/headroom.git
synced 2026-08-27 14:17:10 -04:00
2 commits
| Author | SHA1 | Message | Date | |
|---|---|---|---|---|
Tejas Chopra
|
c502087db7
|
fix(ccr): only buffer a stream when a marker is actually redeemable (#3092)
## Description Closes #3071 `headroom_retrieve` is injected once and kept resident for the session so the tools array stays byte-stable and the prompt cache survives. The buffered-CCR path keyed on that tool merely being **present**, so once a session went sticky, *every* later streaming turn was silently converted to `stream: false`, buffered whole, and resynthesized as SSE: ``` CCR: stream:true request has headroom_retrieve available; using buffered stream:false upstream request ``` Buffering leaves time-to-last-byte roughly unchanged but makes **time-to-first-byte the entire generation**. The reporter measured 8s average and up to 100s across 234 requests in one day — turns that would have streamed a first token in ~1s instead delivered nothing until done. Retrieval can only expand a `<<ccr:...>>` marker present in the outgoing body, so a turn carrying none cannot benefit from the buffered path at all. Gate on that instead of on the tool. This is also the root cause #3082 traced independently from the OpenCode side — its plugin registers `headroom_retrieve` unconditionally, so *every* turn buffered and neither `--no-ccr` nor `HEADROOM_NO_CCR` stopped it. ## Type of Change - [x] Bug fix (non-breaking change that fixes an issue) ## Changes Made - New `_outgoing_body_has_redeemable_marker()` scans the body **about to go on the wire** and verifies ownership against the compression store — the same `exists()` check the retrieve endpoint performs, so a same-shaped marker from another context tool is not adopted (#2836). Unexpected shapes answer `True`, keeping the long-standing behavior. - The buffered-stream decision site gates on it, and logs at INFO when it skips buffering. - The correctness detail worth reviewing: the check reads `body`, **not** the earlier `scan_for_markers(optimized_messages)` result. `optimized_messages` is reassigned five times after that scan (memory hooks, pre-send extensions, tool-search repair, CCR repair), so reusing it would have been stale. - Two existing test files encoded the very coupling this removes and had to be repaired — see Testing. Scope: this narrows *when* buffering happens; it does not make buffered turns stream. A turn that genuinely carries a marker still loses incremental delivery — restoring streaming there means wiring `StreamingCCRHandler`, which is #3069's scope. It does not fix #3088 either, whose requests do carry markers. ## Testing - [x] Unit tests pass (`pytest`) - [x] Linting passes (`ruff check .`) - [x] New tests added for new functionality - [x] Manual testing performed Two existing files built a request with `headroom_retrieve` and **no** marker, relying on the tool alone to trigger buffering: - `tests/test_proxy/test_anthropic_streaming_ccr_retrieve.py` (11 tests) fell through to the live streaming path, where only `_retry_request` is stubbed — so the requests reached the network and the file **hung indefinitely** rather than failing. Seeded real markers; now passes in ~5s. - `tests/test_proxy_response_cache_replay.py::test_buffered_ccr_turn_does_not_write_the_response_cache` asserts its own premise (*"the conversion really happened — otherwise this test proves nothing"*), so it failed loudly instead of passing vacuously. Seeded a marker. New `test_buffering_is_gated_on_a_redeemable_marker` pins all three directions: owned marker → buffered, no marker → streaming, foreign marker → streaming. ### Test Output ```text $ pytest tests/test_ccr_buffered_stream_signed_thinking.py -q 8 passed, 1 warning in 4.45s $ pytest tests/test_proxy/test_anthropic_streaming_ccr_retrieve.py -q 11 passed, 1 warning in 4.94s # was: hung indefinitely $ pytest tests/test_proxy_response_cache_replay.py -q 9 passed, 1 warning in 1.69s $ pytest tests/ -q 3 failed, 11151 passed, 581 skipped in 398.28s (0:06:38) Same 3 failures as a clean-main baseline run on this machine: tests/test_graceful_shutdown.py::test_run_server_installs_cancelled_error_filter tests/test_learn/test_integration.py::TestCodexIntegration::test_full_pipeline tests/test_release_workflows.py::test_no_native_tls_in_wheel_build_tree $ ruff check . && ruff format --check . All checks passed! ``` ## Real Behavior Proof - Environment: this branch driven through the real FastAPI app with the outbound HTTP client captured; macOS arm64, Python 3.12. - Exact command / steps: posted a `stream: true` `/v1/messages` request carrying a resident `headroom_retrieve` tool in three variants — no marker, a marker seeded into the compression store, and a correctly-shaped marker the store does not own — recording whether `_retry_request` saw a `stream: false` body. - Observed result: no marker → **streams**, `_retry_request` never sees a flipped body; owned marker → **buffers**, exactly as before; foreign marker → streams, honoring #2836 rather than adopting another tool's hash. - Not tested: the latency improvement against live client traffic. The mechanism is verified (the buffered conversion no longer occurs), but the reported 8s → ~1s TTFB needs the reporter's traffic to confirm. ## Runtime Rollout Safety - Rollout-managed feature(s): none — this narrows an existing code path and is not behind a rollout channel. - Minimum rollout channel: n/a (ships to stable with the fix). - Stable/default behavior changed: yes. A streaming turn whose body carries no redeemable marker now stays streaming instead of being buffered. Turns carrying a marker are unchanged. - Kill switch / disable path: no new switch. Existing CCR controls still apply — disabling the CCR response handler bypasses this decision site entirely, and the helper fails open (returns `True`, i.e. the old behavior) on any unexpected message shape. - Unsafe override required: no. - Qualification impact: none — no qualification-gated surface is touched. - Rollback path: revert this commit. Note it also carries two test repairs; reverting the production change alone would leave those tests passing but vacuous. ## Review Readiness - [x] I have performed a self-review - [x] This PR is ready for human review ## Checklist - [x] My code follows the project's style guidelines - [x] I have performed a self-review of my code - [x] I have commented my code, particularly in hard-to-understand areas - [x] My changes generate no new warnings - [x] I have added tests that prove my fix is effective or that my feature works - [x] New and existing unit tests pass locally with my changes - [x] I did **not** edit `CHANGELOG.md` ## Additional Notes Documentation update is marked N/A: no user-facing flag or endpoint changes. Type checking (`mypy headroom`) was not run separately; `ruff` is the gate this repo's CI enforces. Related: #2836 (marker ownership), #3069 (streaming CCR handler), #3082, #3088. 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Tejas Chopra <tejas@Tejass-MacBook-Pro.local> Co-authored-by: Claude Opus 5 <noreply@anthropic.com> |
||
|
Parideboy
|
9d370592b0
|
fix(proxy): stop cached responses replaying the producing turn's wire framing (#3024)
## Description
Closes #3019
A response-cache hit could hand the client an HTTP 200 that the client
could not read, and nothing in the logs marked the turn as anything
other than normal.
Two separate problems combine to produce the reported failure.
**The unreadable 200.** A cache entry stores the producing upstream's
response headers verbatim. When the entry is replayed, the Anthropic
handler removed only `content-encoding`, `content-length` and
`content-type` before handing those headers to a brand-new `Response`.
Anything else describing how that *other* connection framed its body
rode along — most damagingly `transfer-encoding: chunked`. RFC 9112 §6.1
makes `Transfer-Encoding` override `Content-Length`, so the client is
told to parse a plain JSON body as chunked frames, finds no valid
chunk-size line, and reads an empty body out of a 200. Every other
response-forwarding site in the Python proxy already strips that header;
the two cache-hit sites were the only ones that did not.
**How a CCR turn could put a foreign response in the cache.** On the
Anthropic path, `cache.get` is gated on `not stream` but `cache.set` was
not, and the cache key has no `stream` component. A CCR buffered-stream
conversion takes a request the client sent with `stream: true`, forces
`stream: false` upstream, and — unlike every other streaming turn, which
returns via `_stream_response` and never touches the cache — falls
through to the store site. The stored reply was shaped by that forced
flip plus CCR tool injection, and the key cannot distinguish it from an
ordinary non-streaming reply, so a later non-streaming caller could be
served a response built for a request it never made. This is why the
reporters saw the failures pair with CCR activity and stop under
`--lossless` / `--no-ccr`.
**Why it was invisible.** The cache-hit block emitted no log line at
all, and the `PERF` line rendered no field for
`RequestOutcome.from_response_cache`. A cache-served turn contacts no
upstream, so it has no `outbound_request` line, no upstream stage
timings, and all-zero token counters — byte-for-byte what a turn that
died would look like. That is why `headroom doctor` reported zero
failures while turns were dying.
### Scope note
The header fix also lands on the OpenAI cache-hit site, which
additionally never received the `content-type` fix from #2952. The `not
stream` gate is added to the OpenAI store site too, where it is
currently redundant — a streaming chat request returns via
`_stream_response` long before that point — purely to state the
invariant, since the Anthropic handler had exactly that shape until a
buffered-CCR branch began falling through to it.
Because the strip list now lives in one shared helper, the OpenAI
handler's other five forwarding sites strip the three added headers as
well. That is a widening, so it is worth being explicit about: each of
those sites builds a fresh fixed-length `Response` (or, at
`openai.py:6122`, synthesises SSE) from `response.content`, so replaying
the upstream's framing there was the same latent bug, just without a
cache to make it outlive the request that produced it. The precedent is
already in the file — `openai.py:9865` passes `"transfer-encoding",
"connection"` as extra names by hand, which is exactly the gap this PR
closes centrally. That call site keeps its now-redundant arguments;
removing them is a cleanup for another PR.
## Type of Change
- [x] Bug fix (non-breaking change that fixes an issue)
## Changes Made
- Added `sanitize_forwarded_response_headers` to
`headroom/proxy/helpers.py`, promoting the private helper that already
lived in `headroom/proxy/handlers/openai.py` and extending it with the
remaining wire-framing headers (`transfer-encoding`, `connection`,
`keep-alive`). Matching is now case-insensitive; surviving headers keep
their original casing. `openai.py`'s
`_sanitize_forwarded_response_headers` is now a thin alias so its six
call sites and the Anthropic handler strip an identical set.
- `headroom/proxy/handlers/anthropic.py`: the response-cache hit now
sanitises through that helper (passing `content-type` as an extra name,
preserving #2952) instead of three hand-rolled `pop` calls.
- `headroom/proxy/handlers/openai.py`: the response-cache hit sanitises
the same way, gains the `content-type` handling it was missing, and sets
`media_type="application/json"` explicitly.
- `headroom/proxy/handlers/anthropic.py`: `cache.set` is now gated on
`not stream`, mirroring the read gate. `stream` still holds the client's
original flag at that point — the buffered-CCR conversion flips
`body["stream"]`, never the local variable.
- `headroom/proxy/handlers/openai.py`: the same `not stream` gate on its
store site, as an invariant guard.
- Both cache-hit sites now log `RESPONSE-CACHE-HIT: model=… bytes=…
age_s=… hits=…`, following the existing `CACHE-MISS-ATTRIBUTION` line
style.
- `headroom/proxy/outcome.py`: the `PERF` line appends `cached=1` on a
response-cache hit. It is appended only on a hit, so every other PERF
line is byte-identical to before and existing parsers are unaffected.
- `headroom/perf/analyzer.py`: `PerfRecord.from_response_cache` reads
that field, so `headroom perf` can tell a cache-served turn from a dead
one. It defaults to `False`, so older logs still parse.
`PERF_RECORD_FIELDS` gains the name at the end of the list, which is
what `headroom perf --format csv --raw` uses as its column set;
appending keeps every existing column at its current position. `--format
json --raw` gains the key too.
- `tests/test_anthropic_pre_upstream_backpressure.py`: its cache-hit
double was a partial hand-rolled stand-in for `CacheEntry` carrying only
a body and headers, so it broke once the hit path started reading the
entry's age and hit count. It now constructs a real `CacheEntry`, which
is what the cache actually returns.
## Testing
- [x] Unit tests pass (`pytest`)
- [x] Linting passes (`ruff check .`)
- [x] Type checking passes (`mypy headroom`)
- [x] New tests added for new functionality
### Test Output
```text
$ python -m pytest tests/test_proxy_response_cache_replay.py -q
tests\test_proxy_response_cache_replay.py ......... [100%]
============================== 9 passed in 4.22s ==============================
# Everything that mentions PERF, the sanitiser, cache.set, PerfRecord or
# response_headers, plus the whole proxy suite.
$ python -m pytest tests/test_proxy/ tests/test_proxy_compression_headers.py \
tests/test_agent_savings.py tests/test_anthropic_pre_upstream_backpressure.py \
tests/test_backend_nonstreaming_cache_metrics.py tests/test_backend_streaming_cache_metrics.py \
tests/test_ccr_buffered_stream_signed_thinking.py tests/test_cli_perf_format.py \
tests/test_codex_ws_compression_scheduler.py tests/test_handler_outcome_tag_invariant.py \
tests/test_openai_codex_ws_lifecycle.py tests/test_provider_codex_images.py \
tests/test_proxy_handlers_batch.py tests/test_proxy_passthrough_transient_retry.py \
tests/test_proxy_response_cache_replay.py tests/test_proxy_semantic_cache_key.py \
tests/test_proxy_streaming_request_logger.py tests/test_request_outcome.py \
tests/test_savings_tool_search_aggregation.py -q
================== 555 passed, 1 skipped in 88.60s (0:01:28) ==================
# Full suite, 16 workers. See "Real Behavior Proof" below for how every
# failure here was traced to a pre-existing failure or a parallelism flake.
$ python -m pytest tests scripts/tests -n 16 -q -p no:randomly --timeout=300
83 failed, 10493 passed, 657 skipped, 80 errors in 437.00s (0:07:17)
$ ruff check .
All checks passed!
$ ruff format --check <the 7 changed files>
7 files already formatted
$ python -m mypy headroom --ignore-missing-imports --python-version 3.13
Found 12 errors in 3 files (checked 520 source files)
# All 12 are pre-existing MCP-SDK/tomllib drift in release_version.py,
# ccr/mcp_server.py and memory/mcp_server.py; identical count before and
# after this change, none in the files it touches.
```
## Real Behavior Proof
- Environment: Windows 11, Python 3.13.11, pytest 9.1.1, ruff 0.16.2,
branch based on `upstream/main` at `
|