akadmin/headroom
1
0
Fork 0
mirror of https://github.com/headroomlabs-ai/headroom.git synced 2026-08-27 14:17:10 -04:00
Code Issues Projects Releases Packages Wiki Activity Actions
headroom/docs/content
History
Exact
Serge ARADJ a3d9424de9
fix(proxy): return 502, not 200, when upstream connect retries are exhausted (#3083) 
## Description

When every connect retry to the upstream API fails,
`_stream_response_inner` synthesizes its own SSE error response (added
in #1639, so an h2 `StreamReset` wouldn't surface as an unhandled 502).
It was built without a `status_code`, so Starlette defaulted it to
**200**.

A 200 carrying a lone `event: error` frame and no `message_start` is
indistinguishable, to every Anthropic/OpenAI SDK, from a successful
stream that produced no events. Claude Code reports:

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

The client also cannot recover, because 200 is not a retryable status.

**It does not self-heal.** Compression fails open on timeout, so the
proxy forwards the full uncompressed body; the client retries, re-sends
the same oversized payload, hits the same transport failure, and gets
another 200. The session is stuck until the client is pointed away from
the proxy.

Related — same *symptom*, different root cause, so this closes none of
them: #3040, #3055, #3019, #2952 (CCR buffered-stream conversion),
#3071, #3017. Worth noting that #3040 ("first messages succeed, fails
after several turns", closed `NOT_PLANNED`) matches this failure's shape
exactly.

## Type of Change

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

Marked breaking because the status code on this path changes 200 to 502.
See **Runtime Rollout Safety**.

## Changes Made

- `handlers/streaming.py` — the synthesized transport-error response now
returns **502**. The structured SSE body is unchanged for clients that
read it. No body byte has been forwarded at that point, so the status
line is still ours to set.
- `prometheus_metrics.py` — new
`headroom_upstream_connection_errors_total{provider}`. This path
forwards no upstream status, so there was nothing to attribute the
failure to in `/metrics`; it survived only as a log line. Mirrors
`record_compression_failed` and takes the same `_obs_counter_lock`.
- `server.py` — `HEADROOM_LOG_LEVEL` for uvicorn's level, previously
hardcoded to `"warning"` with no env var and no CLI flag. Default
unchanged. An unrecognized value warns and falls back rather than
raising (uvicorn raises `KeyError` on unknown levels).
- `docs/content/docs/proxy.mdx` — documents the new env var in the
Observability table.

## 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

`test_stream_reset_exhaustion_yields_sse_error_not_crash` asserted the
SSE body but never the status — which is how the 200 survived. Added a
test that pins the status specifically, a happy-path guard, and coverage
for the counter and the env-var resolver.

### Test Output

```text
$ python -m pytest tests/test_h2_stream_reset_retry.py tests/test_prometheus_obs_counters.py tests/test_uvicorn_log_level_env.py -q
29 passed in 5.26s

$ python -m ruff check .
All checks passed!

$ python -m ruff format --check .
1506 files already formatted

$ python -m mypy headroom/proxy/handlers/streaming.py headroom/proxy/prometheus_metrics.py headroom/proxy/server.py
Success: no issues found in 3 source files

# Fails before the fix (status_code=502 line removed, nothing else changed):
$ python -m pytest tests/test_h2_stream_reset_retry.py -k status_is_not_200
    assert result.status_code == 502
E   assert 200 == 502
FAILED tests/test_h2_stream_reset_retry.py::test_stream_reset_exhaustion_status_is_not_200
1 failed, 5 deselected in 1.28s
```

Broader regression run (181 passed): `test_h2_stream_reset_retry`,
`test_prometheus_obs_counters`, `test_uvicorn_log_level_env`,
`test_prometheus_label_escaping`, `test_observability_metrics`,
`test_prometheus_stage_timing_concurrency`,
`test_proxy_streaming_ratelimit_headers`, `test_proxy_retry_429`,
`test_proxy_byte_faithful_forwarding`, `test_ws_http_fallback`,
`test_mid_turn_steering`, `test_proxy_anthropic_cache_stability`.

## Real Behavior Proof

- Environment: Windows 11, Python 3.13.15, headroom @ this branch.
Genuine `create_app()` FastAPI app under real uvicorn — no mocks, no
TestClient. Upstream pinned to `http://127.0.0.1:59999` (a closed port),
so every connect attempt is a real TCP refusal, producing a real
`httpx.ConnectError` (an `httpx.TransportError`) into the branch under
test. `retry_max_attempts=2`.
- Exact command / steps: boot the real app with
`HEADROOM_LOG_LEVEL=info` and
`ProxyConfig(anthropic_api_url="http://127.0.0.1:59999")`, POST a
`stream:true` request to `/v1/messages`, then scrape `/metrics`.
Verbatim commands below.
- Observed result: `HTTP_STATUS=502` (previously 200), structured SSE
error body intact,
`headroom_upstream_connection_errors_total{provider="anthropic"} 1`, and
a uvicorn access line present only because `HEADROOM_LOG_LEVEL=info` was
honored. Verbatim output below.
- Not tested: the h2 `StreamReset` variant specifically — reproduced via
`ConnectError`, a sibling `httpx.TransportError` travelling the
identical code path (the existing `test_stream_reset_exhaustion_*` tests
cover `RemoteProtocolError` at unit level). Not exercised against the
OpenAI, Gemini, or Bedrock streaming handlers, which have their own
error paths. No load or concurrency testing.

Commands run after the patch:

```bash
# boot the real app with a dead upstream and the new env var set
HEADROOM_LOG_LEVEL=info python run_proxy_proof.py   # ProxyConfig(anthropic_api_url="http://127.0.0.1:59999")

curl -s -o resp.txt -w "HTTP_STATUS=%{http_code}\ncontent_type=%{content_type}\n" \
  http://127.0.0.1:8799/v1/messages \
  -H "content-type: application/json" \
  -H "x-api-key: proof-key" \
  -H "anthropic-version: 2023-06-01" \
  -d @request.json    # {"model":"claude-opus-5","max_tokens":64,"stream":true,"messages":[...]}
```

After-fix evidence:

```text
PROOF: HEADROOM_LOG_LEVEL='info' -> uvicorn log_level='info'
PROOF: upstream pinned to http://127.0.0.1:59999 (closed port)

HTTP_STATUS=502
content_type=text/event-stream; charset=utf-8

event: error
data: {"type": "error", "error": {"type": "connection_error", "message": "Failed to connect to upstream API: All connection attempts failed"}}
```

```text
$ curl -s http://127.0.0.1:8799/metrics | grep upstream_connection_errors
# HELP headroom_upstream_connection_errors_total Exhausted-retries upstream transport failures by provider; the proxy answered 502 itself because no upstream response arrived
# TYPE headroom_upstream_connection_errors_total counter
headroom_upstream_connection_errors_total{provider="anthropic"} 1
```

```text
# uvicorn access log — present only because HEADROOM_LOG_LEVEL=info was honored:
INFO:     127.0.0.1:62472 - "POST /v1/messages HTTP/1.1" 502 Bad Gateway
INFO:     127.0.0.1:62479 - "GET /metrics HTTP/1.1" 200 OK
```

All three changes are exercised end to end: the status is 502, the
structured body survives, the counter increments, and the env var takes
effect.

Separately, this ran against a real deployment: the fix is live on a
self-hosted proxy at `0.35.1-alpha.3` (Azure Container Apps, Cloudflare
in front), where the original HTTP 200 was first observed against
`0.35.1-alpha.1`.

## Runtime Rollout Safety

- Rollout-managed feature(s): none — unconditional bug fix, no flag.
- Minimum rollout channel: n/a — ships with the change.
- Stable/default behavior changed: yes. This path returns 502 instead of
200. `HEADROOM_LOG_LEVEL` and the new counter both default to current
behavior (`warning`; the counter is absent from `/metrics` until the
first occurrence).
- Kill switch / disable path: none. Happy to add an env guard if you
would prefer it staged, though a 200 on this path is never correct.
- Unsafe override required: no.
- Qualification impact: any client treating the synthesized 200 as
success now sees a 5xx. That is the fix — such a client was silently
accepting a truncated response. Retry-on-5xx logic in the Anthropic and
OpenAI SDKs will now retry a transient transport failure, which is the
intended behavior.
- Rollback path: revert the commit; single and self-contained.

## 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] 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
- [x] I did **not** edit `CHANGELOG.md` — it is generated by
release-please from my Conventional Commit PR title (a CI guard enforces
this)

## Screenshots (if applicable)

N/A — terminal output above.

## Additional Notes

**Scope.** Three changes in one PR, against the "one logical change"
guidance. They share a single root cause: this bug was only findable by
reading `/metrics`, because the failing path emitted no status, no
counter, and (see below) no usable log line. The counter and the env var
are the observability that should have made it a five-minute diagnosis
instead of a forensic exercise. Happy to split the `HEADROOM_LOG_LEVEL`
change into its own PR if you would rather keep the fix minimal — just
say so.

**Related defect, filed separately as #3087.** While producing the proof
above I found that the proxy's own `logger.error("Connection error to
upstream API: ...")` never reaches stdout: that run produced **zero**
`headroom.proxy` logger lines, only uvicorn's own. Root cause is
`_setup_file_logging()` setting `propagate = False` on the `headroom`
logger (`helpers.py:1536`), which sends every application record to
`~/.headroom/logs/proxy.log` and nowhere else — invisible in any
container, where stdout is the log channel. That is precisely why this
PR adds a counter rather than trusting a log line. Not fixed here: the
right remedy is a maintainer call, so it is written up in #3087 with a
repro rather than folded into this PR.

**No dependency changes.**

The dead-upstream harness used for the proof above is ~25 lines
(`ProxyConfig(anthropic_api_url="http://127.0.0.1:59999")` +
`uvicorn.run(create_app(config))`); happy to contribute it as an e2e
test if that is useful.

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-20 06:32:30 -07:00
..
docs fix(proxy): return 502, not 200, when upstream connect retries are exhausted (#3083) 2026-08-20 06:32:30 -07:00