search

envoyproxy / envoy

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

Response Body buffer is incomplete when using WASM extension and HTTP/2 #35884

Open balbifm opened 2 weeks ago

balbifm commented 2 weeks ago

Description:

When using HTTP/2, and having a WASM extension that buffers the request body, if the _on_requestbody or _on_responsebody has to be called multiple times, thenonly a part of the body is available to the extension.

This results in errors or unexpected results if doing any transformation on the body, for example.

In the below logs, it can be seen the following:

proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1006] [Tags: "ConnectionId":"1"] dispatching 40055 bytes
proxy-1  | [2024-08-28 16:54:50.750][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 8192, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 8192, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 16384, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 24576, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 7242, 0, 1)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 32768, 1)

Http2Visitor is processing the whole 40.055 bytes, but _proxy_on_responsebody is called with end_of_stream in true with only 32768 bytes.

Repro steps:

A docker compose which reproduces the issue, can be found here: https://github.com/balbifm/envoy-config/tree/envoy-35884

Logs:

proxy-1  | [2024-08-28 16:54:50.701][23][trace][http] [source/common/http/conn_manager_impl.cc:134] LoadShedPoint envoy.load_shed_points.http_connection_manager_decode_headers is not found. Is it configured?
proxy-1  | [2024-08-28 16:54:50.701][23][trace][http] [source/common/http/conn_manager_impl.cc:137] LoadShedPoint envoy.load_shed_points.hcm_ondata_creating_codec is not found. Is it configured?
proxy-1  | [2024-08-28 16:54:50.701][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3eb0b700 for 3600000ms, min is 3600000ms
proxy-1  | [2024-08-28 16:54:50.701][23][debug][conn_handler] [source/common/listener_manager/active_tcp_listener.cc:160] [Tags: "ConnectionId":"0"] new connection from 192.168.65.1:65163
proxy-1  | [2024-08-28 16:54:50.701][23][trace][misc] [source/common/network/tcp_listener_impl.cc:114] TcpListener accepted 1 new connections.
proxy-1  | [2024-08-28 16:54:50.701][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"0"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.701][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"0"] write ready
proxy-1  | [2024-08-28 16:54:50.703][23][trace][connection] [source/common/tls/ssl_handshaker.cc:93] [Tags: "ConnectionId":"0"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.703][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"0"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.703][23][trace][connection] [source/common/tls/ssl_handshaker.cc:93] [Tags: "ConnectionId":"0"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.741][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"0"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.741][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"0"] write ready
proxy-1  | [2024-08-28 16:54:50.741][23][trace][connection] [source/common/network/connection_impl.cc:469] [Tags: "ConnectionId":"0"] raising connection event 2
proxy-1  | [2024-08-28 16:54:50.741][23][trace][conn_handler] [source/common/listener_manager/active_stream_listener_base.cc:126] [Tags: "ConnectionId":"0"] tcp connection on event 2
nginx-1  | 172.21.0.3 - - [28/Aug/2024:16:54:50 +0000] "GET / HTTP/2.0" 200 40010 "-" "curl/8.7.1"
proxy-1  | [2024-08-28 16:54:50.741][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"0"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.741][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: 64
proxy-1  | [2024-08-28 16:54:50.741][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: 39
proxy-1  | [2024-08-28 16:54:50.742][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: -1
proxy-1  | [2024-08-28 16:54:50.742][23][trace][connection] [source/common/tls/ssl_socket.cc:133] [Tags: "ConnectionId":"0"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.742][23][trace][connection] [source/common/tls/ssl_socket.cc:169] [Tags: "ConnectionId":"0"] ssl read 103 bytes
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:2261] LoadShedPoint envoy.load_shed_points.http2_server_go_away_on_dispatch is not found. Is it configured?
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:2019] Codec does not have Metadata frame support.
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http2] [source/common/http/http2/codec_impl.cc:1696] [Tags: "ConnectionId":"0"] updating connection-level initial window size to 268435456
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:1006] [Tags: "ConnectionId":"0"] dispatching 103 bytes
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"0"] Http2Visitor::OnFrameHeader(0, 18, 4, 0)
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"0"] about to recv frame type=4, flags=0, stream_id=0
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"0"] track inbound frame type=4 flags=0 length=18 padding_length=0
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"0"] Http2Visitor::OnFrameHeader(0, 4, 8, 0)
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"0"] about to recv frame type=8, flags=0, stream_id=0
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"0"] track inbound frame type=8 flags=0 length=4 padding_length=0
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"0"] Http2Visitor::OnFrameHeader(1, 30, 1, 5)
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"0"] about to recv frame type=1, flags=5, stream_id=1
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"0"] track inbound frame type=1 flags=5 length=30 padding_length=0
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http] [source/common/http/conn_manager_impl.cc:385] [Tags: "ConnectionId":"0"] new stream
proxy-1  | [2024-08-28 16:54:50.742][23][trace][http] [./source/common/http/filter_manager.h:1116] LoadShedPoint envoy.load_shed_points.http_downstream_filter_check is not found. Is it configured?
proxy-1  | [2024-08-28 16:54:50.742][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http2] [source/common/http/http2/codec_impl.cc:1847] [Tags: "ConnectionId":"0"] Http2Visitor::OnEndHeadersForStream(1)
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http] [source/common/http/conn_manager_impl.cc:1135] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] request headers complete (end_stream=true):
proxy-1  | ':method', 'GET'
proxy-1  | ':scheme', 'https'
proxy-1  | ':authority', 'localhost:9095'
proxy-1  | ':path', '/'
proxy-1  | 'user-agent', 'curl/8.7.1'
proxy-1  | 'accept', '*/*'
proxy-1  |
proxy-1  | [2024-08-28 16:54:50.742][23][debug][http] [source/common/http/conn_manager_impl.cc:1118] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] request end stream
proxy-1  | [2024-08-28 16:54:50.742][23][debug][connection] [./source/common/network/connection_impl.h:98] [Tags: "ConnectionId":"0"] current connecting state: false
proxy-1  | [2024-08-28 16:54:50.742][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_context_create(2, 1)
proxy-1  | [2024-08-28 16:54:50.742][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_context_create return: void
proxy-1  | [2024-08-28 16:54:50.742][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_request_headers(2, 8, 1)
proxy-1  | [2024-08-28 16:54:50.743][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_request_headers return: 0
proxy-1  | [2024-08-28 16:54:50.743][23][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] decode headers called: filter=envoy.filters.http.wasm status=0
proxy-1  | [2024-08-28 16:54:50.743][23][debug][router] [source/common/router/router.cc:525] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] cluster 'backend_service' match for URL '/'
proxy-1  | [2024-08-28 16:54:50.743][23][debug][router] [source/common/router/router.cc:750] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] router decoding headers:
proxy-1  | ':method', 'GET'
proxy-1  | ':scheme', 'https'
proxy-1  | ':authority', 'localhost:9095'
proxy-1  | ':path', '/'
proxy-1  | 'user-agent', 'curl/8.7.1'
proxy-1  | 'accept', '*/*'
proxy-1  | 'x-forwarded-proto', 'https'
proxy-1  | 'x-request-id', 'c9abe34c-4796-4349-9e15-30bf59d844f2'
proxy-1  | 'x-envoy-expected-rq-timeout-ms', '15000'
proxy-1  |
proxy-1  | [2024-08-28 16:54:50.743][23][debug][pool] [source/common/http/conn_pool_base.cc:78] queueing stream due to no available connections (ready=0 busy=0 connecting=0)
proxy-1  | [2024-08-28 16:54:50.743][23][debug][pool] [source/common/conn_pool/conn_pool_base.cc:291] trying to create new connection
proxy-1  | [2024-08-28 16:54:50.743][23][trace][pool] [source/common/conn_pool/conn_pool_base.cc:292] ConnPoolImplBase 0x276f3ea61000, ready_clients_.size(): 0, busy_clients_.size(): 0, connecting_clients_.size(): 0, connecting_stream_capacity_: 0, num_active_streams_: 0, pending_streams_.size(): 1 per upstream preconnect ratio: 1
proxy-1  | [2024-08-28 16:54:50.743][23][debug][pool] [source/common/conn_pool/conn_pool_base.cc:145] creating a new connection (connecting=0)
proxy-1  | [2024-08-28 16:54:50.743][23][trace][http2] [source/common/http/http2/codec_impl.cc:2019] Codec does not have Metadata frame support.
proxy-1  | [2024-08-28 16:54:50.743][23][debug][http2] [source/common/http/http2/codec_impl.cc:1696] [Tags: "ConnectionId":"1"] updating connection-level initial window size to 268435456
proxy-1  | [2024-08-28 16:54:50.743][23][debug][connection] [./source/common/network/connection_impl.h:98] [Tags: "ConnectionId":"1"] current connecting state: true
proxy-1  | [2024-08-28 16:54:50.743][23][debug][client] [source/common/http/codec_client.cc:57] [Tags: "ConnectionId":"1"] connecting
proxy-1  | [2024-08-28 16:54:50.743][23][debug][connection] [source/common/network/connection_impl.cc:1017] [Tags: "ConnectionId":"1"] connecting to 172.21.0.2:443
proxy-1  | [2024-08-28 16:54:50.743][23][debug][connection] [source/common/network/connection_impl.cc:1036] [Tags: "ConnectionId":"1"] connection in progress
proxy-1  | [2024-08-28 16:54:50.743][23][trace][pool] [source/common/conn_pool/conn_pool_base.cc:131] not creating a new connection, shouldCreateNewConnection returned false.
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] decode headers called: filter=envoy.filters.http.upstream_codec status=4
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http] [source/common/http/filter_manager.cc:601] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] decode headers called: filter=envoy.filters.http.router status=1
proxy-1  | [2024-08-28 16:54:50.744][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.744][23][debug][http2] [source/common/http/http2/codec_impl.cc:1908] [Tags: "ConnectionId":"0"] Http2Visitor::OnEndStream(1)
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1044] [Tags: "ConnectionId":"0"] dispatched 103 bytes
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"0"] about to send frame type=4, flags=0
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"0"] send data: bytes=33
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 33 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"0"] sent frame type=4, stream_id=0, length=24
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"0"] about to send frame type=8, flags=0
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"0"] send data: bytes=13
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 13 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"0"] sent frame type=8, stream_id=0, length=4
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"0"] about to send frame type=4, flags=1
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"0"] send data: bytes=9
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 9 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.744][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"0"] sent frame type=4, stream_id=0, length=0
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"0"] socket event: 2
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"0"] write ready
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/tls/ssl_socket.cc:287] [Tags: "ConnectionId":"0"] ssl write returns: 55
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"1"] socket event: 2
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"1"] write ready
proxy-1  | [2024-08-28 16:54:50.744][23][debug][connection] [source/common/network/connection_impl.cc:746] [Tags: "ConnectionId":"1"] connected
proxy-1  | [2024-08-28 16:54:50.744][23][trace][connection] [source/common/tls/ssl_handshaker.cc:93] [Tags: "ConnectionId":"1"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.745][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"0"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.745][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"0"] write ready
proxy-1  | [2024-08-28 16:54:50.745][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"0"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.745][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: 9
proxy-1  | [2024-08-28 16:54:50.745][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: -1
proxy-1  | [2024-08-28 16:54:50.745][23][trace][connection] [source/common/tls/ssl_socket.cc:133] [Tags: "ConnectionId":"0"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.745][23][trace][connection] [source/common/tls/ssl_socket.cc:169] [Tags: "ConnectionId":"0"] ssl read 9 bytes
proxy-1  | [2024-08-28 16:54:50.745][23][trace][http2] [source/common/http/http2/codec_impl.cc:1006] [Tags: "ConnectionId":"0"] dispatching 9 bytes
proxy-1  | [2024-08-28 16:54:50.745][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"0"] Http2Visitor::OnFrameHeader(0, 0, 4, 1)
proxy-1  | [2024-08-28 16:54:50.745][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"0"] about to recv frame type=4, flags=1, stream_id=0
proxy-1  | [2024-08-28 16:54:50.745][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"0"] track inbound frame type=4 flags=1 length=0 padding_length=0
proxy-1  | [2024-08-28 16:54:50.745][23][trace][http2] [source/common/http/http2/codec_impl.cc:1044] [Tags: "ConnectionId":"0"] dispatched 9 bytes
proxy-1  | [2024-08-28 16:54:50.747][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"1"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.747][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"1"] write ready
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:469] [Tags: "ConnectionId":"1"] raising connection event 2
proxy-1  | [2024-08-28 16:54:50.748][23][debug][client] [source/common/http/codec_client.cc:88] [Tags: "ConnectionId":"1"] connected
proxy-1  | [2024-08-28 16:54:50.748][23][debug][pool] [source/common/conn_pool/conn_pool_base.cc:328] [Tags: "ConnectionId":"1"] attaching to next stream
proxy-1  | [2024-08-28 16:54:50.748][23][debug][pool] [source/common/conn_pool/conn_pool_base.cc:182] [Tags: "ConnectionId":"1"] creating stream
proxy-1  | [2024-08-28 16:54:50.748][23][debug][router] [source/common/router/upstream_request.cc:595] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] pool ready
proxy-1  | [2024-08-28 16:54:50.748][23][trace][router] [source/common/router/upstream_codec_filter.cc:61] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] proxying headers
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"1"] send data: bytes=24
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"1"] writing 24 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"1"] about to send frame type=4, flags=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"1"] send data: bytes=39
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"1"] writing 39 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"1"] sent frame type=4, stream_id=0, length=30
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"1"] about to send frame type=8, flags=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"1"] send data: bytes=13
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"1"] writing 13 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"1"] sent frame type=8, stream_id=0, length=4
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"1"] about to send frame type=1, flags=5
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"1"] send data: bytes=126
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"1"] writing 126 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"1"] sent frame type=1, stream_id=1, length=117
proxy-1  | [2024-08-28 16:54:50.748][23][debug][client] [source/common/http/codec_client.cc:142] [Tags: "ConnectionId":"1"] encode complete
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http] [source/common/http/filter_manager.cc:68] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] continuing filter chain: filter=0x276f3ea6d2c0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"1"] write ready
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/tls/ssl_socket.cc:287] [Tags: "ConnectionId":"1"] ssl write returns: 202
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"1"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: 40
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: -1
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/tls/ssl_socket.cc:133] [Tags: "ConnectionId":"1"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/tls/ssl_socket.cc:169] [Tags: "ConnectionId":"1"] ssl read 40 bytes
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1006] [Tags: "ConnectionId":"1"] dispatching 40 bytes
proxy-1  | [2024-08-28 16:54:50.748][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(0, 18, 4, 0)
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=4, flags=0, stream_id=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=4 flags=0 length=18 padding_length=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][pool] [source/common/http/conn_pool_base.cc:140] [Tags: "ConnectionId":"1"] Decreasing stream capacity by 536870784
proxy-1  | [2024-08-28 16:54:50.748][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(0, 4, 8, 0)
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=8, flags=0, stream_id=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=8 flags=0 length=4 padding_length=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1044] [Tags: "ConnectionId":"1"] dispatched 40 bytes
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"1"] about to send frame type=4, flags=1
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"1"] send data: bytes=9
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"1"] writing 9 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.748][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"1"] sent frame type=4, stream_id=0, length=0
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"1"] socket event: 2
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"1"] write ready
proxy-1  | [2024-08-28 16:54:50.748][23][trace][connection] [source/common/tls/ssl_socket.cc:287] [Tags: "ConnectionId":"1"] ssl write returns: 9
proxy-1  | [2024-08-28 16:54:50.749][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"1"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.749][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"1"] write ready
proxy-1  | [2024-08-28 16:54:50.749][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"1"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.749][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: 129
proxy-1  | [2024-08-28 16:54:50.749][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: -1
proxy-1  | [2024-08-28 16:54:50.749][23][trace][connection] [source/common/tls/ssl_socket.cc:133] [Tags: "ConnectionId":"1"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.749][23][trace][connection] [source/common/tls/ssl_socket.cc:169] [Tags: "ConnectionId":"1"] ssl read 129 bytes
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http2] [source/common/http/http2/codec_impl.cc:1006] [Tags: "ConnectionId":"1"] dispatching 129 bytes
proxy-1  | [2024-08-28 16:54:50.749][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(0, 0, 4, 1)
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=4, flags=1, stream_id=0
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=4 flags=1 length=0 padding_length=0
proxy-1  | [2024-08-28 16:54:50.749][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 111, 1, 4)
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=1, flags=4, stream_id=1
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=1 flags=4 length=111 padding_length=0
proxy-1  | [2024-08-28 16:54:50.749][23][debug][http2] [source/common/http/http2/codec_impl.cc:1847] [Tags: "ConnectionId":"1"] Http2Visitor::OnEndHeadersForStream(1)
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.749][23][trace][router] [source/common/router/upstream_request.cc:271] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] end_stream: false, upstream response headers:
proxy-1  | ':status', '200'
proxy-1  | 'server', 'nginx/1.27.1'
proxy-1  | 'date', 'Wed, 28 Aug 2024 16:54:50 GMT'
proxy-1  | 'content-type', 'text/html'
proxy-1  | 'content-length', '40010'
proxy-1  | 'last-modified', 'Tue, 27 Aug 2024 18:29:46 GMT'
proxy-1  | 'etag', '"66ce1b1a-9c4a"'
proxy-1  | 'accept-ranges', 'bytes'
proxy-1  |
proxy-1  | [2024-08-28 16:54:50.749][23][debug][router] [source/common/router/router.cc:1551] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] upstream headers complete: end_stream=false
proxy-1  | [2024-08-28 16:54:50.749][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.749][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_headers(2, 9, 0)
proxy-1  | [2024-08-28 16:54:50.749][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_response_headers return: 0
proxy-1  | [2024-08-28 16:54:50.749][23][trace][http] [source/common/http/filter_manager.cc:1243] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encode headers called: filter=envoy.filters.http.wasm status=0
proxy-1  | [2024-08-28 16:54:50.749][23][debug][http] [source/common/http/conn_manager_impl.cc:1825] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encoding headers via codec (end_stream=false):
proxy-1  | ':status', '200'
proxy-1  | 'server', 'envoy'
proxy-1  | 'date', 'Wed, 28 Aug 2024 16:54:50 GMT'
proxy-1  | 'content-type', 'text/html'
proxy-1  | 'content-length', '40010'
proxy-1  | 'last-modified', 'Tue, 27 Aug 2024 18:29:46 GMT'
proxy-1  | 'etag', '"66ce1b1a-9c4a"'
proxy-1  | 'accept-ranges', 'bytes'
proxy-1  | 'x-envoy-upstream-service-time', '5'
proxy-1  |
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1371] [Tags: "ConnectionId":"0"] about to send frame type=1, flags=4
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1420] [Tags: "ConnectionId":"0"] send data: bytes=124
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 124 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"0"] sent frame type=1, stream_id=1, length=115
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1044] [Tags: "ConnectionId":"1"] dispatched 129 bytes
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"1"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"1"] write ready
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"1"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: 16384
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: 16384
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: 36
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: 7251
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"1"] ssl read returns: -1
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/tls/ssl_socket.cc:133] [Tags: "ConnectionId":"1"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.750][23][trace][connection] [source/common/tls/ssl_socket.cc:169] [Tags: "ConnectionId":"1"] ssl read 40055 bytes
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1006] [Tags: "ConnectionId":"1"] dispatching 40055 bytes
proxy-1  | [2024-08-28 16:54:50.750][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=0, flags=0, stream_id=1
proxy-1  | [2024-08-28 16:54:50.750][23][debug][http2] [source/common/http/http2/codec_impl.cc:1855] [Tags: "ConnectionId":"1"] Http2Visitor::OnBeginDataForStream(1, 8192)
proxy-1  | [2024-08-28 16:54:50.750][23][debug][http2] [source/common/http/http2/codec_impl.cc:1867] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 8192, end_stream: false
proxy-1  | [2024-08-28 16:54:50.750][23][debug][http2] [source/common/http/http2/codec_impl.cc:1896] [Tags: "ConnectionId":"1"] Http2Visitor dispatching DATA for stream 1
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1168] [Tags: "ConnectionId":"1"] recv frame type=DATA stream_id=1
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=0 flags=0 length=8192 padding_length=0
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.750][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.750][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 8192, 0)
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_get_property(1114288, 13, 1048388, 1048392)
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] malloc(8)
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] malloc return: 1114264
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_get_property return: 0
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_log(2, 1114288, 42)
proxy-1  | [2024-08-28 16:54:50.750][23][info][wasm] [source/extensions/common/wasm/context.cc:1195] wasm log body_transform body_transform my_vm_id: Got 8192 , false, HTTP Request body in #2.
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_log return: 0
proxy-1  | [2024-08-28 16:54:50.750][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_response_body return: 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:1428] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encode data called: filter=envoy.filters.http.wasm status=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=0, flags=0, stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1855] [Tags: "ConnectionId":"1"] Http2Visitor::OnBeginDataForStream(1, 8192)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1867] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 8192, end_stream: false
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1903] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 18, end_stream: false
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1896] [Tags: "ConnectionId":"1"] Http2Visitor dispatching DATA for stream 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1168] [Tags: "ConnectionId":"1"] recv frame type=DATA stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=0 flags=0 length=8192 padding_length=0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 8192, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_get_property(1114288, 13, 1048388, 1048392)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] malloc(8)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] malloc return: 1114264
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_get_property return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_log(2, 1114288, 42)
proxy-1  | [2024-08-28 16:54:50.751][23][info][wasm] [source/extensions/common/wasm/context.cc:1195] wasm log body_transform body_transform my_vm_id: Got 8192 , false, HTTP Request body in #2.
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_log return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_response_body return: 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:1428] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encode data called: filter=envoy.filters.http.wasm status=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=0, flags=0, stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1855] [Tags: "ConnectionId":"1"] Http2Visitor::OnBeginDataForStream(1, 8192)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1867] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 8192, end_stream: false
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1896] [Tags: "ConnectionId":"1"] Http2Visitor dispatching DATA for stream 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1168] [Tags: "ConnectionId":"1"] recv frame type=DATA stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=0 flags=0 length=8192 padding_length=0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 16384, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_get_property(1114288, 13, 1048388, 1048392)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] malloc(8)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] malloc return: 1114264
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_get_property return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_log(2, 1114288, 43)
proxy-1  | [2024-08-28 16:54:50.751][23][info][wasm] [source/extensions/common/wasm/context.cc:1195] wasm log body_transform body_transform my_vm_id: Got 16384 , false, HTTP Request body in #2.
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_log return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_response_body return: 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:1428] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encode data called: filter=envoy.filters.http.wasm status=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 8192, 0, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=0, flags=0, stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1855] [Tags: "ConnectionId":"1"] Http2Visitor::OnBeginDataForStream(1, 8192)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1867] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 8192, end_stream: false
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1903] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 36, end_stream: false
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1896] [Tags: "ConnectionId":"1"] Http2Visitor dispatching DATA for stream 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1168] [Tags: "ConnectionId":"1"] recv frame type=DATA stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=0 flags=0 length=8192 padding_length=0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: false, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 24576, 0)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_get_property(1114288, 13, 1048388, 1048392)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] malloc(8)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] malloc return: 1114264
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_get_property return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_log(2, 1114288, 43)
proxy-1  | [2024-08-28 16:54:50.751][23][info][wasm] [source/extensions/common/wasm/context.cc:1195] wasm log body_transform body_transform my_vm_id: Got 24576 , false, HTTP Request body in #2.
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_log return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_response_body return: 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:1428] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encode data called: filter=envoy.filters.http.wasm status=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"1"] Http2Visitor::OnFrameHeader(1, 7242, 0, 1)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"1"] about to recv frame type=0, flags=1, stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1855] [Tags: "ConnectionId":"1"] Http2Visitor::OnBeginDataForStream(1, 7242)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1867] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 7242, end_stream: true
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1903] [Tags: "ConnectionId":"1"] Http2Visitor: remaining data payload: 0, end_stream: true
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1908] [Tags: "ConnectionId":"1"] Http2Visitor::OnEndStream(1)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][http2] [source/common/http/http2/codec_impl.cc:1913] [Tags: "ConnectionId":"1"] Http2Visitor dispatching DATA for stream 1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1168] [Tags: "ConnectionId":"1"] recv frame type=DATA stream_id=1
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"1"] track inbound frame type=0 flags=1 length=7242 padding_length=0
proxy-1  | [2024-08-28 16:54:50.751][23][debug][client] [source/common/http/codec_client.cc:129] [Tags: "ConnectionId":"1"] response complete
proxy-1  | [2024-08-28 16:54:50.751][23][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=1)
proxy-1  | [2024-08-28 16:54:50.751][23][debug][pool] [source/common/conn_pool/conn_pool_base.cc:215] [Tags: "ConnectionId":"1"] destroying stream: 0 remaining
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: true, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=2)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=3)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: true, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_response_body(2, 32768, 1)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_get_property(1114288, 13, 1048388, 1048392)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] malloc(8)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] malloc return: 1114264
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_get_property return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_log(2, 1114288, 42)
proxy-1  | [2024-08-28 16:54:50.751][23][info][wasm] [source/extensions/common/wasm/context.cc:1195] wasm log body_transform body_transform my_vm_id: Got 32768 , true, HTTP Request body in #2.
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_log return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_get_buffer_bytes(1, 0, 40010, 1048388, 1048392)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] malloc(32768)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] malloc return: 1114288
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_get_buffer_bytes return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm->host] env.proxy_set_buffer_bytes(1, 0, 4294967295, 1147064, 32773)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [vm<-host] env.proxy_set_buffer_bytes return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_response_body return: 0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:1428] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encode data called: filter=envoy.filters.http.wasm status=0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:68] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] continuing filter chain: filter=0x276f3e8f27e0
proxy-1  | [2024-08-28 16:54:50.751][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3e8a1200 for 300000ms, min is 300000ms
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/filter_manager.cc:905] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] commonEncodePrefix end_stream: true, isHalfCloseEnabled: false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http] [source/common/http/conn_manager_impl.cc:1848] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] encoding data via codec (size=40015 end_stream=true)
proxy-1  | [2024-08-28 16:54:50.751][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 16393 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"0"] sent frame type=0, stream_id=1, length=16384
proxy-1  | [2024-08-28 16:54:50.751][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 16393 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.751][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"0"] sent frame type=0, stream_id=1, length=16384
proxy-1  | [2024-08-28 16:54:50.752][23][trace][connection] [source/common/network/connection_impl.cc:529] [Tags: "ConnectionId":"0"] writing 7256 bytes, end_stream false
proxy-1  | [2024-08-28 16:54:50.752][23][trace][http2] [source/common/http/http2/codec_impl.cc:1264] [Tags: "ConnectionId":"0"] sent frame type=0, stream_id=1, length=7247
proxy-1  | [2024-08-28 16:54:50.752][23][debug][http] [source/common/http/conn_manager_impl.cc:1937] [Tags: "ConnectionId":"0","StreamId":"10571667775923775459"] Codec completed encoding stream.
proxy-1  | [2024-08-28 16:54:50.752][23][debug][http2] [source/common/http/http2/codec_impl.cc:1445] [Tags: "ConnectionId":"0"] stream 1 closed: 0
proxy-1  | [2024-08-28 16:54:50.752][23][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=4)
proxy-1  | [2024-08-28 16:54:50.752][23][debug][http2] [source/common/http/http2/codec_impl.cc:1508] [Tags: "ConnectionId":"0"] Recouping 0 bytes of flow control window for stream 1.
proxy-1  | [2024-08-28 16:54:50.752][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_log(2)
proxy-1  | [2024-08-28 16:54:50.752][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_log return: void
proxy-1  | [2024-08-28 16:54:50.752][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_done(2)
proxy-1  | [2024-08-28 16:54:50.752][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_done return: 1
proxy-1  | [2024-08-28 16:54:50.752][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host->vm] proxy_on_delete(2)
proxy-1  | [2024-08-28 16:54:50.752][23][trace][wasm] [source/extensions/common/wasm/wasm_vm.cc:39] [host<-vm] proxy_on_delete return: void
proxy-1  | [2024-08-28 16:54:50.752][23][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=5)
proxy-1  | [2024-08-28 16:54:50.752][23][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x276f3eb0b700 for 3600000ms, min is 3600000ms
proxy-1  | [2024-08-28 16:54:50.752][23][debug][http2] [source/common/http/http2/codec_impl.cc:1445] [Tags: "ConnectionId":"1"] stream 1 closed: 0
proxy-1  | [2024-08-28 16:54:50.752][23][trace][main] [source/common/event/dispatcher_impl.cc:228] item added to deferred deletion list (size=6)
proxy-1  | [2024-08-28 16:54:50.752][23][debug][http2] [source/common/http/http2/codec_impl.cc:1508] [Tags: "ConnectionId":"1"] Recouping 0 bytes of flow control window for stream 1.
proxy-1  | [2024-08-28 16:54:50.752][23][trace][http2] [source/common/http/http2/codec_impl.cc:1044] [Tags: "ConnectionId":"1"] dispatched 40055 bytes
proxy-1  | [2024-08-28 16:54:50.752][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"0"] socket event: 2
proxy-1  | [2024-08-28 16:54:50.752][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"0"] write ready
proxy-1  | [2024-08-28 16:54:50.752][23][trace][connection] [source/common/tls/ssl_socket.cc:287] [Tags: "ConnectionId":"0"] ssl write returns: 16384
proxy-1  | [2024-08-28 16:54:50.753][23][trace][connection] [source/common/tls/ssl_socket.cc:287] [Tags: "ConnectionId":"0"] ssl write returns: 16384
proxy-1  | [2024-08-28 16:54:50.753][23][trace][connection] [source/common/tls/ssl_socket.cc:287] [Tags: "ConnectionId":"0"] ssl write returns: 7398
proxy-1  | [2024-08-28 16:54:50.753][23][trace][main] [source/common/event/dispatcher_impl.cc:122] clearing deferred deletion list (size=6)
proxy-1  | [2024-08-28 16:54:50.937][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"0"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.937][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"0"] write ready
proxy-1  | [2024-08-28 16:54:50.937][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"0"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.937][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: 13
proxy-1  | [2024-08-28 16:54:50.937][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: -1
proxy-1  | [2024-08-28 16:54:50.937][23][trace][connection] [source/common/tls/ssl_socket.cc:133] [Tags: "ConnectionId":"0"] ssl error occurred while read: WANT_READ
proxy-1  | [2024-08-28 16:54:50.937][23][trace][connection] [source/common/tls/ssl_socket.cc:169] [Tags: "ConnectionId":"0"] ssl read 13 bytes
proxy-1  | [2024-08-28 16:54:50.937][23][trace][http2] [source/common/http/http2/codec_impl.cc:1006] [Tags: "ConnectionId":"0"] dispatching 13 bytes
proxy-1  | [2024-08-28 16:54:50.937][23][debug][http2] [source/common/http/http2/codec_impl.cc:1803] [Tags: "ConnectionId":"0"] Http2Visitor::OnFrameHeader(1, 4, 3, 0)
proxy-1  | [2024-08-28 16:54:50.937][23][trace][http2] [source/common/http/http2/codec_impl.cc:1116] [Tags: "ConnectionId":"0"] about to recv frame type=3, flags=0, stream_id=1
proxy-1  | [2024-08-28 16:54:50.937][23][trace][http2] [source/common/http/http2/codec_impl.cc:1398] [Tags: "ConnectionId":"0"] track inbound frame type=3 flags=0 length=4 padding_length=0
proxy-1  | [2024-08-28 16:54:50.937][23][trace][http2] [source/common/http/http2/codec_impl.cc:1244] [Tags: "ConnectionId":"0"] recv frame type=RST_STREAM stream_id=1
proxy-1  | [2024-08-28 16:54:50.937][23][trace][http2] [source/common/http/http2/codec_impl.cc:1044] [Tags: "ConnectionId":"0"] dispatched 13 bytes
proxy-1  | [2024-08-28 16:54:50.939][23][trace][connection] [source/common/network/connection_impl.cc:614] [Tags: "ConnectionId":"0"] socket event: 3
proxy-1  | [2024-08-28 16:54:50.939][23][trace][connection] [source/common/network/connection_impl.cc:737] [Tags: "ConnectionId":"0"] write ready
proxy-1  | [2024-08-28 16:54:50.939][23][trace][connection] [source/common/network/connection_impl.cc:654] [Tags: "ConnectionId":"0"] read ready. dispatch_buffered_data=0
proxy-1  | [2024-08-28 16:54:50.939][23][trace][connection] [source/common/tls/ssl_socket.cc:93] [Tags: "ConnectionId":"0"] ssl read returns: 0
proxy-1  | [2024-08-28 16:54:50.939][23][trace][connection] [source/common/tls/ssl_socket.cc:133] [Tags: "ConnectionId":"0"] ssl error occurred while read: ZERO_RETURN
proxy-1  | [2024-08-28 16:54:50.939][23][trace][connection] [source/common/tls/ssl_socket.cc:169] [Tags: "ConnectionId":"0"] ssl read 0 bytes
proxy-1  | [2024-08-28 16:54:50.939][23][debug][connection] [source/common/network/connection_impl.cc:714] [Tags: "ConnectionId":"0"] remote close
proxy-1  | [2024-08-28 16:54:50.939][23][debug][connection] [source/common/network/connection_impl.cc:276] [Tags: "ConnectionId":"0"] closing socket: 0
proxy-1  | [2024-08-28 16:54:50.939][23][debug][connection] [source/common/tls/ssl_socket.cc:339] [Tags: "ConnectionId":"0"] SSL shutdown: rc=1
proxy-1  | [2024-08-28 16:54:50.939][23][trace][connection] [source/common/network/connection_impl.cc:469] [Tags: "ConnectionId":"0"] raising connection event 0
proxy-1  | [2024-08-28 16:54:50.939][23][trace][conn_handler] [source/common/listener_manager/active_stream_listener_base.cc:126] [Tags: "ConnectionId":"0"] tcp connection on event 0
proxy-1  | [2024-08-28 16:54:50.939][23][debug][conn_handler] [source/common/listener_manager/active_stream_listener_base.cc:136] [Tags: "ConnectionId":"0"] adding to cleanup list
juanmolle commented 2 weeks ago

If this Draft PR is the correct way to fix this issue I could proceed with it

juanmolle commented 2 weeks ago

cc @mpwarres

juanmolle commented 1 week ago

/assign @mpwarres

juanmolle commented 5 days ago

@mpwarres any thought about this? should I proceed? cc @lizan

mpwarres commented 3 days ago

Sorry, missed this earlier, taking a look