search

envoyproxy / envoy

Cloud-native high-performance edge/middle/service proxy
https://www.envoyproxy.io
Apache License 2.0
24.27k stars 4.69k forks source link

Envoy doesn't call ExtAuthz filter for some calls #32058

Open jpmca12 opened 5 months ago

jpmca12 commented 5 months ago

Description:

What issue is being seen? Describe what should be happening instead of the bug.

We use ExtAuthz type.googleapis.com/envoy.extensions.filters.http.ext_authz.v3.ExtAuthz filter. Many routes are configured in envoy config and want all requests to first pass through ExtAuthz filter for authentication.

When there is a load on Envoy say more than 15 RPS, we observed that for couple of requests Envoy doesn't call the ExtAuthz filter and just returns 503. looks like we are missing some configuration.

Below is the trimmed version of our envoy config and logs.

Envoy Configuration

admin:
  address:
    socket_address:
      protocol: TCP
      address: 0.0.0.0
      port_value: 9901
static_resources:
  listeners:
    - name: listener_0
      address:
        socket_address:
          protocol: TCP
          address: 0.0.0.0
          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
                http_protocol_options:
                  accept_http_10: true
                stat_prefix: ingress_http
                stream_idle_timeout: 900s
                access_log:
                  - name: envoy.access_loggers.stdout
                    typed_config:
                      "@type": type.googleapis.com/envoy.extensions.access_loggers.stream.v3.StdoutAccessLog
                      log_format:
                        json_format:
                          "start_time": "%START_TIME%"
                          "request_id": "%REQ(X-REQUEST-ID)%"
                          "user_agent": "%REQ(USER-AGENT)%"
                          "method": "%REQ(:METHOD)%"
                          "path": "%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%"
                          "protocol": "%PROTOCOL%"
                          "upstream_protocol": "%UPSTREAM_PROTOCOL%"
                          "request_authority": "%REQ(:AUTHORITY)%"
                          "status": "%RESPONSE_CODE%"
                          "start_time_to_last_byte_out_ms": "%DURATION%"
                          "upstream_service_time": "%RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%"
                          "response_flag": "%RESPONSE_FLAGS%"
                          "response_code_details": "%RESPONSE_CODE_DETAILS%"
                          "hostname": "%HOSTNAME%"
                          "upstream_cluster": "%UPSTREAM_CLUSTER%"
                          "original-host": "%REQ(X-Forwarded-Host)%"
                http_filters:
                  - name: envoy.filters.http.lua
                    typed_config:
                      '@type': type.googleapis.com/envoy.extensions.filters.http.lua.v3.Lua
                      inlineCode: |
                        function envoy_on_request(request_handle)
                        end
                      source_codes:
                        some.lua:
                          inline_string: |
                            function envoy_on_request(request_handle)
                              request_handle:headers():add("X-Forwarded-Host", request_handle:headers():get("host"))
                              local path_without_querystring = string.match(request_handle:headers():get(":path"), "([^?]+)")
                              request_handle:headers():add("X-Forwarded-Path", path_without_querystring)
                            end
                  - name: envoy.filters.http.ext_authz
                    typed_config:
                      "@type": type.googleapis.com/envoy.extensions.filters.http.ext_authz.v3.ExtAuthz
                      clear_route_cache: true
                      transport_api_version: V3
                      include_peer_certificate: true
                      status_on_error:
                        code: "InternalServerError"
                      http_service:
                        server_uri:
                          uri: localhost:8080
                          cluster: ext_authz-http-service
                          timeout: 100s
                        path_prefix: /auth
                        authorization_response:
                          allowed_upstream_headers:
                            patterns:
                              - exact: "authorization"
                              - exact: "correlationid"
                        authorization_request:
                          allowed_headers:
                            patterns:
                              - exact: "authorization"
                              - exact: "host"
                              - exact: "x-request-id"
                  - name: envoy.filters.http.router
                    typed_config:
                      "@type": type.googleapis.com/envoy.extensions.filters.http.router.v3.Router
                route_config:
                  name: some_local_route
                  virtual_hosts:
                    - name: some_domains
                      domains: ["*"]
                      routes:
                        - match:
                            prefix: "/api"
                          route:
                            timeout: 900s
                            cluster: some-cluster
                            auto_host_rewrite: true
                            append_x_forwarded_host: true
                        - match:
                            prefix: "/healthz"
                          route:
                            prefix_rewrite: "/health"
                            timeout: 1s
                            cluster: ext_authz-http-service
                            auto_host_rewrite: true
                            append_x_forwarded_host: true
                          typed_per_filter_config:
                            envoy.filters.http.ext_authz:
                              "@type": type.googleapis.com/envoy.extensions.filters.http.ext_authz.v3.ExtAuthzPerRoute
                              disabled: true
  clusters:
    - name: some-cluster
      type: LOGICAL_DNS
      lb_policy: ROUND_ROBIN
      load_assignment:
        cluster_name: some-cluster
        endpoints:
          - lb_endpoints:
              - endpoint:
                  address:
                    socket_address:
                      address: some-service.com
                      port_value: 443
      transport_socket:
        name: envoy.transport_sockets.tls
        typed_config:
          "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
          sni: some-service.com
    - name: ext_authz-http-service
      connect_timeout: 0.250s
      type: STRICT_DNS
      lb_policy: ROUND_ROBIN
      load_assignment:
        cluster_name: ext_authz-http-service
        endpoints:
          - lb_endpoints:
              - endpoint:
                  address:
                    socket_address:
                      address: localhost
                      port_value: 8080

