2025-04-30 09:17:36,291 Generated random file: hkuebrxtxa of size: 1024 2025-04-30 09:17:36,291 Requests: https://server4:443/hkuebrxtxa 2025-04-30 09:17:36,352 2025-04-30 09:17:36,352 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_j0_bzigb/ TESTCASE_SERVER=v2 TESTCASE_CLIENT=v2 WWW=/tmp/www_k61acodv/ DOWNLOADS=/tmp/download_b8jb24gq/ SERVER_LOGS=/tmp/logs_server_xh8oqg19 CLIENT_LOGS=/tmp/logs_client_nc00bszj SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=stammw/quinn-interop:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/hkuebrxtxa" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 09:17:51,679 Container sim Created 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 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 v2 ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.OduJSj0b2P server | + mkdir -p /neqo/db 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 server | + certutil -N -d sql:/neqo/db --empty-password client | Endpoint's IPv4 address is 193.167.0.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 client | Executing client server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.OduJSj0b2P 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.OduJSj0b2P -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 | 5c:4e:53:08:01:18:49:91:84:4f:0e:fd:2b:02:c8:ad: server | 01:64:84:d6 server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Issuer: "O=interop runner Root Certificate Authority" server | Validity: server | Not Before: Wed Apr 30 09:17:36 2025 server | Not After : Sat May 10 09:17:36 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:d8:52:43:5b:5a:57:74:ed:a1:de:e5:31:46:a9:e3: server | 94:6b:f7:fc:db:5f:7e:51:a3:c6:67:49:cb:f4:76:b6: server | 03:8c:4f:cf:08:02:6d:98:ba:20:b3:82:97:4f:83:0a: server | fd:ff:c3:c3:11:20:82:c4:5d:6f:9f:6d:02:7d:4b:ab: 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 | 5a:3f:a8:3d:bf:96:18:67:a6:c9:1a:2b:e3:62:02:d5: server | 96:fe:2d:2e server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 03:d6:05:82:76:fb:18:01:4b:25:3a:28:39:29:8b:36: server | 7f:31:7f:c0 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:46:02:21:00:c0:fd:57:3b:2a:fc:4e:58:18:9a:bc: server | c0:84:3a:da:f1:a5:98:42:a6:53:45:f5:c5:16:0c:86: server | a9:56:3d:6e:7a:02:21:00:c1:d8:1a:e8:be:ae:38:2e: server | 5f:2d:e1:bc:8b:d4:3f:96:ba:e1:3e:59:35:9d:a9:ba: server | 18:b5:30:6b:33:bd:43:89 server | Fingerprint (SHA-256): server | AC:42:E6:FA:CE:29:EF:FE:CF:A5:33:54:CA:B7:66:9E:5B:74:CA:BE:43:BA:A5:86:5C:0B:E7:BB:3C:5E:AB:BA server | Fingerprint (SHA1): server | DB:F1:8E:A7:94:C6:78:C0:98:17:50:93:B6:CC:F8:61:2D:29:1E:79 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 | + '[' v2 = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test v2 --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 212992 server | 0.002 DEBUG Default socket receive buffer size is 1048576, not changing server | 0.002 INFO Server waiting for connection on: [::]:443 server | 0.785 DEBUG [Server] Unsupported version: 57414954 server | 0.785 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:50631 IpTos(Cs0, NotEct) len 23 sim | server:443 is available after 1.038044233s server | 0.785 DEBUG [Server] Unsupported version: 57414954 server | 0.785 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:50631 IpTos(Cs0, NotEct) len 23 server | 0.785 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.785 DEBUG [Server] Unsupported version: 57414954 server | 0.785 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:50631 IpTos(Cs0, NotEct) len 23 server | 0.785 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0tcpdump: , link-type EN10MB (Ethernet)listening on eth1, snapshot length 262144 bytes sim | , link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds server | 4.004 DEBUG [Server] Handle initial server | 4.004 INFO AddressValidation: no token; accepting server | 4.004 INFO [Server] Accept connection CID [20]: a87d6e5dfff97e35a655c1be442b6103b72fd7c9 server | 4.004 DEBUG Overwrite initial version Version1 ==> Version1 server | 4.005 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 4.005 INFO [Server ...] Received valid Initial packet with scid CID [8]: c644e701cc2b77c6 dcid CID [20]: a87d6e5dfff97e35a655c1be442b6103b72fd7c9 server | 4.005 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=a87d6e5dfff97e35a655c1be442b6103b72fd7c9 server | 4.005 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 4.006 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 4.006 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] State change from Init -> WaitInitial server | 4.006 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 1200 server | -> RX Crypto { offset: 0, len: 286 } server | -> RX Padding { len: 855 } server | 4.006 DEBUG Read Ok(286) bytes server | 4.006 DEBUG 0-RTT: no token, no 0-RTT server | 4.006 DEBUG Read secret available for Handshake: SymKey [32]: 6230f1285266633443bba0ea6a539d141bb58109a35aa2a404d7d1a7a1fbafa6 server | 4.006 DEBUG Write secret available for Handshake: SymKey [32]: c63563379c1c3191ce1544e08e754f1ceca2d7c6e3ad7c87de2a7941e91ef875 server | 4.006 DEBUG Writing transport parameters, msg=8 server | 4.006 DEBUG Read secret available for ApplicationData: SymKey [32]: f33dfebedd0c71b72ba1c691d7284917fb2a4d092ccd63f2240b0a285647f3f3 server | 4.006 DEBUG Write secret available for ApplicationData: SymKey [32]: 41ad0659ead02732c8ace92a01b0fc82b1aa4c5531c5530fbfb8ece33e3f7c93 server | 4.006 DEBUG [Agent 0x55da553721e0] state -> InProgress server | 4.006 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 4.006 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 4.007 DEBUG [Crypto] Handshake keys installed server | 4.007 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 4.007 DEBUG [Crypto] Application write key installed server | 4.007 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 588, tv_nsec: 144450834 } server | 4.007 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:44691] Make permanent server | 4.007 DEBUG [unv-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691] set as primary path server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] State change from WaitInitial -> Handshaking server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.007 DEBUG Building Initial dcid Some(CID [8]: c644e701cc2b77c6) scid Some(CID [10]: 4e2dbde33359a148a09f) server | 4.007 DEBUG CRYPTO for in offset=0, len=90 server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=0 type=Initial pri-unv-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 147 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | TX -> Crypto { offset: 0, len: 90 } server | 4.007 DEBUG Building Handshake dcid Some(CID [8]: c644e701cc2b77c6) scid Some(CID [10]: 4e2dbde33359a148a09f) server | 4.007 DEBUG CRYPTO for hs offset=0, len=744 server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=0 type=Handshake pri-unv-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 939 server | TX -> Crypto { offset: 0, len: 744 } server | 4.007 DEBUG packet_sent this=0x55da55371b20, pn=0, ps=792 server | 4.007 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pad Initial from 939 to PLPMTU 1232 server | 4.007 DEBUG packet_sent this=0x55da55371b20, pn=0, ps=440 server | 4.007 DEBUG ECN probing: sent 1 probes server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.007 DEBUG Building Initial dcid Some(CID [8]: c644e701cc2b77c6) scid Some(CID [10]: 4e2dbde33359a148a09f) server | 4.007 DEBUG Building Handshake dcid Some(CID [8]: c644e701cc2b77c6) scid Some(CID [10]: 4e2dbde33359a148a09f) server | 4.007 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.007 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 297.125365ms server | 4.007 DEBUG Setting timeout of 297.125365ms server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.007 DEBUG Building Initial dcid Some(CID [8]: c644e701cc2b77c6) scid Some(CID [10]: 4e2dbde33359a148a09f) server | 4.007 DEBUG Building Handshake dcid Some(CID [8]: c644e701cc2b77c6) scid Some(CID [10]: 4e2dbde33359a148a09f) server | 4.007 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.007 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.007 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 297.093646ms server | 4.007 DEBUG Setting timeout of 297.093646ms server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=1 type=Initial pri-unv-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 53 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 43, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] Rx ACK space=in, ranges=[0..=0] server | 4.040 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 4.040 DEBUG on_packets_acked this=0x55da55371b20, limited=1, bytes_in_flight=792, cwnd=12320, state=SlowStart, new_acked=440 server | 4.040 DEBUG Acked crypto frame space=in offset=0 length=90 server | 4.040 DEBUG [pri-unv-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691] Path validated Instant { tv_sec: 588, tv_nsec: 180230963 } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] Drop packet number space in server | 4.040 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=0 type=Handshake pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 1147 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 43, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | -> RX Crypto { offset: 0, len: 36 } server | -> RX Padding { len: 1056 } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] Rx ACK space=hs, ranges=[0..=0] server | 4.040 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 4.040 DEBUG on_packets_acked this=0x55da55371b20, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=792 server | 4.040 DEBUG Acked crypto frame space=hs offset=0 length=744 server | 4.040 DEBUG Read Ok(36) bytes server | 4.040 DEBUG [Agent 0x55da553721e0] 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 | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] TLS connection complete server | 4.040 DEBUG [pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691] Path validated Instant { tv_sec: 588, tv_nsec: 180230963 } server | 4.040 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 4.040 DEBUG [Crypto] application read keys installed server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] State change from Handshaking -> Connected server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] State change from Connected -> Confirmed server | 4.040 DEBUG PMTUD started with probe size 1380 server | 4.040 INFO [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] Connection established server | 4.040 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 588, tv_nsec: 180230963 } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.040 DEBUG Building Handshake dcid Some(CID [8]: c644e701cc2b77c6) scid Some(CID [10]: 4e2dbde33359a148a09f) server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=1 type=Handshake pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 52 server | TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] Drop packet number space hs server | 4.040 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 4.040 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=0 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [198, 23, 8, 146, 218, 163, 79, 170, 162, 171], stateless_reset_token: [180, 7, 141, 159, 52, 100, 144, 33, 147, 215, 171, 45, 74, 61, 229, 222] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [144, 132, 23, 117, 186, 171, 101, 243, 99, 42], stateless_reset_token: [55, 185, 230, 90, 85, 245, 223, 51, 190, 79, 42, 147, 126, 231, 153, 154] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [10, 32, 96, 111, 26, 198, 95, 82, 186, 169], stateless_reset_token: [118, 57, 158, 222, 103, 200, 134, 216, 254, 122, 161, 89, 64, 74, 179, 156] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [114, 30, 156, 40, 106, 154, 20, 238, 87, 228], stateless_reset_token: [221, 197, 65, 158, 189, 42, 21, 96, 169, 239, 46, 245, 233, 139, 224, 122] } server | TX -> Padding { len: 1133 } server | 4.040 DEBUG packet_sent this=0x55da55371b20, pn=0, ps=1280 server | 4.040 DEBUG ECN probing: sent 2 probes server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.040 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.040 DEBUG Sending PMTUD probe of size 1380, count 1 server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=1 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 4.040 DEBUG packet_sent this=0x55da55371b20, pn=1, ps=1332 server | 4.040 DEBUG ECN probing: sent 3 probes server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.040 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.040 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 1.305906ms server | 4.040 DEBUG Setting timeout of 1.305906ms server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=0 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 224 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [133, 115, 131, 209, 232, 149, 183, 243], stateless_reset_token: [97, 86, 239, 190, 53, 54, 117, 59, 253, 155, 102, 195, 65, 26, 30, 48] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [117, 159, 186, 147, 253, 151, 144, 211], stateless_reset_token: [119, 98, 153, 249, 209, 219, 105, 188, 41, 76, 171, 116, 231, 34, 38, 78] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [9, 184, 4, 144, 109, 121, 74, 28], stateless_reset_token: [104, 164, 0, 195, 196, 131, 108, 243, 149, 193, 18, 192, 126, 75, 59, 54] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [129, 2, 129, 3, 118, 210, 138, 209], stateless_reset_token: [47, 37, 149, 14, 250, 163, 3, 116, 170, 64, 225, 42, 247, 237, 103, 251] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [208, 227, 100, 144, 188, 195, 28, 42], stateless_reset_token: [244, 136, 195, 22, 117, 7, 129, 112, 182, 72, 190, 72, 98, 239, 14, 76] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [80, 242, 211, 198, 119, 182, 143, 76], stateless_reset_token: [98, 148, 119, 235, 75, 64, 191, 39, 21, 135, 118, 194, 248, 87, 17, 148] } server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [33, 97, 203, 118, 16, 172, 0, 72], stateless_reset_token: [140, 45, 116, 237, 102, 231, 44, 30, 236, 2, 52, 224, 162, 228, 242, 200] } server | 4.040 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 588, tv_nsec: 200955172 } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.040 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.040 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 1.280098ms server | 4.040 DEBUG Setting timeout of 1.280098ms server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=1 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 48 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | 4.040 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 588, tv_nsec: 181052113 } server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.040 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.040 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=2 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 34 server | TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } server | 4.041 DEBUG ECN probing: sent 4 probes server | 4.041 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.041 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.041 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.041 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 1.166162ms server | 4.041 DEBUG Setting timeout of 1.166162ms server | 4.041 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] send session ticket 40770014a87d6e5dfff97e35a655c1be442b6103b72fd7c90104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a4e2dbde33359a148a09f1114000000013a7aaa9a6b3343cf00000001ff00001d6ab200c0000000ff02de1a0243e8200100686921 server | 4.041 DEBUG Path = 'hkuebrxtxa' server | 4.042 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.042 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.042 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.042 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 170.698µs server | 4.042 DEBUG Setting timeout of 170.698µs server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.043 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.043 DEBUG CRYPTO for ap offset=0, len=174 server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=3 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true } server | TX -> Crypto { offset: 0, len: 174 } server | 4.043 DEBUG packet_sent this=0x55da55371b20, pn=3, ps=1232 server | 4.043 DEBUG ECN probing: sent 5 probes server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.043 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.043 DEBUG CRYPTO for ap offset=174, len=163 server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=4 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 239 server | TX -> Crypto { offset: 174, len: 163 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 28, 104, 121, 106, 109, 84, 49, 221, 229, 227, 230, 174, 75, 245, 69, 24, 142, 112, 201, 252, 39, 228, 11, 99, 148, 173, 97, 15, 220, 244, 65, 53, 143, 24, 228, 122] } server | 4.043 DEBUG packet_sent this=0x55da55371b20, pn=4, ps=239 server | 4.043 DEBUG ECN probing: sent 6 probes server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.043 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.043 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 1.060104ms server | 4.043 DEBUG Setting timeout of 1.060104ms server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.043 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.043 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 4.043 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 1.038132ms server | 4.043 DEBUG Setting timeout of 1.038132ms server | 4.045 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.045 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.045 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 112.266834ms server | 4.045 DEBUG Setting timeout of 112.266834ms server | 4.045 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.045 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 4.045 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 112.245694ms server | 4.045 DEBUG Setting timeout of 112.245694ms server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=2 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 36 server | -> RX Ack { largest_acknowledged: 1, ack_delay: 6, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] Rx ACK space=ap, ranges=[0..=1] server | 4.074 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 server | 4.074 DEBUG on_packets_acked this=0x55da55371b20, limited=1, bytes_in_flight=1471, cwnd=12320, state=SlowStart, new_acked=2612 server | 4.074 DEBUG PMTUD probe of size 1380 succeeded server | 4.074 DEBUG PMTUD started with probe size 1420 server | 4.074 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 4.074 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.074 DEBUG Sending PMTUD probe of size 1420, count 1 server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=5 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1345 } server | 4.074 DEBUG packet_sent this=0x55da55371b20, pn=5, ps=1372 server | 4.074 DEBUG ECN probing: sent 7 probes server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 4.074 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.074 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 103.078533ms server | 4.074 DEBUG Setting timeout of 103.078533ms server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 4.074 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.074 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 4.074 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] delay duration 103.045051ms server | 4.074 DEBUG Setting timeout of 103.045051ms server | 4.075 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=3 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 39 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 16, first_ack_range: 3, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } server | -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" } server | 4.075 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] Rx ACK space=ap, ranges=[0..=3] server | 4.075 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=3 server | 4.075 DEBUG on_packets_acked this=0x55da55371b20, limited=1, bytes_in_flight=1611, cwnd=12320, state=SlowStart, new_acked=1232 server | 4.075 DEBUG Acked crypto frame space=ap offset=0 length=174 server | 4.075 INFO [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] ConnectionClose received. Error code: Application(0) frame type 0 reason server | 4.075 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 588, tv_nsec: 501921379 } } server | 4.075 DEBUG [pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691] Path validated Instant { tv_sec: 588, tv_nsec: 215220709 } server | 4.075 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 4.075 DEBUG Building Short dcid Some(CID [8]: c644e701cc2b77c6) server | 4.075 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 588, tv_nsec: 215220709 } server | 4.075 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] pn=6 type=Short pri-path:c644e701cc2b77c6 [::]:443->[::ffff:193.167.0.100]:44691 IpTos(Cs0, Ect0) len 38 server | TX -> 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 | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 4.075 DEBUG ECN probing: sent 8 probes server | 4.075 DEBUG Setting timeout of 286.585967ms server | 4.075 WARN [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 588, tv_nsec: 501921379 } }; Total: 1 server | 4.075 DEBUG Setting timeout of 286.575347ms server | 4.075 DEBUG Setting timeout of 286.564336ms server | 4.105 WARN [Server ...] Dropped received packet: State Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 588, tv_nsec: 501921379 } }; Total: 2 server | 4.105 DEBUG Setting timeout of 255.989182ms server | 4.105 DEBUG Setting timeout of 255.96671ms server | 4.363 DEBUG [Server a87d6e5dfff97e35a655c1be442b6103b72fd7c9] State change from Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 588, tv_nsec: 501921379 } } -> Closed(Transport(PeerApplicationError(0))) server | 4.363 INFO Closing timer expired client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 09:17:51,782 Using the client's key log file. 2025-04-30 09:17:51,793 2025-04-30 09:17:51,793 Using the client's key log file. 2025-04-30 09:17:51,793 Using the client's key log file. 2025-04-30 09:17:51,803 2025-04-30 09:17:51,804 Using the client's key log file. 2025-04-30 09:17:52,369 Wrong version in server Initial. Expected 0x6b3343cf, got {'0x1'}