2025-04-30 08:48:16,735 Generated random file: awqgjqpjvp of size: 5120 2025-04-30 08:48:16,735 Generated random file: vxwcziblkj of size: 10240 2025-04-30 08:48:16,735 Requests: https://server6:443/awqgjqpjvp https://server6:443/vxwcziblkj 2025-04-30 08:48:16,796 2025-04-30 08:48:16,797 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_w0pndbjx/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_r9ni5bps/ DOWNLOADS=/tmp/download_k31f9cdq/ SERVER_LOGS=/tmp/logs_server_523r1rnq CLIENT_LOGS=/tmp/logs_client_0o2h2wux SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/facebook/proxygen/mvfst-interop:latest REQUESTS="https://server6:443/awqgjqpjvp https://server6:443/vxwcziblkj" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:48:29,162 Container sim Recreate Container sim Recreated Container client Recreate Container server Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | + set -o nounset server | + VERSION=1 server | + HQ_CLI=/proxygen/_build/proxygen/bin/hq server | + PORT=443 server | + LOGLEVEL=2 server | + /setup.sh server | Setting up routes... client | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] client | Actual changes: server | tx-checksum-sctp: off client | tx-checksum-ip-generic: off client | tx-tcp-segmentation: off [not requested] client | tx-tcp-ecn-segmentation: off [not requested] client | tx-tcp-mangleid-segmentation: off [not requested] client | tx-tcp6-segmentation: off [not requested] client | tx-udp-segmentation: off [not requested] client | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 client | Endpoint's IPv4 address is 193.167.0.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin client | + '[' -n transfer ']' server | + PROTOCOL=hq-interop client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | + HTTPVERSION=0.9 server | + CONN_FLOW_CONTROL=107374182 server | + STREAM_FLOW_CONTROL=107374182 server | ./run_endpoint.sh: line 28: REQUESTS: unbound variable server | ++ tr ' ' '\n' server | ++ awk -F / '{ print "/" $4 }' server | ++ paste -sd, server | + INVOCATIONS= server | + EARLYDATA=false server | + PSK_FILE= server | + '[' -n transfer ']' server | + case "${TESTCASE}" in server | + STREAM_FLOW_CONTROL=262144 server | + CONN_FLOW_CONTROL=2621440 server | + '[' server == client ']' server | + '[' server == server ']' server | + echo 'Running QUIC server on [::]:443' server | Running QUIC server on [::]:443 server | + /proxygen/_build/proxygen/bin/hq --mode=server --cert=/certs/cert.pem --key=/certs/priv.key --conn_flow_control=2621440 --stream_flow_control=262144 --port=443 --httpversion=0.9 --h2port=443 --static_root=/www --logdir=/logs --qlogger_path=/logs --host=:: --congestion=bbr --pacing=true --v=2 server | + tee /logs/server.log client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | W20250430 08:48:17.384121 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | W20250430 08:48:17.384173 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | W20250430 08:48:17.384181 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | W20250430 08:48:17.384186 25 QuicServerWorker.cpp:1234] HostId is already set to 0 server | I20250430 08:48:17.384462 25 HQServer.cpp:283] HQ server started at: [::]:443 sim | server:443 is available after 1.031316836s sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' 'https://server6:443/awqgjqpjvp https://server6:443/vxwcziblkj' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test transfer --qlog-dir /logs/qlog/ --output-dir /downloads https://server6:443/awqgjqpjvp 'https://server6:443/vxwcziblkj client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is 212992 client | 0.001 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.001 INFO hq-interop Client connecting: [::]:59594 -> [fd00:cafe:cafe:100::100]:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=ca384614c624857b4cf1f5 client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe:100::100 has MTU 1500 client | 0.001 DEBUG [unv-path [::]:59594->[fd00:cafe:cafe:100::100]:443] Make permanent client | 0.001 DEBUG [unv-path:ca384614c624857b4cf1f5 [::]:59594->[fd00:cafe:cafe:100::100]:443] set as primary path client | 0.001 DEBUG [pri-unv-path:ca384614c624857b4cf1f5 [::]:59594->[fd00:cafe:cafe:100::100]:443] Path validated Instant { tv_sec: 562, tv_nsec: 709220372 } client | 0.001 DEBUG [Client ca384614c624857b4cf1f5] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.001 DEBUG [Agent 0x5556665d2ed0] state -> InProgress client | 0.001 DEBUG [Client ca384614c624857b4cf1f5] State change from Init -> WaitInitial client | 0.001 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.001 DEBUG Building Initial dcid Some(CID [11]: ca384614c624857b4cf1f5) scid Some(CID [0]: ) client | 0.001 DEBUG CRYPTO for in offset=0, len=1190 client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] pn=0 type=Initial pri-path:ca384614c624857b4cf1f5 [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1232 client | TX -> Crypto { offset: 0, len: 1190 } client | 0.002 DEBUG packet_sent this=0x5556665e66d0, pn=0, ps=1232 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [11]: ca384614c624857b4cf1f5) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1190, len=349 client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] pn=1 type=Initial pri-path:ca384614c624857b4cf1f5 [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 392 client | TX -> Crypto { offset: 1190, len: 349 } client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] pad Initial from 392 to PLPMTU 1232 client | 0.002 DEBUG packet_sent this=0x5556665e66d0, pn=1, ps=1232 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [11]: ca384614c624857b4cf1f5) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] delay duration 3.911219ms client | 0.002 DEBUG Setting timeout of 3.911219ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [11]: ca384614c624857b4cf1f5) scid Some(CID [0]: ) client | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG [Client ca384614c624857b4cf1f5] delay duration 3.883447ms client | 0.002 DEBUG Setting timeout of 3.883447ms client | 0.007 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [11]: ca384614c624857b4cf1f5) scid Some(CID [0]: ) client | 0.007 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG [Client ca384614c624857b4cf1f5] delay duration 294.821468ms client | 0.007 DEBUG Setting timeout of 294.821468ms client | 0.042 DEBUG [Client ca384614c624857b4cf1f5] pn=1718446 type=Initial pri-path:ca384614c624857b4cf1f5 [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Crypto { offset: 0, len: 90 } client | -> RX Ack { largest_acknowledged: 1, ack_delay: 85, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Padding { len: 1095 } client | 0.042 DEBUG Read Ok(90) bytes client | 0.042 DEBUG Write secret available for Handshake: SymKey [32]: 49596c0253ddd8d7500f74befc1c7160e5078bbdea82e4ca9bd562debc56d39d client | 0.042 DEBUG Read secret available for Handshake: SymKey [32]: 3c77daca1d80f64665cfb4dc717ec5640c4746c47d08bd14f3515f299514324a client | 0.042 DEBUG [Agent 0x5556665d2ed0] state -> InProgress client | 0.042 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG [Crypto] Handshake keys installed client | 0.042 DEBUG [Client ca384614c624857b4cf1f5] Rx ACK space=in, ranges=[0..=1] client | 0.042 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.042 DEBUG on_packets_acked this=0x5556665e66d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=2464 client | 0.042 DEBUG Acked crypto frame space=in offset=1190 length=349 client | 0.042 DEBUG Acked crypto frame space=in offset=0 length=1190 client | 0.042 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 750554604 } client | 0.042 DEBUG [Client ca384614c624857b4cf1f5] Changing to use Server CID=400000d10bf14a3c client | 0.042 DEBUG [Client ca384614c624857b4cf1f5] State change from WaitInitial -> Handshaking client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] pn=2 type=Initial pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 44 client | TX -> Ack { largest_acknowledged: 1718446, ack_delay: 76, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.043 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] pad Initial from 44 to PLPMTU 1232 client | 0.043 DEBUG ECN probing: sent 3 probes client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.043 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] delay duration 79.906197ms client | 0.043 DEBUG Setting timeout of 79.906197ms client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] pn=1718446 type=Handshake pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 755 client | -> RX Crypto { offset: 0, len: 715 } client | 0.043 DEBUG Read Ok(715) bytes client | 0.043 DEBUG [Agent 0x5556665d2ed0] state -> AuthenticationPending client | 0.043 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 751298347 } client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Initial dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.043 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] pn=0 type=Handshake pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 1718446, ack_delay: 93, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] Drop packet number space in client | 0.043 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.043 DEBUG ECN probing: sent 4 probes client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] delay duration 120.83908ms client | 0.043 DEBUG Setting timeout of 120.83908ms client | 0.043 DEBUG StateChange(Handshaking) client | 0.043 WARN Cannot create stream ConnectionState client | 0.043 DEBUG [Client ca384614c624857b4cf1f5] Authenticated Ok client | 0.044 DEBUG Write secret available for ApplicationData: SymKey [32]: e85b73797c16e4589407a3af5d23d67a31fd0fd9111c38eacbd724fa7e9e36bd client | 0.044 DEBUG Read secret available for ApplicationData: SymKey [32]: 6869fc4197a3e69f01793807301956867ff29d03e2ad6ad0f0a5d3f8a362c184 client | 0.044 DEBUG [Agent 0x5556665d2ed0] SSL_AuthCertificateComplete: Ok(()) client | 0.044 DEBUG [Agent 0x5556665d2ed0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.044 DEBUG [Client ca384614c624857b4cf1f5] TLS connection complete client | 0.044 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.044 DEBUG [Crypto] Application write key installed client | 0.044 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.044 DEBUG [Crypto] application read keys installed client | 0.044 DEBUG [Client ca384614c624857b4cf1f5] State change from Handshaking -> Connected client | 0.044 INFO [Client ca384614c624857b4cf1f5] Connection established client | 0.044 DEBUG stream BiDi creatable client | 0.044 INFO Created stream 0 for https://server6/awqgjqpjvp client | 0.044 INFO Saving https://server6/awqgjqpjvp to "/downloads/awqgjqpjvp" client | 0.044 INFO Created stream 4 for https://server6/vxwcziblkj client | 0.044 INFO Saving https://server6/vxwcziblkj to "/downloads/vxwcziblkj" client | 0.044 DEBUG stream UniDi creatable client | 0.044 DEBUG StateChange(Connected) client | 0.044 DEBUG stream 0 writable client | 0.044 DEBUG stream 4 writable client | 0.044 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.044 DEBUG CRYPTO for hs offset=0, len=36 client | 0.044 DEBUG [Client ca384614c624857b4cf1f5] pn=1 type=Handshake pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 73 client | TX -> Crypto { offset: 0, len: 36 } client | 0.044 DEBUG packet_sent this=0x5556665e66d0, pn=1, ps=73 client | 0.044 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.044 DEBUG [Client ca384614c624857b4cf1f5] pn=0 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 139 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | TX -> Stream { stream_id: 4, offset: 0, len: 17, fin: true } client | 0.044 DEBUG packet_sent this=0x5556665e66d0, pn=0, ps=66 client | 0.044 DEBUG ECN probing: sent 5 probes client | 0.044 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.044 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.044 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.044 DEBUG [Client ca384614c624857b4cf1f5] delay duration 120.831028ms client | 0.044 DEBUG Setting timeout of 120.831028ms client | 0.075 DEBUG [Client ca384614c624857b4cf1f5] pn=1718447 type=Handshake pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 38 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 59, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.075 DEBUG [Client ca384614c624857b4cf1f5] Rx ACK space=hs, ranges=[0..=1] client | 0.075 DEBUG [LossRecovery] ACK for Handshake - largest_acked=1 client | 0.075 DEBUG on_packets_acked this=0x5556665e66d0, limited=1, bytes_in_flight=66, cwnd=12320, state=SlowStart, new_acked=73 client | 0.075 DEBUG Acked crypto frame space=hs offset=0 length=36 client | 0.075 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client ca384614c624857b4cf1f5] delay duration 77.691871ms client | 0.075 DEBUG Setting timeout of 77.691871ms client | 0.075 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Handshake dcid Some(CID [8]: 400000d10bf14a3c) scid Some(CID [0]: ) client | 0.075 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client ca384614c624857b4cf1f5] delay duration 77.654351ms client | 0.075 DEBUG Setting timeout of 77.654351ms client | 0.075 DEBUG [Client ca384614c624857b4cf1f5] pn=1718446 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 400 client | -> RX Crypto { offset: 0, len: 250 } client | -> RX Ack { largest_acknowledged: 0, ack_delay: 67, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [64, 0, 0, 197, 87, 121, 40, 203], stateless_reset_token: [56, 236, 180, 53, 7, 213, 83, 194, 148, 108, 8, 71, 170, 135, 96, 128] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [64, 0, 0, 222, 223, 82, 75, 105], stateless_reset_token: [137, 159, 171, 223, 234, 115, 69, 241, 61, 222, 44, 205, 131, 65, 82, 6] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [64, 0, 0, 207, 11, 9, 253, 246], stateless_reset_token: [40, 178, 51, 164, 178, 196, 66, 145, 123, 244, 92, 211, 160, 214, 3, 168] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [64, 0, 0, 201, 44, 115, 250, 85], stateless_reset_token: [47, 243, 64, 28, 149, 185, 24, 185, 199, 140, 2, 236, 81, 53, 184, 217] } client | -> RX Padding { len: 7 } client | 0.076 DEBUG Read Ok(250) bytes client | 0.076 DEBUG [0x5556665d2ed0] Got resumption token [920]: 02000633fafa8a19..9fdd850fdc888d50 client | 0.076 DEBUG [Agent 0x5556665d2ed0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.076 DEBUG setting max_stream_data to 262144 client | 0.076 DEBUG setting max_stream_data to 262144 client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] Rx ACK space=ap, ranges=[0..=0] client | 0.076 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.076 DEBUG on_packets_acked this=0x5556665e66d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=66 client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] State change from Connected -> Confirmed client | 0.076 DEBUG PMTUD started with probe size 1380 client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] Drop packet number space hs client | 0.076 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] No preferred address to migrate to client | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 784140452 } client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.076 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] pn=1 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 1332 client | TX -> Ack { largest_acknowledged: 1718446, ack_delay: 37, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Ping client | TX -> Padding { len: 1297 } client | 0.076 DEBUG packet_sent this=0x5556665e66d0, pn=1, ps=1332 client | 0.076 DEBUG ECN probing: sent 6 probes client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] delay duration 123.003567ms client | 0.076 DEBUG Setting timeout of 123.003567ms client | 0.076 DEBUG stream BiDi creatable client | 0.076 DEBUG stream UniDi creatable client | 0.076 DEBUG stream 0 complete client | 0.076 DEBUG stream 4 complete client | 0.076 WARN Unhandled event StateChange(Confirmed) client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] delay duration 122.960396ms client | 0.076 DEBUG Setting timeout of 122.960396ms client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] pn=1718447 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 0, len: >>1210, fin: false } client | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 805109734 } client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.969433ms client | 0.076 DEBUG Setting timeout of 19.969433ms client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.94644ms client | 0.077 DEBUG Setting timeout of 19.94644ms client | 0.077 DEBUG [Client ca384614c624857b4cf1f5] pn=1718448 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 4, offset: 0, len: >>1210, fin: false } client | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 786081659 } client | 0.077 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.077 DEBUG [Client ca384614c624857b4cf1f5] pn=2 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 1718448, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | 0.077 DEBUG ECN probing: sent 7 probes client | 0.077 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] delay duration 121.380204ms client | 0.078 DEBUG Setting timeout of 121.380204ms client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] delay duration 121.353333ms client | 0.078 DEBUG Setting timeout of 121.353333ms client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] pn=1718449 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 1210, len: >>1208, fin: false } client | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 807104834 } client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.972318ms client | 0.078 DEBUG Setting timeout of 19.972318ms client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.945638ms client | 0.078 DEBUG Setting timeout of 19.945638ms client | 0.079 DEBUG [Client ca384614c624857b4cf1f5] pn=1718450 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 4, offset: 1210, len: >>1208, fin: false } client | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 788130903 } client | 0.079 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.080 DEBUG [Client ca384614c624857b4cf1f5] pn=3 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 1718450, ack_delay: 4, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | 0.080 DEBUG ECN probing: sent 8 probes client | 0.080 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client ca384614c624857b4cf1f5] delay duration 119.332874ms client | 0.080 DEBUG Setting timeout of 119.332874ms client | 0.080 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client ca384614c624857b4cf1f5] delay duration 119.302207ms client | 0.080 DEBUG Setting timeout of 119.302207ms client | 0.081 DEBUG [Client ca384614c624857b4cf1f5] pn=1718451 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 2418, len: >>1208, fin: false } client | 0.081 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 809165475 } client | 0.081 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.971607ms client | 0.081 DEBUG Setting timeout of 19.971607ms client | 0.081 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.955567ms client | 0.081 DEBUG Setting timeout of 19.955567ms client | 0.082 DEBUG [Client ca384614c624857b4cf1f5] pn=1718452 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 4, offset: 2418, len: >>1208, fin: false } client | 0.082 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 790179812 } client | 0.082 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.082 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.082 DEBUG [Client ca384614c624857b4cf1f5] pn=4 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 1718452, ack_delay: 2, first_ack_range: 6, ack_ranges: [], ecn_count: None } client | 0.082 DEBUG ECN probing: sent 9 probes client | 0.082 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.082 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.082 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.082 DEBUG [Client ca384614c624857b4cf1f5] delay duration 117.300195ms client | 0.082 DEBUG Setting timeout of 117.300195ms client | 0.082 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.082 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.082 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.082 DEBUG [Client ca384614c624857b4cf1f5] delay duration 117.273024ms client | 0.082 DEBUG Setting timeout of 117.273024ms client | 0.083 DEBUG [Client ca384614c624857b4cf1f5] pn=1718453 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 3626, len: >>1208, fin: false } client | 0.083 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 811210490 } client | 0.083 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.083 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.938444ms client | 0.083 DEBUG Setting timeout of 19.938444ms client | 0.083 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.083 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.915111ms client | 0.083 DEBUG Setting timeout of 19.915111ms client | 0.084 DEBUG [Client ca384614c624857b4cf1f5] pn=1718454 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 4, offset: 3626, len: >>1208, fin: false } client | 0.084 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 792231630 } client | 0.084 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.084 DEBUG [Client ca384614c624857b4cf1f5] pn=5 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, Ect0) len 34 client | TX -> Ack { largest_acknowledged: 1718454, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: None } client | 0.084 DEBUG ECN probing: sent 10 probes client | 0.084 DEBUG ECN probing concluded with 10 probes sent client | 0.084 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.084 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG [Client ca384614c624857b4cf1f5] delay duration 115.237807ms client | 0.084 DEBUG Setting timeout of 115.237807ms client | 0.084 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.084 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG [Client ca384614c624857b4cf1f5] delay duration 115.213612ms client | 0.084 DEBUG Setting timeout of 115.213612ms client | 0.085 DEBUG [Client ca384614c624857b4cf1f5] pn=1718455 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 4834, len: 286, fin: true } client | -> RX Stream { stream_id: 4, offset: 4834, len: >>916, fin: false } client | 0.085 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 813259490 } client | 0.085 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.085 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.973982ms client | 0.085 DEBUG Setting timeout of 19.973982ms client | 0.085 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.085 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.085 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.923768ms client | 0.085 DEBUG Setting timeout of 19.923768ms client | 0.086 DEBUG [Client ca384614c624857b4cf1f5] pn=1718456 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 4, offset: 5750, len: >>1208, fin: false } client | 0.086 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 794283645 } client | 0.086 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.086 DEBUG [Client ca384614c624857b4cf1f5] pn=6 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 34 client | TX -> Ack { largest_acknowledged: 1718456, ack_delay: 2, first_ack_range: 10, ack_ranges: [], ecn_count: None } client | 0.086 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.086 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG [Client ca384614c624857b4cf1f5] delay duration 113.18988ms client | 0.086 DEBUG Setting timeout of 113.18988ms client | 0.086 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.086 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.086 DEBUG [Client ca384614c624857b4cf1f5] delay duration 113.162028ms client | 0.086 DEBUG Setting timeout of 113.162028ms client | 0.087 DEBUG [Client ca384614c624857b4cf1f5] pn=1718457 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 4, offset: 6958, len: >>1208, fin: false } client | 0.087 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 815306837 } client | 0.087 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.976987ms client | 0.087 DEBUG Setting timeout of 19.976987ms client | 0.087 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.958652ms client | 0.087 DEBUG Setting timeout of 19.958652ms client | 0.088 DEBUG [Client ca384614c624857b4cf1f5] pn=1718458 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 4, offset: 8166, len: >>1208, fin: false } client | 0.088 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 796331313 } client | 0.088 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.088 DEBUG [Client ca384614c624857b4cf1f5] pn=7 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 34 client | TX -> Ack { largest_acknowledged: 1718458, ack_delay: 2, first_ack_range: 12, ack_ranges: [], ecn_count: None } client | 0.088 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.088 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG [Client ca384614c624857b4cf1f5] delay duration 111.150367ms client | 0.088 DEBUG Setting timeout of 111.150367ms client | 0.088 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.088 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG [Client ca384614c624857b4cf1f5] delay duration 111.124108ms client | 0.088 DEBUG Setting timeout of 111.124108ms client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] pn=1718459 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 912 client | -> RX Ack { largest_acknowledged: 2, ack_delay: 8, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Stream { stream_id: 4, offset: 9374, len: 866, fin: true } client | -> RX Padding { len: 17 } client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] Rx ACK space=ap, ranges=[1..=2] client | 0.109 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 client | 0.109 WARN ECN validation failed, no ECN counts in ACK frame client | 0.109 DEBUG on_packets_acked this=0x5556665e66d0, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=1332 client | 0.109 DEBUG PMTUD probe of size 1380 succeeded client | 0.109 DEBUG PMTUD started with probe size 1420 client | 0.109 DEBUG PLPMTU changed from 1232 to 1332, updating pacer client | 0.109 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 562, tv_nsec: 837377784 } client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.109 DEBUG Sending PMTUD probe of size 1420, count 1 client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] pn=8 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 1372 client | TX -> Ping client | TX -> Padding { len: 1345 } client | 0.109 DEBUG packet_sent this=0x5556665e66d0, pn=8, ps=1372 client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.877381ms client | 0.109 DEBUG Setting timeout of 19.877381ms client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.109 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] delay duration 19.791971ms client | 0.109 DEBUG Setting timeout of 19.791971ms client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 563, tv_nsec: 160358709 } } client | 0.109 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 563, tv_nsec: 160358709 } }) client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.109 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.109 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 562, tv_nsec: 817622230 } client | 0.109 DEBUG [Client ca384614c624857b4cf1f5] pn=9 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 45 client | TX -> Ack { largest_acknowledged: 1718459, ack_delay: 30, first_ack_range: 13, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.109 DEBUG Setting timeout of 342.674072ms server | I20250430 08:48:18.508744 35 H1QDownstreamSession.h:84] onConnectionEnd client | 0.140 DEBUG [Client ca384614c624857b4cf1f5] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } client | 0.140 DEBUG Building Short dcid Some(CID [8]: 400000d10bf14a3c) client | 0.140 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 562, tv_nsec: 849119747 } client | 0.140 DEBUG [Client ca384614c624857b4cf1f5] pn=10 type=Short pri-path:400000d10bf14a3c [::]:59594->[fd00:cafe:cafe:100::100]:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 1718459, ack_delay: 3967, first_ack_range: 13, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.141 DEBUG Setting timeout of 311.161197ms client | 0.141 DEBUG Setting timeout of 311.137423ms client | 0.453 DEBUG [Client ca384614c624857b4cf1f5] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 563, tv_nsec: 160358709 } } -> Closed(Application(0)) client | 0.453 INFO Closing timer expired client | 0.453 DEBUG Output::None client | 0.453 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.453 DEBUG Timer fired while closed client | 0.453 DEBUG Output::None client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 08:48:29,266 Using the client's key log file. 2025-04-30 08:48:29,278 2025-04-30 08:48:29,279 Using the client's key log file. 2025-04-30 08:48:29,279 Using the client's key log file. 2025-04-30 08:48:29,290 2025-04-30 08:48:29,291 Using the client's key log file. 2025-04-30 08:48:29,873 Check of downloaded files succeeded. 2025-04-30 08:48:30,454 Check of downloaded files succeeded.