Logs

2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][pool] [source/common/conn_pool/conn_pool_base.cc:215] [Tags: "ConnectionId":"15140"] destroying stream: 0 remaining
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][pool] [source/common/conn_pool/conn_pool_base.cc:484] [Tags: "ConnectionId":"15140"] client disconnected, failure reason:
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][http] [source/common/http/conn_manager_impl.cc:1925] [Tags: "ConnectionId":"15406","StreamId":"13145634703429981886"] Codec completed encoding stream.
2023-11-30 18:16:33.185
2023-11-30 18:16:33.185 'server', 'envoy'
2023-11-30 18:16:33.185 'date', 'Thu, 30 Nov 2023 18:16:33 GMT'
2023-11-30 18:16:33.185 ':status', '500'
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][http] [source/common/http/conn_manager_impl.cc:1820] [Tags: "ConnectionId":"15406","StreamId":"13145634703429981886"] encoding headers via codec (end_stream=true):
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][http] [source/common/http/filter_manager.cc:996] [Tags: "ConnectionId":"15406","StreamId":"13145634703429981886"] Sending local reply with details ext_authz_error
2023-11-30 18:16:33.185
2023-11-30 18:16:33.185 'content-type', 'text/plain'
2023-11-30 18:16:33.185 'content-length', '95'
2023-11-30 18:16:33.185 ':status', '503'
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][http] [source/common/http/async_client_impl.cc:123] async http request response headers (end_stream=false):
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][router] [source/common/router/router.cc:1281] [Tags: "ConnectionId":"0","StreamId":"15018213574545538674"] upstream reset: reset reason: connection termination, transport failure reason:
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][client] [source/common/http/codec_client.cc:158] [Tags: "ConnectionId":"15140"] request reset
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][client] [source/common/http/codec_client.cc:107] [Tags: "ConnectionId":"15140"] disconnect. resetting 1 pending requests
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][connection] [source/common/network/connection_impl.cc:250] [Tags: "ConnectionId":"15140"] closing socket: 0
2023-11-30 18:16:33.185 [2023-11-30 18:16:33.185][18][debug][connection] [source/common/network/connection_impl.cc:663] [Tags: "ConnectionId":"15140"] remote close (edited)

Failures are random.

We tried playing around with below setting but no success.

upstream_connection_options:
  tcp_keepalive:
    keepalive_interval: 10
    keepalive_time: 1

max_requests_per_connection: 1

Happy to share more logs if required. Please help. thanks

zuercher commented 5 months ago

Sending local reply with details ext_authz_error

Envoy encountered an error querying the authz server. I expect looking at the stats for the ext_authz-http-service cluster and/or turning on logging for the ext_authz category will shed more light on the issue.

jpmca12 commented 5 months ago

Thanks @zuercher for your help. Please find TRACE logs below, we didn't get any meaningful insight, would really appreciate your help here, Thanks

logs below are from latest to oldest


