HTTP2 locally-originated stream resets use the NO_ERROR code #36200

AdamEAnderson · 2024-09-18T18:47:30Z

HTTP2 locally-originated stream resets use the NO_ERROR code: When envoy originates a stream reset on an HTTP2 codec it sends a RST_STREAM frame but erroneously uses the NO_ERROR error code, causing clients to think the stream terminated successfully

Description:
When envoy's HTTP2 codec sends a stream reset, it converts the stream reset reason into an HTTP2 error code here. Only two reset reasons are covered, and the remainder reset with NO_ERROR. From the RFC, NO_ERROR indicates:

The associated condition is not a result of an error. For example, a GOAWAY might include this code to indicate graceful shutdown of a connection.

The other reset reasons (see all here) are terminated as NO_ERROR indicating that the stream is complete.

Here's an example where I ran into this issue:

Upstream is HTTP1
Downstream is HTTP2
Downstream sends a GET request as HTTP2
Upstream gets the request headers as HTTP1
Upstream sends happy response headers (200 OK) with Transfer-Encoding: chunked
Downstream receives response headers
Upstream sends response data in chunks, but gets an error part way through the response body. Headers were already sent, so all it can do is reset the HTTP1 stream
Envoy sees this as a protocol error, HPE_INVALID_EOF_STATE
Envoy proxies the reset by resetting the downstream HTTP2 stream
However the downstream stream is reset with 0x00, NO_ERROR
The client sees this and thinks the response body is complete and nothing is amiss, not realizing it doesn't have a complete response

Repro steps:
Python server to provide partial chunked responses over HTTP/1.1:

import socket
import threading

def handle_client(client_socket: socket.socket):
    _ = client_socket.recv(1024).decode()
    response = "HTTP/1.1 200 OK\r\nContent-Type: text/plain\r\nTransfer-Encoding: chunked\r\n\r\n5\r\nHel"
    # response = "HTTP/1.1 200 OK\r\nContent-Type: text/plain\r\nTransfer-Encoding: chunked\r\n\r\n5\r\nHello\r\n0\r\n\r\n"
    client_socket.sendall(response.encode())
    client_socket.close()

def start_server(host='127.0.0.1', port=8080):
    server_socket = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
    server_socket.bind((host, port))
    server_socket.listen(5)
    print(f"Serving HTTP on {host} port {port} ...")

    while True:
        client_socket, _ = server_socket.accept()
        client_handler = threading.Thread(target=handle_client, args=(client_socket,))
        client_handler.start()

if __name__ == "__main__":
    start_server()

Envoy config:

admin:
  address:
    socket_address: { address: 127.0.0.1, port_value: 19901 }
static_resources:
  listeners:
  - name: listener_0
    address:
      socket_address:
        address: 127.0.0.1
        port_value: 10000
    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: ingress_http
          codec_type: HTTP2
          access_log:
          - name: envoy.access_loggers.stdout
            typed_config:
              "@type": type.googleapis.com/envoy.extensions.access_loggers.stream.v3.StdoutAccessLog
          http_filters:
          - name: envoy.filters.http.router
            typed_config:
              "@type": type.googleapis.com/envoy.extensions.filters.http.router.v3.Router
          route_config:
            name: local_route
            virtual_hosts:
            - name: local_service
              domains: ["*"]
              routes:
              - match:
                  prefix: "/"
                route:
                  cluster: service
  clusters:
  - name: service
    type: STATIC
    dns_lookup_family: V4_ONLY
    load_assignment:
      cluster_name: service
      endpoints:
      - lb_endpoints:
        - endpoint:
            address:
              socket_address:
                address: 127.0.0.1
                port_value: 8080

then reach envoy via an nghttp client (settings, priority, window_update frames omitted):

with partial chunked response:

[  0.005] Connected
[  0.005] send HEADERS frame <length=38, flags=0x25, stream_id=13>
          ; END_STREAM | END_HEADERS | PRIORITY
          (padlen=0, dep_stream_id=11, weight=16, exclusive=0)
          ; Open new stream
          :method: GET
          :path: /
          :scheme: http
          :authority: localhost:10000
          accept: */*
          accept-encoding: gzip, deflate
          user-agent: nghttp2/1.63.0
[  0.045] recv (stream_id=13) :status: 200
[  0.045] recv (stream_id=13) content-type: text/plain
[  0.045] recv (stream_id=13) x-envoy-upstream-service-time: 7
[  0.045] recv (stream_id=13) date: Tue, 17 Sep 2024 23:18:26 GMT
[  0.045] recv (stream_id=13) server: envoy
[  0.045] recv HEADERS frame <length=65, flags=0x04, stream_id=13>
          ; END_HEADERS
          (padlen=0)
          ; First response header
[  0.045] recv DATA frame <length=3, flags=0x00, stream_id=13>
[  0.045] recv RST_STREAM frame <length=4, flags=0x00, stream_id=13>
          (error_code=NO_ERROR(0x00))
[  0.045] send GOAWAY frame <length=8, flags=0x00, stream_id=0>
          (last_stream_id=0, error_code=NO_ERROR(0x00), opaque_data(0)=[])

with complete response:

[  0.011] Connected
[  0.011] send HEADERS frame <length=38, flags=0x25, stream_id=13>
          ; END_STREAM | END_HEADERS | PRIORITY
          (padlen=0, dep_stream_id=11, weight=16, exclusive=0)
          ; Open new stream
          :method: GET
          :path: /
          :scheme: http
          :authority: localhost:10000
          accept: */*
          accept-encoding: gzip, deflate
          user-agent: nghttp2/1.63.0
