Commit graph

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>
2026-08-17 11:19:26 -07:00
Parideboy
f1c34d336c
fix(proxy/anthropic): don't buffer a CCR stream when passthrough discards the stream flip (#2953)
## Description

Fixes #2952. Since `dc163bcd` (#2254), a Claude Code session with
extended thinking on dies from the turn where the first signed
`thinking` block enters history:

```
API Error: API returned an empty or malformed response (HTTP 200) — check for a proxy or gateway intercepting the request
```

`select_outbound_body` forwards the client's original bytes whenever the
body carries a signed `thinking` / `redacted_thinking` block, and it
decides that **before** it looks at `body_mutated` — so every edit the
handler made is discarded. The buffered-CCR path depends on exactly such
an edit: it sets `body["stream"] = False` (`anthropic.py:3073-3078`) so
the reply arrives as one JSON document it can scan for
`headroom_retrieve` calls. With the flip discarded, upstream streams,
`response.json()` fails, SSE resynthesis is skipped, and the client is
handed a 200 it cannot read.

From the reporter's `proxy.log`, the turn that breaks — note
`body_bytes` equals the inbound `content_length` byte for byte, and
`source=passthrough` despite two recorded mutations:

```
CCR: stream:true request has headroom_retrieve available; using buffered stream:false upstream request
event=outbound_request forwarder=anthropic_messages body_bytes=132017 body_mutated=true
  mutation_reasons=structural_diff_vs_original,ccr_streaming_retrieve_buffered_non_stream source=passthrough
PERF ... msgs=6 tok_saved=3575 tool_saved=16064 tok_out=0 total_ms=9623
```

This is a different failure from #2251 (a 400 from Anthropic). Signed
thinking blocks still leave as original bytes here, so that fix is
untouched.

## Type of Change

- [x] Bug fix (non-breaking change that fixes an issue)
- [ ] New feature (non-breaking change that adds functionality)
- [ ] Breaking change (fix or feature that would cause existing
functionality to change)
- [ ] Documentation update
- [ ] Performance improvement
- [ ] Code refactoring (no functional changes)

## Changes Made

Primary fix, `headroom/proxy/handlers/anthropic.py`:

- Gate `buffered_stream_ccr` on the outbound body actually being ours to
change, via a new `outbound_body_is_client_bytes()` predicate that
mirrors the passthrough branch. Those turns take the plain streaming
path instead, which is the coherent outcome: the injected retrieve tool
is itself a discarded mutation there, so the model was never going to
see it. One INFO line records the choice.

Three follow-on defenses, each of which independently kept the failure
alive or invisible:

- A non-JSON 200 on the buffered path now logs at WARNING (it was DEBUG,
which is why nothing in `proxy.log` looked wrong) and the upstream SSE
is relayed to the client verbatim, instead of falling through to a plain
`Response` that `_BufferedCCRResponse` can only turn into a bare `event:
error` once its 1 s keepalive has committed headers.
- The semantic cache no longer stores a body that did not parse as JSON,
and drops the stored `content-type` on the hit path. The cache key has
no `stream` component, so a cached SSE body was replayed to buffered
callers for the full 3600 s TTL — that replay is the request the
reporter actually saw the error on (a 2 ms `PERF ... transforms=none`
cache hit).
- `select_outbound_body` now reports the mutations passthrough discarded
(`dropped_mutations` / `dropped_mutation_reasons`), and
`log_outbound_request` logs them as
`event=outbound_body_mutations_dropped` at WARNING. Without it, `PERF`
reports savings and tool injections that never reached the wire and
nothing contradicts it.

`prepare_outbound_body_bytes` keeps its two-value shape, so existing
callers are unchanged.

## Testing

- [x] Unit tests pass (`pytest`)
- [x] Linting passes (`ruff check .`)
- [x] Type checking passes (`mypy headroom`)
- [x] New tests added for new functionality
- [x] Manual testing performed

New `tests/test_ccr_buffered_stream_signed_thinking.py` covers the gate
(signed-thinking history takes the streaming path and still leaves as
`stream: true`; the same request without thinking blocks still takes the
buffered path with `stream: false`), the SSE relay, and the cache
guards. The relay case is parametrized on upstream latency because the
failure only reaches its worst form past the 1 s keepalive, where a
plain `Response` has no `body_iterator` left to forward.