2024-01-31 21:53:37.306 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:122] clearing deferred deletion list (size=1)
2024-01-31 21:53:37.306 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=1)
2024-01-31 21:53:37.306 [2024-01-31 21:53:37.305][27][debug][conn_handler] [source/common/listener_manager/active_stream_listener_base.cc:136] [Tags: "ConnectionId":"17605"] adding to cleanup list
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][conn_handler] [source/common/listener_manager/active_stream_listener_base.cc:126] [Tags: "ConnectionId":"17605"] tcp connection on event 0
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/connection_impl.cc:469] [Tags: "ConnectionId":"17605"] raising connection event 0
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][debug][connection] [source/common/network/connection_impl.cc:278] [Tags: "ConnectionId":"17605"] closing socket: 0
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/connection_impl.cc:687] [Tags: "ConnectionId":"17605"] read: rst close from peer
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/raw_buffer_socket.cc:39] [Tags: "ConnectionId":"17605"] read error: Connection reset by peer, code: 9
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"17605"] read ready. dispatch_buffered_data=0
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"17605"] write ready
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"17605"] socket event: 3
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/raw_buffer_socket.cc:70] [Tags: "ConnectionId":"17605"] write returns: 109
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"17605"] write ready
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"17605"] socket event: 2
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][debug][pool] [source/common/conn_pool/conn_pool_base.cc:215] [Tags: "ConnectionId":"17458"] destroying stream: 0 remaining
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][lua] [./source/extensions/filters/common/lua/lua.h:210] marking dead N5Envoy10Extensions11HttpFilters3Lua19StreamHandleWrapperE at 0x7f3bdd330220
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:122] clearing deferred deletion list (size=8)
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=8)
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=7)
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][debug][pool] [source/common/conn_pool/conn_pool_base.cc:495] [Tags: "ConnectionId":"17458"] client disconnected, failure reason:
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=6)
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x36203f1acc80 for 3600000ms, min is 3600000ms
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=5)
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.305][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=4)
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.304][27][debug][http] [source/common/http/conn_manager_impl.cc:1974] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] Codec completed encoding stream.
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"17605"] writing 109 bytes, end_stream false
2024-01-31 21:53:37.305
2024-01-31 21:53:37.305 'server', 'envoy'
2024-01-31 21:53:37.305 'date', 'Wed, 31 Jan 2024 21:53:36 GMT'
2024-01-31 21:53:37.305 ':status', '500'
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.304][27][debug][http] [source/common/http/conn_manager_impl.cc:1869] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] encoding headers via codec (end_stream=true):
2024-01-31 21:53:37.305 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/filter_manager.cc:1233] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] encode headers called: filter=envoy.filters.http.lua status=0
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/filter_manager.cc:1233] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] encode headers called: filter=envoy.filters.http.ext_authz status=0
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][ext_authz] [source/extensions/filters/http/ext_authz/ext_authz.cc:221] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] ext_authz filter has 0 response header(s) to add and 0 response header(s) to set to the encoded response:
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x36203f17ac00 for 900000ms, min is 900000ms
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][http] [source/common/http/filter_manager.cc:1065] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] Sending local reply with details ext_authz_error
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][ext_authz] [source/extensions/filters/http/ext_authz/ext_authz.cc:468] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] ext_authz filter rejected the request with an error. Response status code: 500
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/async_client_impl.cc:123] async http request response data (length=95 end_stream=true)
2024-01-31 21:53:37.304
2024-01-31 21:53:37.304 'content-type', 'text/plain'
2024-01-31 21:53:37.304 'content-length', '95'
2024-01-31 21:53:37.304 ':status', '503'
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][http] [source/common/http/async_client_impl.cc:106] async http request response headers (end_stream=false):
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=3)
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=2)
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][router] [source/common/router/router.cc:1331] [Tags: "ConnectionId":"0","StreamId":"605854097191452484"] upstream reset: reset reason: connection termination, transport failure reason:
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=1)
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][client] [source/common/http/codec_client.cc:158] [Tags: "ConnectionId":"17458"] request reset
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][client] [source/common/http/codec_client.cc:107] [Tags: "ConnectionId":"17458"] disconnect. resetting 1 pending requests
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/http1/codec_impl.cc:698] [Tags: "ConnectionId":"17458"] parsed 0 bytes
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/http1/codec_impl.cc:648] [Tags: "ConnectionId":"17458"] parsing 0 bytes
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/connection_impl.cc:469] [Tags: "ConnectionId":"17458"] raising connection event 0
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][connection] [source/common/network/connection_impl.cc:278] [Tags: "ConnectionId":"17458"] closing socket: 0
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][connection] [source/common/network/connection_impl.cc:714] [Tags: "ConnectionId":"17458"] remote close
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/raw_buffer_socket.cc:25] [Tags: "ConnectionId":"17458"] read returns: 0
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"17458"] read ready. dispatch_buffered_data=0
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/raw_buffer_socket.cc:70] [Tags: "ConnectionId":"17458"] write returns: 2367
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"17458"] write ready
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"17458"] socket event: 3
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/http1/codec_impl.cc:698] [Tags: "ConnectionId":"17605"] parsed 2423 bytes
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x36203f17ac00 for 900000ms, min is 900000ms
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"17605","StreamId":"12358221844973248411"] decode headers called: filter=envoy.filters.http.ext_authz status=4
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"0","StreamId":"605854097191452484"] decode headers called: filter=envoy.filters.http.upstream_codec status=0
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][client] [source/common/http/codec_client.cc:141] [Tags: "ConnectionId":"17458"] encode complete
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"17458"] writing 2367 bytes, end_stream false
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][router] [source/common/router/upstream_codec_filter.cc:61] [Tags: "ConnectionId":"0","StreamId":"605854097191452484"] proxying headers
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][trace][pool] [source/common/conn_pool/conn_pool_base.cc:131] not creating a new connection, shouldCreateNewConnection returned false.
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][router] [source/common/router/upstream_request.cc:569] [Tags: "ConnectionId":"0","StreamId":"605854097191452484"] pool ready
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][pool] [source/common/conn_pool/conn_pool_base.cc:182] [Tags: "ConnectionId":"17458"] creating stream
2024-01-31 21:53:37.304 [2024-01-31 21:53:37.304][27][debug][pool] [source/common/conn_pool/conn_pool_base.cc:265] [Tags: "ConnectionId":"17458"] using existing fully connected connection
github-actions[bot] commented 4 months ago

