search

envoyproxy / envoy

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

Flaky kill_request_filter_integration_test under coverage #18569

Open davinci26 opened 2 years ago

davinci26 commented 2 years ago

kill_request_filter_integration_test is flaky under coverage.

Logs from run:

2021-10-11T17:57:34.5297422Z [ RUN      ] Protocols/KillRequestFilterIntegrationTestAllProtocols.KillRequestCrashEnvoyWithCustomKillHeader/IPv4_Http2Downstream_Http2Upstream
2021-10-11T17:57:34.5298641Z TestRandomGenerator running with seed 1573743904
2021-10-11T17:57:34.5299519Z TestRandomGenerator running with seed 1573743904
2021-10-11T17:57:34.5301633Z [2021-10-11 17:57:21.434][13846][debug][runtime] [source/common/runtime/runtime_features.cc:31] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
2021-10-11T17:57:34.5303785Z [2021-10-11 17:57:21.434][13846][debug][runtime] [source/common/runtime/runtime_features.cc:20] Unable to use runtime singleton for feature envoy.reloadable_features.header_map_correctly_coalesce_cookies
2021-10-11T17:57:34.5305945Z [2021-10-11 17:57:21.434][13846][debug][runtime] [source/common/runtime/runtime_features.cc:31] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
2021-10-11T17:57:34.5308113Z [2021-10-11 17:57:21.434][13846][debug][runtime] [source/common/runtime/runtime_features.cc:20] Unable to use runtime singleton for feature envoy.reloadable_features.header_map_correctly_coalesce_cookies
2021-10-11T17:57:34.5309551Z TestRandomGenerator running with seed 1573743904
2021-10-11T17:57:34.5311120Z [2021-10-11 17:57:21.440][13846][info][testing] [test/integration/fake_upstream.cc:524] starting fake server at 0.0.0.0:36709. UDP=false codec=http2
2021-10-11T17:57:34.5313212Z [2021-10-11 17:57:21.450][28137][debug][runtime] [source/common/runtime/runtime_features.cc:20] Unable to use runtime singleton for feature envoy.reloadable_features.udp_listener_updates_filter_chain_in_place
2021-10-11T17:57:34.5315134Z [2021-10-11 17:57:21.451][13846][debug][misc] [test/integration/base_integration_test.cc:169] Setting up file-based LDS
2021-10-11T17:57:34.5316826Z [2021-10-11 17:57:21.472][13846][debug][misc] [test/integration/base_integration_test.cc:203] Running Envoy with configuration:
2021-10-11T17:57:34.5317987Z static_resources:
2021-10-11T17:57:34.5318644Z   clusters:
2021-10-11T17:57:34.5319538Z     - name: cluster_0
2021-10-11T17:57:34.5320266Z       connect_timeout: 5s
2021-10-11T17:57:34.5320960Z       load_assignment:
2021-10-11T17:57:34.5321672Z         cluster_name: cluster_0
2021-10-11T17:57:34.5322334Z         endpoints:
2021-10-11T17:57:34.5323358Z           - lb_endpoints:
2021-10-11T17:57:34.5324358Z               - endpoint:
2021-10-11T17:57:34.5325113Z                   address:
2021-10-11T17:57:34.5325858Z                     socket_address:
2021-10-11T17:57:34.5326647Z                       address: 127.0.0.1
2021-10-11T17:57:34.5327407Z                       port_value: 36709
2021-10-11T17:57:34.5328283Z       typed_extension_protocol_options:
2021-10-11T17:57:34.5329153Z         envoy.extensions.upstreams.http.v3.HttpProtocolOptions:
2021-10-11T17:57:34.5330161Z           "@type": type.googleapis.com/envoy.extensions.upstreams.http.v3.HttpProtocolOptions
2021-10-11T17:57:34.5331068Z           explicit_http_config:
2021-10-11T17:57:34.5331879Z             http2_protocol_options:
2021-10-11T17:57:34.5332570Z               {}
2021-10-11T17:57:34.5333193Z   secrets:
2021-10-11T17:57:34.5334184Z     - name: secret_static_0
2021-10-11T17:57:34.5334928Z       tls_certificate:
2021-10-11T17:57:34.5335607Z         certificate_chain:
2021-10-11T17:57:34.5336416Z           inline_string: DUMMY_INLINE_BYTES
2021-10-11T17:57:34.5337157Z         private_key:
2021-10-11T17:57:34.5337986Z           inline_string: DUMMY_INLINE_BYTES
2021-10-11T17:57:34.5338713Z         password:
2021-10-11T17:57:34.5339437Z           inline_string: DUMMY_INLINE_BYTES
2021-10-11T17:57:34.5340350Z dynamic_resources:
2021-10-11T17:57:34.5341022Z   lds_config:
2021-10-11T17:57:34.5342855Z     path: /tmp/sandbox_base/bazel-sandbox.506fa982d9679d3c6eeab1b1d124a688b61c231e37f3485140dfb23bf122cc4f/processwrapper-sandbox/7697/execroot/envoy/_tmp/5bb8e2b84bd509568f57e8ce4366cfe3/13846_1633975041452045
2021-10-11T17:57:34.5344199Z     resource_api_version: V3
2021-10-11T17:57:34.5345095Z admin:
2021-10-11T17:57:34.5345759Z   address:
2021-10-11T17:57:34.5346397Z     socket_address:
2021-10-11T17:57:34.5347114Z       address: 127.0.0.1
2021-10-11T17:57:34.5347799Z       port_value: 0
2021-10-11T17:57:34.5348416Z   access_log:
2021-10-11T17:57:34.5349455Z     - name: envoy.access_loggers.file
2021-10-11T17:57:34.5350236Z       typed_config:
2021-10-11T17:57:34.5351167Z         "@type": type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog
2021-10-11T17:57:34.5352063Z         path: /dev/null
2021-10-11T17:57:34.5352774Z layered_runtime:
2021-10-11T17:57:34.5353384Z   layers:
2021-10-11T17:57:34.5354344Z     - name: static_layer
2021-10-11T17:57:34.5355091Z       static_layer:
2021-10-11T17:57:34.5355732Z         {}
2021-10-11T17:57:34.5356586Z     - name: admin
2021-10-11T17:57:34.5357264Z       admin_layer:
2021-10-11T17:57:34.5357895Z         {}
2021-10-11T17:57:34.5359126Z [2021-10-11 17:57:21.473][13846][info][testing] [test/integration/server.cc:104] starting integration test server
2021-10-11T17:57:34.5360190Z TestRandomGenerator running with seed 1573743904
2021-10-11T17:57:34.5361656Z [2021-10-11 17:57:21.480][28139][info][main] [source/server/server.cc:368] initializing epoch 0 (base id=0, hot restart version=disabled)
2021-10-11T17:57:34.5363329Z [2021-10-11 17:57:21.480][28139][info][main] [source/server/server.cc:370] statically linked extensions:
2021-10-11T17:57:34.5365367Z [2021-10-11 17:57:21.480][28139][info][main] [source/server/server.cc:372]   envoy.transport_sockets.upstream: envoy.transport_sockets.quic, envoy.transport_sockets.raw_buffer, envoy.transport_sockets.tls, raw_buffer, tls
2021-10-11T17:57:34.5367408Z [2021-10-11 17:57:21.480][28139][info][main] [source/server/server.cc:372]   envoy.guarddog_actions: envoy.watchdog.abort_action
2021-10-11T17:57:34.5369183Z [2021-10-11 17:57:21.480][28139][info][main] [source/server/server.cc:372]   envoy.grpc_credentials: envoy.grpc_credentials.default
2021-10-11T17:57:34.5370937Z [2021-10-11 17:57:21.480][28139][info][main] [source/server/server.cc:372]   envoy.tls.cert_validator: envoy.tls.cert_validator.default
2021-10-11T17:57:34.5372594Z [2021-10-11 17:57:21.480][28139][info][main] [source/server/server.cc:372]   envoy.resolvers: envoy.ip
2021-10-11T17:57:34.5374568Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.clusters: envoy.cluster.eds, envoy.cluster.logical_dns, envoy.cluster.original_dst, envoy.cluster.static, envoy.cluster.strict_dns
2021-10-11T17:57:34.5376822Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.upstream_options: envoy.extensions.upstreams.http.v3.HttpProtocolOptions, envoy.upstreams.http.http_protocol_options
2021-10-11T17:57:34.5378972Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.filters.network: envoy.filters.network.http_connection_manager, envoy.http_connection_manager
2021-10-11T17:57:34.5381064Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.upstreams: envoy.filters.connection_pools.http.generic
2021-10-11T17:57:34.5382952Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.bootstrap: envoy.extensions.network.socket_interface.default_socket_interface
2021-10-11T17:57:34.5384856Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.http.original_ip_detection: envoy.http.original_ip_detection.xff
2021-10-11T17:57:34.5386698Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.quic.server.crypto_stream: envoy.quic.crypto_stream.server.quiche
2021-10-11T17:57:34.5389833Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.filters.http: add-body-filter, add-trailers-filter, call-decodedata-once-filter, crash-filter, decode-headers-return-stop-all-filter, encode-headers-return-stop-all-filter, envoy.filters.http.kill_request, envoy.filters.http.on_demand, envoy.filters.http.router, envoy.router, match-wrapper, modify-buffer-filter, passthrough-filter, pause-filter, wait-for-whole-request-and-response-filter
2021-10-11T17:57:34.5393244Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.transport_sockets.downstream: envoy.transport_sockets.quic, envoy.transport_sockets.raw_buffer, envoy.transport_sockets.tls, raw_buffer, tls
2021-10-11T17:57:34.5395446Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.quic.proof_source: envoy.quic.proof_source.filter_chain
2021-10-11T17:57:34.5397149Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.matching.action: skip
2021-10-11T17:57:34.5399335Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.access_loggers: envoy.access_loggers.file, envoy.access_loggers.stderr, envoy.access_loggers.stdout, envoy.file_access_log, envoy.stderr_access_log, envoy.stdout_access_log
2021-10-11T17:57:34.5402030Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.matching.http.input: request-headers, request-trailers, response-headers, response-trailers
2021-10-11T17:57:34.5403882Z [2021-10-11 17:57:21.481][28139][info][main] [source/server/server.cc:372]   envoy.request_id: envoy.request_id.uuid
2021-10-11T17:57:34.5405469Z [2021-10-11 17:57:21.485][28139][info][main] [source/server/server.cc:390] HTTP header map info:
2021-10-11T17:57:34.5407296Z [2021-10-11 17:57:21.485][28139][debug][runtime] [source/common/runtime/runtime_features.cc:31] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
2021-10-11T17:57:34.5409447Z [2021-10-11 17:57:21.485][28139][debug][runtime] [source/common/runtime/runtime_features.cc:20] Unable to use runtime singleton for feature envoy.reloadable_features.header_map_correctly_coalesce_cookies
2021-10-11T17:57:34.5411578Z [2021-10-11 17:57:21.485][28139][debug][runtime] [source/common/runtime/runtime_features.cc:31] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
2021-10-11T17:57:34.5413757Z [2021-10-11 17:57:21.485][28139][debug][runtime] [source/common/runtime/runtime_features.cc:20] Unable to use runtime singleton for feature envoy.reloadable_features.header_map_correctly_coalesce_cookies
2021-10-11T17:57:34.5415890Z [2021-10-11 17:57:21.485][28139][debug][runtime] [source/common/runtime/runtime_features.cc:31] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
2021-10-11T17:57:34.5418059Z [2021-10-11 17:57:21.486][28139][debug][runtime] [source/common/runtime/runtime_features.cc:20] Unable to use runtime singleton for feature envoy.reloadable_features.header_map_correctly_coalesce_cookies
2021-10-11T17:57:34.5420414Z [2021-10-11 17:57:21.486][28139][debug][runtime] [source/common/runtime/runtime_features.cc:31] Unable to use runtime singleton for feature envoy.http.headermap.lazy_map_min_size
2021-10-11T17:57:34.5422773Z [2021-10-11 17:57:21.486][28139][debug][runtime] [source/common/runtime/runtime_features.cc:20] Unable to use runtime singleton for feature envoy.reloadable_features.header_map_correctly_coalesce_cookies
2021-10-11T17:57:34.5427999Z [2021-10-11 17:57:21.486][28139][info][main] [source/server/server.cc:393]   request header map: 496 bytes: :authority,:method,:path,:protocol,:scheme,connection,content-length,content-type,expect,grpc-timeout,keep-alive,proxy-connection,te,transfer-encoding,upgrade,user-agent,via,x-client-trace-id,x-envoy-attempt-count,x-envoy-decorator-operation,x-envoy-downstream-service-cluster,x-envoy-downstream-service-node,x-envoy-expected-rq-timeout-ms,x-envoy-external-address,x-envoy-force-trace,x-envoy-hedge-on-per-try-timeout,x-envoy-internal,x-envoy-ip-tags,x-envoy-max-retries,x-envoy-original-path,x-envoy-original-url,x-envoy-retriable-header-names,x-envoy-retriable-status-codes,x-envoy-retry-grpc-on,x-envoy-retry-on,x-envoy-upstream-alt-stat-name,x-envoy-upstream-rq-per-try-timeout-ms,x-envoy-upstream-rq-timeout-alt-response,x-envoy-upstream-rq-timeout-ms,x-envoy-upstream-stream-duration-ms,x-forwarded-client-cert,x-forwarded-for,x-forwarded-proto,x-request-id
2021-10-11T17:57:34.5432598Z [2021-10-11 17:57:21.486][28139][info][main] [source/server/server.cc:393]   request trailer map: 136 bytes: 
2021-10-11T17:57:34.5435874Z [2021-10-11 17:57:21.486][28139][info][main] [source/server/server.cc:393]   response header map: 328 bytes: :status,connection,content-length,content-type,date,grpc-message,grpc-status,keep-alive,location,proxy-connection,server,transfer-encoding,upgrade,via,x-envoy-attempt-count,x-envoy-decorator-operation,x-envoy-degraded,x-envoy-immediate-health-check-fail,x-envoy-ratelimited,x-envoy-upstream-canary,x-envoy-upstream-healthchecked-cluster,x-envoy-upstream-service-time,x-request-id
2021-10-11T17:57:34.5438870Z [2021-10-11 17:57:21.486][28139][info][main] [source/server/server.cc:393]   response trailer map: 160 bytes: grpc-message,grpc-status
2021-10-11T17:57:34.5440855Z [2021-10-11 17:57:21.533][28139][debug][main] [source/server/overload_manager_impl.cc:376] No overload action is configured for envoy.overload_actions.shrink_heap.
2021-10-11T17:57:34.5442087Z TestRandomGenerator running with seed 1573743904
2021-10-11T17:57:34.5443782Z [2021-10-11 17:57:21.541][28139][debug][main] [source/server/overload_manager_impl.cc:376] No overload action is configured for envoy.overload_actions.reduce_timeouts.
2021-10-11T17:57:34.5446184Z [2021-10-11 17:57:21.541][28139][debug][main] [source/server/overload_manager_impl.cc:376] No overload action is configured for envoy.overload_actions.stop_accepting_connections.
2021-10-11T17:57:34.5448499Z [2021-10-11 17:57:21.541][28139][debug][main] [source/server/overload_manager_impl.cc:376] No overload action is configured for envoy.overload_actions.reject_incoming_connections.
2021-10-11T17:57:34.5450699Z [2021-10-11 17:57:21.541][28139][debug][main] [source/server/overload_manager_impl.cc:376] No overload action is configured for envoy.overload_actions.reset_high_memory_stream.
2021-10-11T17:57:34.5452440Z [2021-10-11 17:57:21.543][28139][info][main] [source/server/server.cc:740] runtime: layers:
2021-10-11T17:57:34.5453645Z   - name: static_layer
2021-10-11T17:57:34.5454359Z     static_layer:
2021-10-11T17:57:34.5454992Z       {}
2021-10-11T17:57:34.5456009Z   - name: admin
2021-10-11T17:57:34.5456806Z     admin_layer:
2021-10-11T17:57:34.5457452Z       {}
2021-10-11T17:57:34.5458768Z [2021-10-11 17:57:21.558][28139][info][admin] [source/server/admin/admin.cc:135] admin address: 127.0.0.1:37977
2021-10-11T17:57:34.5460665Z [2021-10-11 17:57:21.566][28139][info][config] [source/server/configuration_impl.cc:127] loading tracing configuration
2021-10-11T17:57:34.5462424Z [2021-10-11 17:57:21.566][28139][info][config] [source/server/configuration_impl.cc:87] loading 1 static secret(s)
2021-10-11T17:57:34.5464306Z [2021-10-11 17:57:21.566][28139][debug][config] [source/server/configuration_impl.cc:89] static secret #0: secret_static_0
2021-10-11T17:57:34.5465989Z [2021-10-11 17:57:21.566][28139][info][config] [source/server/configuration_impl.cc:93] loading 1 cluster(s)
2021-10-11T17:57:34.5467649Z [2021-10-11 17:57:21.594][28158][debug][grpc] [source/common/grpc/google_async_client_impl.cc:50] completionThread running
2021-10-11T17:57:34.5469591Z [2021-10-11 17:57:21.626][28139][debug][upstream] [source/common/upstream/upstream_impl.cc:256] transport socket match, socket default selected for host with address 127.0.0.1:36709
2021-10-11T17:57:34.5471715Z [2021-10-11 17:57:21.627][28139][trace][upstream] [source/common/upstream/upstream_impl.cc:1468] Local locality: zone: "zone_name"
2021-10-11T17:57:34.5472624Z 
2021-10-11T17:57:34.5474039Z [2021-10-11 17:57:21.627][28139][debug][upstream] [source/common/upstream/upstream_impl.cc:1156] initializing Primary cluster cluster_0 completed
2021-10-11T17:57:34.5476162Z [2021-10-11 17:57:21.627][28139][debug][init] [source/common/init/manager_impl.cc:49] init manager Cluster cluster_0 contains no targets
2021-10-11T17:57:34.5478216Z [2021-10-11 17:57:21.627][28139][debug][init] [source/common/init/watcher_impl.cc:14] init manager Cluster cluster_0 initialized, notifying ClusterImplBase
2021-10-11T17:57:34.5480246Z [2021-10-11 17:57:21.627][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:1024] adding TLS cluster cluster_0
2021-10-11T17:57:34.5482231Z [2021-10-11 17:57:21.631][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:1087] membership update for TLS cluster cluster_0 added 1 removed 0
2021-10-11T17:57:34.5484250Z [2021-10-11 17:57:21.631][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:134] cm init: init complete: cluster=cluster_0 primary=0 secondary=0
2021-10-11T17:57:34.5486147Z [2021-10-11 17:57:21.631][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:154] maybe finish initialize state: 0
2021-10-11T17:57:34.5488135Z [2021-10-11 17:57:21.632][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:100] cm init: adding: cluster=cluster_0 primary=0 secondary=0
2021-10-11T17:57:34.5489989Z [2021-10-11 17:57:21.632][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:154] maybe finish initialize state: 1
2021-10-11T17:57:34.5492064Z [2021-10-11 17:57:21.632][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:163] maybe finish initialize primary init clusters empty: true
2021-10-11T17:57:34.5493850Z [2021-10-11 17:57:21.632][28139][info][config] [source/server/configuration_impl.cc:97] loading 0 listener(s)
2021-10-11T17:57:34.5495557Z [2021-10-11 17:57:21.632][28139][info][config] [source/server/configuration_impl.cc:109] loading stats configuration
2021-10-11T17:57:34.5498188Z [2021-10-11 17:57:21.635][28139][debug][file] [source/common/filesystem/inotify/watcher_impl.cc:47] added watch for directory: '/tmp/sandbox_base/bazel-sandbox.506fa982d9679d3c6eeab1b1d124a688b61c231e37f3485140dfb23bf122cc4f/processwrapper-sandbox/7697/execroot/envoy/_tmp/5bb8e2b84bd509568f57e8ce4366cfe3' file: '13846_1633975041452045' fd: 1
2021-10-11T17:57:34.5501625Z [2021-10-11 17:57:21.635][28139][debug][init] [source/common/init/manager_impl.cc:24] added target LDS to init manager Server
2021-10-11T17:57:34.5503364Z [2021-10-11 17:57:21.635][28139][debug][init] [source/common/init/manager_impl.cc:49] init manager RTDS contains no targets
2021-10-11T17:57:34.5505109Z [2021-10-11 17:57:21.635][28139][debug][init] [source/common/init/watcher_impl.cc:14] init manager RTDS initialized, notifying RTDS
2021-10-11T17:57:34.5506930Z [2021-10-11 17:57:21.635][28139][info][runtime] [source/common/runtime/runtime_impl.cc:449] RTDS has finished initialization
2021-10-11T17:57:34.5508691Z [2021-10-11 17:57:21.635][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:224] continue initializing secondary clusters
2021-10-11T17:57:34.5510612Z [2021-10-11 17:57:21.635][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:154] maybe finish initialize state: 2
2021-10-11T17:57:34.5512538Z [2021-10-11 17:57:21.635][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:163] maybe finish initialize primary init clusters empty: true
2021-10-11T17:57:34.5514569Z [2021-10-11 17:57:21.635][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:178] maybe finish initialize secondary init clusters empty: true
2021-10-11T17:57:34.5516644Z [2021-10-11 17:57:21.635][28139][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:200] maybe finish initialize cds api ready: false
2021-10-11T17:57:34.5518501Z [2021-10-11 17:57:21.635][28139][info][upstream] [source/common/upstream/cluster_manager_impl.cc:206] cm init: all clusters initialized
2021-10-11T17:57:34.5520757Z [2021-10-11 17:57:21.635][28139][warning][main] [source/server/server.cc:715] there is no configured limit to the number of allowed active connections. Set a limit via the runtime key overload.global_downstream_max_connections
2021-10-11T17:57:34.5522345Z TestRandomGenerator running with seed 1573743904
2021-10-11T17:57:34.5523187Z TestRandomGenerator running with seed 1573743904
2021-10-11T17:57:34.5524764Z [2021-10-11 17:57:21.644][13846][info][testing] [test/integration/server.cc:81] listener wait complete
2021-10-11T17:57:34.5526418Z [2021-10-11 17:57:21.644][28139][info][main] [source/server/server.cc:817] all clusters initialized. initializing init manager
2021-10-11T17:57:34.5528110Z [2021-10-11 17:57:21.644][28139][debug][init] [source/common/init/manager_impl.cc:53] init manager Server initializing
2021-10-11T17:57:34.5529891Z [2021-10-11 17:57:21.644][28139][debug][init] [source/common/init/target_impl.cc:15] init manager Server initializing target LDS
2021-10-11T17:57:34.5532501Z [2021-10-11 17:57:21.644][28139][debug][config] [source/common/config/filesystem_subscription_impl.cc:61] Filesystem config refresh for /tmp/sandbox_base/bazel-sandbox.506fa982d9679d3c6eeab1b1d124a688b61c231e37f3485140dfb23bf122cc4f/processwrapper-sandbox/7697/execroot/envoy/_tmp/5bb8e2b84bd509568f57e8ce4366cfe3/13846_1633975041452045
2021-10-11T17:57:34.5535005Z [2021-10-11 17:57:21.655][28139][debug][config] [source/server/listener_manager_impl.cc:391] begin add/update listener: name=http hash=17335715390103856996
2021-10-11T17:57:34.5537017Z [2021-10-11 17:57:21.655][28139][debug][config] [source/server/listener_manager_impl.cc:428] use full listener update path for listener name=http hash=17335715390103856996
2021-10-11T17:57:34.5538797Z [2021-10-11 17:57:21.657][28139][debug][config] [source/server/listener_manager_impl.cc:85]   filter #0:
2021-10-11T17:57:34.5540557Z [2021-10-11 17:57:21.657][28139][debug][config] [source/server/listener_manager_impl.cc:86]     name: http
2021-10-11T17:57:34.5545887Z [2021-10-11 17:57:21.661][28139][debug][config] [source/server/listener_manager_impl.cc:89]   config: {"@type":"type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager","codec_type":"HTTP2","stat_prefix":"config_test","route_config":{"name":"route_config_0","virtual_hosts":[{"name":"integration","domains":["*"],"routes":[{"match":{"prefix":"/"},"route":{"cluster":"cluster_0"}}]}]},"http_filters":[{"name":"envoy.filters.http.kill_request","typed_config":{"@type":"type.googleapis.com/envoy.extensions.filters.http.kill_request.v3.KillRequest","probability":{"numerator":100},"kill_request_header":"x-custom-kill-request"}},{"name":"envoy.filters.http.router"}],"access_log":[{"name":"accesslog","filter":{"not_health_check_filter":{}},"typed_config":{"@type":"type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog","path":"/dev/null"}}],"delayed_close_timeout":"0.000000100s"}
2021-10-11T17:57:34.5550547Z [2021-10-11 17:57:21.726][28139][debug][config] [source/extensions/filters/network/http_connection_manager/config.cc:625]     http filter #0
2021-10-11T17:57:34.5552547Z [2021-10-11 17:57:21.726][28139][debug][config] [source/extensions/filters/network/http_connection_manager/config.cc:654]       name: envoy.filters.http.kill_request
2021-10-11T17:57:34.5554454Z [2021-10-11 17:57:21.727][28139][debug][config] [source/extensions/filters/network/http_connection_manager/config.cc:657]     config: {
2021-10-11T17:57:34.5555809Z  "@type": "type.googleapis.com/envoy.extensions.filters.http.kill_request.v3.KillRequest",
2021-10-11T17:57:34.5556701Z  "probability": {
2021-10-11T17:57:34.5557329Z   "numerator": 100
2021-10-11T17:57:34.5557994Z  },
2021-10-11T17:57:34.5558975Z  "kill_request_header": "x-custom-kill-request"
2021-10-11T17:57:34.5559705Z }
2021-10-11T17:57:34.5560027Z 
2021-10-11T17:57:34.5561344Z [2021-10-11 17:57:21.727][28139][debug][config] [source/extensions/filters/network/http_connection_manager/config.cc:625]     http filter #1
2021-10-11T17:57:34.5563227Z [2021-10-11 17:57:21.731][28139][debug][config] [source/extensions/filters/network/http_connection_manager/config.cc:654]       name: envoy.filters.http.router
2021-10-11T17:57:34.5565270Z [2021-10-11 17:57:21.731][28139][debug][config] [source/extensions/filters/network/http_connection_manager/config.cc:657]     config: {}
2021-10-11T17:57:34.5566070Z 
2021-10-11T17:57:34.5567472Z [2021-10-11 17:57:21.736][28139][debug][config] [source/server/filter_chain_manager_impl.cc:237] new fc_contexts has 1 filter chains, including 1 newly built
2021-10-11T17:57:34.5569533Z [2021-10-11 17:57:21.736][28139][debug][init] [source/common/init/target_impl.cc:15] init manager Server initializing target Listener-init-target http
2021-10-11T17:57:34.5571497Z [2021-10-11 17:57:21.736][28139][debug][init] [source/common/init/manager_impl.cc:49] init manager Listener-local-init-manager http 17335715390103856996 contains no targets
2021-10-11T17:57:34.5573641Z [2021-10-11 17:57:21.736][28139][debug][init] [source/common/init/watcher_impl.cc:14] init manager Listener-local-init-manager http 17335715390103856996 initialized, notifying Listener-local-init-watcher http
2021-10-11T17:57:34.5575738Z [2021-10-11 17:57:21.736][28139][debug][init] [source/common/init/watcher_impl.cc:14] target Listener-init-target http initialized, notifying init manager Server
2021-10-11T17:57:34.5577665Z [2021-10-11 17:57:21.736][28139][debug][config] [source/server/listener_impl.cc:145] Create listen socket for listener http on address 127.0.0.1:0
2021-10-11T17:57:34.5579461Z [2021-10-11 17:57:21.736][28139][debug][config] [source/server/listener_impl.cc:155] http: Setting socket options succeeded
2021-10-11T17:57:34.5581486Z [2021-10-11 17:57:21.736][28139][debug][config] [source/server/listener_impl.cc:99] Set listener http socket factory local address to 127.0.0.1:41733
2021-10-11T17:57:34.5583498Z [2021-10-11 17:57:21.736][28139][debug][config] [source/server/listener_impl.cc:743] add active listener: name=http, hash=17335715390103856996, address=127.0.0.1:0
2021-10-11T17:57:34.5585281Z [2021-10-11 17:57:21.736][28139][info][upstream] [source/server/lds_api.cc:77] lds: add/update listener 'http'
2021-10-11T17:57:34.5586984Z [2021-10-11 17:57:21.736][28139][debug][init] [source/common/init/watcher_impl.cc:14] target LDS initialized, notifying init manager Server
2021-10-11T17:57:34.5588763Z [2021-10-11 17:57:21.737][28139][debug][init] [source/common/init/watcher_impl.cc:14] init manager Server initialized, notifying RunHelper
2021-10-11T17:57:34.5590563Z [2021-10-11 17:57:21.737][28139][info][config] [source/server/listener_manager_impl.cc:779] all dependencies initialized. starting workers
2021-10-11T17:57:34.5592265Z [2021-10-11 17:57:21.737][28139][debug][config] [source/server/listener_manager_impl.cc:816] starting worker 0
2021-10-11T17:57:34.5593930Z [2021-10-11 17:57:21.737][28207][debug][main] [source/server/worker_impl.cc:123] worker entering dispatch loop
2021-10-11T17:57:34.5595687Z [2021-10-11 17:57:21.738][28207][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:1024] adding TLS cluster cluster_0
2021-10-11T17:57:34.5597585Z [2021-10-11 17:57:21.739][28207][debug][upstream] [source/common/upstream/cluster_manager_impl.cc:1087] membership update for TLS cluster cluster_0 added 1 removed 0
2021-10-11T17:57:34.5600629Z [2021-10-11 17:57:21.747][28139][debug][config] [source/common/config/filesystem_subscription_impl.cc:71] Filesystem config update accepted for /tmp/sandbox_base/bazel-sandbox.506fa982d9679d3c6eeab1b1d124a688b61c231e37f3485140dfb23bf122cc4f/processwrapper-sandbox/7697/execroot/envoy/_tmp/5bb8e2b84bd509568f57e8ce4366cfe3/13846_1633975041452045: version_info: "0"
2021-10-11T17:57:34.5602496Z resources {
2021-10-11T17:57:34.5603308Z   [type.googleapis.com/envoy.config.listener.v3.Listener] {
2021-10-11T17:57:34.5604113Z     name: "http"
2021-10-11T17:57:34.5604711Z     address {
2021-10-11T17:57:34.5605350Z       socket_address {
2021-10-11T17:57:34.5606117Z         address: "127.0.0.1"
2021-10-11T17:57:34.5606820Z         port_value: 0
2021-10-11T17:57:34.5607496Z       }
2021-10-11T17:57:34.5608085Z     }
2021-10-11T17:57:34.5608830Z     filter_chains {
2021-10-11T17:57:34.5609446Z       filters {
2021-10-11T17:57:34.5610097Z         name: "http"
2021-10-11T17:57:34.5610839Z         typed_config {
2021-10-11T17:57:34.5611768Z           [type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager] {
2021-10-11T17:57:34.5612879Z             codec_type: HTTP2
2021-10-11T17:57:34.5613616Z             stat_prefix: "config_test"
2021-10-11T17:57:34.5614429Z             route_config {
2021-10-11T17:57:34.5615159Z               name: "route_config_0"
2021-10-11T17:57:34.5615938Z               virtual_hosts {
2021-10-11T17:57:34.5616682Z                 name: "integration"
2021-10-11T17:57:34.5617390Z                 domains: "*"
2021-10-11T17:57:34.5618055Z                 routes {
2021-10-11T17:57:34.5618735Z                   match {
2021-10-11T17:57:34.5619521Z                     prefix: "/"
2021-10-11T17:57:34.5620453Z                   }
2021-10-11T17:57:34.5621131Z                   route {
2021-10-11T17:57:34.5621918Z                     cluster: "cluster_0"
2021-10-11T17:57:34.5622632Z                   }
2021-10-11T17:57:34.5623333Z                 }
2021-10-11T17:57:34.5623948Z               }
2021-10-11T17:57:34.5624537Z             }
2021-10-11T17:57:34.5625157Z             http_filters {
2021-10-11T17:57:34.5625907Z               name: "envoy.filters.http.kill_request"
2021-10-11T17:57:34.5626747Z               typed_config {
2021-10-11T17:57:34.5627660Z                 [type.googleapis.com/envoy.extensions.filters.http.kill_request.v3.KillRequest] {
2021-10-11T17:57:34.5628575Z                   probability {
2021-10-11T17:57:34.5629355Z                     numerator: 100
2021-10-11T17:57:34.5630053Z                   }
2021-10-11T17:57:34.5631181Z                   kill_request_header: "x-custom-kill-request"
2021-10-11T17:57:34.5632018Z                 }
2021-10-11T17:57:34.5632652Z               }
2021-10-11T17:57:34.5633332Z             }
2021-10-11T17:57:34.5633999Z             http_filters {
2021-10-11T17:57:34.5634732Z               name: "envoy.filters.http.router"
2021-10-11T17:57:34.5635520Z             }
2021-10-11T17:57:34.5636168Z             access_log {
2021-10-11T17:57:34.5636921Z               name: "accesslog"
2021-10-11T17:57:34.5637678Z               filter {
2021-10-11T17:57:34.5638427Z                 not_health_check_filter {
2021-10-11T17:57:34.5639106Z                 }
2021-10-11T17:57:34.5639801Z               }
2021-10-11T17:57:34.5640435Z               typed_config {
2021-10-11T17:57:34.5641327Z                 [type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog] {
2021-10-11T17:57:34.5642315Z                   path: "/dev/null"
2021-10-11T17:57:34.5643032Z                 }
2021-10-11T17:57:34.5643631Z               }
2021-10-11T17:57:34.5644314Z             }
2021-10-11T17:57:34.5645001Z             delayed_close_timeout {
2021-10-11T17:57:34.5645709Z               nanos: 100
2021-10-11T17:57:34.5646670Z             }
2021-10-11T17:57:34.5647332Z           }
2021-10-11T17:57:34.5647898Z         }
2021-10-11T17:57:34.5648548Z       }
2021-10-11T17:57:34.5649129Z     }
2021-10-11T17:57:34.5649741Z   }
2021-10-11T17:57:34.5650316Z }
2021-10-11T17:57:34.5650639Z 
2021-10-11T17:57:34.5651799Z [2021-10-11 17:57:21.748][28139][info][main] [source/server/server.cc:836] starting main dispatch loop
2021-10-11T17:57:34.5653503Z [2021-10-11 17:57:21.749][13846][debug][testing] [test/integration/base_integration_test.cc:312] registered 'http' as port 41733.
2021-10-11T17:57:34.5655234Z [2021-10-11 17:57:21.754][28208][debug][grpc] [source/common/grpc/google_async_client_impl.cc:50] completionThread running
2021-10-11T17:57:34.5657158Z [2021-10-11 17:57:21.761][13846][debug][upstream] [source/common/upstream/upstream_impl.cc:256] transport socket match, socket test selected for host with address 127.0.0.1:80
2021-10-11T17:57:34.5659326Z [2021-10-11 17:57:21.772][13846][debug][http2] [source/common/http/http2/codec_impl.cc:1313] [C30] updating connection-level initial window size to 268435456
2021-10-11T17:57:34.5661478Z [2021-10-11 17:57:21.772][13846][debug][client] [source/common/http/codec_client.cc:60] [C30] connecting
2021-10-11T17:57:34.5663211Z [2021-10-11 17:57:21.772][13846][debug][connection] [source/common/network/connection_impl.cc:890] [C30] connecting to 127.0.0.1:41733
2021-10-11T17:57:34.5665347Z [2021-10-11 17:57:21.773][28207][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x2c19580 for 3600000ms, min is 3600000ms
2021-10-11T17:57:34.5667305Z [2021-10-11 17:57:21.774][28207][debug][conn_handler] [source/server/active_tcp_listener.cc:140] [C31] new connection from 127.0.0.1:42660
2021-10-11T17:57:34.5669190Z [2021-10-11 17:57:21.774][28207][trace][connection] [source/common/network/connection_impl.cc:554] [C31] socket event: 2
2021-10-11T17:57:34.5670878Z [2021-10-11 17:57:21.774][28207][trace][connection] [source/common/network/connection_impl.cc:663] [C31] write ready
2021-10-11T17:57:34.5672596Z [2021-10-11 17:57:21.774][13846][debug][connection] [source/common/network/connection_impl.cc:909] [C30] connection in progress
2021-10-11T17:57:34.5674400Z [2021-10-11 17:57:21.774][13846][trace][connection] [source/common/network/connection_impl.cc:554] [C30] socket event: 2
2021-10-11T17:57:34.5676088Z [2021-10-11 17:57:21.774][13846][trace][connection] [source/common/network/connection_impl.cc:663] [C30] write ready
2021-10-11T17:57:34.5677861Z [2021-10-11 17:57:21.774][13846][debug][connection] [source/common/network/connection_impl.cc:672] [C30] connected
2021-10-11T17:57:34.5679603Z [2021-10-11 17:57:21.774][13846][trace][connection] [source/common/network/connection_impl.cc:417] [C30] raising connection event 2
2021-10-11T17:57:34.5681363Z [2021-10-11 17:57:21.774][13846][debug][client] [source/common/http/codec_client.cc:88] [C30] connected
2021-10-11T17:57:34.5682781Z -- Test timed out at 2021-10-11 17:57:32 UTC --
alyssawilk commented 2 years ago

@qqustc could you take a look at this?

kyessenov commented 1 year ago

Flakey under release, too: https://dev.azure.com/cncf/envoy/_build/results?buildId=122380&view=logs&j=b840a642-5ff3-5357-2e4b-e06e40b0cffd&t=67965174-5100-5631-9dc0-68b9f0aacb53