Verified red before green — with the source changes stashed and the
tests in place:

```text
FAILED tests/test_ccr_buffered_stream_signed_thinking.py::test_signed_thinking_history_skips_the_buffered_ccr_path[True-True]
FAILED tests/test_ccr_buffered_stream_signed_thinking.py::test_buffered_ccr_relays_an_unexpected_sse_reply_and_does_not_cache_it[prompt]
FAILED tests/test_ccr_buffered_stream_signed_thinking.py::test_buffered_ccr_relays_an_unexpected_sse_reply_and_does_not_cache_it[past-keepalive]
FAILED tests/test_ccr_buffered_stream_signed_thinking.py::test_cache_hit_never_replays_a_foreign_content_type
========================= 4 failed, 1 passed in 8.88s =========================
```

With the fix applied:

```text
$ python -m pytest tests/test_proxy_byte_faithful_forwarding.py tests/test_ccr_buffered_stream_signed_thinking.py -q
55 passed in 11.40s

$ python -m pytest tests/test_compression_cache.py tests/test_ccr_inline_resolve_handlers.py \
    tests/test_ccr_sqlite_backend.py tests/test_anthropic_stage_timings.py \
    tests/test_backend_nonstreaming_cache_metrics.py tests/test_cache_mode_cold_start.py \
    tests/test_cache_breakpoint_diagnostics.py -q
87 passed, 1 skipped in 17.57s

$ python -m ruff check .
All checks passed!

$ python -m mypy headroom --ignore-missing-imports --python-version 3.13
Found 12 errors in 3 files (checked 517 source files)
# all 12 pre-existing in headroom/ccr/mcp_server.py and headroom/memory/mcp_server.py
# (local mcp package version); none in the four files this PR touches
```

## Real Behavior Proof

- Environment: headroom 0.35.0-dev source checkout, Python 3.13.11,
Windows 11, Claude Code CLI 2.1.228 against api.anthropic.com
(claude-opus-5), proxy run as `headroom proxy --port 8787 --memory
--code-aware --mode token`
- Exact command / steps: reproduced from the reporter's
`~/.headroom/logs/proxy.log` — request `hr_1786551079_000005` shows
`source=passthrough` with `body_bytes` identical to the inbound
`content_length` while `mutation_reasons` contains
`ccr_streaming_retrieve_buffered_non_stream`, then `tok_out=0`; request
`hr_1786551089_000006` is the 2 ms `transforms=none` semantic-cache hit
that returned the poisoned SSE body to a caller asking for JSON. The
preceding turn (`...000004`, no thinking block yet) was
`source=canonical` with `tok_out=341`. Then: pytest suites above, with
the red/green stash comparison
- Observed result: with the gate in place the thinking-bearing turn goes
down `_stream_response` and the forwarded body still says `"stream":
true`, matching the bytes passthrough will send; a buffered turn whose
upstream answers with SSE reaches the client as a stream and writes
nothing to the semantic cache; a cache entry can no longer hand a caller
a content-type from a differently-shaped request
- Not tested: a live end-to-end Claude Code session against Anthropic
with the patched proxy (the reproduction here is the reporter's proxy
log plus handler-level tests); `/v1/responses`, which has the same
`stream`-flip pattern (`openai.py:5479-5487`) but carries `input` rather
than `messages`, so `has_signed_thinking_blocks` never fires there and I
left it alone

## 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
- [ ] I have made corresponding changes to the documentation
- [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
- [ ] I have updated the CHANGELOG.md if applicable

## Additional Notes

Deliberately out of scope, worth a separate issue: option (b) of #2251 —
a canonical re-serialization that preserves signed blocks byte-for-byte
so compression and tool injection survive a thinking-bearing history
rather than being silently dropped. #2251 reports a 400 even on a no-op
re-encode whose only transform was `tool_search_deferral`, which hints
the signature covers `tools` too, so getting it wrong would re-break
every multi-turn thinking session. That needs validating against the
live API, not guessing. Until then the new WARNING at least makes the
dropped work visible.

Also unfixed by design: the savings accounting itself. A passthrough
turn still books `tok_saved` / `tool_saved` in `PERF` for bytes that
never shipped; correcting the numbers is a wider change than this bug
needs.

Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
Co-authored-by: JD Davis <mxjerrett@gmail.com>
2026-08-13 11:46:55 -05:00