This issue has been automatically marked as stale because it has not had activity in the last 30 days. It will be closed in the next 7 days unless it is tagged "help wanted" or "no stalebot" or other activity occurs. Thank you for your contributions.

github-actions[bot] commented 3 months ago

This issue has been automatically closed because it has not had activity in the last 37 days. If this issue is still valid, please ping a maintainer and ask them to label it as "help wanted" or "no stalebot". Thank you for your contributions.

jpmca12 commented 3 months ago

@zuercher This issue is blocking us, appreciate any help on this please. Adding complete trace log below,

Not sure if this information helps,

{
"start_time":"2024-03-14T23:21:13.407Z",
"upstream_service_time":null,
"upstream_request_attempt_count":0,
"response_code_details":"ext_authz_error",
"response_flag":"UAEX",
"original-host":null,
"path":"some-path",
"start_time_to_first_byte_from_upstream_ms":null,
"x-correlationid":null,
"connection_termination_details":null,
"upstream_protocol":null,
"start_time_to_last_byte_out_ms":2,
"request_authority":"some-url",
"status":500,
"protocol":"HTTP/1.1",
"method":"GET",
"user_agent":"PostmanRuntime/7.32.2",
"upstream_cluster":"some-cluster",
"hostname":"some-host",
"request_id":"59f410fa-0748-40f7-ac59-5a9a15d0d4e8",
"start_time_to_last_byte_to_upstream_ms":null,
"start_time_to_last_byte_from_downstream_ms":0
}

Log

