2025-12-13 13:07:48,210 Generated random file: brutal-slow-keyboard of size: 1024 2025-12-13 13:07:48,210 Requests: https://server4:443/brutal-slow-keyboard 2025-12-13 13:07:48,270 2025-12-13 13:07:48,271 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_txwtl_3a/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_nuucd12n/ DOWNLOADS=/tmp/download_o0riob1x/ SERVER_LOGS=/tmp/logs_server_kki7y7id CLIENT_LOGS=/tmp/logs_client_gc19rqua SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/microsoft/msquic/qns:main SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/brutal-slow-keyboard" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-12-13 13:08:09,750 Container sim Recreate Container sim Recreated Container server Recreate Container client 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 client | Setting up routes... client | Actual changes: client | tx-checksumming: off client | tx-checksum-ip-generic: off client | tx-checksum-sctp: off client | tcp-segmentation-offload: off client | tx-tcp-segmentation: off [requested on] client | tx-tcp-ecn-segmentation: off [requested on] client | tx-tcp-mangleid-segmentation: off [requested on] client | tx-tcp6-segmentation: off [requested on] client | tx-udp-segmentation: off [requested on] 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 handshake ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp client | Endpoint's IPv4 address is 193.167.0.100 server | + P12CERT=/tmp/tmp.pKOGUCGQ6D server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password 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.pKOGUCGQ6D server | Warning: output encryption option -nodes ignored with -export client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | + pk12util -d sql:/neqo/db -i /tmp/tmp.pKOGUCGQ6D -W '' 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 | 5f:a3:a1:06:57:63:a2:00:f6:e9:b5:45:b7:fb:3e:ca: server | 1f:37:33:cd 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 13:07:48 2025 server | Not After : Tue Dec 23 13:07:48 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:21:45:d6:ee:ec:a4:aa:b8:ad:40:d3:33:f4:14:30: server | f0:05:3a:3e:fe:eb:27:92:33:b5:6a:ba:cc:56:9a:32: server | 3b:ba:05:6d:97:fe:55:e3:fe:2d:1b:ee:01:2c:9c:60: server | b8:fc:e2:a4:5e:89:7b:98:2d:d6:af:d0:43:a9:51:22: server | 79 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 | 92:7b:49:e7:3b:16:1a:e6:50:a3:0b:cb:ca:88:31:3a: server | 12:da:df:8f server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 45:ce:87:2c:99:9d:b8:75:ce:1a:24:1c:5d:ab:9a:00: server | 3f:ca:91:57 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:46:02:21:00:e7:e2:99:d2:30:12:11:8e:2b:0a:b7: server | df:fb:8f:0f:ba:54:4d:76:75:fd:6a:16:aa:b7:d8:9d: server | 87:a4:95:55:9c:02:21:00:b5:a2:bd:69:3a:0f:f3:5f: server | 92:5c:1e:6e:54:72:cb:f1:44:ed:27:c1:f9:1c:c8:b6: server | 5d:30:df:cc:b4:53:03:35 server | Fingerprint (SHA-256): server | C8:11:BD:58:D1:C8:61:E7:DA:41:27:FD:4A:19:53:C3:F9:EC:E4:8B:17:98:57:56:91:E9:E9:93:92:28:BF:73 server | Fingerprint (SHA1): server | 26:AA:8D:D8:80:33:4C:47:0E:21:BB:09:D8:B1:54:B3:98:BF:39:54 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 | + '[' handshake = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test handshake --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.003 DEBUG Default socket send buffer size is Ok(212992) server | 0.003 DEBUG Default socket receive buffer size is 1048576, not changing server | 0.003 INFO Server waiting for connection on: Ok([::]:443) server | 0.295 DEBUG [Server] Unsupported version: 57414954 server | 0.295 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:58422 Tos(Cs0, NotEct) len 15 sim | server:443 is available after 501.22604ms sim | Using scenario: simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25 sim | Capturing on 'eth1' sim | Capturing on 'eth0' sim | File: /logs/trace_node_right.pcap sim | File: /logs/trace_node_left.pcap client | wait-for-it.sh: sim:57832 is available after 1 seconds client | Connecting to server4 client | Client params (before files):-test:H -sslkeylogfile:/logs/keys.log server | 1.748 DEBUG [Server] Handle initial server | 1.749 INFO AddressValidation: no token; accepting server | 1.749 INFO [Server] Accept connection CID [8]: 910c1609ce23416a server | 1.749 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.750 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.750 INFO [Server ...] Received valid Initial packet with scid CID [0]: dcid CID [8]: 910c1609ce23416a server | 1.750 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=910c1609ce23416a server | 1.750 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=54 server | 1.750 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.750 DEBUG [Server 910c1609ce23416a] State change from Init -> WaitInitial server | 1.750 DEBUG [Server 910c1609ce23416a] pn=113 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 1220 server | -> RX Crypto { offset: 0, len: 297 } server | -> RX Padding { len: 881 } server | 1.750 DEBUG 0-RTT: no token, no 0-RTT server | 1.751 DEBUG Read secret available for Handshake: SymKey [32]: 0f3122813d145ffcb148d6a5cd7e237d321260f7f84b13528e99c46803673967 server | 1.751 DEBUG Write secret available for Handshake: SymKey [32]: f12143f8496c6efc39a59c748e21e7b4454c5a4371018d4c28bc9305892e3f59 server | 1.751 DEBUG Writing transport parameters, msg=8 server | 1.751 DEBUG Read secret available for ApplicationData: SymKey [32]: 97a560e43b5bfd1fe274b85e9cecac3148113baa53da049556de7fadeedb94d1 server | 1.751 DEBUG Write secret available for ApplicationData: SymKey [32]: 1d6615f7d04cd799df792e6da8cf00b764913b64b94e4f7c1974282f7194881c server | 1.751 DEBUG [Agent 0x55f3df4fcee0] state -> InProgress server | 1.751 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.751 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.751 DEBUG [Crypto] Handshake keys installed server | 1.751 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 1.751 DEBUG [Crypto] Application write key installed server | 1.751 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 692655309 } server | 1.751 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:60975] Make permanent server | 1.751 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:60975] set as primary path server | 1.751 DEBUG [Server 910c1609ce23416a] State change from WaitInitial -> Handshaking server | 1.751 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.751 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.751 DEBUG CRYPTO for in offset=0, len=90 server | 1.751 DEBUG [Server 910c1609ce23416a] pn=54 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 137 server | TX -> Ack { largest_acknowledged: 113, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 90 } server | 1.751 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.751 DEBUG CRYPTO for hs offset=0, len=726 server | 1.751 DEBUG [Server 910c1609ce23416a] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 903 server | TX -> Crypto { offset: 0, len: 726 } server | 1.751 DEBUG packet_sent this=0x55f3df56dc50, pn=0, ps=766 server | 1.751 DEBUG Building Short dcid Some(CID [0]: ) server | 1.751 DEBUG [Server 910c1609ce23416a] pad Initial from 903 to PLPMTU 1232 server | 1.751 DEBUG packet_sent this=0x55f3df56dc50, pn=54, ps=466 server | 1.751 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.751 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.751 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.751 DEBUG Building Short dcid Some(CID [0]: ) server | 1.751 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.751 DEBUG [Server 910c1609ce23416a] delay duration 297.044747ms server | 1.751 DEBUG Setting timeout of 297.044747ms server | 1.751 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.751 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.751 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.751 DEBUG Building Short dcid Some(CID [0]: ) server | 1.751 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.751 DEBUG [Server 910c1609ce23416a] delay duration 297.007358ms server | 1.751 DEBUG Setting timeout of 297.007358ms server | 1.894 DEBUG [Server 910c1609ce23416a] pn=114 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 1220 server | -> RX Crypto { offset: 0, len: 297 } server | -> RX Ping server | -> RX Padding { len: 880 } server | 1.894 DEBUG unmark 0-length range at 0 server | 1.894 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 222, tv_nsec: 838136848 } server | 1.894 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 838136848 } server | 1.894 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.894 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG CRYPTO for in offset=0, len=90 server | 1.894 DEBUG [Server 910c1609ce23416a] pn=55 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 137 server | TX -> Ack { largest_acknowledged: 114, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 90 } server | 1.894 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG CRYPTO for hs offset=0, len=726 server | 1.894 DEBUG [Server 910c1609ce23416a] pn=1 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 903 server | TX -> Crypto { offset: 0, len: 726 } server | 1.894 DEBUG packet_sent this=0x55f3df56dc50, pn=1, ps=766 server | 1.894 DEBUG Building Short dcid Some(CID [0]: ) server | 1.894 DEBUG [Server 910c1609ce23416a] pad Initial from 903 to PLPMTU 1232 server | 1.894 DEBUG packet_sent this=0x55f3df56dc50, pn=55, ps=466 server | 1.894 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.894 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG Building Short dcid Some(CID [0]: ) server | 1.894 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.894 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.894 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG Building Short dcid Some(CID [0]: ) server | 1.894 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.894 DEBUG [Server 910c1609ce23416a] delay duration 299.749782ms server | 1.894 DEBUG Setting timeout of 299.749782ms server | 1.894 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.894 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 1.894 DEBUG Building Short dcid Some(CID [0]: ) server | 1.894 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.894 DEBUG [Server 910c1609ce23416a] delay duration 299.679602ms server | 1.894 DEBUG Setting timeout of 299.679602ms server | 2.195 DEBUG [Server 910c1609ce23416a] pn=115 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 1220 server | -> RX Crypto { offset: 0, len: 297 } server | -> RX Ping server | -> RX Padding { len: 880 } server | 2.195 DEBUG unmark 0-length range at 0 server | 2.195 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 223, tv_nsec: 138675258 } server | 2.195 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 223, tv_nsec: 138675258 } server | 2.195 DEBUG [recovery::Loss] PTO timer fired for Initial server | 2.195 DEBUG [recovery::Loss] PTO timer fired for Handshake server | 2.195 DEBUG [Server 910c1609ce23416a] Lost: Ack(AckToken { space: Initial, ranges: [PacketRange { largest: 113, smallest: 113, ack_needed: true }] }) server | 2.195 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 222, tv_nsec: 692655309 } server | 2.195 DEBUG [Server 910c1609ce23416a] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 90 }) server | 2.195 INFO Lost crypto frame space=in offset=0 length=90 server | 2.195 DEBUG [Server 910c1609ce23416a] Lost: Ack(AckToken { space: Initial, ranges: [PacketRange { largest: 114, smallest: 113, ack_needed: true }] }) server | 2.195 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 222, tv_nsec: 838136848 } server | 2.195 DEBUG [Server 910c1609ce23416a] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 90 }) server | 2.195 INFO Lost crypto frame space=in offset=0 length=90 server | 2.195 DEBUG [Server 910c1609ce23416a] Lost: Crypto(CryptoRecoveryToken { space: Handshake, offset: 0, length: 726 }) server | 2.195 INFO Lost crypto frame space=hs offset=0 length=726 server | 2.195 DEBUG [Server 910c1609ce23416a] Lost: Crypto(CryptoRecoveryToken { space: Handshake, offset: 0, length: 726 }) server | 2.195 INFO Lost crypto frame space=hs offset=0 length=726 server | 2.195 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(Initial | Handshake), paced: false } server | 2.195 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG CRYPTO for in offset=0, len=90 server | 2.195 DEBUG [Server 910c1609ce23416a] pn=56 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 137 server | TX -> Ack { largest_acknowledged: 115, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 90 } server | 2.195 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG CRYPTO for hs offset=0, len=726 server | 2.195 DEBUG [Server 910c1609ce23416a] pn=2 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 903 server | TX -> Crypto { offset: 0, len: 726 } server | 2.195 DEBUG packet_sent this=0x55f3df56dc50, pn=2, ps=766 server | 2.195 DEBUG Building Short dcid Some(CID [0]: ) server | 2.195 DEBUG [Server 910c1609ce23416a] pad Initial from 903 to PLPMTU 1232 server | 2.195 DEBUG packet_sent this=0x55f3df56dc50, pn=56, ps=466 server | 2.195 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(), paced: false } server | 2.195 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG Building Short dcid Some(CID [0]: ) server | 2.195 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(), paced: false } server | 2.195 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.195 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG Building Short dcid Some(CID [0]: ) server | 2.195 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.195 DEBUG [Server 910c1609ce23416a] delay duration 599.741919ms server | 2.195 DEBUG Setting timeout of 599.741919ms server | 2.195 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.195 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.195 DEBUG Building Short dcid Some(CID [0]: ) server | 2.195 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.195 DEBUG [Server 910c1609ce23416a] delay duration 599.697186ms server | 2.195 DEBUG Setting timeout of 599.697186ms client | Sending request: GET /brutal-slow-keyboard server | 2.795 DEBUG [Server 910c1609ce23416a] pn=116 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 1220 server | -> RX Crypto { offset: 0, len: 297 } server | -> RX Ping server | -> RX Padding { len: 880 } server | 2.795 DEBUG unmark 0-length range at 0 server | 2.795 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 223, tv_nsec: 739519364 } server | 2.795 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 223, tv_nsec: 739519364 } server | 2.795 DEBUG [recovery::Loss] PTO timer fired for Initial server | 2.795 DEBUG [recovery::Loss] PTO timer fired for Handshake server | 2.795 DEBUG [Server 910c1609ce23416a] Lost: Ack(AckToken { space: Initial, ranges: [PacketRange { largest: 115, smallest: 113, ack_needed: true }] }) server | 2.795 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 223, tv_nsec: 138675258 } server | 2.795 DEBUG [Server 910c1609ce23416a] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 90 }) server | 2.795 INFO Lost crypto frame space=in offset=0 length=90 server | 2.795 DEBUG [Server 910c1609ce23416a] Lost: Crypto(CryptoRecoveryToken { space: Handshake, offset: 0, length: 726 }) server | 2.795 INFO Lost crypto frame space=hs offset=0 length=726 server | 2.795 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(Initial | Handshake), paced: false } server | 2.795 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.795 DEBUG CRYPTO for in offset=0, len=90 server | 2.795 DEBUG [Server 910c1609ce23416a] pn=57 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 137 server | TX -> Ack { largest_acknowledged: 116, ack_delay: 0, first_ack_range: 3, ack_ranges: [], ecn_count: None } server | TX -> Crypto { offset: 0, len: 90 } server | 2.796 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.796 DEBUG CRYPTO for hs offset=0, len=726 server | 2.796 DEBUG [Server 910c1609ce23416a] pn=3 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 903 server | TX -> Crypto { offset: 0, len: 726 } server | 2.796 DEBUG packet_sent this=0x55f3df56dc50, pn=3, ps=766 server | 2.796 DEBUG Building Short dcid Some(CID [0]: ) server | 2.796 DEBUG [Server 910c1609ce23416a] pad Initial from 903 to PLPMTU 1232 server | 2.796 DEBUG packet_sent this=0x55f3df56dc50, pn=57, ps=466 server | 2.796 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(), paced: false } server | 2.796 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.796 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.796 DEBUG Building Short dcid Some(CID [0]: ) server | 2.796 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: Some(Initial), probe: EnumSet(), paced: false } server | 2.796 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.796 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.796 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.796 DEBUG Building Short dcid Some(CID [0]: ) server | 2.796 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.796 DEBUG [Server 910c1609ce23416a] delay duration 1.199682891s server | 2.796 DEBUG Setting timeout of 1.199682891s server | 2.796 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.796 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.796 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 2.796 DEBUG Building Short dcid Some(CID [0]: ) server | 2.796 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 2.796 DEBUG [Server 910c1609ce23416a] delay duration 1.199649058s server | 2.796 DEBUG Setting timeout of 1.199649058s server | 3.254 DEBUG [Server 910c1609ce23416a] Drop packet number space in server | 3.254 DEBUG [recovery::Loss] Reset loss recovery state for Initial server | 3.254 INFO [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975] discarding a packet without an RTT estimate; guessing RTT=1.50557862s server | 3.254 DEBUG [Server 910c1609ce23416a] pn=117 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 83 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 1, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | -> RX Crypto { offset: 0, len: 36 } server | 3.254 DEBUG [Server 910c1609ce23416a] Rx ACK space=hs, ranges=[0..=0] server | 3.254 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=0 server | 3.254 DEBUG on_packets_acked this=0x55f3df56dc50, limited=1, bytes_in_flight=2298, cwnd=12320, state=SlowStart, new_acked=766 server | 3.254 DEBUG Acked crypto frame space=hs offset=0 length=726 server | 3.254 DEBUG [Agent 0x55f3df4fcee0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 3.254 DEBUG [Server 910c1609ce23416a] TLS connection complete server | 3.254 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60975] Path validated Instant { tv_sec: 224, tv_nsec: 198233929 } server | 3.254 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 server | 3.254 DEBUG [Crypto] application read keys installed server | 3.254 DEBUG [Server 910c1609ce23416a] State change from Handshaking -> Connected server | 3.254 DEBUG [Server 910c1609ce23416a] State change from Connected -> Confirmed server | 3.254 DEBUG PMTUD started, PLPMTU is now 1280 server | 3.254 DEBUG PMTUD started with probe size 1380 server | 3.254 INFO [Server 910c1609ce23416a] Connection established server | 3.254 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 224, tv_nsec: 198233929 } server | 3.254 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.254 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 50111681c59cd49d6615) server | 3.255 DEBUG [Server 910c1609ce23416a] pn=4 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 42 server | TX -> Ack { largest_acknowledged: 117, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 3.255 DEBUG [Server 910c1609ce23416a] Drop packet number space hs server | 3.255 DEBUG [recovery::Loss] Reset loss recovery state for Handshake server | 3.255 DEBUG Building Short dcid Some(CID [0]: ) server | 3.255 DEBUG [Server 910c1609ce23416a] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [70, 132, 172, 84, 239, 77, 157, 13, 10, 3], stateless_reset_token: Token([15, 210, 53, 130, 237, 151, 106, 26, 221, 153, 133, 89, 200, 45, 199, 129]) } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [44, 93, 165, 39, 9, 252, 82, 234, 173, 252], stateless_reset_token: Token([105, 101, 198, 156, 102, 30, 190, 50, 212, 42, 190, 31, 253, 248, 3, 238]) } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [229, 30, 90, 213, 197, 254, 176, 197, 194, 51], stateless_reset_token: Token([206, 72, 201, 177, 33, 83, 163, 127, 177, 239, 67, 120, 182, 197, 183, 43]) } server | TX -> Padding { len: 1181 } server | 3.255 DEBUG packet_sent this=0x55f3df56dc50, pn=0, ps=1290 server | 3.255 DEBUG ECN probing: sent 1 probes server | 3.255 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.255 DEBUG Building Short dcid Some(CID [0]: ) server | 3.255 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.255 DEBUG [Server 910c1609ce23416a] delay duration 2.932586ms server | 3.255 DEBUG Setting timeout of 2.932586ms server | 3.256 DEBUG [Server 910c1609ce23416a] send session ticket 40620008910c1609ce23416a0104800075300404802000000504801000000604801000000704801000000801100901100b01140e01080f0a50111681c59cd49d6615110c00000001aaba8aca000000016ab200c0000000ff02de1a0243e820048000ffff686921 server | 3.256 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG Building Short dcid Some(CID [0]: ) server | 3.256 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG [Server 910c1609ce23416a] delay duration 1.795298ms server | 3.256 DEBUG Setting timeout of 1.795298ms server | 3.256 DEBUG [Server 910c1609ce23416a] pn=118 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 1252 server | -> RX Ping server | -> RX Padding { len: 1220 } server | 3.256 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 224, tv_nsec: 200036686 } server | 3.256 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 224, tv_nsec: 200036686 } server | 3.256 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG Building Short dcid Some(CID [0]: ) server | 3.256 DEBUG [Server 910c1609ce23416a] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 24 server | TX -> Ack { largest_acknowledged: 118, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None } server | 3.256 DEBUG ECN probing: sent 2 probes server | 3.256 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG Building Short dcid Some(CID [0]: ) server | 3.256 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG [Server 910c1609ce23416a] delay duration 3.053375ms server | 3.256 DEBUG Setting timeout of 3.053375ms server | 3.256 DEBUG [Server 910c1609ce23416a] pn=119 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 35 server | -> RX Stream { stream_id: 0, offset: 0, len: 0, fin: false } server | 3.256 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 224, tv_nsec: 220302101 } server | 3.256 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG Building Short dcid Some(CID [0]: ) server | 3.256 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG [Server 910c1609ce23416a] delay duration 2.973045ms server | 3.256 DEBUG Setting timeout of 2.973045ms server | 3.256 DEBUG [Server 910c1609ce23416a] pn=120 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 62 server | -> RX Stream { stream_id: 0, offset: 0, len: 27, fin: true } server | 3.256 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 224, tv_nsec: 200424008 } server | 3.256 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.256 DEBUG Building Short dcid Some(CID [0]: ) server | 3.256 DEBUG [Server 910c1609ce23416a] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 24 server | TX -> Ack { largest_acknowledged: 120, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | 3.256 DEBUG ECN probing: sent 3 probes server | 3.257 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.257 DEBUG Building Short dcid Some(CID [0]: ) server | 3.257 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.257 DEBUG [Server 910c1609ce23416a] delay duration 4.048113ms server | 3.257 DEBUG Setting timeout of 4.048113ms server | 3.257 DEBUG Path = 'brutal-slow-keyboard' server | 3.257 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.257 DEBUG Building Short dcid Some(CID [0]: ) server | 3.257 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.257 DEBUG [Server 910c1609ce23416a] delay duration 3.923823ms server | 3.257 DEBUG Setting timeout of 3.923823ms server | 3.262 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.262 DEBUG Building Short dcid Some(CID [0]: ) server | 3.262 DEBUG Sending PMTUD probe of size 1380, count 1 server | 3.262 DEBUG CRYPTO for ap offset=0, len=281 server | 3.262 DEBUG [Server 910c1609ce23416a] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true } server | TX -> Crypto { offset: 0, len: 281 } server | 3.262 DEBUG packet_sent this=0x55f3df56dc50, pn=3, ps=1332 server | 3.262 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.262 DEBUG Building Short dcid Some(CID [0]: ) server | 3.262 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.262 DEBUG ECN probing: sent 4 probes server | 3.262 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.262 DEBUG Building Short dcid Some(CID [0]: ) server | 3.262 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.262 DEBUG [Server 910c1609ce23416a] delay duration 80.127979ms server | 3.262 DEBUG Setting timeout of 80.127979ms server | 3.262 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.262 DEBUG Building Short dcid Some(CID [0]: ) server | 3.262 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.262 DEBUG [Server 910c1609ce23416a] delay duration 80.110437ms server | 3.262 DEBUG Setting timeout of 80.110437ms server | 3.343 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.343 DEBUG Building Short dcid Some(CID [0]: ) server | 3.343 DEBUG CRYPTO for ap offset=281, len=24 server | 3.343 DEBUG [Server 910c1609ce23416a] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 91 server | TX -> Crypto { offset: 281, len: 24 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 196, 98, 41, 111, 90, 103, 57, 145, 44, 23, 227, 117, 190, 167, 130, 16, 36, 153, 11, 0, 8, 42, 77, 164, 123, 170, 189, 177, 186, 145, 35, 246, 159, 67, 31, 129] } server | 3.343 DEBUG packet_sent this=0x55f3df56dc50, pn=4, ps=91 server | 3.343 DEBUG ECN probing: sent 5 probes server | 3.343 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.343 DEBUG Building Short dcid Some(CID [0]: ) server | 3.343 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.343 DEBUG [Server 910c1609ce23416a] delay duration 4.196298ms server | 3.343 DEBUG Setting timeout of 4.196298ms server | 3.343 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.343 DEBUG Building Short dcid Some(CID [0]: ) server | 3.343 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 3.343 DEBUG [Server 910c1609ce23416a] delay duration 4.165651ms server | 3.343 DEBUG Setting timeout of 4.165651ms server | 3.348 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.349 DEBUG Building Short dcid Some(CID [0]: ) server | 3.349 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.349 DEBUG [Server 910c1609ce23416a] delay duration 3.784619819s server | 3.349 DEBUG Setting timeout of 3.784619819s server | 3.349 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.349 DEBUG Building Short dcid Some(CID [0]: ) server | 3.349 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.349 DEBUG [Server 910c1609ce23416a] delay duration 3.784595113s server | 3.349 DEBUG Setting timeout of 3.784595113s server | 3.421 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 1 server | 3.421 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.421 DEBUG Building Short dcid Some(CID [0]: ) server | 3.421 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.421 DEBUG [Server 910c1609ce23416a] delay duration 3.711887599s server | 3.421 DEBUG Setting timeout of 3.711887599s server | 3.421 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.421 DEBUG Building Short dcid Some(CID [0]: ) server | 3.421 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.421 DEBUG [Server 910c1609ce23416a] delay duration 3.711829661s server | 3.421 DEBUG Setting timeout of 3.711829661s server | 3.722 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 2 server | 3.722 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.722 DEBUG Building Short dcid Some(CID [0]: ) server | 3.722 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.722 DEBUG [Server 910c1609ce23416a] delay duration 3.411206775s server | 3.722 DEBUG Setting timeout of 3.411206775s server | 3.722 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.722 DEBUG Building Short dcid Some(CID [0]: ) server | 3.722 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 3.722 DEBUG [Server 910c1609ce23416a] delay duration 3.411136775s server | 3.722 DEBUG Setting timeout of 3.411136775s client | brutal-slow-keyboard: Wrote 1024 bytes.(0 ms/0 ms/0 ms) client | brutal-slow-keyboard: Completed download! (0 ms) server | 4.323 DEBUG [Server ...] Dropped received packet: Decryption failure; Total: 3 server | 4.323 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.323 DEBUG Building Short dcid Some(CID [0]: ) server | 4.323 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.323 DEBUG [Server 910c1609ce23416a] delay duration 2.810323215s server | 4.323 DEBUG Setting timeout of 2.810323215s server | 4.323 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.323 DEBUG Building Short dcid Some(CID [0]: ) server | 4.323 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.323 DEBUG [Server 910c1609ce23416a] delay duration 2.810226375s server | 4.323 DEBUG Setting timeout of 2.810226375s server | 4.758 DEBUG [Server 910c1609ce23416a] pn=124 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 1332 server | -> RX Ping server | -> RX Padding { len: 1300 } server | 4.758 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 225, tv_nsec: 702363735 } server | 4.758 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 225, tv_nsec: 702363735 } server | 4.758 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.758 DEBUG Building Short dcid Some(CID [0]: ) server | 4.758 DEBUG [Server 910c1609ce23416a] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 26 server | TX -> Ack { largest_acknowledged: 124, ack_delay: 0, first_ack_range: 0, ack_ranges: [AckRange { gap: 2, range: 2 }], ecn_count: None } server | 4.758 DEBUG ECN probing: sent 6 probes server | 4.758 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.758 DEBUG Building Short dcid Some(CID [0]: ) server | 4.758 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.758 DEBUG [Server 910c1609ce23416a] delay duration 2.374738189s server | 4.758 DEBUG Setting timeout of 2.374738189s server | 4.758 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.758 DEBUG Building Short dcid Some(CID [0]: ) server | 4.758 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.758 DEBUG [Server 910c1609ce23416a] delay duration 2.374702041s server | 4.758 DEBUG Setting timeout of 2.374702041s server | 4.764 DEBUG [Server 910c1609ce23416a] pn=125 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 44 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } server | -> RX MaxData { maximum_data: 16778240 } server | 4.764 DEBUG [Server 910c1609ce23416a] Rx ACK space=ap, ranges=[0..=3] server | 4.764 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=3 server | 4.764 DEBUG on_packets_acked this=0x55f3df56dc50, limited=1, bytes_in_flight=91, cwnd=12320, state=SlowStart, new_acked=2622 server | 4.764 DEBUG PMTUD probe of size 1380 succeeded server | 4.764 DEBUG PMTUD started with probe size 1420 server | 4.764 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 4.764 DEBUG Acked crypto frame space=ap offset=0 length=281 server | 4.764 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 225, tv_nsec: 727750455 } server | 4.764 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 4.764 DEBUG Building Short dcid Some(CID [0]: ) server | 4.764 DEBUG Sending PMTUD probe of size 1420, count 1 server | 4.764 DEBUG [Server 910c1609ce23416a] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 } server | TX -> Padding { len: 1351 } server | 4.764 DEBUG packet_sent this=0x55f3df56dc50, pn=6, ps=1372 server | 4.764 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.764 DEBUG Building Short dcid Some(CID [0]: ) server | 4.764 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.764 DEBUG ECN probing: sent 7 probes server | 4.764 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.764 DEBUG Building Short dcid Some(CID [0]: ) server | 4.764 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.764 DEBUG [Server 910c1609ce23416a] delay duration 9.138217ms server | 4.764 DEBUG Setting timeout of 9.138217ms server | 4.764 DEBUG [Server 910c1609ce23416a] pn=126 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, NotEct) len 34 server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" } server | 4.764 INFO [Server 910c1609ce23416a] ConnectionClose received. Error code: Application(0) frame type 0 reason server | 4.764 DEBUG [Server 910c1609ce23416a] State change from Confirmed -> Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 235, tv_nsec: 393878326 } } server | 4.764 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:60975] Path validated Instant { tv_sec: 225, tv_nsec: 707943605 } server | 4.764 DEBUG [Server 910c1609ce23416a] output_dgram_on_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.764 DEBUG Building Short dcid Some(CID [0]: ) server | 4.764 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 225, tv_nsec: 707943605 } server | 4.764 DEBUG [Server 910c1609ce23416a] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60975 Tos(Cs0, Ect0) len 28 server | TX -> Ack { largest_acknowledged: 126, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: None } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 4.764 DEBUG ECN probing: sent 8 probes server | 4.764 DEBUG Setting timeout of 9.685746979s server | 4.764 DEBUG Setting timeout of 9.685735197s server | 4.844 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 235, tv_nsec: 393878326 } }; Total: 4 server | 4.844 DEBUG Setting timeout of 9.605450236s server | 4.844 DEBUG Setting timeout of 9.605410743s client | client | TARGET VHDCRZSQUMBGA2E VERSION ALPN client | ============================================ client | server4 -H------------- 0x00000001 hq-interop client | client | Total execution time: 4.524s client | server | 6.259 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 235, tv_nsec: 393878326 } }; Total: 5 server | 6.259 DEBUG Setting timeout of 8.190469373s server | 6.259 DEBUG Setting timeout of 8.19043025s server | 6.265 DEBUG [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplication(0)), timeout: Instant { tv_sec: 235, tv_nsec: 393878326 } }; Total: 6 server | 6.265 DEBUG Setting timeout of 8.184305012s server | 6.265 DEBUG Setting timeout of 8.184280155s client | Client complete. client | Script complete. 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 13:08:09,840 Using the client's key log file. 2025-12-13 13:08:09,849 2025-12-13 13:08:09,850 Using the client's key log file. 2025-12-13 13:08:09,850 Using the client's key log file. 2025-12-13 13:08:09,858 2025-12-13 13:08:09,859 Using the client's key log file. 2025-12-13 13:08:10,095 Check of downloaded files succeeded. 2025-12-13 13:08:11,063 Check of downloaded files succeeded.