Envoy not retrying Http2 streams sent but ignored by server after a GOAWAY frame and returning 503s
- Dominant language
- C++
- Stars
- 28.9k
- Forks
- 5.6k
- Avg merge
- 1d 20h
- Merged PRs (30d)
- 437
Description
*Title*: Envoy not retrying Http2 streams sent but ignored by server after a GOAWAY frame and returning 503s
*Description*:
After configuring an Http2 AWS Application Load Balancer (ALB) as an upstream target and running load tests through Envoy, we observed sporadic 503s (a few out of every 10k) and did some investigation.
The problem appears to stem from ALB's [default behavior](https://docs.aws.amazon.com/elasticloadbalancing/latest/application/load-balancer-troubleshooting.html#response-code-000) of sending a `GOAWAY` frame every time a connection hits 10000 streams:

We validated this by looking at access logs and grouping them by TCP connection (`upstream_local_address`). Every observed 503 response would be the 10001+ request on that TCP connection.
I also captured and decrypted a PCAP between Envoy and the ALB and saw the same thing. At the very end of the TCP stream, Envoy sends an HTTP2 frame to the ALB with 6 streams inside, corresponding to 6 GET requests (19999, 20001, 20003, 20005, 20007, 20009)

The next frame is a `GOAWAY` response from the ALB indicating that the last stream processed was `19999`:

The ALB then gives the response for stream 19999 and sends a `FIN ACK`.
The problem is that each of those other streams that were sent in the frame before the `GOAWAY` are never retried. Each one of those requests results in a 503 from Envoy to the downstream (verified by looking at the request_id header in Wireshark)
Reading the [HTTP2 RFC](https://datatracker.ietf.org/doc/html/rfc9113#name-goaway), I think both AWS and Envoy are a little to blame. I think Envoy is _supposed_ to retry those streams on a new connection:
> If the receiver of the GOAWAY has sent data on streams with a higher stream identifier than what is indicated in the GOAWAY frame, those streams are not or will not be processed. The receiver of the GOAWAY frame can treat the streams as though they had never been created at all, thereby allowing those streams to be retried later on a new connection.
However, the ALB should also probably be more graceful about how it handles shutdowns on the 10k request mark:
> A server that is attempting to gracefully shut down a connection SHOULD send an initial GOAWAY frame with the last stream identifier set to 2^31-1 and a NO_ERROR code. This signals to the client that a shutdown is imminent and that initiating further requests is prohibited. After allowing time for any in-flight stream creation (at least one round-trip time), the server MAY send another GOAWAY frame with an updated last stream identifier. This ensures that a connection can be cleanly shut down without losing requests.
Doing some more digging, it looks like the official Go HTTP2 package also has the same issue with how to handle the ALB's abrupt `GOAWAYs`: https://github.com/golang/go/issues/18639
Is this a bug with Envoy's Http2 client? Should it be retrying lost streams on a new connection when it receives a `GOAWAY` for with a stream ID lower than the last one it sent?
I am also pursuing this with AWS support on the ALB side as well.
*Repro steps*:
Point to an Http2 Amazon ALB as an upstream cluster and run a load test with hey:
```
hey -z 5m http://127.0.0.1/ping
```
After a few minutes, some 503s will start to appear
*Config*:
```
admin:
address:
socket_address:
address: 0.0.0.0
port_value: 9090
static_resources:
listeners:
- name: envoy-listener-8080
traffic_direction: OUTBOUND
address:
socket_address:
address: 0.0.0.0
port_value: 8080
protocol: TCP
filter_chains:
- name: default_filter_chain
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
server_name: envoy
use_remote_address: true
generate_request_id: true
request_id_extension:
typed_config:
'@type': type.googleapis.com/envoy.extensions.request_id.uuid.v3.UuidRequestIdConfig
use_request_id_for_trace_sampling: false
access_log:
- name: envoy.access_loggers.file
typed_config:
'@type': type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog
path: "/dev/stdout"
log_format:
json_format:
component: http
# log the original authority before its rewritten
authority: "REQ(:AUTHORITY)"
bytes_received: "%BYTES_RECEIVED%"
bytes_sent: "%BYTES_SENT%"
downstream_local_address: "%DOWNSTREAM_LOCAL_ADDRESS%"
downstream_remote_address: "%DOWNSTREAM_REMOTE_ADDRESS%"
duration: "%DURATION%"
method: "%REQ(:METHOD)%"
path: "%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%"
protocol: "%PROTOCOL%"
request_id: "%REQ(X-REQUEST-ID)%"
requested_server_name: "%REQUESTED_SERVER_NAME%"
response_code: "%RESPONSE_CODE%"
response_code_details: '%RESPONSE_CODE_DETAILS%'
response_flags: "%RESPONSE_FLAGS%"
start_time: "%START_TIME%"
upstream_cluster: "%UPSTREAM_CLUSTER%"
upstream_host: "%UPSTREAM_HOST%"
upstream_authority: "%REQ(:AUTHORITY)%"
upstream_protocol: "%UPSTREAM_PROTOCOL%"
upstream_path: "%REQ(:PATH)%"
upstream_local_address: "%UPSTREAM_LOCAL_ADDRESS%"
upstream_service_time: "%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%"
upstream_transport_failure_reason: "%UPSTREAM_TRANSPORT_FAILURE_REASON%"
upstream_request_attempt_count: "%UPSTREAM_REQUEST_ATTEMPT_COUNT%"
upstream_request_bytes_received: "%UPSTREAM_HEADER_BYTES_RECEIVED%"
upstream_connection_pool_ready_duration: "%UPSTREAM_CONNECTION_POOL_READY_DURATION%"
upstream_peer_subject: "%UPSTREAM_PEER_SUBJECT%"
upstream_peer_issuer: "%UPSTREAM_PEER_ISSUER%"
upstream_tls_session_id: "%UPSTREAM_TLS_SESSION_ID%"
upstream_tls_cipher: "%UPSTREAM_TLS_CIPHER%"
upstream_tls_version: "%UPSTREAM_TLS_VERSION%"
upstream_peer_cert: "%UPSTREAM_PEER_CERT%"
upstream_peer_cert_v_start: "%UPSTREAM_PEER_CERT_V_START%"
upstream_peer_cert_v_end: "%UPSTREAM_PEER_CERT_V_END%"
user_agent: "%REQ(USER-AGENT)%"
x_forwarded_for: "%REQ(X-FORWARDED-FOR)%"
upstream_connection_id: "%UPSTREAM_CONNECTION_ID%"
stream_id: "%STREAM_ID%"
upstream_connection_pool_ready: "%UPSTREAM_CONNECTION_POOL_READY_DURATION%"
http_filters:
- name: envoy.filters.http.router
typed_config:
'@type': type.googleapis.com/envoy.extensions.filters.http.router.v3.Router
route_config:
virtual_hosts:
- name: poc-alb
domains: ["*"]
routes:
- match:
prefix: "/"
route:
cluster: poc-alb
clusters:
- name: poc-alb
dns_lookup_family: V4_ONLY
connect_timeout: 5s
type: LOGICAL_DNS
lb_policy: ROUND_ROBIN
transport_socket:
name: envoy.transport_socket.tls
typed_config:
'@type': type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
common_tls_context:
key_log:
path: /configs/keylog.log
typed_extension_protocol_options:
envoy.extensions.upstreams.http.v3.HttpProtocolOptions:
"@type": type.googleapis.com/envoy.extensions.upstreams.http.v3.HttpProtocolOptions
auto_config:
http_protocol_options: {}
http2_protocol_options: {}
load_assignment:
cluster_name: poc-alb
endpoints:
- lb_endpoints:
- endpoint:
address:
socket_address:
address: 10.162.31.60 # private ALB IP address
port_value: 443
protocol: TCP
```
*Logs*:
The debug logs during the load test are ~650MB. I will try to do some filteirng and sorting if there's specific things I should be grepping for?
Contributor guide
Assessment
This issue has not been assessed yet.