2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][http] [source/common/http/conn_manager_impl.cc:1192] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] request headers complete (end_stream=true):
2024-03-15 07:00:59.290 ':authority', 'some-url'
2024-03-15 07:00:59.290 ':path', 'some-path'
2024-03-15 07:00:59.290 ':method', 'GET'
2024-03-15 07:00:59.290 'user-agent', 'PostmanRuntime/7.32.2'
2024-03-15 07:00:59.290 'accept-encoding', 'gzip, deflate, br'
2024-03-15 07:00:59.290 'accept', '*/*'
2024-03-15 07:00:59.290 'authorization', 'Bearer <token>'
2024-03-15 07:00:59.290 'content-type', 'application/json'
2024-03-15 07:00:59.290 'x-forwarded-proto', 'https'
2024-03-15 07:00:59.290 'x-ssl-client-something1', ''
2024-03-15 07:00:59.290 'x-ssl-client-something2', ''
2024-03-15 07:00:59.290 'x-ssl-client-something3', ''
2024-03-15 07:00:59.290 'x-forwarded-for', '131.211.231.41'
2024-03-15 07:00:59.290
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][http] [source/common/http/conn_manager_impl.cc:1175] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] request end stream
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][connection] [./source/common/network/connection_impl.h:98] [Tags: "ConnectionId":"291883"] current connecting state: false
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][lua] [./source/extensions/filters/common/lua/lua.h:149] creating N5Envoy10Extensions11HttpFilters3Lua19StreamHandleWrapperE at 0x7ff5b800c6d0
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][lua] [./source/extensions/filters/common/lua/lua.h:149] creating N5Envoy10Extensions11HttpFilters3Lua16HeaderMapWrapperE at 0x7ff5b800c870
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][lua] [source/extensions/filters/common/lua/lua.cc:39] coroutine finished
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][lua] [./source/extensions/filters/common/lua/lua.h:210] marking dead N5Envoy10Extensions11HttpFilters3Lua19StreamHandleWrapperE at 0x7ff5b800c6d0
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][lua] [./source/extensions/filters/common/lua/lua.h:210] marking dead N5Envoy10Extensions11HttpFilters3Lua16HeaderMapWrapperE at 0x7ff5b800c870
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] decode headers called: filter=envoy.filters.http.lua status=0
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][ext_authz] [source/extensions/filters/http/ext_authz/ext_authz.cc:111] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] ext_authz filter calling authorization server
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][router] [source/common/router/router.cc:514] [Tags: "ConnectionId":"0","StreamId":"3156243965685767052"] cluster 'ext_authz-http-service' match for URL 'some-path'
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][router] [source/common/router/router.cc:731] [Tags: "ConnectionId":"0","StreamId":"3156243965685767052"] router decoding headers:
2024-03-15 07:00:59.290 ':path', 'some-path'
2024-03-15 07:00:59.290 ':authority', 'some-url'
2024-03-15 07:00:59.290 ':method', 'GET'
2024-03-15 07:00:59.290 ':scheme', 'http'
2024-03-15 07:00:59.290 'content-length', '0'
2024-03-15 07:00:59.290 'x-ssl-client-something2', ''
2024-03-15 07:00:59.290 'authorization', 'Bearer <token>'
2024-03-15 07:00:59.290 'x-request-id', '59f410fa-0748-40f7-ac59-5a9a15d0d4e8'
2024-03-15 07:00:59.290 'x-ssl-client-something1', ''
2024-03-15 07:00:59.290 'x-envoy-internal', 'true'
2024-03-15 07:00:59.290 'x-envoy-expected-rq-timeout-ms', '100000'
2024-03-15 07:00:59.290
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][pool] [source/common/conn_pool/conn_pool_base.cc:265] [Tags: "ConnectionId":"291861"] using existing fully connected connection
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][pool] [source/common/conn_pool/conn_pool_base.cc:182] [Tags: "ConnectionId":"291861"] creating stream
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][router] [source/common/router/upstream_request.cc:578] [Tags: "ConnectionId":"0","StreamId":"3156243965685767052"] pool ready
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][pool] [source/common/conn_pool/conn_pool_base.cc:131] not creating a new connection, shouldCreateNewConnection returned false.
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][router] [source/common/router/upstream_codec_filter.cc:61] [Tags: "ConnectionId":"0","StreamId":"3156243965685767052"] proxying headers
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"291861"] writing 2367 bytes, end_stream false
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][debug][client] [source/common/http/codec_client.cc:141] [Tags: "ConnectionId":"291861"] encode complete
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"0","StreamId":"3156243965685767052"] decode headers called: filter=envoy.filters.http.upstream_codec status=0
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] decode headers called: filter=envoy.filters.http.ext_authz status=4
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x5823f2d0e80 for 900000ms, min is 900000ms
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][http] [source/common/http/http1/codec_impl.cc:698] [Tags: "ConnectionId":"291883"] parsed 2423 bytes
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"291861"] socket event: 2
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"291861"] write ready
2024-03-15 07:00:59.290 [2024-03-15 07:00:59.290][22][trace][connection] [source/common/network/raw_buffer_socket.cc:70] [Tags: "ConnectionId":"291861"] write returns: 2367
2024-03-15 07:00:59.293 [2024-03-15 07:00:59.293][22][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"291861"] socket event: 3
2024-03-15 07:00:59.293 [2024-03-15 07:00:59.293][22][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"291861"] write ready
2024-03-15 07:00:59.293 [2024-03-15 07:00:59.293][22][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"291861"] read ready. dispatch_buffered_data=0
2024-03-15 07:00:59.293 [2024-03-15 07:00:59.293][22][trace][connection] [source/common/network/raw_buffer_socket.cc:39] [Tags: "ConnectionId":"291861"] read error: Connection reset by peer, code: 9
2024-03-15 07:00:59.293 [2024-03-15 07:00:59.293][22][trace][connection] [source/common/network/connection_impl.cc:687] [Tags: "ConnectionId":"291861"] read: rst close from peer
2024-03-15 07:00:59.293 [2024-03-15 07:00:59.293][22][debug][connection] [source/common/network/connection_impl.cc:278] [Tags: "ConnectionId":"291861"] closing socket: 0
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.293][22][trace][connection] [source/common/network/connection_impl.cc:469] [Tags: "ConnectionId":"291861"] raising connection event 0
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.293][22][trace][http] [source/common/http/http1/codec_impl.cc:648] [Tags: "ConnectionId":"291861"] parsing 0 bytes
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.293][22][trace][http] [source/common/http/http1/codec_impl.cc:698] [Tags: "ConnectionId":"291861"] parsed 0 bytes
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.293][22][debug][client] [source/common/http/codec_client.cc:107] [Tags: "ConnectionId":"291861"] disconnect. resetting 1 pending requests
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.293][22][debug][client] [source/common/http/codec_client.cc:158] [Tags: "ConnectionId":"291861"] request reset
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=1)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][router] [source/common/router/router.cc:1332] [Tags: "ConnectionId":"0","StreamId":"3156243965685767052"] upstream reset: reset reason: connection termination, transport failure reason:
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=2)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=3)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][http] [source/common/http/async_client_impl.cc:106] async http request response headers (end_stream=false):

2024-03-15 07:00:59.294 ':status', '503'

