2025-04-30 10:25:30,747 Generated random file: fdmwphtjwo of size: 1024 2025-04-30 10:25:30,747 Requests: https://server4:443/fdmwphtjwo 2025-04-30 10:25:30,814 2025-04-30 10:25:30,815 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_ev1lbhvf/ TESTCASE_SERVER=ecn TESTCASE_CLIENT=ecn WWW=/tmp/www_122quiyi/ DOWNLOADS=/tmp/download_v3fe94o5/ SERVER_LOGS=/tmp/logs_server_lkkh3hv_ CLIENT_LOGS=/tmp/logs_client_53b10ogg SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/ngtcp2/ngtcp2-interop:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/fdmwphtjwo" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 10:25:42,894 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 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 | 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 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 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.SfiJXRHOy2 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.SfiJXRHOy2 server | Warning: output encryption option -nodes ignored with -export server | + pk12util -d sql:/neqo/db -i /tmp/tmp.SfiJXRHOy2 -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 | 2a:89:d5:70:f3:c8:c2:8f:40:1a:56:69:08:62:77:93: server | 5b:ef:89:b9 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 10:25:30 2025 server | Not After : Sat May 10 10:25:30 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:5a:9c:90:78:cc:34:5d:d6:07:71:a4:1c:23:6e:53: server | 63:17:db:c6:40:6b:03:24:38:15:ee:cc:93:f5:93:f2: server | 5a:6a:91:58:c0:29:d4:9b:46:03:dd:fb:b1:a4:62:dc: server | 27:a8:69:ee:19:3f:35:dd:ee:9c:f8:08:2f:1e:5c:3a: server | 98 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 | 1c:43:a4:50:a4:80:fe:9e:ce:60:ed:bd:4c:1c:cf:cf: server | 7b:14:1d:68 server | server | Name: Certificate Authority Key Identifier server | Key ID: server | 5a:d1:66:8f:d8:18:ac:ea:fc:93:f5:77:84:05:fc:0d: server | 87:f3:b1:27 server | server | Signature Algorithm: X9.62 ECDSA signature with SHA256 server | Signature: server | 30:45:02:20:72:27:08:01:6e:29:13:c8:b0:8c:b6:ef: server | c7:e6:da:bc:77:b7:9d:69:5b:9c:b2:c1:48:3b:2f:e9: server | fc:7a:61:a6:02:21:00:b3:f7:4e:c9:82:37:8f:64:6c: server | bd:49:f3:35:c7:26:f5:4d:35:46:7c:47:71:68:fd:66: server | 85:6c:54:d4:75:84:38 server | Fingerprint (SHA-256): server | 70:A4:40:B8:C9:46:17:27:13:CD:63:34:30:53:42:76:76:01:DB:68:02:2C:A9:D9:86:49:1C:D8:1E:99:94:76 server | Fingerprint (SHA1): server | 9D:37:E4:AE:CA:D4:D8:8F:FE:04:FA:7D:D9:DA:68:05:AA:F1:DE:2D 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.753 DEBUG [Server] Unsupported version: 57414954 server | 0.753 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59519 IpTos(Cs0, NotEct) len 15 sim | server:443 is available after 1.009857989s server | 0.754 DEBUG [Server] Unsupported version: 57414954 server | 0.754 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59519 IpTos(Cs0, NotEct) len 15 server | 0.754 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" }) server | 0.754 DEBUG [Server] Unsupported version: 57414954 server | 0.754 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:59519 IpTos(Cs0, NotEct) len 15 server | 0.754 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 eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds server | 1.055 DEBUG [Server] Handle initial server | 1.055 INFO AddressValidation: no token; accepting server | 1.055 INFO [Server] Accept connection CID [18]: bbc4ff208104fd379ca8c3155c6a6ce72a9b server | 1.055 DEBUG Overwrite initial version Version1 ==> Version1 server | 1.057 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500 server | 1.057 INFO [Server ...] Received valid Initial packet with scid CID [17]: 708ac4ff5e433e96988219a82d276f9e08 dcid CID [18]: bbc4ff208104fd379ca8c3155c6a6ce72a9b server | 1.057 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=bbc4ff208104fd379ca8c3155c6a6ce72a9b server | 1.057 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 server | 1.057 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 server | 1.057 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] State change from Init -> WaitInitial server | 1.057 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=48004473 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 1200 server | -> RX Crypto { offset: 0, len: 263 } server | -> RX Padding { len: 866 } server | 1.057 DEBUG Read Ok(263) bytes server | 1.057 DEBUG 0-RTT: no token, no 0-RTT server | 1.058 DEBUG Read secret available for Handshake: SymKey [32]: 94b4e143c434ce4bd945698d780a31a71effe26fd5c9434efdc627841904f798 server | 1.058 DEBUG Write secret available for Handshake: SymKey [32]: 148fa1c2596785682e3f81964df1e2a7aa081c72983e04684e3d5ab18402583c server | 1.058 DEBUG Writing transport parameters, msg=8 server | 1.058 DEBUG Read secret available for ApplicationData: SymKey [32]: df44d86733fe3746c84b905509490c2d6621209644e9dc863c48a2144b024695 server | 1.058 DEBUG Write secret available for ApplicationData: SymKey [32]: bf8d510c13d76db88428d9bc5b666a65a8de9e7411113a3f5a8ced815dc7d476 server | 1.058 DEBUG [Agent 0x55ad50d5f1d0] state -> InProgress server | 1.058 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.058 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 server | 1.058 DEBUG [Crypto] Handshake keys installed server | 1.058 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.058 DEBUG [Crypto] Application write key installed server | 1.058 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 356, tv_nsec: 249219486 } server | 1.058 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:36084] Make permanent server | 1.058 DEBUG [unv-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084] set as primary path server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] State change from WaitInitial -> Handshaking server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG Building Initial dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) scid Some(CID [10]: 8087d91b895937f04f4d) server | 1.058 DEBUG CRYPTO for in offset=0, len=90 server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=0 type=Initial pri-unv-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 159 server | TX -> Ack { largest_acknowledged: 48004473, 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 | 1.058 DEBUG Building Handshake dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) scid Some(CID [10]: 8087d91b895937f04f4d) server | 1.058 DEBUG CRYPTO for hs offset=0, len=734 server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=0 type=Handshake pri-unv-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 950 server | TX -> Crypto { offset: 0, len: 734 } server | 1.058 DEBUG packet_sent this=0x55ad50d5eb40, pn=0, ps=791 server | 1.058 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pad Initial from 950 to PLPMTU 1232 server | 1.058 DEBUG packet_sent this=0x55ad50d5eb40, pn=0, ps=441 server | 1.058 DEBUG ECN probing: sent 1 probes server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG Building Initial dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) scid Some(CID [10]: 8087d91b895937f04f4d) server | 1.058 DEBUG Building Handshake dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) scid Some(CID [10]: 8087d91b895937f04f4d) server | 1.058 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 296.819263ms server | 1.058 DEBUG Setting timeout of 296.819263ms server | 1.058 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.058 DEBUG Building Initial dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) scid Some(CID [10]: 8087d91b895937f04f4d) server | 1.059 DEBUG Building Handshake dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) scid Some(CID [10]: 8087d91b895937f04f4d) server | 1.059 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.059 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.059 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 296.78064ms server | 1.059 DEBUG Setting timeout of 296.78064ms server | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=48004474 type=Initial pri-unv-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 64 server | -> RX 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 | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] Rx ACK space=in, ranges=[0..=0] server | 1.093 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 server | 1.093 DEBUG on_packets_acked this=0x55ad50d5eb40, limited=1, bytes_in_flight=791, cwnd=12320, state=SlowStart, new_acked=441 server | 1.093 DEBUG Acked crypto frame space=in offset=0 length=90 server | 1.093 DEBUG [pri-unv-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084] Path validated Instant { tv_sec: 356, tv_nsec: 286901252 } server | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] Drop packet number space in server | 1.093 DEBUG [LossRecovery] Reset loss recovery state for Initial server | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=48004473 type=Handshake pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 105 server | -> RX 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 | -> RX Crypto { offset: 0, len: 36 } server | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] Rx ACK space=hs, ranges=[0..=0] server | 1.093 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0 server | 1.093 DEBUG on_packets_acked this=0x55ad50d5eb40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=791 server | 1.093 DEBUG Acked crypto frame space=hs offset=0 length=734 server | 1.093 DEBUG Read Ok(36) bytes server | 1.093 DEBUG [Agent 0x55ad50d5f1d0] 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 | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] TLS connection complete server | 1.093 DEBUG [pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084] Path validated Instant { tv_sec: 356, tv_nsec: 286901252 } server | 1.093 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 server | 1.093 DEBUG [Crypto] application read keys installed server | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] State change from Handshaking -> Connected server | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] State change from Connected -> Confirmed server | 1.093 DEBUG PMTUD started with probe size 1380 server | 1.093 INFO [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] Connection established server | 1.093 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 356, tv_nsec: 286901252 } server | 1.093 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=48004473 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 1031 server | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [136, 30, 6, 128, 241, 15, 114, 21, 237, 205, 162, 32, 42, 52, 217, 75, 191], stateless_reset_token: [70, 253, 108, 173, 115, 218, 124, 153, 127, 86, 199, 190, 57, 91, 104, 253] } server | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [56, 229, 205, 184, 48, 58, 155, 241, 168, 37, 95, 101, 238, 134, 245, 185, 115], stateless_reset_token: [70, 104, 235, 18, 129, 147, 124, 36, 19, 24, 36, 250, 213, 69, 45, 212] } server | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [57, 75, 222, 19, 228, 231, 133, 110, 169, 62, 170, 223, 255, 44, 46, 252, 45], stateless_reset_token: [67, 37, 197, 47, 141, 8, 104, 57, 242, 246, 158, 126, 211, 227, 110, 168] } server | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [77, 109, 19, 230, 177, 28, 232, 201, 71, 123, 171, 210, 62, 197, 227, 32, 17], stateless_reset_token: [224, 167, 181, 102, 25, 130, 62, 34, 173, 252, 122, 87, 53, 126, 242, 126] } server | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [216, 72, 189, 238, 236, 163, 204, 2, 122, 12, 17, 94, 174, 247, 221, 151, 30], stateless_reset_token: [153, 19, 27, 191, 96, 193, 247, 144, 134, 53, 183, 171, 197, 48, 190, 70] } server | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [243, 62, 57, 56, 225, 100, 137, 73, 53, 171, 160, 238, 200, 47, 142, 27, 136], stateless_reset_token: [168, 161, 111, 3, 214, 35, 57, 144, 116, 66, 166, 221, 162, 134, 157, 163] } server | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [156, 184, 190, 191, 30, 193, 168, 55, 40, 98, 13, 166, 184, 185, 203, 150, 217], stateless_reset_token: [101, 87, 55, 228, 108, 147, 122, 113, 144, 140, 80, 127, 67, 237, 207, 168] } server | -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true } server | -> RX Padding { len: 721 } server | 1.094 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 356, tv_nsec: 286901252 } server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.094 DEBUG Building Handshake dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) scid Some(CID [10]: 8087d91b895937f04f4d) server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=1 type=Handshake pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 64 server | TX -> Ack { largest_acknowledged: 48004473, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] Drop packet number space hs server | 1.094 DEBUG [LossRecovery] Reset loss recovery state for Handshake server | 1.094 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=0 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 1332 server | TX -> Ack { largest_acknowledged: 48004473, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } server | TX -> HandshakeDone server | TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [197, 155, 33, 78, 227, 78, 86, 209, 68, 8], stateless_reset_token: [204, 13, 188, 193, 204, 238, 119, 46, 234, 167, 161, 139, 120, 156, 112, 27] } server | TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [120, 102, 239, 29, 208, 75, 188, 230, 189, 184], stateless_reset_token: [75, 109, 106, 165, 129, 118, 126, 171, 13, 120, 218, 48, 65, 228, 128, 71] } server | TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [87, 163, 147, 77, 112, 227, 174, 3, 255, 44], stateless_reset_token: [53, 114, 82, 109, 140, 187, 236, 0, 59, 22, 83, 206, 131, 115, 153, 29] } server | TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [249, 241, 161, 199, 229, 69, 138, 110, 53, 111], stateless_reset_token: [123, 130, 172, 231, 126, 129, 54, 148, 65, 186, 192, 77, 160, 136, 195, 193] } server | TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [145, 31, 205, 162, 134, 99, 228, 240, 57, 56], stateless_reset_token: [251, 216, 213, 140, 123, 178, 188, 126, 134, 180, 243, 25, 23, 144, 9, 78] } server | TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [187, 34, 65, 254, 50, 74, 202, 130, 151, 247], stateless_reset_token: [96, 226, 99, 130, 152, 89, 167, 79, 6, 182, 162, 243, 32, 124, 11, 173] } server | TX -> Padding { len: 1041 } server | 1.094 DEBUG packet_sent this=0x55ad50d5eb40, pn=0, ps=1268 server | 1.094 DEBUG ECN probing: sent 2 probes server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.094 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.094 DEBUG Sending PMTUD probe of size 1380, count 1 server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=1 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 1332 server | TX -> Ping server | TX -> Padding { len: 1296 } server | 1.094 DEBUG packet_sent this=0x55ad50d5eb40, pn=1, ps=1332 server | 1.094 DEBUG ECN probing: sent 3 probes server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.094 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.094 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.094 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 1.169225ms server | 1.094 DEBUG Setting timeout of 1.169225ms server | 1.095 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] send session ticket 406d0012bbc4ff208104fd379ca8c3155c6a6ce72a9b0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a8087d91b895937f04f4d110c000000017aea9a6a000000016ab200c0000000ff02de1a0243e8200100686921 server | 1.095 DEBUG Path = 'fdmwphtjwo' server | 1.095 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.095 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.095 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.095 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 62.899µs server | 1.095 DEBUG Setting timeout of 62.899µs server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.096 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.096 DEBUG CRYPTO for ap offset=0, len=165 server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=2 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 1232 server | TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true } server | TX -> Crypto { offset: 0, len: 165 } server | 1.096 DEBUG packet_sent this=0x55ad50d5eb40, pn=2, ps=1232 server | 1.096 DEBUG ECN probing: sent 4 probes server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.096 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.096 DEBUG CRYPTO for ap offset=165, len=156 server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=3 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 241 server | TX -> Crypto { offset: 165, len: 156 } server | TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 232, 29, 112, 77, 245, 135, 71, 189, 168, 250, 159, 126, 231, 207, 9, 248, 141, 152, 185, 236, 223, 77, 58, 44, 67, 84, 21, 74, 81, 232, 188, 20, 81, 65, 201, 123] } server | 1.096 DEBUG packet_sent this=0x55ad50d5eb40, pn=3, ps=241 server | 1.096 DEBUG ECN probing: sent 5 probes server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.096 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 1.065063ms server | 1.096 DEBUG Setting timeout of 1.065063ms server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.096 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } server | 1.096 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 1.04713ms server | 1.096 DEBUG Setting timeout of 1.04713ms server | 1.098 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.098 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.098 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.098 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 117.029364ms server | 1.098 DEBUG Setting timeout of 117.029364ms server | 1.098 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.098 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.098 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false } server | 1.098 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 117.008835ms server | 1.098 DEBUG Setting timeout of 117.008835ms server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=48004474 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 39 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 | -> RX Padding { len: 3 } server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] Rx ACK space=ap, ranges=[0..=1] server | 1.127 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1 server | 1.127 DEBUG on_packets_acked this=0x55ad50d5eb40, limited=1, bytes_in_flight=1473, cwnd=12320, state=SlowStart, new_acked=2600 server | 1.127 DEBUG PMTUD probe of size 1380 succeeded server | 1.127 DEBUG PMTUD started with probe size 1420 server | 1.127 DEBUG PLPMTU changed from 1232 to 1332, updating pacer server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.127 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.127 DEBUG Sending PMTUD probe of size 1420, count 1 server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=4 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 1372 server | TX -> Ping server | TX -> Padding { len: 1336 } server | 1.127 DEBUG packet_sent this=0x55ad50d5eb40, pn=4, ps=1372 server | 1.127 DEBUG ECN probing: sent 6 probes server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.127 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.127 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 109.043899ms server | 1.127 DEBUG Setting timeout of 109.043899ms server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.127 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.127 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.127 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] delay duration 109.018261ms server | 1.127 DEBUG Setting timeout of 109.018261ms server | 1.128 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=48004475 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 39 server | -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" } server | -> RX Padding { len: 7 } server | 1.128 INFO [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] ConnectionClose received. Error code: Transport(0) frame type 0 reason server | 1.128 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 356, tv_nsec: 649474132 } } server | 1.128 DEBUG [pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084] Path validated Instant { tv_sec: 356, tv_nsec: 321571549 } server | 1.128 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false } server | 1.128 DEBUG Building Short dcid Some(CID [17]: 708ac4ff5e433e96988219a82d276f9e08) server | 1.128 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 356, tv_nsec: 321571549 } server | 1.128 DEBUG [Server bbc4ff208104fd379ca8c3155c6a6ce72a9b] pn=5 type=Short pri-path:708ac4ff5e433e96988219a82d276f9e08 [::]:443->[::ffff:193.167.0.100]:36084 IpTos(Cs0, Ect0) len 50 server | TX -> Ack { largest_acknowledged: 48004475, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } server | TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" } server | 1.128 DEBUG ECN probing: sent 7 probes server | 1.128 DEBUG Setting timeout of 327.789521ms server | 1.128 DEBUG Setting timeout of 327.776126ms 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 10:25:42,998 Using the client's key log file. 2025-04-30 10:25:43,011 2025-04-30 10:25:43,012 Using the client's key log file. 2025-04-30 10:25:43,012 Using the client's key log file. 2025-04-30 10:25:43,023 2025-04-30 10:25:43,024 Using the client's key log file. 2025-04-30 10:25:43,320 Check of downloaded files succeeded. 2025-04-30 10:25:43,923 Using the client's key log file. 2025-04-30 10:25:44,212 Check of downloaded files succeeded. 2025-04-30 10:25:45,107 ECN.NONE 0 2025-04-30 10:25:45,108 ECN.ECT1 0 2025-04-30 10:25:45,108 ECN.ECT0 4 2025-04-30 10:25:45,108 ECN.CE 0 2025-04-30 10:25:45,417 ECN.NONE 0 2025-04-30 10:25:45,417 ECN.ECT1 0 2025-04-30 10:25:45,417 ECN.ECT0 7 2025-04-30 10:25:45,417 ECN.CE 0