Stream Idle Timer Fires Even When Stream Was Active

[modatwork]

Description:

Envoy should not fire stream idle timer when it's active.

Repro steps:

1. create a listener with stream_idle_timeout set to 60s
2. a client with a low bandwidth network download a file through Envoy proxy, curl -v -k --limit-rate 1 https://localhost:7443/2MB.txt -o 2MB.txt
3. after about 65 seconds, envoy close the connection and output an access log with an SI flag in it: [2024-05-09T03:15:14.949Z] "GET /2MB.txt HTTP/1.1" 200 SI 0 835584 60020 2 "172.16.120.74" "curl/8.6.0" "bc69c5d5-e27e-4809-aac4-420acaae5b47" "localhost:7443" "127.0.0.1:8080"

Admin and Stats Output:

• stats: stats.log
• clusters: clusters.log
• routes: routes.log
• server info: server_info.log

Config:

- 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
          use_remote_address: true
          normalize_path: true
          merge_slashes: true
          path_with_escaped_slashes_action: UNESCAPE_AND_REDIRECT
          request_timeout: 1200s
          request_headers_timeout: 65s
          stream_idle_timeout: 60s
          common_http_protocol_options:
            max_stream_duration: 3600s
            idle_timeout: 70s
          http2_protocol_options:
            max_concurrent_streams: 100
            initial_stream_window_size: 65536 # 64 KiB
            initial_connection_window_size: 1048576 # 1 MiB
          access_log:
          - name: envoy.access_loggers.file
            typed_config:
              "@type": type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog
              path: "debug/logs/access_7443.log"
          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: default
              domains: ["*"]
              routes:
              - match: {prefix: "/"}
                route:
                  cluster: service_foo
                  timeout: 3600s

Logs:

• debug log: stdout.log

[modatwork]

[2024-05-09 11:15:14.963][11636530][debug][http] [source/common/http/conn_manager_impl.cc:1939] [Tags: "ConnectionId":"0","StreamId" :"13380574157739000950"] Disabling upstream stream due to downstream stream watermark.

For a slow downstream, stream buffer's watermark is high and it takes a long time to recover to low. During this time client is downloading slowly but Envoy won't receive from upstream and won't reset its idle timer.

In my case the client is an IoT device with a 4kbps bandwidth. Envoy's per_connection_buffer_limit_bytes is set to 32 KB. So it takes 32 seconds (32KB / 2 / (4kbps / 8)) to return to low watermark. But if the connection buffer is higher it may take much more time.

[modatwork]

The issue can be mitigated by either increasing the stream_idle_timeout or decreasing the per_connection_buffer_limit_bytes, if applicable to the use case.

[phlax]

cc @alyssawilk @mattklein123

[alyssawilk]

I think we could add a config option for not making progress when backed up. I'm not sure we'd want it on by default but we could also runtime guard and add a knob if folks prefer the old behavior