envoyproxy / envoyproxy/envoy

ext_proc: HTTP/1.1 upgrade request hangs with BUFFERED request body mode`

Open
#47,081 8 comments 0 reactions 0 assignees View on GitHub
area/ext_proc bug
Dominant language
C++
Stars
28.9k
Forks
5.6k
Avg merge
1d 20h
Merged PRs (30d)
437

Description

*Title*: ext_proc: HTTP/1.1 upgrade request hangs with BUFFERED request body mode`

*Description*:

When a request carries `Connection: Upgrade` plus a matching `Upgrade` header, and the HCM has an `upgrade_configs` entry for that type, an ext_proc filter configured with `request_body_mode: BUFFERED` never forwards the request upstream. The stream stalls until `stream_idle_timeout` fires (300s by default) and the client gets a 408.

Observed on a stalled request:

* The ext_proc server receives `request_headers` with `end_of_stream=false`, even for a header-only GET, and answers CONTINUE.
* It never receives a `request_body` message.
* The upstream is never contacted at all (`upstream=-` in the access log, no connection opened).

So this is not a slow ext_proc server and not an upstream problem. The request is stuck in the filter chain after the headers response was already handled, which is also why `message_timeout` does not fire: that call completed and its timer was stopped. `stream_idle_timeout` is the only backstop, and the route timeout never starts because the request never reaches the router.

Expected: the request should be proxied normally. In the header-only case there is no body to buffer, so the BUFFERED phase has nothing to do. If a body mode that waits for end-of-stream genuinely cannot be honoured on a tunnel, Envoy should fail deterministically rather than stall for `stream_idle_timeout`.

**Mechanism**