2024-03-15 07:00:59.294 'content-length', '95'
2024-03-15 07:00:59.294 'content-type', 'text/plain'
2024-03-15 07:00:59.294
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][http] [source/common/http/async_client_impl.cc:123] async http request response data (length=95 end_stream=true)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][ext_authz] [source/extensions/filters/http/ext_authz/ext_authz.cc:468] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] ext_authz filter rejected the request with an error. Response status code: 500
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][http] [source/common/http/filter_manager.cc:1065] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] Sending local reply with details ext_authz_error
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x5823f2d0e80 for 900000ms, min is 900000ms
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][ext_authz] [source/extensions/filters/http/ext_authz/ext_authz.cc:221] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] ext_authz filter has 0 response header(s) to add and 0 response header(s) to set to the encoded response:
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][http] [source/common/http/filter_manager.cc:1233] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] encode headers called: filter=envoy.filters.http.ext_authz status=0
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][http] [source/common/http/filter_manager.cc:1233] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] encode headers called: filter=envoy.filters.http.lua status=0
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][http] [source/common/http/conn_manager_impl.cc:1869] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] encoding headers via codec (end_stream=true):
2024-03-15 07:00:59.294 ':status', '500'
2024-03-15 07:00:59.294 'date', 'Fri, 15 Mar 2024 07:00:58 GMT'
2024-03-15 07:00:59.294 'server', 'envoy'
2024-03-15 07:00:59.294
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"291883"] writing 109 bytes, end_stream false
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][http] [source/common/http/conn_manager_impl.cc:1974] [Tags: "ConnectionId":"291883","StreamId":"10440038835343958989"] Codec completed encoding stream.
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=4)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=5)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x5823e620d80 for 3600000ms, min is 3600000ms
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=6)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][pool] [source/common/conn_pool/conn_pool_base.cc:495] [Tags: "ConnectionId":"291861"] client disconnected, failure reason:
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=7)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=8)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][pool] [source/common/conn_pool/conn_pool_base.cc:463] invoking 1 idle callback(s) - is_draining_for_deletion_=false
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][upstream] [source/common/upstream/cluster_manager_impl.cc:2098] Erasing idle pool for host localhost
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=9)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][upstream] [source/common/upstream/cluster_manager_impl.cc:2105] Pool container empty for host localhost, erasing host entry
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][main] [source/common/event/dispatcher_impl.cc:122] clearing deferred deletion list (size=9)
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][lua] [./source/extensions/filters/common/lua/lua.h:210] marking dead N5Envoy10Extensions11HttpFilters3Lua19StreamHandleWrapperE at 0x7ff5b800c6d0
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][debug][pool] [source/common/conn_pool/conn_pool_base.cc:215] [Tags: "ConnectionId":"291861"] destroying stream: 0 remaining
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"291883"] socket event: 2
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"291883"] write ready
2024-03-15 07:00:59.294 [2024-03-15 07:00:59.294][22][trace][connection] [source/common/network/raw_buffer_socket.cc:70] [Tags: "ConnectionId":"291883"] write returns: 109
2024-03-15 07:00:59.300 [2024-03-15 07:00:59.300][1][trace][upstream] [source/extensions/clusters/strict_dns/strict_dns_cluster.cc:104] starting async DNS resolution for localhost
2024-03-15 07:00:59.300 [2024-03-15 07:00:59.300][1][debug][dns] [source/extensions/network/dns_resolver/cares/dns_impl.cc:365] dns resolution for localhost started
2024-03-15 07:00:59.300 [2024-03-15 07:00:59.300][1][debug][dns] [source/extensions/network/dns_resolver/cares/dns_impl.cc:285] dns resolution for localhost completed with status 0
2024-03-15 07:00:59.300 [2024-03-15 07:00:59.300][1][trace][upstream] [source/extensions/clusters/strict_dns/strict_dns_cluster.cc:112] async DNS resolution complete for localhost
2024-03-15 07:00:59.300 [2024-03-15 07:00:59.300][1][debug][upstream] [source/common/upstream/upstream_impl.cc:437] transport socket match, socket default selected for host with address [::1]:8080
2024-03-15 07:00:59.300 [2024-03-15 07:00:59.300][1][debug][upstream] [source/extensions/clusters/strict_dns/strict_dns_cluster.cc:177] DNS refresh rate reset for localhost, refresh rate 5000 ms
2024-03-15 07:00:59.469 [2024-03-15 07:00:59.469][13][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x5823ee16900 for 3600000ms, min is 3600000ms
2024-03-15 07:00:59.469 [2024-03-15 07:00:59.469][13][trace][connection] [source/common/network/connection_impl.cc:469] [Tags: "ConnectionId":"291884"] raising connection event 2
2024-03-15 07:00:59.469 [2024-03-15 07:00:59.469][13][debug][conn_handler] [source/common/listener_manager/active_tcp_listener.cc:160] [Tags: "ConnectionId":"291884"] new connection from 100.96.35.13:35568
2024-03-15 07:00:59.469 [2024-03-15 07:00:59.469][13][trace][misc] [source/common/network/tcp_listener_impl.cc:114] TcpListener accepted 1 new connections.
2024-03-15 07:00:59.469 [2024-03-15 07:00:59.469][13][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"291884"] socket event: 3
2024-03-15 07:00:59.469 [2024-03-15 07:00:59.469][13][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"291884"] write ready
2024-03-15 07:00:59.469 [2024-03-15 07:00:59.469][13][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"291884"] read ready. dispatch_buffered_data=0

stats

cluster.ext_authz-http-service.assignment_stale: 0
cluster.ext_authz-http-service.assignment_timeout_received: 0
cluster.ext_authz-http-service.assignment_use_cached: 0
cluster.ext_authz-http-service.bind_errors: 0
cluster.ext_authz-http-service.circuit_breakers.default.cx_open: 0
cluster.ext_authz-http-service.circuit_breakers.default.cx_pool_open: 0
cluster.ext_authz-http-service.circuit_breakers.default.rq_open: 0
cluster.ext_authz-http-service.circuit_breakers.default.rq_pending_open: 0
cluster.ext_authz-http-service.circuit_breakers.default.rq_retry_open: 0
cluster.ext_authz-http-service.circuit_breakers.high.cx_open: 0
cluster.ext_authz-http-service.circuit_breakers.high.cx_pool_open: 0
cluster.ext_authz-http-service.circuit_breakers.high.rq_open: 0
cluster.ext_authz-http-service.circuit_breakers.high.rq_pending_open: 0
cluster.ext_authz-http-service.circuit_breakers.high.rq_retry_open: 0
cluster.ext_authz-http-service.default.total_match_count: 244035
cluster.ext_authz-http-service.external.upstream_rq_200: 122108
cluster.ext_authz-http-service.external.upstream_rq_2xx: 122108
cluster.ext_authz-http-service.external.upstream_rq_completed: 122108
cluster.ext_authz-http-service.http1.dropped_headers_with_underscores: 0
cluster.ext_authz-http-service.http1.metadata_not_supported_error: 0
cluster.ext_authz-http-service.http1.requests_rejected_with_underscores_in_headers: 0
cluster.ext_authz-http-service.http1.response_flood: 0
cluster.ext_authz-http-service.internal.upstream_rq_200: 3763
cluster.ext_authz-http-service.internal.upstream_rq_2xx: 3763
cluster.ext_authz-http-service.internal.upstream_rq_403: 2
cluster.ext_authz-http-service.internal.upstream_rq_4xx: 2
cluster.ext_authz-http-service.internal.upstream_rq_503: 1
cluster.ext_authz-http-service.internal.upstream_rq_5xx: 1
cluster.ext_authz-http-service.internal.upstream_rq_completed: 3766
cluster.ext_authz-http-service.lb_healthy_panic: 0
cluster.ext_authz-http-service.lb_local_cluster_not_ok: 0
cluster.ext_authz-http-service.lb_recalculate_zone_structures: 0
cluster.ext_authz-http-service.lb_subsets_active: 0
cluster.ext_authz-http-service.lb_subsets_created: 0
cluster.ext_authz-http-service.lb_subsets_fallback: 0
cluster.ext_authz-http-service.lb_subsets_fallback_panic: 0
cluster.ext_authz-http-service.lb_subsets_removed: 0
cluster.ext_authz-http-service.lb_subsets_selected: 0
cluster.ext_authz-http-service.lb_zone_cluster_too_small: 0
cluster.ext_authz-http-service.lb_zone_no_capacity_left: 0
cluster.ext_authz-http-service.lb_zone_number_differs: 0
cluster.ext_authz-http-service.lb_zone_routing_all_directly: 0
cluster.ext_authz-http-service.lb_zone_routing_cross_zone: 0
cluster.ext_authz-http-service.lb_zone_routing_sampled: 0
cluster.ext_authz-http-service.max_host_weight: 1
cluster.ext_authz-http-service.membership_change: 1
cluster.ext_authz-http-service.membership_degraded: 0
cluster.ext_authz-http-service.membership_excluded: 0
cluster.ext_authz-http-service.membership_healthy: 1
cluster.ext_authz-http-service.membership_total: 1
cluster.ext_authz-http-service.original_dst_host_invalid: 0
cluster.ext_authz-http-service.retry_or_shadow_abandoned: 0
cluster.ext_authz-http-service.update_attempt: 244035
cluster.ext_authz-http-service.update_empty: 0
cluster.ext_authz-http-service.update_failure: 0
cluster.ext_authz-http-service.update_no_rebuild: 244034
cluster.ext_authz-http-service.update_success: 244035
cluster.ext_authz-http-service.upstream_cx_active: 0
cluster.ext_authz-http-service.upstream_cx_close_notify: 0
cluster.ext_authz-http-service.upstream_cx_connect_attempts_exceeded: 0
cluster.ext_authz-http-service.upstream_cx_connect_fail: 0
cluster.ext_authz-http-service.upstream_cx_connect_timeout: 0
cluster.ext_authz-http-service.upstream_cx_connect_with_0_rtt: 0
cluster.ext_authz-http-service.upstream_cx_destroy: 123476
cluster.ext_authz-http-service.upstream_cx_destroy_local: 0
cluster.ext_authz-http-service.upstream_cx_destroy_local_with_active_rq: 0
cluster.ext_authz-http-service.upstream_cx_destroy_remote: 123476
cluster.ext_authz-http-service.upstream_cx_destroy_remote_with_active_rq: 1
cluster.ext_authz-http-service.upstream_cx_destroy_with_active_rq: 1
cluster.ext_authz-http-service.upstream_cx_http1_total: 123476
cluster.ext_authz-http-service.upstream_cx_http2_total: 0
cluster.ext_authz-http-service.upstream_cx_http3_total: 0
cluster.ext_authz-http-service.upstream_cx_idle_timeout: 0
cluster.ext_authz-http-service.upstream_cx_max_duration_reached: 0
cluster.ext_authz-http-service.upstream_cx_max_requests: 0
cluster.ext_authz-http-service.upstream_cx_none_healthy: 0
cluster.ext_authz-http-service.upstream_cx_overflow: 0
cluster.ext_authz-http-service.upstream_cx_pool_overflow: 0
cluster.ext_authz-http-service.upstream_cx_protocol_error: 0
cluster.ext_authz-http-service.upstream_cx_rx_bytes_buffered: 0
cluster.ext_authz-http-service.upstream_cx_rx_bytes_total: 712157967
cluster.ext_authz-http-service.upstream_cx_total: 123476
cluster.ext_authz-http-service.upstream_cx_tx_bytes_buffered: 0
cluster.ext_authz-http-service.upstream_cx_tx_bytes_total: 66545108
cluster.ext_authz-http-service.upstream_flow_control_backed_up_total: 0
cluster.ext_authz-http-service.upstream_flow_control_drained_total: 0
cluster.ext_authz-http-service.upstream_flow_control_paused_reading_total: 0
cluster.ext_authz-http-service.upstream_flow_control_resumed_reading_total: 0
cluster.ext_authz-http-service.upstream_http3_broken: 0
cluster.ext_authz-http-service.upstream_internal_redirect_failed_total: 0
cluster.ext_authz-http-service.upstream_internal_redirect_succeeded_total: 0
cluster.ext_authz-http-service.upstream_rq_0rtt: 0
cluster.ext_authz-http-service.upstream_rq_200: 125871
cluster.ext_authz-http-service.upstream_rq_2xx: 125871
cluster.ext_authz-http-service.upstream_rq_403: 2
cluster.ext_authz-http-service.upstream_rq_4xx: 2
cluster.ext_authz-http-service.upstream_rq_503: 1
cluster.ext_authz-http-service.upstream_rq_5xx: 1
cluster.ext_authz-http-service.upstream_rq_active: 0
cluster.ext_authz-http-service.upstream_rq_cancelled: 0
cluster.ext_authz-http-service.upstream_rq_completed: 125874
cluster.ext_authz-http-service.upstream_rq_maintenance_mode: 0
cluster.ext_authz-http-service.upstream_rq_max_duration_reached: 0
cluster.ext_authz-http-service.upstream_rq_pending_active: 0
cluster.ext_authz-http-service.upstream_rq_pending_failure_eject: 0
cluster.ext_authz-http-service.upstream_rq_pending_overflow: 0
cluster.ext_authz-http-service.upstream_rq_pending_total: 123476
cluster.ext_authz-http-service.upstream_rq_per_try_idle_timeout: 0
cluster.ext_authz-http-service.upstream_rq_per_try_timeout: 0
cluster.ext_authz-http-service.upstream_rq_retry: 0
cluster.ext_authz-http-service.upstream_rq_retry_backoff_exponential: 0
cluster.ext_authz-http-service.upstream_rq_retry_backoff_ratelimited: 0
cluster.ext_authz-http-service.upstream_rq_retry_limit_exceeded: 0
cluster.ext_authz-http-service.upstream_rq_retry_overflow: 0
cluster.ext_authz-http-service.upstream_rq_retry_success: 0
cluster.ext_authz-http-service.upstream_rq_rx_reset: 0
cluster.ext_authz-http-service.upstream_rq_timeout: 0
cluster.ext_authz-http-service.upstream_rq_total: 125874
cluster.ext_authz-http-service.upstream_rq_tx_reset: 0
cluster.ext_authz-http-service.version: 0
cluster.ext_authz-http-service.warming_state: 0
jpmca12 commented 3 months ago

@zuercher: is there anyway i can reopen this issue. please help. thanks

zuercher commented 3 months ago

Look at the metrics for the ext authz cluster. ~If it’s returning 503 without sending it’s probably the default circuit breaker settings.~ Given those stats, it seems like for the single 503, the auth service closed its connection without a response or perhaps closed a connection that was to be reused at a bad time. I don’t really have much more advice to give.

jpmca12 commented 3 months ago

Hello @zuercher, we are experiencing more such failures in load scenario, wondering if there is any way in Envoy to retry the call? (we are using ExtAuthz, configuration above)

jpmca12 commented 3 months ago

Hello @alyssawilk, @zuercher, any ideas here? I am looking for how can i retry in case of such failures, appreciate any help. thanks

jpmca12 commented 3 months ago

Hello @zuercher, started a separate thread on how to retries in case of failures https://github.com/envoyproxy/envoy/issues/33108

appreciate any help. thanks