cloudflare / cloudflare/pingora

HTTP/1 upgrade torn down when the upstream's 101 is read before the request's empty body

Open
#946 0 comments 0 reactions 0 assignees View on GitHub
bug
Dominant language
Rust
Stars
27.4k
Forks
1.7k
Avg merge
6h 22m
Merged PRs (30d)
3

Description

## Describe the bug

An HTTP/1 upgrade (WebSocket) is torn down immediately after a successful `101`
whenever the upstream's response is read **before** the proxy has drained the
upgrade request's own (empty) body.

In `proxy_handle_upstream`, the end of the upgrade request's empty body is
mistaken for the end of the upgraded tunnel:

https://github.com/cloudflare/pingora/blob/main/pingora-proxy/src/proxy_h1.rs

```rust
body = rx.recv(), if !request_done => {
match send_body_to1(client_session, body).await {
Ok(send_done) => {
request_done = send_done;
// An upgraded request is terminated when either side is done
if request_done && client_session.was_upgraded() {
response_done = true;
}
},
```

A `GET` upgrade request has no body, so the downstream half sends exactly one
`HttpTask::Body(None, true)`. Two orderings are possible:

* **Body task consumed first** (slower upstream): `request_done = true` while
`was_upgraded()` is still `false`, so `response_done` stays `false`. The
`101` is then read, which sets `request_done = false` again, and the tunnel
works.
* **`101` read first** (fast upstream): `upgraded = true` and
`request_done = false`. The queued empty-body task then arrives,
`send_body_to1` returns `true`, and because `was_upgraded()` is now `true`,
`response_done = true` as well. Both flags are set, `while !request_done ||
!response_done` exits, and `rx` is dropped.

In the second case `proxy_handle_downstream` correctly logs
`reset downstream state on upgrade`, but the body pipe to the upstream is
already gone:

```
Read -1 bytes body from downstream
finish sending body to upstream
upstream event: Some(Header(ResponseHeader { status: 101, headers: {"connection": "Upgrade", "upgrade": "websocket"} }, false))
reset downstream state on upgrade
waiting for permit Err(Error { etype: InternalError, cause: Some("Closed(..)"),
context: Some(Static("try_reserve() body pipe for upstream")) }), upstream closed true
upstream event: None
empty upstream event
finished sending body to downstream
```

The client→upstream direction of the tunnel is therefore never wired, and both
connections are closed. The client sees the `101`, writes its first frame, and
gets a clean EOF; the upstream gets EOF while waiting for that frame.

This looks like the other half of #475. The fix merged for that issue
(`98bdb521`) stops the resulting spin by marking the downstream finished when
`tx.is_closed()`, which turns the symptom from a busy loop into a silent
connection teardown — but the early exit of `proxy_handle_upstream` that
`taikulawo` diagnosed in that thread ("pingora send body to
proxy_handle_upstream even if body is empty, which send `upstream_end_of_body
== true`, causing proxy_handle_upstream exit early") is still present.

## Steps to reproduce

The race is decided by whether the upstream's `101` wins against the proxy's
own empty-body processing, so it reproduces on a loaded or CPU-limited host and
is hard to see on an idle workstation.

With a plain reverse-proxy config, a raw client sending

```
GET /socket HTTP/1.1
Host:
Connection: Upgrade
Upgrade: websocket
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: dGhlIHNhbXBsZSBub25jZQ==
```

and an upstream that replies `101 Switching Protocols` immediately, then reads
11 bytes and replies:

| environment | result |
| --- | --- |
| idle 10-core macOS | 40/40 pass |
| 2-CPU Linux container (`docker run --cpus=2`) | 34/40 pass, **6 fail** |
| same, upstream `101` delayed by *any* amount, including a bare `sleep(0).await` | 15/15 pass at 0 ms, 5 ms, 25 ms and 100 ms |

That last row is the clearest signal: inserting a single yield point before the
upstream writes its `101` moves the body task ahead of the response task and
makes the failure disappear entirely.

Failing runs always produce the same pair:

```
upstream: Err(Custom { kind: UnexpectedEof, error: "early eof" }) // waiting for the client's first frame
client: stream closed before the expected marker // waiting for the upstream's reply
```

The client's idle time between receiving `101` and writing its first frame does
not matter — 0 ms, 300 ms and 1500 ms all fail at the same rate — which rules
out an idle-timeout explanation.

## Pingora info

**Pingora version**: `pingora-proxy` 0.8.1 (also `pingora` 0.8 with
features `["proxy", "boringssl"]`)
**Rust version**: 1.88.0
**Operating system version**: Debian 12 (bookworm) in Docker, and Ubuntu 24.04
on GitHub Actions `ubuntu-latest`

Observed in the wild as an ~8% failure rate for one WebSocket integration test
on 2-core GitHub Actions runners, across commits that changed no proxy code at
all — including a commit that only edited Markdown.

Contributor guide

Open the contributing guide

Research direction

Start in pingora-proxy/src/proxy_h1.rs at proxy_handle_upstream and trace how the upstream 101 response and the request's HttpTask::Body(None, true) update request_done and response_done. Reproduce with the raw upgrade client and immediate-101 upstream described in the issue, especially under CPU limits. Done means the client-to-upstream tunnel direction remains wired and the upgraded connection does not close prematurely.

Written by the indexing model from the issue text.

Assessment

Tech stack
rust
Domain
backend, networking
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Quiet
Clarity
Mostly clear
Newbie friendliness
52/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.