The HTTP/1 codec enters upgrade mode and swallows `onMessageComplete` (https://github.com/envoyproxy/envoy/blob/main/source/common/http/http1/codec_impl.cc#L966), so the request stream never sees `end_stream` and `decodeHeaders` is called with `end_stream=false` even for a header-only GET.

A single zero-length data callback does follow `decodeData(0): end_stream = false`, but with `end_stream` unset, `handleDataBufferedMode()` (https://github.com/envoyproxy/envoy/blob/main/source/extensions/filters/http/ext_proc/ext_proc.cc#L958) returns `StopIterationAndBuffer` and the filter stays paused. It only sends the buffer to the processor once `end_stream` is seen, which in upgrade mode never happens.

When the headers response comes back, `ProcessorState::handleHeaderContinue()` (https://github.com/envoyproxy/envoy/blob/main/source/extensions/filters/http/ext_proc/processor_state.cc#L250) sees `no_body_ == false` and takes the BUFFERED branch, which returns without resuming iteration. Nothing is left that can wake the stream.

A request with a real body stalls the same way.

**Relation to #47048 / #47060**

Close, but a different path:

* #47048 and PR #47060 concern `STREAMED` / `FULL_DUPLEX_STREAMED`, and that is a regression: it worked in 1.38.0 and broke in 1.38.4.
* The `BUFFERED` branch of `handleHeaderContinue()` is unchanged from 1.36 through main, so this is not a regression.
* PR #47060 adds `continueIfNecessary()` to the STREAMED branch only, so it does not cover this.

Filing separately since the version range and the fix differ, but happy to fold it into #47060 if you would prefer.

This is also not WebSocket specific. Apache HttpClient 5 sets `Connection: Upgrade` and `Upgrade: TLS/1.2` on every plain HTTP request by default, which is a valid RFC 2817 opportunistic TLS offer, so any proxy with an `upgrade_configs` entry for `TLS/1.2` and ext_proc body processing stalls on ordinary GETs and POSTs from those clients.

*Repro steps*:

Envoy `v1.36.2`, an ext_proc server that answers CONTINUE to everything and mutates nothing, and an upstream that returns 200. `stream_idle_timeout` is lowered to 20s so a stalled request terminates within a test run.

```
# stalls
curl -s -o /dev/null -w 'HTTP %{http_code} in %{time_total}s\n' --max-time 40 \
http://localhost:8080/anything -H 'Connection: Upgrade' -H 'Upgrade: TLS/1.2'
HTTP 408 in 20.010270s

# stalls with a Content-Length delimited body too
curl -s -o /dev/null -w 'HTTP %{http_code} in %{time_total}s\n' --max-time 40 \
-X POST http://localhost:8080/anything -H 'Connection: Upgrade' -H 'Upgrade: TLS/1.2' \
-H 'Content-Type: application/json' -d '{"a":"b"}'
HTTP 408 in 20.009069s

# same config plus ignore_http_11_upgrade for the same token: passes
curl -s -o /dev/null -w 'HTTP %{http_code} in %{time_total}s\n' --max-time 40 \
http://localhost:8083/anything -H 'Connection: Upgrade' -H 'Upgrade: TLS/1.2'
HTTP 200 in 0.019825s
```

Across seven request shapes on four otherwise identical listeners, varying only `request_body_mode`:

| Request | BUFFERED | STREAMED | NONE | BUFFERED + `ignore_http_11_upgrade` |
|---|---|---|---|---|
| plain GET, no body | 200 (6ms) | 200 | 200 | 200 |
| plain POST, body | 200 (3ms) | 200 | 200 | 200 |
| UPGRADE GET, no body | **408 @ 20.0s** | 200 (6ms) | 200 | 200 |
| UPGRADE GET, body | **408 @ 20.0s** | 200 (3ms) | 200 | 200 |
| UPGRADE POST, body | **408 @ 20.0s** | 200 (3ms) | 200 | 200 |
| `Connection: Upgrade` only | 200 (11ms) | 200 | 200 | 200 |
| `Upgrade: TLS/1.2` only | 200 (4ms) | 200 | 200 | 200 |

What this pins down:

* Both headers are required. Either alone passes, since `Utility::isUpgrade()` wants an `Upgrade` header *and* `Upgrade` in the `Connection` token list.
* It is not about whether a body exists: `UPGRADE POST, body` stalls too. That rules out skipping the body phase only when a request has no body.
* `BUFFERED` alone is fine and upgrade alone is fine. Only the combination stalls.
* `ignore_http_11_upgrade` for the same token keeps the codec out of upgrade mode and everything passes, which isolates upgrade mode as the cause.

The same scenario reproduces in `test/extensions/filters/http/ext_proc/ext_proc_misc_test.cc` alongside `WebSocketExtProcCombo`, by setting `request_body_mode: BUFFERED` on `proto_config_` and adding an `upgrade_configs` entry: the request headers reach the processor with `end_of_stream=false` and `fake_upstreams_[0]->waitForHttpConnection()` never completes.

*Admin and Stats Output*:

```
$ curl -s localhost:9901/server_info | jq -r '.version, .state'
dc2d3098ae5641555f15c71d5bb5ce0060a8015c/1.36.2/Clean/RELEASE/BoringSSL
LIVE
```

After the two stalling requests on the BUFFERED listener and one on the `ignore_http_11_upgrade` listener:

```
$ curl -s localhost:9901/stats | grep -E 'downstream_rq' | grep -v ': 0$'
http.buffered.downstream_rq_4xx: 2
http.buffered.downstream_rq_idle_timeout: 2
http.buffered.downstream_rq_total: 2
http.buffered_ignore_upgrade.downstream_rq_2xx: 1
http.buffered_ignore_upgrade.downstream_rq_total: 1
```

Both requests to the BUFFERED listener were reaped by the stream idle timeout. Nothing is recorded against the upstream cluster for them.

*Config*:

The stalling listener, trimmed to the relevant parts:

```yaml
- name: buffered
address: {socket_address: {address: 0.0.0.0, port_value: 8080}}
filter_chains:
- filters:
- name: envoy.filters.network.http_connection_manager
typed_config:
"@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager
stat_prefix: buffered
stream_idle_timeout: 20s # lowered from the 300s default
upgrade_configs:
- upgrade_type: "TLS/1.2"
enabled: true
route_config:
name: r
virtual_hosts:
- name: vh
domains: ["*"]
routes:
- match: {prefix: "/"}
route: {cluster: upstream, timeout: 5s}
http_filters:
- name: envoy.filters.http.ext_proc
typed_config:
"@type": type.googleapis.com/envoy.extensions.filters.http.ext_proc.v3.ExternalProcessor
grpc_service:
envoy_grpc: {cluster_name: extproc}
failure_mode_allow: false
message_timeout: 5s
processing_mode:
request_header_mode: SEND
response_header_mode: SEND
request_body_mode: BUFFERED
response_body_mode: NONE
request_trailer_mode: SKIP
response_trailer_mode: SKIP
- name: envoy.filters.http.router
typed_config:
"@type": type.googleapis.com/envoy.extensions.filters.http.router.v3.Router
```

The passing control listener is identical plus:

```yaml
http_protocol_options:
ignore_http_11_upgrade:
- exact: "TLS/1.2"
```

There is no per-route `ExtProcPerRoute` override anywhere in the config; the body modes are static filter config, so the stall is not related to ext_proc mode override.

*Logs*:

Envoy access log. `%RESPONSE_CODE_DETAILS%` and `%UPSTREAM_HOST%` are the informative fields:

```
[BUFFERED] GET /anything -> code=408 details=stream_idle_timeout flags=SI dur=20003ms upstream=-
[BUFFERED] POST /anything -> code=408 details=stream_idle_timeout flags=SI dur=20002ms upstream=-
[BUF+IGN ] GET /anything -> code=200 details=via_upstream flags=- dur=14ms upstream=172.25.0.3:8080
```

ext_proc server log for the same three requests. Streams 1 and 2 are the stalling ones: headers arrive with `end_of_stream=false`, no body message ever follows, and the stream is torn down 20s later without a response phase. Stream 3 is the `ignore_http_11_upgrade` control:

```
06:02:02.050406 [stream 1] === opened ===
06:02:02.052407 [stream 1] >> REQUEST_HEADERS end_of_stream=false :path="/anything" :method="GET" connection="Upgrade" upgrade="TLS/1.2"
06:02:22.050752 [stream 1] === closed ===
06:02:22.087935 [stream 2] === opened ===
06:02:22.088089 [stream 2] >> REQUEST_HEADERS end_of_stream=false :path="/anything" :method="POST" connection="Upgrade" upgrade="TLS/1.2" content-type="application/json" content-length="9"
06:02:42.091112 [stream 2] === closed ===
06:02:42.131579 [stream 3] === opened ===
06:02:42.131850 [stream 3] >> REQUEST_HEADERS end_of_stream=true :path="/anything" :method="GET"
06:02:42.141702 [stream 3] << RESPONSE_HEADERS end_of_stream=false
06:02:42.142213 [stream 3] === closed ===
```

Note stream 2: `content-length="9"` is present, so the request body is normally delimited, and it is still never delivered to the processor.

Upstream access log across all three requests. Only the control arrives:

```
[ORIGIN REACHED] GET /anything content-length=- bytes_received=0
```

With `--component-log-level http:trace` the codec logs `codec entering upgrade mode.` and `Pausing parser due to upgrade.` for the stalling requests.

*Call Stack*:

Not applicable, Envoy does not crash.

---

*Notes on the fix*

Copying #47060's `isConnect() || isUpgrade()` guard into the BUFFERED branch is not sufficient on its own. Resuming iteration does not change the data path, so a request with a body would block again on the first `decodeData`. Body processing would also have to be retired for the stream, for example `body_mode_ = ProcessingMode::NONE`.

That has a consequence worth deciding deliberately: body processing would then be skipped for upgrade requests carrying a normal `Content-Length` delimited body, not only for actual tunnels (see stream 2 above). For an extension that authorizes on the body, a client could skip inspection by adding two headers. The current behaviour is a stall, which at least fails safe.

Since BUFFERED plus upgrade has never worked on any release, no deployment depends on the current behaviour, so failing closed with a local reply is also available and would break nobody. Two questions:

1. Should a tunnel skip ext_proc request body processing, or should the request be rejected?
2. If it skips, can that be observable, a stat or a warn log, rather than silent?

Separately, and not a blocker: per RFC 9112 an upgrade request's body is delimited normally and the protocol switch happens after the 101, so the `content-length: 9` request above has a well defined 9 byte body. `codec_impl.cc:958` returns `CallbackResult::NoBodyData` for every upgrade request and discards that delimitation. Honouring it would fix the BUFFERED case without skipping anything, though I assume that is a much larger change given the HTTP/1 tunnel is modelled as the request body.

Contributor guide

Open the contributing guide

Research direction

Start with the upgrade handling in source/common/http/http1/codec_impl.cc, then trace BUFFERED processing in source/extensions/filters/http/ext_proc/ext_proc.cc and processor_state.cc. Reproduce the case in test/extensions/filters/http/ext_proc/ext_proc_misc_test.cc; done means an HTTP/1.1 upgrade with BUFFERED processing no longer hangs, either by completing the request or failing deterministically under the chosen policy.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp, grpc
Domain
backend, networking
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.