envoy: Cannot access route after response headers are sent?

Title: Cannot access route after response headers are sent?

Description:

Hi team, we have a custom filter which will log the request to our report service. And after upgrading from v1.25.4 to v1.26.3, we found one scenario will cause crash here https://github.com/GoogleCloudPlatform/esp-v2/blob/7ba0794eeb6bf4fb5f88fe6d73687f2f4a3a01b1/src/envoy/http/service_control/handler_impl.cc#L125C31-L125C65.

Here’s the stack trace

[2023-07-25 19:07:10.628][456853][error][envoy_bug] [external/envoy/source/common/http/conn_manager_impl.h:322] envoy bug failure: !route_cache_blocked_. Details: Should never try to refresh or clear the route cache when it is blocked! To temporarily ignore this new constraint, set runtime flag `envoy.reloadable_features.prohibit_route_refresh_after_response_headers_sent` to `false`
[2023-07-25 19:07:10.628][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:38] stacktrace for envoy bug
[2023-07-25 19:07:10.639][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #0 Envoy::Http::ConnectionManagerImpl::ActiveStream::refreshCachedRoute() [0x55721de40f66]
[2023-07-25 19:07:10.649][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #1 Envoy::Http::ConnectionManagerImpl::ActiveStream::route() [0x55721de45f12]
[2023-07-25 19:07:10.663][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #2 Envoy::Http::ActiveStreamFilterBase::getRoute() [0x55721e51b183]
[2023-07-25 19:07:10.676][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #3 Envoy::Http::ActiveStreamFilterBase::mostSpecificPerFilterConfig() [0x55721e51b237]
[2023-07-25 19:07:10.690][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #4 espv2::envoy::http_filters::service_control::ServiceControlHandlerImpl::getOperationFromPerRoute() [0x55721d9b49f5]
[2023-07-25 19:07:10.702][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #5 espv2::envoy::http_filters::service_control::ServiceControlHandlerImpl::ServiceControlHandlerImpl() [0x55721d9b3e76]
[2023-07-25 19:07:10.713][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #6 espv2::envoy::http_filters::service_control::ServiceControlHandlerFactoryImpl::createHandler() [0x55721d9b2b00]
[2023-07-25 19:07:10.727][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #7 espv2::envoy::http_filters::service_control::ServiceControlFilter::log() [0x55721d9f5647]
[2023-07-25 19:07:10.740][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #8 Envoy::Http::FilterManager::log() [0x55721de37a14]
[2023-07-25 19:07:10.755][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #9 Envoy::Http::ConnectionManagerImpl::doDeferredStreamDestroy() [0x55721de3744f]
[2023-07-25 19:07:10.769][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #10 Envoy::Http::ConnectionManagerImpl::doEndStream() [0x55721de36d25]
[2023-07-25 19:07:10.781][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #11 Envoy::Http::FilterManager::encodeData() [0x55721e5210f6]
[2023-07-25 19:07:10.796][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #12 Envoy::Http::Utility::encodeLocalReply() [0x55721e610557]
[2023-07-25 19:07:10.807][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #13 Envoy::Http::Utility::sendLocalReply() [0x55721e610679]
[2023-07-25 19:07:10.821][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #14 Envoy::Http::DownstreamFilterManager::sendLocalReplyViaFilterChain() [0x55721e523766]
[2023-07-25 19:07:10.833][456853][error][envoy_bug] [external/envoy/source/common/common/assert.h:43] #15 Envoy::Http::DownstreamFilterManager::sendLocalReply() [0x55721e52294e]
[2023-07-25 19:07:10.834][456853][critical][main] [external/envoy/source/exe/terminate_handler.cc:12] std::terminate called! (possible uncaught exception, see trace)
[2023-07-25 19:07:10.834][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:91] Backtrace (use tools/stack_decode.py to get line numbers):
[2023-07-25 19:07:10.834][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:92] Envoy version: 0/1.26.3//RELEASE/BoringSSL
[2023-07-25 19:07:10.844][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:96] #0: Envoy::TerminateHandler::logOnTerminate()::$_0::__invoke() [0x55721d999060]
[2023-07-25 19:07:10.854][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:96] #1: __cxxabiv1::__terminate() [0x55721eca3d3a]
[2023-07-25 19:07:10.854][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:104] Caught Aborted, suspect faulting address 0x5ae550006f887
[2023-07-25 19:07:10.854][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:91] Backtrace (use tools/stack_decode.py to get line numbers):
[2023-07-25 19:07:10.854][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:92] Envoy version: 0/1.26.3//RELEASE/BoringSSL
[2023-07-25 19:07:10.854][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:98] #0: [0x7fb1c9762f90]
[2023-07-25 19:07:10.855][456853][critical][backtrace] [external/envoy/source/server/backtrace.h:98] #1: [0x59d7f4ccd90]
ActiveStream 0x59d7f2b0e00, stream_id_: 11458794960188920096&filter_manager_: 
  FilterManager 0x59d7f2b0ea8, state_.has_1xx_headers_: 0
  filter_manager_callbacks_.requestHeaders(): 
    ':authority', '127.0.0.1:20920'
    ':path', '/echo/123/path/'
    ':method', 'GET'
    'user-agent', 'Go-http-client/1.1'
    'accept-encoding', 'gzip'
  filter_manager_callbacks_.requestTrailers():   null
  filter_manager_callbacks_.responseHeaders(): 
    ':status', '307'
    'location', '/echo/123/path/'
    'content-length', '26'
    'content-type', 'application/json'
    'date', 'Tue, 25 Jul 2023 19:07:10 GMT'
    'server', 'envoy'
  filter_manager_callbacks_.responseTrailers():   null
  &streamInfo(): 
    StreamInfoImpl 0x59d7f2b0fd8, protocol_: 1, response_code_: 307, response_code_details_: path_normalization_failed, attempt_count_: null, health_check_request_: 0, route_name_:     upstream_info_:     null
    OverridableRemoteConnectionInfoSetterStreamInfo 0x59d7f2b0fd8, remoteAddress(): 127.0.0.1:56406, directRemoteAddress(): 127.0.0.1:56406, localAddress(): 127.0.0.1:20920

We need the route info to report the corresponding api method. Some preliminary study showed to me we cannot access route after the response is sent and the route is empty. Is this expected? Thanks.

After setting envoy.reloadable_features.prohibit_route_refresh_after_response_headers_sent to false, the issue disappeared.