ext_proc: HTTP/1.1 upgrade request hangs with BUFFERED request body mode`
- 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
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