2025-04-30 08:49:44,699 Generated random file: fvmihfojup of size: 1024 2025-04-30 08:49:44,699 Requests: https://server4:443/fvmihfojup 2025-04-30 08:49:44,759 2025-04-30 08:49:44,760 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_zqb4ijsx/ TESTCASE_SERVER=v2 TESTCASE_CLIENT=v2 WWW=/tmp/www_wsh1akds/ DOWNLOADS=/tmp/download_iqgdkr12/ SERVER_LOGS=/tmp/logs_server_m9yeepb5 CLIENT_LOGS=/tmp/logs_client_332e00t0 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=privateoctopus/picoquic:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/fvmihfojup" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:49:56,780 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 client | Setting up the simulation with setup.sh 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 client | Setup.sh completed client | Waiting for the simulator to start client | wait-for-it.sh: waiting 30 seconds for sim:57832 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.rfMghDuhfe server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.rfMghDuhfe server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.rfMghDuhfe -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 | 48:06:39:4d:50:88:4e:24:18:6a:b1:2c:8a:9b:66:ca: server | 5a:a9:c6:dc 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 08:49:44 2025 server | Not After : Sat May 10 08:49:44 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:ab:39:01:fc:1d:23:6b:12:4a:2c:d9:4c:fa:dc:69: server | 8a:7d:be:9f:45:71:9b:18:ff:cc:c8:7e:b1:a4:ee:57: server | b4:72:f0:94:6c:4e:1b:33:79:ce:be:d3:ec:5a:9d:b2: server | 05:4b:ff:e0:b8:73:3c:36:fc:c3:ca:b7:bc:9e:c6:69: server | 44 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 | ab:2d:e3:c1:42:e0:69:90:74:7e:65:28:67:12:e5:e7: server | b6:02:be:be server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 4d:fe:4f:a0:b6:91:d4:fa:d9:b3:3f:72:02:36:73:ed: server | 9c:fb:8e:67 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:46:02:21:00:c8:f4:0a:6c:16:34:7d:bc:77:58:7a: server | f0:cf:c2:bc:b9:fb:21:88:fb:79:12:22:53:1f:ce:26: server | 09:f3:7c:57:3b:02:21:00:df:69:e0:40:36:dd:36:4f: server | 8d:0c:31:5d:00:d1:50:13:0e:47:c4:83:4d:75:f8:4e: server | f0:3f:87:8c:85:6f:18:82 server | Fingerprint (SHA-256): server | 75:3E:6B:C0:BB:46:AF:3C:C6:34:90:6E:BC:A9:4A:A6:22:A5:CD:18:97:1C:99:B7:E9:84:AF:7A:B0:8C:EC:C9 server | Fingerprint (SHA1): server | 30:39:53:DC:E8:B7:98:E0:5E:80:4A:43:56:88:5D:A6:2F:DF:47:6C 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.762 DEBUG [Server] Unsupported version: 57414954 server | 0.762 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48710 IpTos(Cs0, NotEct) len 23 server | 0.762 DEBUG [Server] Unsupported version: 57414954 sim | server:443 is available after 1.020795243s server | 0.762 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48710 IpTos(Cs0, NotEct) len 23 server | 0.762 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.762 DEBUG [Server] Unsupported version: 57414954 server | 0.762 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:48710 IpTos(Cs0, NotEct) len 23 server | 0.762 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 eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | Starting picoquic client for test: v2 client | Starting picoquic client ... client | Parsing server name from first request: https://server4:443/fvmihfojup client | Server set to: server4 client | Requests: https://server4:443/fvmihfojup client | parsing as client | Starting Picoquic (v1.1.26.1) connection to server = server4, port = 443 client | No token file present. Will create one as . client | Testing scenario: <-:/fvmihfojup;> client | Max stream id bidir remote before start = 0 (0) client | Starting client connection. Version = 1, I-CID: c8cc19cfe90fa8dd client | Max stream id bidir remote after start = -4 (0) client | Waiting for packets. server | 0.973 DEBUG [Server] Handle initial server | 0.973 INFO AddressValidation: no token; accepting server | 0.973 INFO [Server] Accept connection CID [8]: c8cc19cfe90fa8dd server | 0.973 DEBUG Overwrite initial version Version1 ==> Version1 server | 0.974 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 0.974 INFO [Server ...] Received valid Initial packet with scid CID [8]: 76c66a42931de614 dcid CID [8]: c8cc19cfe90fa8dd server | 0.974 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=c8cc19cfe90fa8dd server | 0.974 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 0.974 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 0.974 DEBUG [Server c8cc19cfe90fa8dd] State change from Init -> WaitInitial server | 0.974 DEBUG [Server c8cc19cfe90fa8dd] pn=83014 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect1) len 1252 server | -> RX Ping server | -> RX Crypto { offset: 0, len: 300 } server | -> RX Padding { len: 901 } server | 0.974 DEBUG unmark 0-length range at 0 server | 0.974 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 661, tv_nsec: 178979134 } server | 0.974 DEBUG Read Ok(300) bytes server | 0.974 INFO Compatible upgrade Version1 ==> Version2 server | 0.974 DEBUG Overwrite initial version Version1 ==> Version2 server | 0.974 DEBUG 0-RTT: no token, no 0-RTT server | 0.975 DEBUG Read secret available for Handshake: SymKey [32]: eb9582c2e01bfcebf4f4c68c6e5e902295f8733e6a4bd68b6de23cb04efb90bf server | 0.975 DEBUG Write secret available for Handshake: SymKey [32]: 5ec69253199cbeea7991951d5f2983e8e2e03993233c0aaabc2e6bace1fea1bd server | 0.975 DEBUG Writing transport parameters, msg=8 server | 0.976 DEBUG Read secret available for ApplicationData: SymKey [32]: ead97c52fd262feb266ea34ccbeaf6c28a4965bb7bee38f1bc07ba92933372a7 server | 0.976 DEBUG Write secret available for ApplicationData: SymKey [32]: 94dae90502b332345440870bcbd167d1d9be7c728674791a6274436bca2aeb0d server | 0.976 DEBUG [Agent 0x5563995e91e0] state -> InProgress server | 0.976 DEBUG [CryptoStates] Creating initial cipher state v=Version2, role=Server dcid=c8cc19cfe90fa8dd server | 0.976 DEBUG Making Write Initial CryptoDxState, v=Version2 cipher=4865 server | 0.976 DEBUG Making Read Initial CryptoDxState, v=Version2 cipher=4865 server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] Compatible upgrade Version1 ==> Version2 server | 0.976 DEBUG Making Write Handshake CryptoDxState, v=Version2 cipher=4865 server | 0.976 DEBUG Making Read Handshake CryptoDxState, v=Version2 cipher=4865 server | 0.976 DEBUG [Crypto] Handshake keys installed server | 0.976 DEBUG Making Write ApplicationData CryptoDxState, v=Version2 cipher=4865 server | 0.976 DEBUG [Crypto] Application write key installed server | 0.976 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 661, tv_nsec: 178979134 } server | 0.976 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:52338] Make permanent server | 0.976 DEBUG [unv-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338] set as primary path server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] State change from WaitInitial -> Handshaking server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.976 DEBUG Building Initial dcid Some(CID [8]: 76c66a42931de614) scid Some(CID [10]: cb6665655cb8c20aa12e) server | 0.976 DEBUG CRYPTO for in offset=0, len=123 server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] pn=0 type=Initial pri-unv-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect0) len 183 server | TX -> Ack { largest_acknowledged: 83014, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) } server | TX -> Crypto { offset: 0, len: 123 } server | 0.976 DEBUG Building Handshake dcid Some(CID [8]: 76c66a42931de614) scid Some(CID [10]: cb6665655cb8c20aa12e) server | 0.976 DEBUG CRYPTO for hs offset=0, len=731 server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] pn=0 type=Handshake pri-unv-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect0) len 962 server | TX -> Crypto { offset: 0, len: 731 } server | 0.976 DEBUG packet_sent this=0x5563995e8b20, pn=0, ps=779 server | 0.976 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] pad Initial from 962 to PLPMTU 1232 server | 0.976 DEBUG packet_sent this=0x5563995e8b20, pn=0, ps=453 server | 0.976 DEBUG ECN probing: sent 1 probes server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.976 DEBUG Building Initial dcid Some(CID [8]: 76c66a42931de614) scid Some(CID [10]: cb6665655cb8c20aa12e) server | 0.976 DEBUG Building Handshake dcid Some(CID [8]: 76c66a42931de614) scid Some(CID [10]: cb6665655cb8c20aa12e) server | 0.976 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 0.976 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] delay duration 296.552147ms server | 0.976 DEBUG Setting timeout of 296.552147ms server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.976 DEBUG Building Initial dcid Some(CID [8]: 76c66a42931de614) scid Some(CID [10]: cb6665655cb8c20aa12e) server | 0.976 DEBUG Building Handshake dcid Some(CID [8]: 76c66a42931de614) scid Some(CID [10]: cb6665655cb8c20aa12e) server | 0.976 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 0.976 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.976 DEBUG [Server c8cc19cfe90fa8dd] delay duration 296.517272ms server | 0.976 DEBUG Setting timeout of 296.517272ms client | Client port (AF=2): 29388. client | Negotiated ALPN: hq-interop client | Almost ready! client | client | Connection established. Version = 6b3343cf, I-CID: c8cc19cfe90fa8dd, verified: 1 client | Opening stream 0 to GET /fvmihfojup server | 1.008 DEBUG [Server c8cc19cfe90fa8dd] Drop packet number space in server | 1.008 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.008 INFO [pri-unv-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338] discarding a packet without an RTT estimate; guessing RTT=35.535758ms server | 1.008 DEBUG [Server c8cc19cfe90fa8dd] pn=0 type=Handshake pri-unv-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect1) len 94 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 36, 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 | 1.008 DEBUG [Server c8cc19cfe90fa8dd] Rx ACK space=hs, ranges=[0..=0] server | 1.008 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.008 DEBUG on_packets_acked this=0x5563995e8b20, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=779 server | 1.008 DEBUG Acked crypto frame space=hs offset=0 length=731 server | 1.008 DEBUG Read Ok(36) bytes server | 1.008 DEBUG [Agent 0x5563995e91e0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 23, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) server | 1.008 DEBUG [Server c8cc19cfe90fa8dd] TLS connection complete server | 1.008 DEBUG [pri-unv-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338] Path validated Instant { tv_sec: 661, tv_nsec: 214514892 } server | 1.008 DEBUG Making Read ApplicationData CryptoDxState, v=Version2 cipher=4865 server | 1.008 DEBUG [Crypto] application read keys installed server | 1.008 DEBUG [Server c8cc19cfe90fa8dd] State change from Handshaking -> Connected server | 1.008 DEBUG [Server c8cc19cfe90fa8dd] State change from Connected -> Confirmed server | 1.008 DEBUG PMTUD started with probe size 1380 server | 1.008 INFO [Server c8cc19cfe90fa8dd] Connection established server | 1.008 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 661, tv_nsec: 214514892 } server | 1.008 DEBUG [Server c8cc19cfe90fa8dd] pn=0 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect1) len 311 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [157, 27, 228, 159, 24, 194, 70, 70], stateless_reset_token: [117, 14, 5, 226, 2, 122, 176, 171, 201, 165, 144, 62, 108, 221, 50, 43] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [21, 180, 57, 101, 183, 245, 146, 111], stateless_reset_token: [192, 254, 31, 135, 40, 22, 254, 78, 181, 183, 192, 134, 117, 138, 29, 228] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [111, 44, 145, 126, 169, 140, 91, 242], stateless_reset_token: [14, 185, 9, 0, 151, 57, 212, 251, 244, 182, 219, 132, 152, 178, 203, 48] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [70, 137, 175, 48, 123, 45, 65, 153], stateless_reset_token: [45, 192, 160, 140, 42, 226, 31, 110, 222, 230, 199, 240, 115, 230, 230, 95] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [125, 188, 218, 108, 46, 19, 14, 252], stateless_reset_token: [89, 87, 141, 71, 49, 169, 44, 148, 219, 224, 96, 246, 238, 231, 108, 227] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [218, 179, 45, 80, 39, 170, 176, 199], stateless_reset_token: [47, 87, 12, 123, 179, 182, 67, 196, 241, 168, 192, 218, 172, 233, 177, 57] } server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [218, 227, 1, 17, 60, 211, 185, 110], stateless_reset_token: [98, 163, 212, 168, 239, 231, 249, 108, 251, 59, 173, 243, 172, 250, 85, 102] } server | -> RX Padding { len: 87 } server | 1.009 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 661, tv_nsec: 234514892 } server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.009 DEBUG Building Handshake dcid Some(CID [8]: 76c66a42931de614) scid Some(CID [10]: cb6665655cb8c20aa12e) server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] pn=1 type=Handshake pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 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: 1, Ect0: 0, Ce: 0})) } server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] Drop packet number space hs server | 1.009 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.009 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] pn=0 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [230, 42, 242, 223, 5, 2, 116, 102, 37, 97], stateless_reset_token: [93, 255, 170, 239, 30, 82, 121, 160, 131, 216, 79, 172, 82, 70, 169, 146] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [255, 10, 47, 195, 178, 238, 110, 120, 171, 56], stateless_reset_token: [197, 168, 221, 76, 249, 253, 98, 195, 1, 98, 15, 33, 162, 236, 35, 221] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [72, 234, 14, 94, 117, 154, 191, 70, 36, 145], stateless_reset_token: [142, 136, 84, 199, 193, 209, 59, 71, 180, 215, 197, 169, 36, 83, 150, 165] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [188, 161, 163, 224, 35, 110, 129, 67, 88, 121], stateless_reset_token: [167, 163, 4, 80, 97, 91, 38, 22, 226, 40, 184, 123, 107, 160, 210, 15] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [10, 3, 242, 178, 149, 105, 98, 9, 34, 223], stateless_reset_token: [130, 0, 247, 244, 34, 195, 223, 74, 128, 183, 85, 35, 50, 106, 19, 48] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [99, 81, 255, 21, 9, 233, 175, 236, 85, 82], stateless_reset_token: [213, 59, 210, 203, 32, 72, 153, 243, 186, 247, 151, 116, 229, 235, 98, 223] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [216, 207, 240, 111, 113, 51, 226, 245, 88, 60], stateless_reset_token: [12, 34, 77, 213, 59, 76, 226, 25, 76, 94, 192, 220, 160, 242, 217, 0] } server | TX -> Padding { len: 1043 } server | 1.009 DEBUG packet_sent this=0x5563995e8b20, pn=0, ps=1280 server | 1.009 DEBUG ECN probing: sent 2 probes server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.009 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.009 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] pn=1 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.009 DEBUG packet_sent this=0x5563995e8b20, pn=1, ps=1332 server | 1.009 DEBUG ECN probing: sent 3 probes server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.009 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.009 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] delay duration 1.384565ms server | 1.009 DEBUG Setting timeout of 1.384565ms server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] pn=1 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect1) len 55 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | -> RX Padding { len: 7 } server | 1.009 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 661, tv_nsec: 215148174 } server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.009 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] pn=2 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 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: 2, Ect0: 0, Ce: 0})) } server | 1.009 DEBUG ECN probing: sent 4 probes server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.009 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.009 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.009 DEBUG [Server c8cc19cfe90fa8dd] delay duration 1.322276ms server | 1.009 DEBUG Setting timeout of 1.322276ms server | 1.010 DEBUG [Server c8cc19cfe90fa8dd] send session ticket 406b0008c8cc19cfe90fa8dd0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0acb6665655cb8c20aa12e11146b3343cf0a5a2a2a6b3343cf00000001ff00001d6ab200c0000000ff02de1a0243e8200100686921 server | 1.010 DEBUG Path = 'fvmihfojup' server | 1.010 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.010 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.010 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.010 DEBUG [Server c8cc19cfe90fa8dd] delay duration 250.646µs server | 1.010 DEBUG Setting timeout of 250.646µs server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.011 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.011 DEBUG CRYPTO for ap offset=0, len=174 server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] pn=3 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 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 | 1.011 DEBUG packet_sent this=0x5563995e8b20, pn=3, ps=1232 server | 1.011 DEBUG ECN probing: sent 5 probes server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.011 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.011 DEBUG CRYPTO for ap offset=174, len=147 server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] pn=4 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect0) len 223 server | TX -> Crypto { offset: 174, len: 147 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 95, 78, 111, 209, 41, 42, 247, 78, 238, 247, 101, 167, 206, 211, 145, 86, 141, 37, 148, 9, 93, 147, 149, 237, 21, 56, 159, 202, 129, 96, 238, 64, 131, 235, 99, 5] } server | 1.011 DEBUG packet_sent this=0x5563995e8b20, pn=4, ps=223 server | 1.011 DEBUG ECN probing: sent 6 probes server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.011 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.011 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] delay duration 1.097452ms server | 1.011 DEBUG Setting timeout of 1.097452ms server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.011 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.011 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.011 DEBUG [Server c8cc19cfe90fa8dd] delay duration 1.080019ms server | 1.011 DEBUG Setting timeout of 1.080019ms server | 1.013 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.013 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.013 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.013 DEBUG [Server c8cc19cfe90fa8dd] delay duration 96.652473ms server | 1.013 DEBUG Setting timeout of 96.652473ms server | 1.013 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.013 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.013 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.013 DEBUG [Server c8cc19cfe90fa8dd] delay duration 96.62404ms server | 1.013 DEBUG Setting timeout of 96.62404ms client | Stream 0 ended after 1024 bytes client | All done, Closing the connection. server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] pn=2 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect1) len 55 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 2, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | -> RX Padding { len: 19 } server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] Rx ACK space=ap, ranges=[0..=2] server | 1.042 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 1.042 DEBUG on_packets_acked this=0x5563995e8b20, limited=1, bytes_in_flight=1455, cwnd=12320, state=SlowStart, new_acked=2612 server | 1.042 DEBUG PMTUD probe of size 1380 succeeded server | 1.042 DEBUG PMTUD started with probe size 1420 server | 1.042 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.042 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] pn=5 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1345 } server | 1.042 DEBUG packet_sent this=0x5563995e8b20, pn=5, ps=1372 server | 1.042 DEBUG ECN probing: sent 7 probes server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] delay duration 87.462247ms server | 1.042 DEBUG Setting timeout of 87.462247ms server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.042 DEBUG [Server c8cc19cfe90fa8dd] delay duration 87.434776ms server | 1.042 DEBUG Setting timeout of 87.434776ms server | 1.043 DEBUG [Server c8cc19cfe90fa8dd] pn=3 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 IpTos(Cs0, Ect1) len 39 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 14, 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 | 1.043 DEBUG [Server c8cc19cfe90fa8dd] Rx ACK space=ap, ranges=[0..=3] server | 1.043 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=3 server | 1.043 DEBUG on_packets_acked this=0x5563995e8b20, limited=1, bytes_in_flight=1595, cwnd=12320, state=SlowStart, new_acked=1232 server | 1.043 DEBUG Acked crypto frame space=ap offset=0 length=174 server | 1.043 INFO [Server c8cc19cfe90fa8dd] ConnectionClose received. Error code: Application(0) frame type 0 reason server | 1.043 DEBUG [Server c8cc19cfe90fa8dd] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 661, tv_nsec: 489047055 } } server | 1.043 DEBUG [pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338] Path validated Instant { tv_sec: 661, tv_nsec: 249348738 } server | 1.043 DEBUG [Server c8cc19cfe90fa8dd] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.043 DEBUG Building Short dcid Some(CID [8]: 76c66a42931de614) server | 1.043 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 661, tv_nsec: 249348738 } server | 1.043 DEBUG [Server c8cc19cfe90fa8dd] pn=6 type=Short pri-path:76c66a42931de614 [::]:443->[::ffff:193.167.0.100]:52338 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: 4, Ect0: 0, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" } server | 1.043 DEBUG ECN probing: sent 8 probes server | 1.043 DEBUG Setting timeout of 239.585186ms server | 1.043 DEBUG Setting timeout of 239.571651ms client | Received a request to close the connection. client | The connection is closed! client | Address Discovery mode: 0 / 0 (0:0) client | Quic Bit was greased by the client. client | Quic Bit was greased by the server. client | ECN was received (ect0: 6, ect1: 0, ce: 0). client | ECN was acknowledged (ect0: 0, ect1: 2, ce: 0). client | Successfully negotiated version 0x6b3343cf. client | Received 1024 bytes in 0.109213 seconds, 0.075009 Mbps. client | Sent 17 bytes in 0.109213 seconds, 0.001245 Mbps. client | max_data_local: 1048576 client | max_stream_data_local: 2097152 client | max_data_remote: 4611686018427387903 client | max_stream_data_remote: 1048576 client | ack_delay_remote: 1000 ... 4129 client | max_ack_gap_remote: 2 client | ack_delay_local: 25000 ... 25000 client | max_ack_gap_local: 2 client | max_mtu_sent: 1252 client | max_mtu_received: 1372 client | System call duration max: 6 client | System call duration smoothed: 0 client | System call duration deviation: 0 client | Client exit with code = 0 client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 08:49:56,877 Using the client's key log file. 2025-04-30 08:49:56,888 2025-04-30 08:49:56,889 Using the client's key log file. 2025-04-30 08:49:56,889 Using the client's key log file. 2025-04-30 08:49:56,899 2025-04-30 08:49:56,899 Using the client's key log file. 2025-04-30 08:49:58,032 Check of downloaded files succeeded.