2025-04-30 08:45:51,949 Generated random file: hvazerrnya of size: 1024 2025-04-30 08:45:51,949 Requests: https://server4:443/hvazerrnya 2025-04-30 08:45:52,010 2025-04-30 08:45:52,011 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_zfc8matm/ TESTCASE_SERVER=ecn TESTCASE_CLIENT=ecn WWW=/tmp/www_f35qu4ns/ DOWNLOADS=/tmp/download_dzy5gyg3/ SERVER_LOGS=/tmp/logs_server_lfiz20f8 CLIENT_LOGS=/tmp/logs_client_27sn6uum SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=privateoctopus/picoquic:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/hvazerrnya" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 08:46:04,009 Container sim Created Container client Recreate Container server 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... server | 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 | 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 client | Endpoint's IPv4 address is 193.167.0.100 server | Endpoint's IPv4 address is 193.167.100.100 client | Endpoint's IPv6 address is fd00:cafe:cafe::100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | Setup.sh completed client | Waiting for the simulator to start 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 ecn ']' server | + '[' -n /logs/qlog/ ']' server | + case "$ROLE" in server | + DB=/neqo/db server | + CERT=cert server | ++ mktemp server | + P12CERT=/tmp/tmp.51KaA6SQMP server | + mkdir -p /neqo/db server | + certutil -N -d sql:/neqo/db --empty-password client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.51KaA6SQMP server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.51KaA6SQMP -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 | 64:13:9a:5e:40:bf:c2:08:2a:20:6a:19:58:bd:f7:2e: server | 30:1e:d8:34 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:45:51 2025 server | Not After : Sat May 10 08:45:51 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:75:74:da:a3:48:f0:10:e9:b3:18:74:56:5f:e7:81: server | 82:0e:19:d2:8e:4c:37:04:66:60:9a:d0:b2:96:0d:7d: server | 20:54:d9:02:6a:7e:97:e4:b8:e2:d1:fd:8c:6b:b5:91: server | 0d:72:af:a6:fb:b6:58:46:b7:be:4a:bd:b3:5d:79:12: server | 23 server | Curve: ANSI X9.62 elliptic curve prime256v1 (aka secp256r1, NIST P-256) server | Signed Extensions: server | Name: Certificate Subject Alt Name server | DNS name: "server" server | DNS name: "server4" server | DNS name: "server6" server | DNS name: "server46" server | server | Name: Certificate Subject Key ID server | Data: server | 33:19:9e:71:98:55:d2:84:9c:cb:3e:9c:c7:a9:56:5a: server | 91:3e:5f:20 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | cd:79:ee:4f:e4:a6:59:9e:ce:92:b1:95:44:5a:f4:e3: server | 60:a1:f9:d8 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:21:00:92:38:1b:8e:5d:a0:19:5b:a4:67:a7: server | b1:a9:59:21:48:31:7f:ba:32:b2:09:91:e5:6d:65:a8: server | d4:78:02:95:04:02:20:22:67:ee:a4:0b:6e:1f:ca:d9: server | 97:08:98:8a:28:78:2f:25:2f:b9:d6:2b:11:c4:c2:e4: server | b4:f0:4b:91:93:1d:f3 server | Fingerprint (SHA-256): server | FF:D3:FD:AF:58:DB:08:B1:BD:98:CC:1A:53:D0:6D:6F:5F:8B:77:A4:BA:85:F5:2E:84:F6:4B:AF:C1:87:5C:F2 server | Fingerprint (SHA1): server | 28:B0:E3:FB:3E:57:CA:7B:CA:2B:49:7F:01:2E:21:03:1E:E2:2A:6A 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 | + '[' ecn = connectionmigration ']' server | + RUST_LOG=debug server | + RUST_BACKTRACE=1 server | + neqo-server --cc cubic --qns-test ecn --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.775 DEBUG [Server] Unsupported version: 57414954 server | 0.775 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:53866 IpTos(Cs0, NotEct) len 15 server | 0.775 DEBUG [Server] Unsupported version: 57414954 server | 0.775 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:53866 IpTos(Cs0, NotEct) len 15 server | 0.775 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) sim | server:443 is available after 1.030990548s server | 0.775 DEBUG [Server] Unsupported version: 57414954 server | 0.775 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:53866 IpTos(Cs0, NotEct) len 15 server | 0.775 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: ecn client | Starting picoquic client ... client | Parsing server name from first request: https://server4:443/hvazerrnya client | Server set to: server4 client | Requests: https://server4:443/hvazerrnya 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: <-:/hvazerrnya;> client | Max stream id bidir remote before start = 0 (0) client | Starting client connection. Version = 1, I-CID: af57db5db6757c8a client | Max stream id bidir remote after start = -4 (0) client | Waiting for packets. server | 0.996 DEBUG [Server] Handle initial server | 0.996 INFO AddressValidation: no token; accepting server | 0.996 INFO [Server] Accept connection CID [8]: af57db5db6757c8a server | 0.996 DEBUG Overwrite initial version Version1 ==> Version1 server | 0.997 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 0.997 INFO [Server ...] Received valid Initial packet with scid CID [8]: 01d366c5ad3b99be dcid CID [8]: af57db5db6757c8a server | 0.997 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=af57db5db6757c8a server | 0.997 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 0.997 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 0.997 DEBUG [Server af57db5db6757c8a] State change from Init -> WaitInitial server | 0.998 DEBUG [Server af57db5db6757c8a] pn=111751 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect1) len 1252 server | -> RX Ping server | -> RX Crypto { offset: 0, len: 285 } server | -> RX Padding { len: 916 } server | 0.998 DEBUG unmark 0-length range at 0 server | 0.998 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 428, tv_nsec: 421041329 } server | 0.998 DEBUG Read Ok(285) bytes server | 0.998 DEBUG 0-RTT: no token, no 0-RTT server | 0.998 DEBUG Read secret available for Handshake: SymKey [32]: 73f28f04ab2e5996c1f9c4650ea14ceb721d33fe1a31db958b8b517d8b3d7c44 server | 0.998 DEBUG Write secret available for Handshake: SymKey [32]: 9e8af7579c9ef367ff1da68c04f7558f4b102db74b4c3662475724b58820f7bc server | 0.998 DEBUG Writing transport parameters, msg=8 server | 0.999 DEBUG Read secret available for ApplicationData: SymKey [32]: d7065618b92c4257527dca43420a2c98758d516c4b7058a6959b10d9e929b2fb server | 0.999 DEBUG Write secret available for ApplicationData: SymKey [32]: 05b043c66d8a4c3e1befb29073d19c8871781a0b41efaaa2a8ac65bc3b4d0bf6 server | 0.999 DEBUG [Agent 0x5575b4c571d0] state -> InProgress server | 0.999 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 0.999 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 0.999 DEBUG [Crypto] Handshake keys installed server | 0.999 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 0.999 DEBUG [Crypto] Application write key installed server | 0.999 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 428, tv_nsec: 421041329 } server | 0.999 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:33445] Make permanent server | 0.999 DEBUG [unv-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445] set as primary path server | 0.999 DEBUG [Server af57db5db6757c8a] State change from WaitInitial -> Handshaking server | 0.999 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.999 DEBUG Building Initial dcid Some(CID [8]: 01d366c5ad3b99be) scid Some(CID [10]: 1dddf7c8acad9aa1a327) server | 0.999 DEBUG CRYPTO for in offset=0, len=123 server | 0.999 DEBUG [Server af57db5db6757c8a] pn=0 type=Initial pri-unv-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect0) len 183 server | TX -> Ack { largest_acknowledged: 111751, 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.999 DEBUG Building Handshake dcid Some(CID [8]: 01d366c5ad3b99be) scid Some(CID [10]: 1dddf7c8acad9aa1a327) server | 0.999 DEBUG CRYPTO for hs offset=0, len=722 server | 0.999 DEBUG [Server af57db5db6757c8a] pn=0 type=Handshake pri-unv-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect0) len 953 server | TX -> Crypto { offset: 0, len: 722 } server | 0.999 DEBUG packet_sent this=0x5575b4c56b40, pn=0, ps=770 server | 0.999 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 0.999 DEBUG [Server af57db5db6757c8a] pad Initial from 953 to PLPMTU 1232 server | 0.999 DEBUG packet_sent this=0x5575b4c56b40, pn=0, ps=462 server | 0.999 DEBUG ECN probing: sent 1 probes server | 0.999 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.999 DEBUG Building Initial dcid Some(CID [8]: 01d366c5ad3b99be) scid Some(CID [10]: 1dddf7c8acad9aa1a327) server | 0.999 DEBUG Building Handshake dcid Some(CID [8]: 01d366c5ad3b99be) scid Some(CID [10]: 1dddf7c8acad9aa1a327) server | 0.999 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 0.999 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.999 DEBUG [Server af57db5db6757c8a] delay duration 296.709516ms server | 0.999 DEBUG Setting timeout of 296.709516ms server | 0.999 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.999 DEBUG Building Initial dcid Some(CID [8]: 01d366c5ad3b99be) scid Some(CID [10]: 1dddf7c8acad9aa1a327) server | 0.999 DEBUG Building Handshake dcid Some(CID [8]: 01d366c5ad3b99be) scid Some(CID [10]: 1dddf7c8acad9aa1a327) server | 0.999 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 0.999 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 0.999 DEBUG [Server af57db5db6757c8a] delay duration 296.667758ms server | 0.999 DEBUG Setting timeout of 296.667758ms client | Client port (AF=2): 42370. client | Negotiated ALPN: hq-interop client | Almost ready! client | client | Connection established. Version = 1, I-CID: af57db5db6757c8a, verified: 1 client | Opening stream 0 to GET /hvazerrnya server | 1.031 DEBUG [Server af57db5db6757c8a] Drop packet number space in server | 1.031 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.031 INFO [pri-unv-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445] discarding a packet without an RTT estimate; guessing RTT=35.359425ms server | 1.031 DEBUG [Server af57db5db6757c8a] pn=0 type=Handshake pri-unv-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect1) len 94 server | -> RX Ack { largest_acknowledged: 0, ack_delay: 35, 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.031 DEBUG [Server af57db5db6757c8a] Rx ACK space=hs, ranges=[0..=0] server | 1.031 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.031 DEBUG on_packets_acked this=0x5575b4c56b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=770 server | 1.031 DEBUG Acked crypto frame space=hs offset=0 length=722 server | 1.031 DEBUG Read Ok(36) bytes server | 1.031 DEBUG [Agent 0x5575b4c571d0] 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.031 DEBUG [Server af57db5db6757c8a] TLS connection complete server | 1.031 DEBUG [pri-unv-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445] Path validated Instant { tv_sec: 428, tv_nsec: 456400754 } server | 1.031 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.031 DEBUG [Crypto] application read keys installed server | 1.031 DEBUG [Server af57db5db6757c8a] State change from Handshaking -> Connected server | 1.031 DEBUG [Server af57db5db6757c8a] State change from Connected -> Confirmed server | 1.031 DEBUG PMTUD started with probe size 1380 server | 1.031 INFO [Server af57db5db6757c8a] Connection established server | 1.031 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 428, tv_nsec: 456400754 } server | 1.031 DEBUG [Server af57db5db6757c8a] pn=0 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect1) len 311 server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [235, 210, 180, 199, 55, 187, 232, 176], stateless_reset_token: [243, 247, 174, 248, 147, 27, 86, 37, 211, 218, 121, 252, 173, 191, 159, 224] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [146, 228, 35, 209, 22, 140, 102, 122], stateless_reset_token: [19, 152, 65, 27, 15, 22, 214, 110, 43, 185, 77, 62, 175, 79, 167, 36] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [76, 88, 182, 169, 72, 38, 100, 18], stateless_reset_token: [32, 105, 10, 28, 114, 199, 151, 102, 82, 129, 216, 79, 186, 137, 47, 157] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [225, 76, 62, 146, 13, 51, 180, 243], stateless_reset_token: [182, 64, 226, 68, 68, 87, 213, 18, 167, 98, 214, 80, 235, 117, 105, 166] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [196, 231, 195, 62, 59, 120, 52, 218], stateless_reset_token: [111, 232, 113, 224, 237, 14, 201, 228, 46, 120, 55, 130, 150, 23, 193, 176] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [46, 169, 189, 245, 203, 104, 125, 116], stateless_reset_token: [74, 194, 121, 16, 101, 74, 15, 213, 230, 132, 203, 35, 134, 255, 232, 68] } server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [63, 25, 16, 166, 103, 238, 21, 41], stateless_reset_token: [132, 190, 80, 161, 138, 52, 178, 36, 171, 70, 71, 96, 176, 244, 159, 4] } server | -> RX Padding { len: 87 } server | 1.031 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 428, tv_nsec: 476400754 } server | 1.032 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.032 DEBUG Building Handshake dcid Some(CID [8]: 01d366c5ad3b99be) scid Some(CID [10]: 1dddf7c8acad9aa1a327) server | 1.032 DEBUG [Server af57db5db6757c8a] pn=1 type=Handshake pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 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.032 DEBUG [Server af57db5db6757c8a] Drop packet number space hs server | 1.032 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.032 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.032 DEBUG [Server af57db5db6757c8a] pn=0 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect0) len 1332 server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [122, 153, 198, 202, 78, 25, 5, 40, 101, 47], stateless_reset_token: [211, 74, 5, 156, 115, 143, 30, 161, 174, 21, 170, 123, 198, 143, 91, 218] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [116, 145, 154, 156, 198, 89, 169, 174, 150, 220], stateless_reset_token: [121, 121, 87, 50, 187, 125, 127, 240, 35, 118, 145, 189, 148, 91, 10, 2] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [17, 118, 242, 182, 168, 168, 127, 39, 171, 80], stateless_reset_token: [178, 203, 165, 2, 5, 67, 188, 27, 13, 73, 199, 97, 118, 96, 153, 13] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [41, 196, 212, 237, 223, 248, 213, 213, 1, 224], stateless_reset_token: [7, 123, 214, 70, 225, 42, 135, 188, 177, 48, 50, 26, 122, 16, 127, 246] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [31, 65, 229, 204, 179, 46, 179, 90, 150, 118], stateless_reset_token: [132, 103, 107, 242, 245, 154, 37, 52, 202, 137, 218, 210, 103, 17, 88, 107] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [17, 170, 56, 211, 163, 19, 183, 40, 192, 31], stateless_reset_token: [113, 112, 47, 147, 219, 208, 138, 241, 20, 145, 5, 136, 96, 37, 101, 64] } server | TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [65, 138, 101, 151, 111, 96, 58, 164, 81, 91], stateless_reset_token: [2, 50, 207, 44, 226, 151, 150, 93, 83, 8, 106, 32, 171, 240, 11, 165] } server | TX -> Padding { len: 1043 } server | 1.032 DEBUG packet_sent this=0x5575b4c56b40, pn=0, ps=1280 server | 1.032 DEBUG ECN probing: sent 2 probes server | 1.032 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.032 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.032 DEBUG [Server af57db5db6757c8a] pn=1 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1305 } server | 1.032 DEBUG packet_sent this=0x5575b4c56b40, pn=1, ps=1332 server | 1.032 DEBUG ECN probing: sent 3 probes server | 1.032 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG [Server af57db5db6757c8a] delay duration 1.340578ms server | 1.032 DEBUG Setting timeout of 1.340578ms server | 1.032 DEBUG [Server af57db5db6757c8a] pn=1 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect1) len 55 server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | -> RX Padding { len: 7 } server | 1.032 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 428, tv_nsec: 457068649 } server | 1.032 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.032 DEBUG [Server af57db5db6757c8a] pn=2 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 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.032 DEBUG ECN probing: sent 4 probes server | 1.032 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.032 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.032 DEBUG [Server af57db5db6757c8a] delay duration 1.291984ms server | 1.032 DEBUG Setting timeout of 1.291984ms server | 1.033 DEBUG [Server af57db5db6757c8a] send session ticket 40630008af57db5db6757c8a0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a1dddf7c8acad9aa1a327110c00000001ca0a0a9a000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.033 DEBUG Path = 'hvazerrnya' server | 1.033 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.033 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.033 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.033 DEBUG [Server af57db5db6757c8a] delay duration 337.431µs server | 1.033 DEBUG Setting timeout of 337.431µs server | 1.034 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.034 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.034 DEBUG CRYPTO for ap offset=0, len=174 server | 1.034 DEBUG [Server af57db5db6757c8a] pn=3 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 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.034 DEBUG packet_sent this=0x5575b4c56b40, pn=3, ps=1232 server | 1.034 DEBUG ECN probing: sent 5 probes server | 1.034 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG [Server af57db5db6757c8a] delay duration 909.531µs server | 1.034 DEBUG Setting timeout of 909.531µs server | 1.034 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.034 DEBUG [Server af57db5db6757c8a] delay duration 888.001µs server | 1.034 DEBUG Setting timeout of 888.001µs server | 1.036 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.036 DEBUG CRYPTO for ap offset=174, len=131 server | 1.036 DEBUG [Server af57db5db6757c8a] pn=4 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect0) len 207 server | TX -> Crypto { offset: 174, len: 131 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 200, 47, 241, 16, 68, 132, 2, 91, 58, 108, 62, 170, 84, 31, 221, 252, 120, 211, 100, 135, 168, 230, 249, 96, 31, 56, 177, 243, 234, 156, 118, 243, 243, 146, 64, 141] } server | 1.036 DEBUG packet_sent this=0x5575b4c56b40, pn=4, ps=207 server | 1.036 DEBUG ECN probing: sent 6 probes server | 1.036 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.036 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG [Server af57db5db6757c8a] delay duration 98.318692ms server | 1.036 DEBUG Setting timeout of 98.318692ms server | 1.036 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.036 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.036 DEBUG [Server af57db5db6757c8a] delay duration 98.297222ms server | 1.036 DEBUG Setting timeout of 98.297222ms client | Stream 0 ended after 1024 bytes client | All done, Closing the connection. server | 1.064 DEBUG [Server af57db5db6757c8a] pn=2 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect1) len 55 server | -> RX Ack { largest_acknowledged: 2, ack_delay: 3, 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.064 DEBUG [Server af57db5db6757c8a] Rx ACK space=ap, ranges=[0..=2] server | 1.064 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2 server | 1.064 DEBUG on_packets_acked this=0x5575b4c56b40, limited=1, bytes_in_flight=1439, cwnd=12320, state=SlowStart, new_acked=2612 server | 1.064 DEBUG PMTUD probe of size 1380 succeeded server | 1.064 DEBUG PMTUD started with probe size 1420 server | 1.064 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.064 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.064 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.064 DEBUG [Server af57db5db6757c8a] pn=5 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1345 } server | 1.064 DEBUG packet_sent this=0x5575b4c56b40, pn=5, ps=1372 server | 1.064 DEBUG ECN probing: sent 7 probes server | 1.064 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.064 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.064 DEBUG [Server af57db5db6757c8a] delay duration 87.47566ms server | 1.064 DEBUG Setting timeout of 87.47566ms server | 1.064 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG [Server af57db5db6757c8a] delay duration 87.443671ms server | 1.065 DEBUG Setting timeout of 87.443671ms server | 1.065 DEBUG [Server af57db5db6757c8a] pn=3 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 IpTos(Cs0, Ect1) len 39 server | -> RX Ack { largest_acknowledged: 3, ack_delay: 12, 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.065 DEBUG [Server af57db5db6757c8a] Rx ACK space=ap, ranges=[0..=3] server | 1.065 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=3 server | 1.065 DEBUG on_packets_acked this=0x5575b4c56b40, limited=1, bytes_in_flight=1579, cwnd=12320, state=SlowStart, new_acked=1232 server | 1.065 DEBUG Acked crypto frame space=ap offset=0 length=174 server | 1.065 INFO [Server af57db5db6757c8a] ConnectionClose received. Error code: Application(0) frame type 0 reason server | 1.065 DEBUG [Server af57db5db6757c8a] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 428, tv_nsec: 730773355 } } server | 1.065 DEBUG [pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445] Path validated Instant { tv_sec: 428, tv_nsec: 490714816 } server | 1.065 DEBUG [Server af57db5db6757c8a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.065 DEBUG Building Short dcid Some(CID [8]: 01d366c5ad3b99be) server | 1.065 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 428, tv_nsec: 490714816 } server | 1.066 DEBUG [Server af57db5db6757c8a] pn=6 type=Short pri-path:01d366c5ad3b99be [::]:443->[::ffff:193.167.0.100]:33445 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.066 DEBUG ECN probing: sent 8 probes server | 1.066 DEBUG Setting timeout of 239.936982ms server | 1.066 DEBUG Setting timeout of 239.92495ms 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 | Received 1024 bytes in 0.108480 seconds, 0.075516 Mbps. client | Sent 17 bytes in 0.108480 seconds, 0.001254 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 ... 4049 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: 5 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:46:04,115 Using the client's key log file. 2025-04-30 08:46:04,127 2025-04-30 08:46:04,127 Using the client's key log file. 2025-04-30 08:46:04,127 Using the client's key log file. 2025-04-30 08:46:04,138 2025-04-30 08:46:04,139 Using the client's key log file. 2025-04-30 08:46:04,426 Check of downloaded files succeeded. 2025-04-30 08:46:05,000 Using the client's key log file. 2025-04-30 08:46:05,284 Check of downloaded files succeeded. 2025-04-30 08:46:06,149 ECN.NONE 0 2025-04-30 08:46:06,149 ECN.ECT1 5 2025-04-30 08:46:06,149 ECN.ECT0 0 2025-04-30 08:46:06,149 ECN.CE 0 2025-04-30 08:46:06,448 ECN.NONE 0 2025-04-30 08:46:06,448 ECN.ECT1 0 2025-04-30 08:46:06,448 ECN.ECT0 8 2025-04-30 08:46:06,448 ECN.CE 0