[  0.014] recv (stream_id=13) :status: 200
[  0.014] recv (stream_id=13) content-type: text/plain
[  0.014] recv (stream_id=13) x-envoy-upstream-service-time: 1
[  0.014] recv (stream_id=13) date: Tue, 17 Sep 2024 23:22:55 GMT
[  0.014] recv (stream_id=13) server: envoy
[  0.014] recv HEADERS frame <length=65, flags=0x04, stream_id=13>
          ; END_HEADERS
          (padlen=0)
          ; First response header
[  0.014] recv DATA frame <length=5, flags=0x00, stream_id=13>
[  0.014] recv DATA frame <length=0, flags=0x01, stream_id=13>
          ; END_STREAM
[  0.014] send GOAWAY frame <length=8, flags=0x00, stream_id=0>
          (last_stream_id=0, error_code=NO_ERROR(0x00), opaque_data(0)=[])

Envoy trace logs around the event:

[2024-09-17 15:54:44.924][54449801][debug][client] [source/common/http/codec_client.cc:170] [Tags: "ConnectionId":"1"] Error dispatching received data: http/1.1 protocol error: HPE_INVALID_EOF_STATE
[2024-09-17 15:54:44.924][54449801][debug][client] [source/common/http/codec_client.cc:107] [Tags: "ConnectionId":"1"] disconnect. resetting 1 pending requests
[2024-09-17 15:54:44.924][54449801][debug][client] [source/common/http/codec_client.cc:158] [Tags: "ConnectionId":"1"] request reset
[2024-09-17 15:54:44.924][54449801][trace][main] [source/common/event/dispatcher_impl.cc:242] item added to deferred deletion list (size=1)
[2024-09-17 15:54:44.924][54449801][debug][router] [source/common/router/router.cc:1323] [Tags: "ConnectionId":"0","StreamId":"164029717455481211"] upstream reset: reset reason: protocol error, transport failure reason: 
[2024-09-17 15:54:44.924][54449801][trace][main] [source/common/event/dispatcher_impl.cc:242] item added to deferred deletion list (size=2)
[2024-09-17 15:54:44.924][54449801][trace][main] [source/common/event/dispatcher_impl.cc:242] item added to deferred deletion list (size=3)
[2024-09-17 15:54:44.924][54449801][debug][http] [source/common/http/filter_manager.cc:974] [Tags: "ConnectionId":"0","StreamId":"164029717455481211"] Resetting stream due to upstream_reset_after_response_started{protocol_error}. Prior headers have already been sent
[2024-09-17 15:54:44.925][54449801][debug][http] [source/common/http/conn_manager_impl.cc:243] [Tags: "ConnectionId":"0","StreamId":"164029717455481211"] doEndStream() resetting stream
[2024-09-17 15:54:44.925][54449801][debug][http] [source/common/http/conn_manager_impl.cc:1932] [Tags: "ConnectionId":"0","StreamId":"164029717455481211"] stream reset: reset reason: protocol error, response details: -
[2024-09-17 15:54:44.925][54449801][trace][main] [source/common/event/dispatcher_impl.cc:242] item added to deferred deletion list (size=4)
[2024-09-17 15:54:44.925][54449801][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x11e76c2b0 for 3600000ms, min is 3600000ms
[2024-09-17 15:54:44.925][54449801][trace][http2] [source/common/http/http2/codec_impl.cc:1315] [Tags: "ConnectionId":"0"] about to send frame type=3, flags=0
[2024-09-17 15:54:44.925][54449801][trace][http2] [source/common/http/http2/codec_impl.cc:1337] [Tags: "ConnectionId":"0"] send data: bytes=13
[2024-09-17 15:54:44.925][54449801][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 13 bytes, end_stream false
[2024-09-17 15:54:44.925][54449801][trace][http2] [source/common/http/http2/codec_impl.cc:1208] [Tags: "ConnectionId":"0"] sent frame type=3, stream_id=1, length=4
[2024-09-17 15:54:44.925][54449801][debug][http2] [source/common/http/http2/codec_impl.cc:1237] [Tags: "ConnectionId":"0"] sent reset code=0
[2024-09-17 15:54:44.925][54449801][debug][http2] [source/common/http/http2/codec_impl.cc:1362] [Tags: "ConnectionId":"0"] stream 1 closed: 0

Desired behavior:
Envoy should use a non-zero error code when resetting HTTP2 streams. For the chunked encoding case, PROTOCOL_ERROR would seem appropriate.

I have a PR (will submit soon) that should fix this, but it will require us to make some decisions about what the right error codes are for each situation.

The text was updated successfully, but these errors were encountered:

zuercher · 2024-09-18T21:00:54Z

cc @alyssawilk

AdamEAnderson added bug triage Issue requires triage labels Sep 18, 2024

AdamEAnderson linked a pull request Sep 18, 2024 that will close this issue

http2: improve coordination between StreamResetReason and HTTP2 RST_STREAM error codes #36203

Draft

zuercher added the area/http label Sep 18, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

HTTP2 locally-originated stream resets use the NO_ERROR code #36200

HTTP2 locally-originated stream resets use the NO_ERROR code #36200

AdamEAnderson commented Sep 18, 2024 •

edited

Loading

zuercher commented Sep 18, 2024

HTTP2 locally-originated stream resets use the NO_ERROR code #36200

HTTP2 locally-originated stream resets use the NO_ERROR code #36200

Comments

AdamEAnderson commented Sep 18, 2024 • edited Loading

zuercher commented Sep 18, 2024

AdamEAnderson commented Sep 18, 2024 •

edited

Loading