2025-12-13 11:26:04,505 Generated random file: enormous-peaceful-witch of size: 5120 2025-12-13 11:26:04,506 Generated random file: overjoyed-zestful-giraffe of size: 10240 2025-12-13 11:26:04,506 Requests: https://server4:443/enormous-peaceful-witch https://server4:443/overjoyed-zestful-giraffe 2025-12-13 11:26:04,564 2025-12-13 11:26:04,565 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_1t1x2wf9/ TESTCASE_SERVER=resumption TESTCASE_CLIENT=resumption WWW=/tmp/www_9miqr4fu/ DOWNLOADS=/tmp/download_zuiyl245/ SERVER_LOGS=/tmp/logs_server_fhamv1x5 CLIENT_LOGS=/tmp/logs_client_5hfhek07 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/enormous-peaceful-witch https://server4:443/overjoyed-zestful-giraffe" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-12-13 11:26:17,117 Container client Recreate Container server Recreate Container client Recreated Container server Recreated Attaching to client, server, sim sim | waiting 10s for server:443 server | 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] server | tx-checksum-sctp: off server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 server | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin server | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin server | + '[' -n resumption ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.3CtQ6e9gLf server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password client | Setting up routes... client | Actual changes: 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 client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.3CtQ6e9gLf 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 resumption ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.3CtQ6e9gLf -W '' client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | pk12util: PKCS12 IMPORT SUCCESSFUL server | + certutil -L -d sql:/neqo/db -n cert server | Certificate: server | Data: server | Version: 3 (0x2) server | Serial Number: server | 06:aa:c3:6e:1f:36:c7:20:5f:f0:b2:27:70:36:9c:a2: server | 66:a6:83:a5 server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Issuer: "O=interop runner Root Certificate Authority" server | Validity: server | Not Before: Sat Dec 13 11:26:04 2025 server | Not After : Tue Dec 23 11:26:04 2025 server | Subject: "O=interop runner leaf" server | Subject Public Key Info: server | Public Key Algorithm: X9.62 elliptic curve public key server | Args: server | 06:08:2a:86:48:ce:3d:03:01:07 server | EC Public Key: server | PublicValue: server | 04:5b:dc:3c:cf:6a:60:f0:b8:1d:f8:d0:c2:6f:c4:45: server | 4d:60:3b:2d:fe:b6:30:69:be:c6:68:99:97:f4:2c:44: server | 94:be:8e:8a:ce:5e:4a:57:6a:d7:57:22:d7:4c:29:69: server | 1a:72:96:87:ea:6e:76:c2:1c:92:0e:a6:bf:e2:e2:32: server | 23 server | Curve: ANSI X9.62 elliptic curve prime256v1 (aka secp256r1, NIST P-256) server | Signed Extensions: server | Name: Certificate Subject Alt Name server | DNS name: "server" server | DNS name: "server4" server | DNS name: "server6" server | DNS name: "server46" server | server | Name: Certificate Subject Key ID server | Data: server | 4a:79:d2:ea:4a:96:8d:44:f8:e8:29:38:46:d9:1f:d8: server | 82:3b:59:d1 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | fc:30:cc:e2:86:76:17:af:c2:96:cf:5d:53:8e:35:6b: server | 25:9e:9a:9d server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:20:39:90:dd:1d:8d:c8:94:17:ee:2e:a3:93: server | 82:9d:3e:3a:03:02:41:de:ad:4e:67:27:a4:89:e1:f8: server | 78:3a:96:9f:02:21:00:bb:76:12:20:cc:a1:00:d5:7d: server | 56:92:cc:d6:cc:f9:14:05:2a:8e:54:ec:d9:0e:bb:c8: server | de:1f:a1:3f:8b:80:53 server | Fingerprint (SHA-256): server | 22:CB:87:74:17:EB:53:E1:D3:4B:F2:8E:34:55:61:F2:A9:4C:46:B6:B9:D4:3F:87:BB:DB:09:83:04:DA:80:17 server | Fingerprint (SHA1): server | 20:CA:CC:3A:40:5B:3B:37:59:93:7E:1B:C8:85:FD:51:57:7F:13:8D server | server | Mozilla-CA-Policy: false (attribute missing) server | Certificate Trust Flags: server | SSL Flags: server | User server | Email Flags: server | User server | Object Signing Flags: server | User server | server | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" -d "$DB" -k "$CERT") server | + '[' resumption = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test resumption --qlog-dir /logs/qlog/ -d /neqo/db -k cert '[::]:443' server | ++ tee -i -a /logs/server.log server | 0.000 DEBUG Logging initialized server | 0.002 DEBUG Default socket send buffer size is Ok(212992) server | 0.002 DEBUG Default socket receive buffer size is 1048576, not changing server | 0.002 INFO Server waiting for connection on: Ok([::]:443) server | 0.312 DEBUG [Server] Unsupported version: 57414954 server | 0.312 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:56046 Tos(Cs0, NotEct) len 15 sim | server:443 is available after 501.677835ms sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | Capturing on 'eth1' sim | Capturing on 'eth0' sim | File: /logs/trace_node_left.pcap sim | File: /logs/trace_node_right.pcap 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://server4:443/enormous-peaceful-witch https://server4:443/overjoyed-zestful-giraffe' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test resumption --qlog-dir /logs/qlog/ --output-dir /downloads https://server4:443/enormous-peaceful-witch 'https://server4:443/overjoyed-zestful-giraffe client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.000 DEBUG Default socket send buffer size is Ok(212992) client | 0.000 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.000 INFO hq-interop Client connecting: 0.0.0.0:53186 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=5227f644bd6bbbc444713cea386d25 client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=29 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.001 DEBUG [unv-path 0.0.0.0:53186->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:5227f644bd6bbbc444713cea386d25 0.0.0.0:53186->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:5227f644bd6bbbc444713cea386d25 0.0.0.0:53186->193.167.100.100:443] Path validated Instant { tv_sec: 413, tv_nsec: 668459984 } client | 0.001 DEBUG [Client 5227f644bd6bbbc444713cea386d25] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x556048427660] state -> InProgress client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 5227f644bd6bbbc444713cea386d25) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1206 client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=29 type=Initial pri-path:5227f644bd6bbbc444713cea386d25 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1206 } client | 0.002 DEBUG packet_sent this=0x55604843a690, pn=29, ps=1252 client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 5227f644bd6bbbc444713cea386d25) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1206, len=332 client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=30 type=Initial pri-path:5227f644bd6bbbc444713cea386d25 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 379 client | TX -> Crypto { offset: 1206, len: 332 } client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pad Initial from 379 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x55604843a690, pn=30, ps=1252 client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 5227f644bd6bbbc444713cea386d25) 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 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 5227f644bd6bbbc444713cea386d25) 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 5227f644bd6bbbc444713cea386d25] delay duration 3.173362ms client | 0.002 DEBUG Setting timeout of 3.173362ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [15]: 5227f644bd6bbbc444713cea386d25) 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 5227f644bd6bbbc444713cea386d25] delay duration 3.136864ms client | 0.002 DEBUG Setting timeout of 3.136864ms client | 0.006 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.006 DEBUG Building Initial dcid Some(CID [15]: 5227f644bd6bbbc444713cea386d25) scid Some(CID [0]: ) client | 0.006 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.006 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 294.681067ms client | 0.006 DEBUG Setting timeout of 294.681067ms server | 1.011 DEBUG [Server] Handle initial server | 1.011 INFO AddressValidation: no token; accepting server | 1.011 INFO [Server] Accept connection CID [15]: 5227f644bd6bbbc444713cea386d25 server | 1.011 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.013 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.013 INFO [Server ...] Received valid Initial packet with scid CID [0]: dcid CID [15]: 5227f644bd6bbbc444713cea386d25 server | 1.013 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=5227f644bd6bbbc444713cea386d25 server | 1.013 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=13 server | 1.013 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] State change from Init -> WaitInitial server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=29 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1252 server | -> RX Crypto { offset: 0, len: 1206 } server | 1.013 DEBUG [Agent 0x557ee442aee0] state -> InProgress server | 1.013 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 423, tv_nsec: 691613287 } server | 1.013 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:53186] Make permanent server | 1.013 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:53186] set as primary path server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] State change from WaitInitial -> WaitVersion server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.013 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=13 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 42 server | TX -> Ack { largest_acknowledged: 29, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.013 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.013 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 298.065066ms server | 1.013 DEBUG Setting timeout of 298.065066ms server | 1.013 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=30 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 379 server | -> RX Crypto { offset: 1206, len: 332 } server | 1.013 DEBUG 0-RTT: no token, no 0-RTT server | 1.014 DEBUG Read secret available for Handshake: SymKey [32]: 43c25c3d800c3c42129b9d8a146aab25e17cd646ce78a90c16bd8f94b66fe0c8 server | 1.014 DEBUG Write secret available for Handshake: SymKey [32]: 4ef9d2eb64adc52760230d696359101f9ac6eb0fb0361e4f7e4f13a3c4a21456 server | 1.014 DEBUG Writing transport parameters, msg=8 server | 1.015 DEBUG Read secret available for ApplicationData: SymKey [32]: b88316b4d36c84ec7864cc7a4fda6e1eebf92f22d22f0da1af0902138a85a92d server | 1.015 DEBUG Write secret available for ApplicationData: SymKey [32]: 33d45b076d5068679a9abfc983507a58bacf986b40fe178013fef164d78112d3 server | 1.015 DEBUG [Agent 0x557ee442aee0] state -> InProgress server | 1.015 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.015 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.015 DEBUG [Crypto] Handshake keys installed server | 1.015 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.015 DEBUG [Crypto] Application write key installed server | 1.015 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 423, tv_nsec: 693579139 } server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] State change from WaitVersion -> Handshaking server | 1.015 DEBUG [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1 server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.015 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG CRYPTO for in offset=0, len=1178 server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=14 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1224 server | TX -> Ack { largest_acknowledged: 30, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 1178 } server | 1.015 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pad Initial from 1224 to PLPMTU 1232 server | 1.015 DEBUG packet_sent this=0x557ee449bc50, pn=14, ps=1232 server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.015 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG CRYPTO for hs offset=0, len=740 server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 780 server | TX -> Crypto { offset: 0, len: 740 } server | 1.015 DEBUG packet_sent this=0x557ee449bc50, pn=0, ps=780 server | 1.015 DEBUG Building Short dcid Some(CID [0]: ) server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.015 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG Building Short dcid Some(CID [0]: ) server | 1.015 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 298.059667ms server | 1.015 DEBUG Setting timeout of 298.059667ms server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.015 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.015 DEBUG Building Short dcid Some(CID [0]: ) server | 1.015 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.015 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 298.031383ms server | 1.015 DEBUG Setting timeout of 298.031383ms client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=13 type=Initial pri-path:5227f644bd6bbbc444713cea386d25 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 42 client | -> RX Ack { largest_acknowledged: 29, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Rx ACK space=in, ranges=[29..=29] client | 0.041 DEBUG [recovery::Loss] ACK for Initial - largest_acked=29 client | 0.041 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.041 DEBUG Acked crypto frame space=in offset=0 length=1206 client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Changing to use Server CID=474258bdfab7b3d465f1 client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] State change from WaitInitial -> WaitVersion client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Initial dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 79.281394ms client | 0.041 DEBUG Setting timeout of 79.281394ms client | 0.041 WARN Unhandled event StateChange(WaitVersion) client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Initial dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 79.247691ms client | 0.041 DEBUG Setting timeout of 79.247691ms client | 0.044 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=14 type=Initial pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1224 client | -> RX Ack { largest_acknowledged: 30, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 1178 } client | 0.044 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Rx ACK space=in, ranges=[29..=30] client | 0.044 DEBUG [recovery::Loss] ACK for Initial - largest_acked=30 client | 0.044 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.044 DEBUG Acked crypto frame space=in offset=1206 length=332 client | 0.045 DEBUG Write secret available for Handshake: SymKey [32]: 43c25c3d800c3c42129b9d8a146aab25e17cd646ce78a90c16bd8f94b66fe0c8 client | 0.045 DEBUG Read secret available for Handshake: SymKey [32]: 4ef9d2eb64adc52760230d696359101f9ac6eb0fb0361e4f7e4f13a3c4a21456 client | 0.045 DEBUG [Agent 0x556048427660] state -> InProgress client | 0.045 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.045 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.045 DEBUG [Crypto] Handshake keys installed client | 0.045 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 711653246 } client | 0.045 DEBUG [Client 5227f644bd6bbbc444713cea386d25] State change from WaitVersion -> Handshaking client | 0.045 INFO [Client 5227f644bd6bbbc444713cea386d25] Garbage packet: an invalid packet was dropped (internal use only) client | 0.045 DEBUG [Client ...] Dropped received packet: Garbage packet; Total: 1 client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG Building Initial dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=31 type=Initial pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 14, ack_delay: 233, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.046 DEBUG Building Handshake dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pad Initial from 43 to PLPMTU 1252 client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG Building Initial dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG Building Handshake dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG Building Initial dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG Building Handshake dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 57.863028ms client | 0.046 DEBUG Setting timeout of 57.863028ms client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=0 type=Handshake pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 780 client | -> RX Crypto { offset: 0, len: 740 } client | 0.046 DEBUG [Agent 0x556048427660] state -> AuthenticationPending client | 0.046 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 713710769 } client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG Building Initial dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG Building Handshake dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=0 type=Handshake pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 85, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Drop packet number space in client | 0.046 DEBUG [recovery::Loss] Reset loss recovery state for Initial client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG Building Handshake dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.046 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 102.378199ms client | 0.046 DEBUG Setting timeout of 102.378199ms client | 0.046 DEBUG StateChange(Handshaking) client | 0.046 WARN Cannot create stream ConnectionState client | 0.046 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Authenticated Ok client | 0.047 DEBUG Write secret available for ApplicationData: SymKey [32]: b88316b4d36c84ec7864cc7a4fda6e1eebf92f22d22f0da1af0902138a85a92d client | 0.047 DEBUG Read secret available for ApplicationData: SymKey [32]: 33d45b076d5068679a9abfc983507a58bacf986b40fe178013fef164d78112d3 client | 0.047 DEBUG [Agent 0x556048427660] SSL_AuthCertificateComplete: Ok(()) client | 0.047 DEBUG [Agent 0x556048427660] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.047 DEBUG [Client 5227f644bd6bbbc444713cea386d25] TLS connection complete client | 0.047 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.047 DEBUG [Crypto] Application write key installed client | 0.047 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.047 DEBUG [Crypto] application read keys installed client | 0.047 DEBUG [Client 5227f644bd6bbbc444713cea386d25] State change from Handshaking -> Connected client | 0.047 INFO [Client 5227f644bd6bbbc444713cea386d25] Connection established client | 0.047 DEBUG stream BiDi creatable client | 0.047 INFO Created stream 0 for https://server4/enormous-peaceful-witch client | 0.047 INFO Saving https://server4/enormous-peaceful-witch to "/downloads/enormous-peaceful-witch" client | 0.047 DEBUG stream UniDi creatable client | 0.047 DEBUG StateChange(Connected) client | 0.047 DEBUG stream 0 writable client | 0.047 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.047 DEBUG Building Handshake dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.047 DEBUG CRYPTO for hs offset=0, len=36 client | 0.047 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=1 type=Handshake pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 75 client | TX -> Crypto { offset: 0, len: 36 } client | 0.047 DEBUG packet_sent this=0x55604843a690, pn=1, ps=75 client | 0.047 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.047 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=0 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 143 client | TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 10011, ignore_order: false } client | TX -> Stream { stream_id: 0, offset: 0, len: 30, fin: true } client | 0.047 DEBUG packet_sent this=0x55604843a690, pn=0, ps=68 client | 0.047 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.047 DEBUG Building Handshake dcid Some(CID [10]: 474258bdfab7b3d465f1) scid Some(CID [0]: ) client | 0.047 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.047 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.047 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 102.374302ms client | 0.047 DEBUG Setting timeout of 102.374302ms server | 1.049 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=31 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 43 server | -> RX Ack { largest_acknowledged: 14, ack_delay: 233, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.049 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Rx ACK space=in, ranges=[13..=14] server | 1.049 DEBUG [recovery::Loss] ACK for Initial - largest_acked=14 server | 1.049 DEBUG on_packets_acked this=0x557ee449bc50, limited=1, bytes_in_flight=780, cwnd=12320, state=SlowStart, new_acked=1232 server | 1.049 DEBUG Acked crypto frame space=in offset=0 length=1178 server | 1.049 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186] Path validated Instant { tv_sec: 423, tv_nsec: 729800141 } server | 1.049 DEBUG [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 2 server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.050 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.050 DEBUG Building Short dcid Some(CID [0]: ) server | 1.050 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 72.442004ms server | 1.050 DEBUG Setting timeout of 72.442004ms server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Drop packet number space in server | 1.050 DEBUG [recovery::Loss] Reset loss recovery state for Initial server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=0 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 42 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 85, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Rx ACK space=hs, ranges=[0..=0] server | 1.050 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=0 server | 1.050 DEBUG on_packets_acked this=0x557ee449bc50, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=780 server | 1.050 DEBUG Acked crypto frame space=hs offset=0 length=740 server | 1.050 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:53186] Path validated Instant { tv_sec: 423, tv_nsec: 729924663 } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.050 DEBUG Building Short dcid Some(CID [0]: ) server | 1.050 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 54.347067ms server | 1.050 DEBUG Setting timeout of 54.347067ms server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.050 DEBUG Building Short dcid Some(CID [0]: ) server | 1.050 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 54.234486ms server | 1.050 DEBUG Setting timeout of 54.234486ms server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 75 server | -> RX Crypto { offset: 0, len: 36 } server | 1.050 DEBUG [Agent 0x557ee442aee0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] TLS connection complete server | 1.050 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:53186] Path validated Instant { tv_sec: 423, tv_nsec: 730252215 } server | 1.050 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.050 DEBUG [Crypto] application read keys installed server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] State change from Handshaking -> Connected server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] State change from Connected -> Confirmed server | 1.050 DEBUG PMTUD started, PLPMTU is now 1280 server | 1.050 DEBUG PMTUD started with probe size 1380 server | 1.050 INFO [Server 5227f644bd6bbbc444713cea386d25] Connection established server | 1.050 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 423, tv_nsec: 730252215 } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 68 server | -> RX AckFrequency { seqno: 0, tolerance: 2, delay: 10011, ignore_order: false } server | -> RX Stream { stream_id: 0, offset: 0, len: 30, fin: true } server | 1.050 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 423, tv_nsec: 740263215 } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 474258bdfab7b3d465f1) server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 41 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Drop packet number space hs server | 1.050 DEBUG [recovery::Loss] Reset loss recovery state for Handshake server | 1.050 DEBUG Building Short dcid Some(CID [0]: ) server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [224, 171, 148, 57, 53, 217, 8, 84, 207, 161], stateless_reset_token: Token([145, 8, 241, 153, 133, 132, 107, 134, 143, 67, 146, 151, 203, 253, 12, 153]) } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [85, 141, 236, 207, 92, 128, 143, 100, 130, 126], stateless_reset_token: Token([59, 58, 190, 152, 185, 115, 142, 93, 62, 77, 236, 216, 213, 189, 234, 49]) } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [87, 168, 122, 250, 29, 237, 100, 212, 196, 21], stateless_reset_token: Token([160, 185, 189, 225, 97, 32, 112, 0, 222, 128, 144, 59, 57, 92, 139, 131]) } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [69, 101, 164, 64, 234, 202, 166, 79, 124, 4], stateless_reset_token: Token([165, 191, 216, 159, 184, 115, 169, 49, 239, 135, 222, 97, 108, 65, 178, 63]) } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [199, 162, 110, 36, 2, 170, 215, 86, 130, 147], stateless_reset_token: Token([22, 85, 229, 171, 10, 210, 209, 205, 181, 108, 220, 47, 105, 112, 46, 154]) } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [103, 135, 37, 114, 81, 151, 66, 118, 229, 76], stateless_reset_token: Token([229, 54, 132, 215, 214, 33, 54, 157, 218, 99, 167, 38, 136, 224, 151, 166]) } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [164, 233, 245, 51, 248, 174, 188, 206, 188, 154], stateless_reset_token: Token([59, 163, 203, 139, 200, 238, 23, 53, 76, 117, 91, 152, 38, 106, 206, 85]) } server | TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 9059, ignore_order: false } server | TX -> Padding { len: 1055 } server | 1.050 DEBUG packet_sent this=0x557ee449bc50, pn=0, ps=1291 server | 1.050 DEBUG ECN probing: sent 1 probes server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.050 DEBUG Building Short dcid Some(CID [0]: ) server | 1.050 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1313 } server | 1.050 DEBUG packet_sent this=0x557ee449bc50, pn=1, ps=1332 server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.050 DEBUG Building Short dcid Some(CID [0]: ) server | 1.050 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.050 DEBUG ECN probing: sent 2 probes server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.050 DEBUG Building Short dcid Some(CID [0]: ) server | 1.050 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.050 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 1.449006ms server | 1.050 DEBUG Setting timeout of 1.449006ms server | 1.051 DEBUG [Server 5227f644bd6bbbc444713cea386d25] send session ticket 4069000f5227f644bd6bbbc444713cea386d250104800075300404802000000504801000000604801000000704801000000801100901100b01140e01080f0a474258bdfab7b3d465f1110c000000014abaaa9a000000016ab200c0000000ff02de1a0243e820048000ffff686921 server | 1.051 DEBUG Path = 'enormous-peaceful-witch' server | 1.051 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.051 DEBUG Building Short dcid Some(CID [0]: ) server | 1.051 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.051 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 444.57µs server | 1.051 DEBUG Setting timeout of 444.57µs server | 1.053 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.053 DEBUG Building Short dcid Some(CID [0]: ) server | 1.053 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1212, fin: false } server | 1.053 DEBUG packet_sent this=0x557ee449bc50, pn=2, ps=1232 server | 1.053 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG Building Short dcid Some(CID [0]: ) server | 1.053 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG ECN probing: sent 3 probes server | 1.053 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG Building Short dcid Some(CID [0]: ) server | 1.053 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 1.135353ms server | 1.053 DEBUG Setting timeout of 1.135353ms server | 1.053 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG Building Short dcid Some(CID [0]: ) server | 1.053 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.053 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 1.118271ms server | 1.053 DEBUG Setting timeout of 1.118271ms server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.055 DEBUG Building Short dcid Some(CID [0]: ) server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false } server | 1.055 DEBUG packet_sent this=0x557ee449bc50, pn=3, ps=1232 server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.055 DEBUG Building Short dcid Some(CID [0]: ) server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false } server | 1.055 DEBUG packet_sent this=0x557ee449bc50, pn=4, ps=1232 server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.055 DEBUG Building Short dcid Some(CID [0]: ) server | 1.055 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.055 DEBUG ECN probing: sent 5 probes server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.055 DEBUG Building Short dcid Some(CID [0]: ) server | 1.055 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 2.533772ms server | 1.055 DEBUG Setting timeout of 2.533772ms server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.055 DEBUG Building Short dcid Some(CID [0]: ) server | 1.055 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.055 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 2.5113ms server | 1.055 DEBUG Setting timeout of 2.5113ms server | 1.058 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG Building Short dcid Some(CID [0]: ) server | 1.058 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false } server | 1.058 DEBUG packet_sent this=0x557ee449bc50, pn=5, ps=1232 server | 1.058 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.058 DEBUG Building Short dcid Some(CID [0]: ) server | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.058 DEBUG ECN probing: sent 6 probes server | 1.058 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.058 DEBUG Building Short dcid Some(CID [0]: ) server | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.058 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 1.159687ms server | 1.058 DEBUG Setting timeout of 1.159687ms server | 1.058 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.058 DEBUG Building Short dcid Some(CID [0]: ) server | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.058 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 1.138307ms server | 1.058 DEBUG Setting timeout of 1.138307ms server | 1.060 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.060 DEBUG Building Short dcid Some(CID [0]: ) server | 1.060 DEBUG CRYPTO for ap offset=0, len=321 server | 1.060 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 678 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 1280, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Stream { stream_id: 0, offset: 4842, len: 278, fin: true } server | TX -> Crypto { offset: 0, len: 321 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 241, 22, 227, 16, 254, 226, 138, 0, 53, 18, 81, 148, 221, 230, 36, 18, 238, 134, 81, 163, 55, 80, 179, 245, 128, 156, 55, 112, 107, 1, 46, 184, 145, 76, 226, 213] } server | 1.060 DEBUG packet_sent this=0x557ee449bc50, pn=6, ps=678 server | 1.060 DEBUG ECN probing: sent 7 probes server | 1.060 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.060 DEBUG Building Short dcid Some(CID [0]: ) server | 1.060 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.060 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 110.615607ms server | 1.060 DEBUG Setting timeout of 110.615607ms server | 1.060 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.060 DEBUG Building Short dcid Some(CID [0]: ) server | 1.060 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.060 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 110.599598ms server | 1.060 DEBUG Setting timeout of 110.599598ms client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=1 type=Handshake pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 41 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Rx ACK space=hs, ranges=[0..=1] client | 0.079 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=1 client | 0.079 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=68, cwnd=12520, state=SlowStart, new_acked=75 client | 0.079 DEBUG Acked crypto frame space=hs offset=0 length=36 client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=0 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1291 client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [224, 171, 148, 57, 53, 217, 8, 84, 207, 161], stateless_reset_token: Token([145, 8, 241, 153, 133, 132, 107, 134, 143, 67, 146, 151, 203, 253, 12, 153]) } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [85, 141, 236, 207, 92, 128, 143, 100, 130, 126], stateless_reset_token: Token([59, 58, 190, 152, 185, 115, 142, 93, 62, 77, 236, 216, 213, 189, 234, 49]) } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [87, 168, 122, 250, 29, 237, 100, 212, 196, 21], stateless_reset_token: Token([160, 185, 189, 225, 97, 32, 112, 0, 222, 128, 144, 59, 57, 92, 139, 131]) } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [69, 101, 164, 64, 234, 202, 166, 79, 124, 4], stateless_reset_token: Token([165, 191, 216, 159, 184, 115, 169, 49, 239, 135, 222, 97, 108, 65, 178, 63]) } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [199, 162, 110, 36, 2, 170, 215, 86, 130, 147], stateless_reset_token: Token([22, 85, 229, 171, 10, 210, 209, 205, 181, 108, 220, 47, 105, 112, 46, 154]) } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [103, 135, 37, 114, 81, 151, 66, 118, 229, 76], stateless_reset_token: Token([229, 54, 132, 215, 214, 33, 54, 157, 218, 99, 167, 38, 136, 224, 151, 166]) } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [164, 233, 245, 51, 248, 174, 188, 206, 188, 154], stateless_reset_token: Token([59, 163, 203, 139, 200, 238, 23, 53, 76, 117, 91, 152, 38, 106, 206, 85]) } client | -> RX AckFrequency { seqno: 0, tolerance: 2, delay: 9059, ignore_order: false } client | -> RX Padding { len: 1055 } client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] State change from Connected -> Confirmed client | 0.079 DEBUG PMTUD started, PLPMTU is now 1280 client | 0.079 DEBUG PMTUD started with probe size 1380 client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Drop packet number space hs client | 0.079 DEBUG [recovery::Loss] Reset loss recovery state for Handshake client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] No preferred address to migrate to client | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 756039079 } client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.079 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=1 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1323 } client | 0.079 DEBUG packet_sent this=0x55604843a690, pn=1, ps=1352 client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG ECN probing: sent 1 probes client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 8.809935ms client | 0.079 DEBUG Setting timeout of 8.809935ms client | 0.079 WARN Unhandled event StateChange(Confirmed) client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.079 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 8.766554ms client | 0.079 DEBUG Setting timeout of 8.766554ms client | 0.080 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=1 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1332 client | -> RX Ping client | -> RX Padding { len: 1313 } client | 0.080 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 413, tv_nsec: 748054405 } client | 0.080 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 748054405 } client | 0.080 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.080 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=2 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 36 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | 0.080 DEBUG ECN probing: sent 2 probes client | 0.080 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 112.809642ms client | 0.080 DEBUG Setting timeout of 112.809642ms client | 0.080 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.080 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 112.786479ms client | 0.080 DEBUG Setting timeout of 112.786479ms client | 0.081 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=2 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1232 client | -> RX Stream { stream_id: 0, offset: 0, len: >>1212, fin: false } client | 0.081 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 758202850 } client | 0.081 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 9.031168ms client | 0.081 DEBUG Setting timeout of 9.031168ms client | 0.081 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.081 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.081 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 9.009988ms client | 0.081 DEBUG Setting timeout of 9.009988ms client | 0.083 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=3 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1232 client | -> RX Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false } client | 0.083 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 751327938 } client | 0.083 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.083 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=3 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 36 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | 0.083 DEBUG ECN probing: sent 3 probes client | 0.083 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.083 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 109.528615ms client | 0.083 DEBUG Setting timeout of 109.528615ms client | 0.083 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.083 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.083 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 109.503619ms client | 0.083 DEBUG Setting timeout of 109.503619ms client | 0.084 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=4 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1232 client | -> RX Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false } client | 0.084 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 761401463 } client | 0.084 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.084 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 9.033562ms client | 0.084 DEBUG Setting timeout of 9.033562ms client | 0.084 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.084 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.084 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 9.012724ms client | 0.084 DEBUG Setting timeout of 9.012724ms client | 0.086 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=5 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1232 client | -> RX Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false } client | 0.087 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 754507847 } client | 0.087 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.087 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=4 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 36 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 2, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } client | 0.087 DEBUG ECN probing: sent 4 probes client | 0.087 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 106.328038ms client | 0.087 DEBUG Setting timeout of 106.328038ms client | 0.087 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.087 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.087 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 106.302851ms client | 0.087 DEBUG Setting timeout of 106.302851ms client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=6 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 678 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 1280, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX Stream { stream_id: 0, offset: 4842, len: 278, fin: true } client | -> RX Crypto { offset: 0, len: 321 } client | -> RX NewToken { token: [173, 154, 139, 141, 134, 1, 0, 241, 22, 227, 16, 254, 226, 138, 0, 53, 18, 81, 148, 221, 230, 36, 18, 238, 134, 81, 163, 55, 80, 179, 245, 128, 156, 55, 112, 107, 1, 46, 184, 145, 76, 226, 213] } client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] Rx ACK space=ap, ranges=[0..=0] client | 0.088 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=0 client | 0.088 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=1352, cwnd=12520, state=SlowStart, new_acked=68 client | 0.088 DEBUG [0x556048427660] Got resumption token [986]: 02000645d3a4d527..cc02218df7c82914 client | 0.088 DEBUG [Agent 0x556048427660] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.088 DEBUG setting max_stream_data to 1048576 client | 0.088 DEBUG resumption token [1142]: 0000000127406900..cc02218df7c82914 client | 0.088 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 413, tv_nsec: 765350950 } client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.088 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 8.934999ms client | 0.088 DEBUG Setting timeout of 8.934999ms client | 0.088 DEBUG stream 0 complete client | 0.088 DEBUG stream BiDi creatable client | 0.088 DEBUG stream UniDi creatable client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.088 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] delay duration 8.88233ms client | 0.088 DEBUG Setting timeout of 8.88233ms client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 414, tv_nsec: 34835449 } } client | 0.088 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 414, tv_nsec: 34835449 } }) client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.088 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.088 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 413, tv_nsec: 756493215 } client | 0.088 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=5 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 47 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 25, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.088 DEBUG ECN probing: sent 5 probes client | 0.089 DEBUG Setting timeout of 278.288233ms server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1352 server | -> RX Ping server | -> RX Padding { len: 1323 } server | 1.083 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 423, tv_nsec: 763436984 } server | 1.083 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 423, tv_nsec: 763436984 } server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [0]: ) server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 26 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 1.083 DEBUG ECN probing: sent 8 probes server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [0]: ) server | 1.083 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 87.630478ms server | 1.083 DEBUG Setting timeout of 87.630478ms server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 36 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Rx ACK space=ap, ranges=[0..=1] server | 1.083 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=1 server | 1.083 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 5606/14943 ssthresh 18446744073709551615] slow start += 2623 server | 1.083 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 5606/14943 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=5606, cwnd=14943, state=SlowStart, new_acked=2623 server | 1.083 DEBUG PMTUD probe of size 1380 succeeded server | 1.083 DEBUG PMTUD started with probe size 1420 server | 1.083 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [0]: ) server | 1.083 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=8 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1353 } server | 1.083 DEBUG packet_sent this=0x557ee449bc50, pn=8, ps=1372 server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [0]: ) server | 1.083 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG ECN probing: sent 9 probes server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [0]: ) server | 1.083 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 89.05061ms server | 1.083 DEBUG Setting timeout of 89.05061ms server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG Building Short dcid Some(CID [0]: ) server | 1.083 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.083 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 89.031153ms server | 1.083 DEBUG Setting timeout of 89.031153ms server | 1.086 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 36 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } server | 1.086 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Rx ACK space=ap, ranges=[0..=3] server | 1.086 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=3 server | 1.086 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 4514/17407 ssthresh 18446744073709551615] slow start += 2464 server | 1.086 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 4514/17407 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=4514, cwnd=17407, state=SlowStart, new_acked=2464 server | 1.086 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG Building Short dcid Some(CID [0]: ) server | 1.086 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 78.880683ms server | 1.086 DEBUG Setting timeout of 78.880683ms server | 1.086 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG Building Short dcid Some(CID [0]: ) server | 1.086 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.086 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 78.809811ms server | 1.086 DEBUG Setting timeout of 78.809811ms server | 1.089 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 36 server | -> RX Ack { largest_acknowledged: 5, ack_delay: 2, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } server | 1.089 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Rx ACK space=ap, ranges=[0..=5] server | 1.089 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=5 server | 1.089 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 2050/19871 ssthresh 18446744073709551615] slow start += 2464 server | 1.089 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 2050/19871 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=2050, cwnd=19871, state=SlowStart, new_acked=2464 server | 1.089 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG Building Short dcid Some(CID [0]: ) server | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 69.567204ms server | 1.089 DEBUG Setting timeout of 69.567204ms server | 1.089 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG Building Short dcid Some(CID [0]: ) server | 1.089 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.089 DEBUG [Server 5227f644bd6bbbc444713cea386d25] delay duration 69.512982ms server | 1.089 DEBUG Setting timeout of 69.512982ms server | 1.091 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 47 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 25, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } server | 1.091 DEBUG [Server 5227f644bd6bbbc444713cea386d25] Rx ACK space=ap, ranges=[0..=6] server | 1.091 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=6 server | 1.091 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 1372/20549 ssthresh 18446744073709551615] slow start += 678 server | 1.091 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 1372/20549 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=1372, cwnd=20549, state=SlowStart, new_acked=678 server | 1.091 DEBUG Acked crypto frame space=ap offset=0 length=321 server | 1.091 INFO [Server 5227f644bd6bbbc444713cea386d25] ConnectionClose received. Error code: Application(0) frame type 0 reason kthxbye! server | 1.091 DEBUG [Server 5227f644bd6bbbc444713cea386d25] State change from Confirmed -> Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 423, tv_nsec: 984468963 } } server | 1.091 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:53186] Path validated Instant { tv_sec: 423, tv_nsec: 771736518 } server | 1.091 DEBUG [Server 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.091 DEBUG Building Short dcid Some(CID [0]: ) server | 1.091 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 423, tv_nsec: 771736518 } server | 1.091 DEBUG [Server 5227f644bd6bbbc444713cea386d25] pn=9 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 30 server | TX -> Ack { largest_acknowledged: 5, ack_delay: 0, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.091 DEBUG ECN probing: sent 10 probes server | 1.091 DEBUG ECN probing concluded with 10 probes sent server | 1.091 DEBUG Setting timeout of 212.62786ms server | 1.091 DEBUG Setting timeout of 212.615156ms client | 0.111 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.111 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.111 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 413, tv_nsec: 778725280 } client | 0.111 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=6 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 2804, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.111 DEBUG ECN probing: sent 6 probes client | 0.111 DEBUG Setting timeout of 256.050798ms client | 0.111 DEBUG Setting timeout of 256.039968ms client | 0.112 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.112 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.112 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 413, tv_nsec: 779978289 } client | 0.112 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=7 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 2960, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.112 DEBUG ECN probing: sent 7 probes client | 0.112 DEBUG Setting timeout of 254.780647ms client | 0.112 DEBUG Setting timeout of 254.770859ms client | 0.119 DEBUG [Client 5227f644bd6bbbc444713cea386d25] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.119 DEBUG Building Short dcid Some(CID [10]: 474258bdfab7b3d465f1) client | 0.119 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 413, tv_nsec: 787022846 } client | 0.119 DEBUG [Client 5227f644bd6bbbc444713cea386d25] pn=8 type=Short pri-path:474258bdfab7b3d465f1 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 3841, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.119 DEBUG ECN probing: sent 8 probes client | 0.119 DEBUG Setting timeout of 247.743283ms client | 0.119 DEBUG Setting timeout of 247.731041ms server | 1.114 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 423, tv_nsec: 984468963 } }; Total: 3 server | 1.114 DEBUG Setting timeout of 190.477321ms server | 1.114 DEBUG Setting timeout of 190.441454ms server | 1.115 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 423, tv_nsec: 984468963 } }; Total: 4 server | 1.115 DEBUG Setting timeout of 189.237084ms server | 1.115 DEBUG Setting timeout of 189.223329ms server | 1.122 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 423, tv_nsec: 984468963 } }; Total: 5 server | 1.122 DEBUG Setting timeout of 182.195552ms server | 1.122 DEBUG Setting timeout of 182.179502ms server | 1.305 DEBUG [Server 5227f644bd6bbbc444713cea386d25] State change from Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 423, tv_nsec: 984468963 } } -> Closed(Transport(PeerApplication(0))) server | 1.305 INFO Closing timer expired client | 0.367 DEBUG [Client 5227f644bd6bbbc444713cea386d25] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 414, tv_nsec: 34835449 } } -> Closed(Application(0)) client | 0.367 INFO Closing timer expired client | 0.367 DEBUG Output::None client | 0.367 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.367 DEBUG Timer fired while closed client | 0.367 DEBUG Output::None client | 0.368 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=205c21e459aeb18d client | 0.368 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=16 client | 0.368 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.368 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.368 DEBUG [unv-path 0.0.0.0:53186->193.167.100.100:443] Make permanent client | 0.368 DEBUG [unv-path:205c21e459aeb18d 0.0.0.0:53186->193.167.100.100:443] set as primary path client | 0.368 DEBUG [pri-unv-path:205c21e459aeb18d 0.0.0.0:53186->193.167.100.100:443] Path validated Instant { tv_sec: 414, tv_nsec: 35604713 } client | 0.368 INFO [Client 205c21e459aeb18d] resumption token [1142]: 0000000127406900..cc02218df7c82914 client | 0.368 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.368 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.368 DEBUG [Client 205c21e459aeb18d] client_start client | 0.369 DEBUG Writing transport parameters, msg=1 client | 0.369 DEBUG Write secret available for ZeroRtt: SymKey [32]: 34a1e62874d71ab7e1e91014ba65c96f15dd2501c4f1c98caa52facd84ad9d1d client | 0.369 DEBUG [Agent 0x556048427660] state -> InProgress client | 0.369 DEBUG [Client 205c21e459aeb18d] State change from Init -> WaitInitial client | 0.369 DEBUG Making Write ZeroRtt CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.369 DEBUG [Client 205c21e459aeb18d] Enabled 0-RTT client | 0.369 DEBUG stream BiDi creatable client | 0.369 INFO Created stream 0 for https://server4/overjoyed-zestful-giraffe client | 0.369 INFO Saving https://server4/overjoyed-zestful-giraffe to "/downloads/overjoyed-zestful-giraffe" client | 0.369 DEBUG stream UniDi creatable client | 0.369 DEBUG StateChange(WaitInitial) client | 0.369 DEBUG stream 0 writable client | 0.369 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.369 DEBUG Building Initial dcid Some(CID [8]: 205c21e459aeb18d) scid Some(CID [0]: ) client | 0.369 DEBUG CRYPTO for in offset=0, len=1170 client | 0.369 DEBUG [Client 205c21e459aeb18d] pn=16 type=Initial pri-path:205c21e459aeb18d 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1170 } client | 0.369 DEBUG packet_sent this=0x55604843a690, pn=16, ps=1252 client | 0.369 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.369 DEBUG Building Initial dcid Some(CID [8]: 205c21e459aeb18d) scid Some(CID [0]: ) client | 0.369 DEBUG CRYPTO for in offset=1170, len=709 client | 0.369 DEBUG [Client 205c21e459aeb18d] pn=17 type=Initial pri-path:205c21e459aeb18d 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 792 client | TX -> Crypto { offset: 1170, len: 709 } client | 0.369 DEBUG Building ZeroRtt dcid Some(CID [8]: 205c21e459aeb18d) scid Some(CID [0]: ) client | 0.369 DEBUG [Client 205c21e459aeb18d] pn=0 type=ZeroRtt pri-path:205c21e459aeb18d 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 861 client | TX -> Stream { stream_id: 0, offset: 0, len: 32, fin: true } client | 0.369 DEBUG packet_sent this=0x55604843a690, pn=0, ps=69 client | 0.369 DEBUG [Client 205c21e459aeb18d] pad Initial from 861 to PLPMTU 1252 client | 0.369 DEBUG packet_sent this=0x55604843a690, pn=17, ps=1183 client | 0.369 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.369 DEBUG Building Initial dcid Some(CID [8]: 205c21e459aeb18d) scid Some(CID [0]: ) client | 0.369 DEBUG Building ZeroRtt dcid Some(CID [8]: 205c21e459aeb18d) scid Some(CID [0]: ) client | 0.369 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.369 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.369 DEBUG Building Initial dcid Some(CID [8]: 205c21e459aeb18d) scid Some(CID [0]: ) client | 0.369 DEBUG Building ZeroRtt dcid Some(CID [8]: 205c21e459aeb18d) scid Some(CID [0]: ) client | 0.369 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.369 DEBUG [Client 205c21e459aeb18d] delay duration 116.838238ms client | 0.369 DEBUG Setting timeout of 116.838238ms server | 1.373 DEBUG [Server] Handle initial server | 1.373 INFO AddressValidation: valid NEW_TOKEN token; accepting server | 1.373 INFO [Server] Accept connection CID [8]: 205c21e459aeb18d server | 1.373 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.375 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.375 INFO [Server ...] Received valid Initial packet with scid CID [0]: dcid CID [8]: 205c21e459aeb18d server | 1.375 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=205c21e459aeb18d server | 1.375 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=683 server | 1.375 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.375 DEBUG [Server 205c21e459aeb18d] State change from Init -> WaitInitial server | 1.375 DEBUG [Server 205c21e459aeb18d] pn=16 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1252 server | -> RX Crypto { offset: 0, len: 1170 } server | 1.375 DEBUG [Agent 0x557ee4473e40] state -> InProgress server | 1.375 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 424, tv_nsec: 53544910 } server | 1.375 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:53186] Make permanent server | 1.375 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:53186] set as primary path server | 1.375 DEBUG [Server 205c21e459aeb18d] State change from WaitInitial -> WaitVersion server | 1.375 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.375 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.375 DEBUG [Server 205c21e459aeb18d] pn=683 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 43 server | TX -> Ack { largest_acknowledged: 16, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.375 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.375 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.375 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.375 DEBUG [Server 205c21e459aeb18d] delay duration 298.272613ms server | 1.375 DEBUG Setting timeout of 298.272613ms server | 1.375 DEBUG [Server 205c21e459aeb18d] pn=17 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 792 server | -> RX Crypto { offset: 1170, len: 709 } server | 1.375 INFO 0-RTT: transport parameters OK, passing to application checker server | 1.375 WARN AllowZeroRtt accepting 0-RTT server | 1.376 DEBUG Read secret available for ZeroRtt: SymKey [32]: 34a1e62874d71ab7e1e91014ba65c96f15dd2501c4f1c98caa52facd84ad9d1d server | 1.376 DEBUG Read secret available for Handshake: SymKey [32]: 2a5033fc240e8a121af284c6ca68c16c54982f4aa604b3a702f5d35e9f2e6bdb server | 1.376 DEBUG Write secret available for Handshake: SymKey [32]: 35870ef847424a33b715d6d8d99c61c1e4929e2d1094d930ea3b8b6486407cea server | 1.376 DEBUG Writing transport parameters, msg=8 server | 1.376 DEBUG Read secret available for ApplicationData: SymKey [32]: 64287963b26ac215727cfef522f4878d01c22840e765eb4559cddc0840c6f351 server | 1.376 DEBUG Write secret available for ApplicationData: SymKey [32]: 7773a49119af9499d6d138c0eeda8a3e1c4492671313dfa6c8f992e3df28e2e4 server | 1.376 DEBUG [Agent 0x557ee4473e40] state -> InProgress server | 1.376 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.376 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.376 DEBUG [Crypto] Handshake keys installed server | 1.376 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.376 DEBUG [Crypto] Application write key installed server | 1.376 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 424, tv_nsec: 55302673 } server | 1.376 DEBUG [Server 205c21e459aeb18d] State change from WaitVersion -> Handshaking server | 1.376 DEBUG Making Read ZeroRtt CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.376 DEBUG [Server 205c21e459aeb18d] Accepted 0-RTT server | 1.376 DEBUG [Server 205c21e459aeb18d] pn=0 type=ZeroRtt pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 69 server | -> RX Stream { stream_id: 0, offset: 0, len: 32, fin: true } server | 1.376 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 424, tv_nsec: 75302673 } server | 1.376 DEBUG [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 1 server | 1.376 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.377 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG CRYPTO for in offset=0, len=1184 server | 1.377 DEBUG [Server 205c21e459aeb18d] pn=684 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1231 server | TX -> Ack { largest_acknowledged: 17, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 1184 } server | 1.377 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG [Server 205c21e459aeb18d] pad Initial from 1231 to PLPMTU 1232 server | 1.377 DEBUG packet_sent this=0x557ee449bc50, pn=684, ps=1232 server | 1.377 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.377 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG CRYPTO for hs offset=0, len=187 server | 1.377 DEBUG [Server 205c21e459aeb18d] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 227 server | TX -> Crypto { offset: 0, len: 187 } server | 1.377 DEBUG packet_sent this=0x557ee449bc50, pn=0, ps=227 server | 1.377 DEBUG Building Short dcid Some(CID [0]: ) server | 1.377 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.377 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Short dcid Some(CID [0]: ) server | 1.377 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.377 DEBUG [Server 205c21e459aeb18d] delay duration 18.316325ms server | 1.377 DEBUG Setting timeout of 18.316325ms server | 1.377 DEBUG Path = 'overjoyed-zestful-giraffe' server | 1.377 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.377 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Short dcid Some(CID [0]: ) server | 1.377 DEBUG [Server 205c21e459aeb18d] pn=0 type=Short pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: >>1212, fin: false } server | 1.377 DEBUG packet_sent this=0x557ee449bc50, pn=0, ps=1232 server | 1.377 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.377 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Short dcid Some(CID [0]: ) server | 1.377 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.377 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.377 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.377 DEBUG Building Short dcid Some(CID [0]: ) server | 1.377 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.377 DEBUG [Server 205c21e459aeb18d] delay duration 2.486858ms server | 1.377 DEBUG Setting timeout of 2.486858ms server | 1.380 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.380 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Short dcid Some(CID [0]: ) server | 1.380 DEBUG [Server 205c21e459aeb18d] pn=1 type=Short pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false } server | 1.380 DEBUG packet_sent this=0x557ee449bc50, pn=1, ps=1232 server | 1.380 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.380 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Short dcid Some(CID [0]: ) server | 1.380 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.380 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.380 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Short dcid Some(CID [0]: ) server | 1.380 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.380 DEBUG [Server 205c21e459aeb18d] delay duration 4.326775ms server | 1.380 DEBUG Setting timeout of 4.326775ms server | 1.380 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.380 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.380 DEBUG Building Short dcid Some(CID [0]: ) server | 1.380 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.380 DEBUG [Server 205c21e459aeb18d] delay duration 4.304533ms server | 1.380 DEBUG Setting timeout of 4.304533ms server | 1.385 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.385 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Short dcid Some(CID [0]: ) server | 1.385 DEBUG [Server 205c21e459aeb18d] pn=2 type=Short pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false } server | 1.385 DEBUG packet_sent this=0x557ee449bc50, pn=2, ps=1232 server | 1.385 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.385 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Short dcid Some(CID [0]: ) server | 1.385 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.385 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.385 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Short dcid Some(CID [0]: ) server | 1.385 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.385 DEBUG [Server 205c21e459aeb18d] delay duration 4.103549ms server | 1.385 DEBUG Setting timeout of 4.103549ms server | 1.385 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.385 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.385 DEBUG Building Short dcid Some(CID [0]: ) server | 1.385 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.385 DEBUG [Server 205c21e459aeb18d] delay duration 4.0718ms server | 1.385 DEBUG Setting timeout of 4.0718ms client | 0.402 DEBUG [Client 205c21e459aeb18d] pn=683 type=Initial pri-path:205c21e459aeb18d 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 43 client | -> RX Ack { largest_acknowledged: 16, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.402 DEBUG [Client 205c21e459aeb18d] Rx ACK space=in, ranges=[16..=16] client | 0.402 DEBUG [recovery::Loss] ACK for Initial - largest_acked=16 client | 0.402 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.402 DEBUG Acked crypto frame space=in offset=0 length=1170 client | 0.402 DEBUG [Client 205c21e459aeb18d] Changing to use Server CID=8ec7cfc664ad30d9eafd client | 0.402 DEBUG [Client 205c21e459aeb18d] State change from WaitInitial -> WaitVersion client | 0.402 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.402 DEBUG Building Initial dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.403 DEBUG Building ZeroRtt dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) server | 1.390 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.390 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.403 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.403 DEBUG [Client 205c21e459aeb18d] delay duration 66.358617ms client | 0.403 DEBUG Setting timeout of 66.358617ms client | 0.403 WARN Unhandled event StateChange(WaitVersion) client | 0.403 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.403 DEBUG Building Initial dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.403 DEBUG Building ZeroRtt dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.403 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.403 DEBUG [Client 205c21e459aeb18d] delay duration 66.325666ms client | 0.403 DEBUG Setting timeout of 66.325666ms server | 1.390 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.390 DEBUG Building Short dcid Some(CID [0]: ) server | 1.390 DEBUG [Server 205c21e459aeb18d] pn=3 type=Short pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false } server | 1.390 DEBUG packet_sent this=0x557ee449bc50, pn=3, ps=1232 server | 1.390 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1082, pto: None, probe: EnumSet(), paced: false } server | 1.390 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.390 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.390 DEBUG Building Short dcid Some(CID [0]: ) server | 1.390 DEBUG [Server 205c21e459aeb18d] pn=4 type=Short pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1082 server | TX -> Stream { stream_id: 0, offset: 4842, len: >>1060, fin: false } server | 1.390 DEBUG packet_sent this=0x557ee449bc50, pn=4, ps=1082 server | 1.391 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.391 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.391 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.391 DEBUG Building Short dcid Some(CID [0]: ) server | 1.391 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.391 DEBUG [Server 205c21e459aeb18d] delay duration 4.409722ms server | 1.391 DEBUG Setting timeout of 4.409722ms server | 1.391 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.391 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.391 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.391 DEBUG Building Short dcid Some(CID [0]: ) server | 1.391 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.391 DEBUG [Server 205c21e459aeb18d] delay duration 4.378102ms server | 1.391 DEBUG Setting timeout of 4.378102ms client | 0.405 DEBUG [Client 205c21e459aeb18d] pn=684 type=Initial pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1231 client | -> RX Ack { largest_acknowledged: 17, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | -> RX Crypto { offset: 0, len: 1184 } client | 0.405 DEBUG [Client 205c21e459aeb18d] Rx ACK space=in, ranges=[16..=17] client | 0.405 DEBUG [recovery::Loss] ACK for Initial - largest_acked=17 client | 0.405 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=69, cwnd=12520, state=SlowStart, new_acked=1183 client | 0.405 DEBUG Acked crypto frame space=in offset=1170 length=709 client | 0.406 DEBUG Write secret available for Handshake: SymKey [32]: 2a5033fc240e8a121af284c6ca68c16c54982f4aa604b3a702f5d35e9f2e6bdb client | 0.406 DEBUG Read secret available for Handshake: SymKey [32]: 35870ef847424a33b715d6d8d99c61c1e4929e2d1094d930ea3b8b6486407cea client | 0.406 DEBUG [Agent 0x556048427660] state -> InProgress client | 0.406 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.406 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.407 DEBUG [Crypto] Handshake keys installed client | 0.407 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 73075047 } client | 0.407 DEBUG [Client 205c21e459aeb18d] State change from WaitVersion -> Handshaking client | 0.407 INFO [Client 205c21e459aeb18d] Garbage packet: an invalid packet was dropped (internal use only) client | 0.407 DEBUG [Client ...] Dropped received packet: Garbage packet; Total: 1 client | 0.407 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Initial dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG [Client 205c21e459aeb18d] pn=18 type=Initial pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 87 client | TX -> Ack { largest_acknowledged: 684, ack_delay: 186, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.407 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building ZeroRtt dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG [Client 205c21e459aeb18d] pad Initial from 87 to PLPMTU 1252 client | 0.407 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Initial dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building ZeroRtt dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Initial dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building ZeroRtt dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG [Client 205c21e459aeb18d] delay duration 48.557028ms client | 0.407 DEBUG Setting timeout of 48.557028ms client | 0.407 DEBUG [Client 205c21e459aeb18d] pn=0 type=Handshake pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 227 client | -> RX Crypto { offset: 0, len: 187 } client | 0.407 DEBUG Write secret available for ApplicationData: SymKey [32]: 64287963b26ac215727cfef522f4878d01c22840e765eb4559cddc0840c6f351 client | 0.407 DEBUG Read secret available for ApplicationData: SymKey [32]: 7773a49119af9499d6d138c0eeda8a3e1c4492671313dfa6c8f992e3df28e2e4 client | 0.407 DEBUG [Agent 0x556048427660] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.407 DEBUG [Client 205c21e459aeb18d] TLS connection complete client | 0.407 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.407 DEBUG [Crypto] Application write key installed client | 0.407 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.407 DEBUG [Crypto] application read keys installed client | 0.407 DEBUG setting max_stream_data to 1048576 client | 0.407 DEBUG [Client 205c21e459aeb18d] State change from Handshaking -> Connected client | 0.407 INFO [Client 205c21e459aeb18d] Connection established client | 0.407 DEBUG setting max_stream_data to 1048576 client | 0.407 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 74700633 } client | 0.407 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Initial dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG CRYPTO for hs offset=0, len=36 client | 0.407 DEBUG [Client 205c21e459aeb18d] pn=0 type=Handshake pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 80 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 43, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 0.407 DEBUG packet_sent this=0x55604843a690, pn=0, ps=80 client | 0.407 DEBUG [Client 205c21e459aeb18d] Drop packet number space in client | 0.407 DEBUG [recovery::Loss] Reset loss recovery state for Initial client | 0.407 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.407 DEBUG [Client 205c21e459aeb18d] pn=1 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 115 client | TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 8386, ignore_order: false } client | 0.407 DEBUG packet_sent this=0x55604843a690, pn=1, ps=35 client | 0.407 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG [Client 205c21e459aeb18d] delay duration 85.91409ms client | 0.407 DEBUG Setting timeout of 85.91409ms client | 0.407 DEBUG [Client 205c21e459aeb18d] pn=0 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 0, len: >>1212, fin: false } client | 0.407 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 95168858 } client | 0.407 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG [Client 205c21e459aeb18d] delay duration 19.979191ms client | 0.407 DEBUG Setting timeout of 19.979191ms client | 0.407 DEBUG StateChange(Handshaking) client | 0.407 DEBUG stream BiDi creatable client | 0.407 DEBUG stream UniDi creatable client | 0.407 DEBUG StateChange(Connected) client | 0.407 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.407 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.407 DEBUG [Client 205c21e459aeb18d] delay duration 19.951159ms client | 0.407 DEBUG Setting timeout of 19.951159ms server | 1.396 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.396 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.396 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.396 DEBUG Building Short dcid Some(CID [0]: ) server | 1.396 DEBUG [Server 205c21e459aeb18d] pn=5 type=Short pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 24 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 2589, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.396 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.396 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.396 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.396 DEBUG Building Short dcid Some(CID [0]: ) server | 1.396 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.396 DEBUG [Server 205c21e459aeb18d] delay duration 29.979221712s server | 1.396 DEBUG Setting timeout of 29.979221712s server | 1.396 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.396 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.396 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.396 DEBUG Building Short dcid Some(CID [0]: ) server | 1.396 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false } server | 1.396 DEBUG [Server 205c21e459aeb18d] delay duration 29.979194571s server | 1.396 DEBUG Setting timeout of 29.979194571s client | 0.408 DEBUG [Client 205c21e459aeb18d] pn=1 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false } client | 0.408 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 76413132 } client | 0.408 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.408 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.408 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.408 DEBUG [Client 205c21e459aeb18d] pn=2 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 33 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.408 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.408 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.408 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.408 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.408 DEBUG [Client 205c21e459aeb18d] delay duration 84.562295ms client | 0.408 DEBUG Setting timeout of 84.562295ms client | 0.408 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.409 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.409 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.409 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.409 DEBUG [Client 205c21e459aeb18d] delay duration 84.534273ms client | 0.409 DEBUG Setting timeout of 84.534273ms client | 0.414 DEBUG [Client 205c21e459aeb18d] pn=2 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false } client | 0.414 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 101640315 } client | 0.414 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.414 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.414 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.414 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.414 DEBUG [Client 205c21e459aeb18d] delay duration 19.975374ms client | 0.414 DEBUG Setting timeout of 19.975374ms client | 0.414 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.414 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.414 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.414 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.414 DEBUG [Client 205c21e459aeb18d] delay duration 19.95139ms client | 0.414 DEBUG Setting timeout of 19.95139ms client | 0.419 DEBUG [Client 205c21e459aeb18d] pn=3 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false } client | 0.419 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 87054517 } client | 0.419 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.419 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.419 DEBUG [Client 205c21e459aeb18d] pn=3 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 33 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 0.419 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.419 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.419 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG [Client 205c21e459aeb18d] delay duration 73.92627ms client | 0.419 DEBUG Setting timeout of 73.92627ms client | 0.419 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.419 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.419 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.419 DEBUG [Client 205c21e459aeb18d] delay duration 73.901864ms client | 0.419 DEBUG Setting timeout of 73.901864ms client | 0.420 DEBUG [Client 205c21e459aeb18d] pn=4 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1082 client | -> RX Stream { stream_id: 0, offset: 4842, len: >>1060, fin: false } client | 0.420 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 107934070 } client | 0.420 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.420 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.420 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.420 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.420 DEBUG [Client 205c21e459aeb18d] delay duration 19.979011ms client | 0.420 DEBUG Setting timeout of 19.979011ms client | 0.420 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.420 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.420 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.420 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.420 DEBUG [Client 205c21e459aeb18d] delay duration 19.963212ms client | 0.420 DEBUG Setting timeout of 19.963212ms server | 1.410 DEBUG [Server 205c21e459aeb18d] pn=18 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 87 server | -> RX Ack { largest_acknowledged: 684, ack_delay: 186, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.410 DEBUG [Server 205c21e459aeb18d] Rx ACK space=in, ranges=[683..=684] server | 1.410 DEBUG [recovery::Loss] ACK for Initial - largest_acked=684 server | 1.410 DEBUG on_packets_acked this=0x557ee449bc50, limited=1, bytes_in_flight=6237, cwnd=12320, state=SlowStart, new_acked=1232 server | 1.410 DEBUG Acked crypto frame space=in offset=0 length=1184 server | 1.410 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:53186] Path validated Instant { tv_sec: 424, tv_nsec: 90817535 } server | 1.410 DEBUG [Server ...] Dropped received packet: Coalesced packet has different DCID; Total: 2 server | 1.410 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.410 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.410 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG [Server 205c21e459aeb18d] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 5902, len: >>1210, fin: false } server | 1.411 DEBUG packet_sent this=0x557ee449bc50, pn=6, ps=1232 server | 1.411 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.411 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG [Server 205c21e459aeb18d] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 7112, len: >>1210, fin: false } server | 1.411 DEBUG packet_sent this=0x557ee449bc50, pn=7, ps=1232 server | 1.411 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.411 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG [Server 205c21e459aeb18d] pn=8 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 1232 server | TX -> Stream { stream_id: 0, offset: 8322, len: >>1210, fin: false } server | 1.411 DEBUG packet_sent this=0x557ee449bc50, pn=8, ps=1232 server | 1.411 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG [Server 205c21e459aeb18d] delay duration 1.528551ms server | 1.411 DEBUG Setting timeout of 1.528551ms server | 1.411 DEBUG [Server 205c21e459aeb18d] Drop packet number space in server | 1.411 DEBUG [recovery::Loss] Reset loss recovery state for Initial server | 1.411 DEBUG [Server 205c21e459aeb18d] pn=0 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 80 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 43, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | -> RX Crypto { offset: 0, len: 36 } server | 1.411 DEBUG [Server 205c21e459aeb18d] Rx ACK space=hs, ranges=[0..=0] server | 1.411 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=0 server | 1.411 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 9706/12547 ssthresh 18446744073709551615] slow start += 227 server | 1.411 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 9706/12547 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=9706, cwnd=12547, state=SlowStart, new_acked=227 server | 1.411 DEBUG Acked crypto frame space=hs offset=0 length=187 server | 1.411 DEBUG [Agent 0x557ee4473e40] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.411 DEBUG [Server 205c21e459aeb18d] TLS connection complete server | 1.411 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:53186] Path validated Instant { tv_sec: 424, tv_nsec: 91109490 } server | 1.411 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.411 DEBUG [Crypto] application read keys installed server | 1.411 DEBUG [Server 205c21e459aeb18d] State change from Handshaking -> Connected server | 1.411 DEBUG [Server 205c21e459aeb18d] State change from Connected -> Confirmed server | 1.411 DEBUG PMTUD started, PLPMTU is now 1280 server | 1.411 DEBUG PMTUD started with probe size 1380 server | 1.411 INFO [Server 205c21e459aeb18d] Connection established server | 1.411 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 424, tv_nsec: 91109490 } server | 1.411 DEBUG [Server 205c21e459aeb18d] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 35 server | -> RX AckFrequency { seqno: 0, tolerance: 2, delay: 8386, ignore_order: false } server | 1.411 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 424, tv_nsec: 99495490 } server | 1.411 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.424 DEBUG [Client 205c21e459aeb18d] pn=5 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 24 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 2589, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.424 DEBUG [Client 205c21e459aeb18d] Rx ACK space=ap, ranges=[0..=0] client | 0.424 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=0 client | 0.424 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=115, cwnd=12520, state=SlowStart, new_acked=69 client | 0.424 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.424 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.424 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.424 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.424 DEBUG [Client 205c21e459aeb18d] delay duration 16.362316ms client | 0.424 DEBUG Setting timeout of 16.362316ms client | 0.424 DEBUG stream 0 complete client | 0.424 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.424 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.424 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.424 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.424 DEBUG [Client 205c21e459aeb18d] delay duration 16.338352ms client | 0.424 DEBUG Setting timeout of 16.338352ms server | 1.411 DEBUG [Server 205c21e459aeb18d] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 41 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 1.411 DEBUG [Server 205c21e459aeb18d] Drop packet number space hs server | 1.411 DEBUG [recovery::Loss] Reset loss recovery state for Handshake server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG ECN probing: sent 1 probes server | 1.411 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG [Server 205c21e459aeb18d] delay duration 991.586µs server | 1.411 DEBUG Setting timeout of 991.586µs server | 1.411 DEBUG [Server 205c21e459aeb18d] send session ticket 40620008205c21e459aeb18d0104800075300404802000000504801000000604801000000704801000000801100901100b01140e01080f0a8ec7cfc664ad30d9eafd110c00000001ba2a1a1a000000016ab200c0000000ff02de1a0243e820048000ffff686921 server | 1.411 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG Building Short dcid Some(CID [0]: ) server | 1.411 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.411 DEBUG [Server 205c21e459aeb18d] delay duration 858.798µs server | 1.411 DEBUG Setting timeout of 858.798µs server | 1.412 DEBUG [Server 205c21e459aeb18d] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 3, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | 1.412 DEBUG [Server 205c21e459aeb18d] Rx ACK space=ap, ranges=[0..=1] server | 1.412 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=1 server | 1.412 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 7242/15011 ssthresh 18446744073709551615] slow start += 2464 server | 1.412 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 7242/15011 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=7242, cwnd=15011, state=SlowStart, new_acked=2464 server | 1.412 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.412 DEBUG Building Short dcid Some(CID [0]: ) server | 1.412 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.412 DEBUG [Server 205c21e459aeb18d] delay duration 468.988µs server | 1.412 DEBUG Setting timeout of 468.988µs server | 1.412 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.412 DEBUG Building Short dcid Some(CID [0]: ) server | 1.412 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.412 DEBUG [Server 205c21e459aeb18d] delay duration 418.053µs server | 1.412 DEBUG Setting timeout of 418.053µs server | 1.413 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.413 DEBUG Building Short dcid Some(CID [0]: ) server | 1.413 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.413 DEBUG CRYPTO for ap offset=0, len=305 server | 1.413 DEBUG [Server 205c21e459aeb18d] pn=9 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [53, 159, 85, 53, 28, 102, 50, 104, 175, 34], stateless_reset_token: Token([117, 79, 59, 185, 115, 50, 0, 209, 223, 245, 253, 130, 127, 127, 102, 96]) } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [141, 248, 187, 169, 23, 42, 216, 222, 90, 232], stateless_reset_token: Token([87, 146, 96, 111, 37, 202, 80, 42, 154, 222, 193, 67, 169, 207, 89, 80]) } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [254, 13, 29, 144, 202, 110, 157, 173, 220, 212], stateless_reset_token: Token([237, 47, 198, 81, 69, 2, 191, 214, 96, 188, 12, 170, 141, 211, 224, 178]) } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [101, 87, 53, 94, 87, 72, 95, 79, 113, 193], stateless_reset_token: Token([95, 158, 180, 23, 23, 123, 99, 170, 183, 59, 207, 144, 139, 163, 60, 165]) } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [16, 208, 56, 227, 183, 75, 120, 175, 211, 43], stateless_reset_token: Token([232, 45, 171, 224, 88, 139, 74, 49, 236, 63, 18, 227, 165, 231, 104, 182]) } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [217, 22, 230, 79, 105, 151, 111, 57, 219, 166], stateless_reset_token: Token([107, 230, 221, 115, 10, 185, 26, 239, 113, 107, 14, 161, 4, 156, 0, 4]) } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [191, 199, 121, 235, 133, 2, 1, 216, 141, 134], stateless_reset_token: Token([100, 104, 72, 111, 183, 140, 143, 213, 41, 2, 112, 80, 246, 207, 128, 239]) } server | TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 8887, ignore_order: false } server | TX -> Stream { stream_id: 0, offset: 9532, len: 708, fin: true } server | TX -> Crypto { offset: 0, len: 305 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 89, 104, 150, 147, 64, 172, 25, 243, 149, 141, 208, 0, 48, 103, 140, 226, 245, 59, 5, 44, 122, 105, 235, 86, 79, 176, 60, 91, 170, 58, 27, 220, 58, 61, 20, 186] } server | TX -> Padding { len: 27 } server | 1.413 DEBUG packet_sent this=0x557ee449bc50, pn=9, ps=1332 server | 1.413 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.413 DEBUG Building Short dcid Some(CID [0]: ) server | 1.413 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.413 DEBUG ECN probing: sent 2 probes server | 1.413 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.413 DEBUG Building Short dcid Some(CID [0]: ) server | 1.413 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.413 DEBUG [Server 205c21e459aeb18d] delay duration 6.174299ms server | 1.413 DEBUG Setting timeout of 6.174299ms server | 1.413 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.413 DEBUG Building Short dcid Some(CID [0]: ) server | 1.413 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.413 DEBUG [Server 205c21e459aeb18d] delay duration 6.141658ms server | 1.413 DEBUG Setting timeout of 6.141658ms server | 1.420 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.420 DEBUG Building Short dcid Some(CID [0]: ) server | 1.420 DEBUG [Server 205c21e459aeb18d] pn=10 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 24 server | TX -> Ack { largest_acknowledged: 2, ack_delay: 1068, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 1.420 DEBUG ECN probing: sent 3 probes server | 1.420 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.420 DEBUG Building Short dcid Some(CID [0]: ) server | 1.420 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.420 DEBUG [Server 205c21e459aeb18d] delay duration 79.722489ms server | 1.420 DEBUG Setting timeout of 79.722489ms server | 1.420 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.420 DEBUG Building Short dcid Some(CID [0]: ) server | 1.420 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.420 DEBUG [Server 205c21e459aeb18d] delay duration 79.692042ms server | 1.420 DEBUG Setting timeout of 79.692042ms server | 1.422 DEBUG [Server 205c21e459aeb18d] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: None } server | 1.422 DEBUG [Server 205c21e459aeb18d] Rx ACK space=ap, ranges=[0..=3] server | 1.422 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=3 server | 1.422 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 6110/17475 ssthresh 18446744073709551615] slow start += 2464 server | 1.422 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 6110/17475 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=6110, cwnd=17475, state=SlowStart, new_acked=2464 server | 1.422 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.422 DEBUG Building Short dcid Some(CID [0]: ) server | 1.422 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.422 DEBUG [Server 205c21e459aeb18d] delay duration 77.916916ms server | 1.422 DEBUG Setting timeout of 77.916916ms server | 1.422 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.422 DEBUG Building Short dcid Some(CID [0]: ) server | 1.422 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.422 DEBUG [Server 205c21e459aeb18d] delay duration 77.856744ms server | 1.422 DEBUG Setting timeout of 77.856744ms client | 0.439 DEBUG [Client 205c21e459aeb18d] pn=6 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 5902, len: >>1210, fin: false } client | 0.439 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 107466472 } client | 0.439 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.439 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.439 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.439 DEBUG [Client 205c21e459aeb18d] pn=4 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 33 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 4, first_ack_range: 6, ack_ranges: [], ecn_count: None } client | 0.440 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.440 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.440 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.440 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.440 DEBUG [Client 205c21e459aeb18d] delay duration 40.452316ms client | 0.440 DEBUG Setting timeout of 40.452316ms client | 0.440 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.440 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.440 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.440 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.440 DEBUG [Client 205c21e459aeb18d] delay duration 40.422671ms client | 0.440 DEBUG Setting timeout of 40.422671ms client | 0.440 DEBUG [Client 205c21e459aeb18d] pn=7 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 7112, len: >>1210, fin: false } client | 0.440 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 128466370 } client | 0.440 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.440 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.440 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.440 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.440 DEBUG [Client 205c21e459aeb18d] delay duration 19.977839ms client | 0.440 DEBUG Setting timeout of 19.977839ms client | 0.440 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.440 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.440 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.441 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.441 DEBUG [Client 205c21e459aeb18d] delay duration 19.952161ms client | 0.441 DEBUG Setting timeout of 19.952161ms client | 0.441 DEBUG [Client 205c21e459aeb18d] pn=8 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 1232 client | -> RX Stream { stream_id: 0, offset: 8322, len: >>1210, fin: false } client | 0.441 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 109474593 } client | 0.441 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.441 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.441 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.441 DEBUG [Client 205c21e459aeb18d] pn=5 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, NotEct) len 33 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: None } client | 0.442 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.442 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.442 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG [Client 205c21e459aeb18d] delay duration 38.452761ms client | 0.442 DEBUG Setting timeout of 38.452761ms client | 0.442 DEBUG [Client 205c21e459aeb18d] pn=1 type=Handshake pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 41 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.442 DEBUG [Client 205c21e459aeb18d] Rx ACK space=hs, ranges=[0..=0] client | 0.442 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=0 client | 0.442 DEBUG on_packets_acked this=0x55604843a690, limited=1, bytes_in_flight=35, cwnd=12520, state=SlowStart, new_acked=80 client | 0.442 DEBUG Acked crypto frame space=hs offset=0 length=36 client | 0.442 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.442 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.442 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG [Client 205c21e459aeb18d] delay duration 29.634564ms client | 0.442 DEBUG Setting timeout of 29.634564ms client | 0.442 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG Building Handshake dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) scid Some(CID [0]: ) client | 0.442 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.442 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.442 DEBUG [Client 205c21e459aeb18d] delay duration 29.611361ms client | 0.442 DEBUG Setting timeout of 29.611361ms client | 0.443 DEBUG [Client 205c21e459aeb18d] pn=9 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1332 client | -> RX Ping client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [53, 159, 85, 53, 28, 102, 50, 104, 175, 34], stateless_reset_token: Token([117, 79, 59, 185, 115, 50, 0, 209, 223, 245, 253, 130, 127, 127, 102, 96]) } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [141, 248, 187, 169, 23, 42, 216, 222, 90, 232], stateless_reset_token: Token([87, 146, 96, 111, 37, 202, 80, 42, 154, 222, 193, 67, 169, 207, 89, 80]) } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [254, 13, 29, 144, 202, 110, 157, 173, 220, 212], stateless_reset_token: Token([237, 47, 198, 81, 69, 2, 191, 214, 96, 188, 12, 170, 141, 211, 224, 178]) } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [101, 87, 53, 94, 87, 72, 95, 79, 113, 193], stateless_reset_token: Token([95, 158, 180, 23, 23, 123, 99, 170, 183, 59, 207, 144, 139, 163, 60, 165]) } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [16, 208, 56, 227, 183, 75, 120, 175, 211, 43], stateless_reset_token: Token([232, 45, 171, 224, 88, 139, 74, 49, 236, 63, 18, 227, 165, 231, 104, 182]) } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [217, 22, 230, 79, 105, 151, 111, 57, 219, 166], stateless_reset_token: Token([107, 230, 221, 115, 10, 185, 26, 239, 113, 107, 14, 161, 4, 156, 0, 4]) } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [191, 199, 121, 235, 133, 2, 1, 216, 141, 134], stateless_reset_token: Token([100, 104, 72, 111, 183, 140, 143, 213, 41, 2, 112, 80, 246, 207, 128, 239]) } client | -> RX AckFrequency { seqno: 0, tolerance: 2, delay: 8887, ignore_order: false } client | -> RX Stream { stream_id: 0, offset: 9532, len: 708, fin: true } client | -> RX Crypto { offset: 0, len: 305 } client | -> RX NewToken { token: [173, 154, 139, 141, 134, 1, 0, 89, 104, 150, 147, 64, 172, 25, 243, 149, 141, 208, 0, 48, 103, 140, 226, 245, 59, 5, 44, 122, 105, 235, 86, 79, 176, 60, 91, 170, 58, 27, 220, 58, 61, 20, 186] } client | -> RX Padding { len: 27 } client | 0.443 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 414, tv_nsec: 110619043 } client | 0.443 DEBUG [Client 205c21e459aeb18d] State change from Connected -> Confirmed client | 0.443 DEBUG PMTUD started, PLPMTU is now 1280 client | 0.443 DEBUG PMTUD started with probe size 1380 client | 0.443 DEBUG [Client 205c21e459aeb18d] Drop packet number space hs client | 0.443 DEBUG [recovery::Loss] Reset loss recovery state for Handshake client | 0.443 DEBUG [Client 205c21e459aeb18d] No preferred address to migrate to client | 0.443 DEBUG [0x556048427660] Got resumption token [970]: 02000645d3a4da8f..e0567ae87257ddbe client | 0.443 DEBUG [Agent 0x556048427660] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 4588, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.443 DEBUG resumption token [1119]: 0000000121406200..e0567ae87257ddbe client | 0.443 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 414, tv_nsec: 110619043 } client | 0.443 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.443 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.443 DEBUG [Client 205c21e459aeb18d] pn=6 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 1352 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 27, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> Ping client | TX -> Padding { len: 1315 } client | 0.443 DEBUG packet_sent this=0x55604843a690, pn=6, ps=1352 client | 0.443 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.443 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG ECN probing: sent 1 probes client | 0.443 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.443 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG [Client 205c21e459aeb18d] delay duration 84.115557ms client | 0.443 DEBUG Setting timeout of 84.115557ms client | 0.443 WARN Unhandled event StateChange(Confirmed) client | 0.443 DEBUG stream BiDi creatable client | 0.443 DEBUG stream UniDi creatable client | 0.443 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.443 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG [Client 205c21e459aeb18d] delay duration 84.060574ms client | 0.443 DEBUG Setting timeout of 84.060574ms client | 0.443 DEBUG [Client 205c21e459aeb18d] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 414, tv_nsec: 363570383 } } client | 0.443 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 414, tv_nsec: 363570383 } }) client | 0.443 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.443 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.443 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 414, tv_nsec: 110996188 } client | 0.443 DEBUG [Client 205c21e459aeb18d] pn=7 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 47 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 47, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.443 DEBUG ECN probing: sent 2 probes client | 0.443 DEBUG Setting timeout of 252.50713ms client | 0.448 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.448 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.448 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 414, tv_nsec: 115688298 } client | 0.448 DEBUG [Client 205c21e459aeb18d] pn=8 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 633, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.448 DEBUG ECN probing: sent 3 probes client | 0.448 DEBUG Setting timeout of 247.822684ms client | 0.448 DEBUG Setting timeout of 247.812745ms server | 1.442 DEBUG [Server 205c21e459aeb18d] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 6, ack_delay: 4, first_ack_range: 6, ack_ranges: [], ecn_count: None } server | 1.442 DEBUG [Server 205c21e459aeb18d] Rx ACK space=ap, ranges=[0..=6] server | 1.442 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=6 server | 1.442 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 3796/19789 ssthresh 18446744073709551615] slow start += 2314 server | 1.442 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 3796/19789 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=3796, cwnd=19789, state=SlowStart, new_acked=2314 server | 1.442 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.442 DEBUG Building Short dcid Some(CID [0]: ) server | 1.442 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.442 DEBUG [Server 205c21e459aeb18d] delay duration 54.800495ms server | 1.442 DEBUG Setting timeout of 54.800495ms server | 1.442 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.442 DEBUG Building Short dcid Some(CID [0]: ) server | 1.442 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.442 DEBUG [Server 205c21e459aeb18d] delay duration 54.726347ms server | 1.442 DEBUG Setting timeout of 54.726347ms server | 1.444 DEBUG [Server 205c21e459aeb18d] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, NotEct) len 33 server | -> RX Ack { largest_acknowledged: 8, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: None } server | 1.444 DEBUG [Server 205c21e459aeb18d] Rx ACK space=ap, ranges=[0..=8] server | 1.444 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=8 server | 1.444 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 1332/22253 ssthresh 18446744073709551615] slow start += 2464 server | 1.444 DEBUG [Cubic [w_max: 0, k: 0, t_epoch: None] CongCtrl 1332/22253 ssthresh 18446744073709551615] on_packets_acked this=0x557ee449bc50, limited=0, bytes_in_flight=1332, cwnd=22253, state=SlowStart, new_acked=2464 server | 1.444 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.444 DEBUG Building Short dcid Some(CID [0]: ) server | 1.444 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.444 DEBUG [Server 205c21e459aeb18d] delay duration 45.642098ms server | 1.444 DEBUG Setting timeout of 45.642098ms server | 1.444 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.444 DEBUG Building Short dcid Some(CID [0]: ) server | 1.444 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.444 DEBUG [Server 205c21e459aeb18d] delay duration 45.597675ms server | 1.444 DEBUG Setting timeout of 45.597675ms server | 1.447 DEBUG [Server 205c21e459aeb18d] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1352 server | -> RX Ack { largest_acknowledged: 9, ack_delay: 27, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX Ping server | -> RX Padding { len: 1315 } server | 1.447 DEBUG [Server 205c21e459aeb18d] Rx ACK space=ap, ranges=[0..=9] server | 1.447 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=9 server | 1.447 DEBUG on_packets_acked this=0x557ee449bc50, limited=1, bytes_in_flight=0, cwnd=22253, state=SlowStart, new_acked=1332 server | 1.447 DEBUG PMTUD probe of size 1380 succeeded server | 1.447 DEBUG PMTUD started with probe size 1420 server | 1.447 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.447 DEBUG Acked crypto frame space=ap offset=0 length=305 server | 1.447 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 424, tv_nsec: 127305440 } server | 1.447 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 424, tv_nsec: 127305440 } server | 1.447 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.447 DEBUG Building Short dcid Some(CID [0]: ) server | 1.447 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.447 DEBUG [Server 205c21e459aeb18d] pn=11 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 1372 server | TX -> Ack { largest_acknowledged: 6, ack_delay: 0, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | TX -> Ping server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | TX -> Padding { len: 1343 } server | 1.447 DEBUG packet_sent this=0x557ee449bc50, pn=11, ps=1372 server | 1.447 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.447 DEBUG Building Short dcid Some(CID [0]: ) server | 1.447 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.447 DEBUG ECN probing: sent 4 probes server | 1.447 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.447 DEBUG Building Short dcid Some(CID [0]: ) server | 1.447 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.447 DEBUG [Server 205c21e459aeb18d] delay duration 52.774133ms server | 1.447 DEBUG Setting timeout of 52.774133ms server | 1.447 DEBUG [Server 205c21e459aeb18d] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 47 server | -> RX Ack { largest_acknowledged: 9, ack_delay: 47, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } server | 1.447 DEBUG [Server 205c21e459aeb18d] Rx ACK space=ap, ranges=[0..=9] server | 1.447 INFO [Server 205c21e459aeb18d] ConnectionClose received. Error code: Application(0) frame type 0 reason kthxbye! server | 1.447 DEBUG [Server 205c21e459aeb18d] State change from Confirmed -> Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 424, tv_nsec: 309342836 } } server | 1.447 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:53186] Path validated Instant { tv_sec: 424, tv_nsec: 127480847 } server | 1.447 DEBUG [Server 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.447 DEBUG Building Short dcid Some(CID [0]: ) server | 1.447 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 424, tv_nsec: 127480847 } server | 1.447 DEBUG [Server 205c21e459aeb18d] pn=12 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:53186 Tos(Cs0, Ect0) len 30 server | TX -> Ack { largest_acknowledged: 7, ack_delay: 0, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.447 DEBUG ECN probing: sent 5 probes server | 1.447 DEBUG Setting timeout of 181.733178ms server | 1.447 DEBUG Setting timeout of 181.719232ms server | 1.451 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 424, tv_nsec: 309342836 } }; Total: 3 server | 1.451 DEBUG Setting timeout of 178.383502ms server | 1.451 DEBUG Setting timeout of 178.365749ms client | 0.476 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.476 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.476 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 414, tv_nsec: 143782220 } client | 0.476 DEBUG [Client 205c21e459aeb18d] pn=9 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 4145, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.476 DEBUG ECN probing: sent 4 probes client | 0.476 DEBUG Setting timeout of 219.715628ms client | 0.476 DEBUG [Client 205c21e459aeb18d] output_dgram_on_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.476 DEBUG Building Short dcid Some(CID [10]: 8ec7cfc664ad30d9eafd) client | 0.476 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 414, tv_nsec: 143867489 } client | 0.476 DEBUG [Client 205c21e459aeb18d] pn=10 type=Short pri-path:8ec7cfc664ad30d9eafd 0.0.0.0:53186->193.167.100.100:443 Tos(Cs0, Ect0) len 48 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 4156, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.476 DEBUG ECN probing: sent 5 probes client | 0.476 DEBUG Setting timeout of 219.651709ms client | 0.476 DEBUG Setting timeout of 219.646008ms server | 1.479 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 424, tv_nsec: 309342836 } }; Total: 4 server | 1.479 DEBUG Setting timeout of 150.240007ms server | 1.479 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 424, tv_nsec: 309342836 } }; Total: 5 server | 1.479 DEBUG Setting timeout of 150.210392ms server | 1.479 DEBUG Setting timeout of 150.203028ms server | 1.630 DEBUG [Server 205c21e459aeb18d] State change from Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 424, tv_nsec: 309342836 } } -> Closed(Transport(PeerApplication(0))) server | 1.630 INFO Closing timer expired client | 0.697 DEBUG [Client 205c21e459aeb18d] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 414, tv_nsec: 363570383 } } -> Closed(Application(0)) client | 0.697 INFO Closing timer expired client | 0.697 DEBUG Output::None client | 0.697 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.697 DEBUG Timer fired while closed client | 0.697 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-12-13 11:26:17,204 Using the client's key log file. 2025-12-13 11:26:17,214 2025-12-13 11:26:17,214 Using the client's key log file. 2025-12-13 11:26:17,214 Using the client's key log file. 2025-12-13 11:26:17,222 2025-12-13 11:26:17,223 Using the client's key log file. 2025-12-13 11:26:17,223 Using the client's key log file. 2025-12-13 11:26:17,861 Check of downloaded files succeeded.