2025-04-30 10:29:47,236 Generated random file: yezyqtevix of size: 1024
2025-04-30 10:29:47,236 Requests: https://server4:443/yezyqtevix
2025-04-30 10:29:47,300 
2025-04-30 10:29:47,300 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_p3sa29y3/ TESTCASE_SERVER=v2 TESTCASE_CLIENT=v2 WWW=/tmp/www_pgqdms4d/ DOWNLOADS=/tmp/download_0m3bc4n_/ SERVER_LOGS=/tmp/logs_server_9pgk8jot CLIENT_LOGS=/tmp/logs_client_o3akcped 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/yezyqtevix"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 10:29:59,373  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
server  | Setting up routes...
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
server  | Endpoint's IPv4 address is 193.167.100.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
client  | Setting up routes...
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
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  | + P12CERT=/tmp/tmp.syCClWonot
server  | + mkdir -p /neqo/db
client  | Endpoint's IPv4 address is 193.167.0.100
server  | + certutil -N -d sql:/neqo/db --empty-password
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.syCClWonot
server  | Warning: output encryption option -nodes ignored with -export
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.syCClWonot -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  |             28:03:dc:35:cc:bc:37:3b:58:04:45:22:c6:3e:8e:37:
server  |             89:24:15:fb
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:29:47 2025
server  |             Not After : Sat May 10 10:29:47 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:e2:f1:90:62:ce:65:e6:6c:7c:e6:49:24:2c:d7:c7:
server  |                     f1:79:bd:c4:93:d2:89:91:98:9c:ea:d4:da:57:16:e0:
server  |                     3d:20:db:6a:8d:8d:c3:fd:39:6f:41:b1:c8:28:a8:4c:
server  |                     22:aa:69:50:5e:f0:45:a2:09:41:11:5a:cf:08:f0:b6:
server  |                     f9
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  |                 ad:97:f5:b4:b4:43:57:ed:68:98:a8:71:0a:2f:7c:d4:
server  |                 4f:12:44:81
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 86:53:75:ea:99:98:24:75:59:ac:ee:cd:54:bb:9d:76:
server  |                 55:bd:5e:4a
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:44:02:20:19:4a:33:4b:2b:bd:ef:01:87:33:08:e5:
server  |         b7:ab:2b:e0:72:e9:8b:75:38:dc:69:e9:97:f4:c2:ed:
server  |         44:b9:2e:e1:02:20:62:d3:a4:13:88:eb:b9:35:4f:cb:
server  |         e9:9d:e7:32:39:23:86:3d:13:c2:43:05:b1:cc:8e:0d:
server  |         82:ee:b9:ed:15:39
server  |     Fingerprint (SHA-256):
server  |         54:BA:60:BF:FD:D2:41:8B:E9:CD:0C:7C:BD:71:FB:92:F6:69:C5:07:AD:69:73:90:10:CD:CF:23:B0:B9:FD:48
server  |     Fingerprint (SHA1):
server  |         BE:03:BF:50:9D:45:85:9E:27:24:AC:A5:F1:7E:75:45:5D:5F:6F:F7
server  | 
server  |     Mozilla-CA-Policy: false (attribute missing)
server  |     Certificate Trust Flags:
server  |         SSL Flags:
server  |             User
server  |         Email Flags:
server  |             User
server  |         Object Signing Flags:
server  |             User
server  | 
server  | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" -d "$DB" -k "$CERT")
server  | + '[' v2 = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test v2 --qlog-dir /logs/qlog/ -d /neqo/db -k cert '[::]:443'
server  | ++ tee -i -a /logs/server.log
server  | 0.000 DEBUG Logging initialized
server  | 0.002 DEBUG Default socket send buffer size is 212992
server  | 0.002 DEBUG Default socket receive buffer size is 1048576, not changing
server  | 0.002 INFO Server waiting for connection on: [::]:443
server  | 0.785 DEBUG [Server] Unsupported version: 57414954
server  | 0.785 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:56532 IpTos(Cs0, NotEct) len 23
sim     | server:443 is available after 1.058316987s
server  | 0.785 DEBUG [Server] Unsupported version: 57414954
server  | 0.785 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:56532 IpTos(Cs0, NotEct) len 23
server  | 0.785 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.785 DEBUG [Server] Unsupported version: 57414954
server  | 0.785 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:56532 IpTos(Cs0, NotEct) len 23
server  | 0.785 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: tcpdump: listening on eth0listening on eth1, link-type EN10MB (Ethernet), link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | , snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
server  | 1.062 DEBUG [Server] Handle initial
server  | 1.062 INFO AddressValidation: no token; accepting
server  | 1.062 INFO [Server] Accept connection CID [18]: 9fc9d577d43f35e97a8504f23875e3b9dff4
server  | 1.062 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.063 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.063 INFO [Server ...] Received valid Initial packet with scid CID [17]: e1e22028730438e9780ec5090f97029b6c dcid CID [18]: 9fc9d577d43f35e97a8504f23875e3b9dff4
server  | 1.063 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=9fc9d577d43f35e97a8504f23875e3b9dff4
server  | 1.063 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.063 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.063 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] State change from Init -> WaitInitial
server  | 1.063 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1079053506 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 1200
server  |   -> RX Crypto { offset: 0, len: 267 }
server  |   -> RX Padding { len: 862 }
server  | 1.064 DEBUG Read Ok(267) bytes
server  | 1.064 INFO Compatible upgrade Version1 ==> Version2
server  | 1.064 DEBUG Overwrite initial version Version1 ==> Version2
server  | 1.064 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.064 DEBUG Read secret available for Handshake: SymKey [32]: 2ba8e29c176800bae5f97268af9cbb969ceceb3c45b1d9e1e81b515c72bbdbe0
server  | 1.064 DEBUG Write secret available for Handshake: SymKey [32]: 3154deeee8b109dfea871a5eeec34527fba9dae56f6f1b7b0de08ecd917dd8c0
server  | 1.064 DEBUG Writing transport parameters, msg=8
server  | 1.064 DEBUG Read secret available for ApplicationData: SymKey [32]: 2fad2f27cee9ad25dfcbed74ee29af75daa9bad6fe490f0a0d440489d46b6664
server  | 1.064 DEBUG Write secret available for ApplicationData: SymKey [32]: 67fcbfee8d024ef4cf4882d2089974612e825fdcb759cc8e6458dc249597ff62
server  | 1.064 DEBUG [Agent 0x5650a1af81e0] state -> InProgress
server  | 1.064 DEBUG [CryptoStates] Creating initial cipher state v=Version2, role=Server dcid=9fc9d577d43f35e97a8504f23875e3b9dff4
server  | 1.064 DEBUG Making Write Initial CryptoDxState, v=Version2 cipher=4865
server  | 1.064 DEBUG Making Read Initial CryptoDxState, v=Version2 cipher=4865
server  | 1.064 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] Compatible upgrade Version1 ==> Version2
server  | 1.064 DEBUG Making Write Handshake CryptoDxState, v=Version2 cipher=4865
server  | 1.065 DEBUG Making Read Handshake CryptoDxState, v=Version2 cipher=4865
server  | 1.065 DEBUG [Crypto] Handshake keys installed
server  | 1.065 DEBUG Making Write ApplicationData CryptoDxState, v=Version2 cipher=4865
server  | 1.065 DEBUG [Crypto] Application write key installed
server  | 1.065 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 612, tv_nsec: 736328383 }
server  | 1.065 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:40828] Make permanent
server  | 1.065 DEBUG [unv-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828] set as primary path
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] State change from WaitInitial -> Handshaking
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG Building Initial dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c) scid Some(CID [10]: d99f964a8c46760fc608)
server  | 1.065 DEBUG CRYPTO for in offset=0, len=90
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=0 type=Initial pri-unv-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 163
server  |   TX -> Ack { largest_acknowledged: 1079053506, 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.065 DEBUG Building Handshake dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c) scid Some(CID [10]: d99f964a8c46760fc608)
server  | 1.065 DEBUG CRYPTO for hs offset=0, len=742
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=0 type=Handshake pri-unv-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 962
server  |   TX -> Crypto { offset: 0, len: 742 }
server  | 1.065 DEBUG packet_sent this=0x5650a1af7b20, pn=0, ps=799
server  | 1.065 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pad Initial from 962 to PLPMTU 1232
server  | 1.065 DEBUG packet_sent this=0x5650a1af7b20, pn=0, ps=433
server  | 1.065 DEBUG ECN probing: sent 1 probes
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG Building Initial dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c) scid Some(CID [10]: d99f964a8c46760fc608)
server  | 1.065 DEBUG Building Handshake dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c) scid Some(CID [10]: d99f964a8c46760fc608)
server  | 1.065 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 296.884044ms
server  | 1.065 DEBUG Setting timeout of 296.884044ms
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG Building Initial dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c) scid Some(CID [10]: d99f964a8c46760fc608)
server  | 1.065 DEBUG Building Handshake dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c) scid Some(CID [10]: d99f964a8c46760fc608)
server  | 1.065 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.065 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.065 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 296.840563ms
server  | 1.065 DEBUG Setting timeout of 296.840563ms
server  | 1.100 WARN Crypto operation failed NssError { name: "SEC_ERROR_BAD_DATA", code: -8190, desc: "security library: received bad data." }
server  | 1.100 WARN [Server ...] Dropped received packet: Decryption failure; Total: 1
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] Drop packet number space in
server  | 1.100 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.100 INFO [pri-unv-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828] discarding a packet without an RTT estimate; guessing RTT=37.94137ms
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1079053506 type=Handshake pri-unv-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 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.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] Rx ACK space=hs, ranges=[0..=0]
server  | 1.100 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.100 DEBUG on_packets_acked this=0x5650a1af7b20, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=799
server  | 1.100 DEBUG Acked crypto frame space=hs offset=0 length=742
server  | 1.100 DEBUG Read Ok(36) bytes
server  | 1.100 DEBUG [Agent 0x5650a1af81e0] 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.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] TLS connection complete
server  | 1.100 DEBUG [pri-unv-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828] Path validated Instant { tv_sec: 612, tv_nsec: 774269753 }
server  | 1.100 DEBUG Making Read ApplicationData CryptoDxState, v=Version2 cipher=4865
server  | 1.100 DEBUG [Crypto] application read keys installed
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] State change from Handshaking -> Connected
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] State change from Connected -> Confirmed
server  | 1.100 DEBUG PMTUD started with probe size 1380
server  | 1.100 INFO [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] Connection established
server  | 1.100 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 612, tv_nsec: 774269753 }
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1079053506 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 1031
server  |   -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [84, 89, 33, 222, 115, 191, 11, 215, 70, 197, 255, 193, 209, 200, 129, 89, 2], stateless_reset_token: [163, 229, 16, 152, 160, 232, 36, 197, 224, 221, 252, 27, 254, 66, 6, 99] }
server  |   -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [88, 55, 199, 150, 68, 145, 87, 207, 198, 129, 143, 184, 146, 28, 118, 99, 70], stateless_reset_token: [250, 59, 237, 144, 93, 94, 218, 33, 227, 61, 239, 215, 97, 78, 70, 215] }
server  |   -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [202, 193, 22, 53, 160, 5, 136, 218, 229, 32, 170, 255, 216, 125, 143, 85, 228], stateless_reset_token: [240, 249, 41, 102, 251, 38, 226, 221, 106, 104, 83, 98, 29, 250, 12, 10] }
server  |   -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [216, 206, 124, 76, 196, 134, 6, 100, 232, 48, 171, 86, 31, 236, 28, 248, 218], stateless_reset_token: [64, 145, 159, 1, 141, 3, 62, 82, 50, 133, 235, 68, 65, 68, 33, 192] }
server  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [31, 121, 241, 131, 17, 196, 17, 51, 122, 115, 255, 199, 55, 7, 180, 63, 179], stateless_reset_token: [142, 119, 138, 214, 191, 160, 180, 129, 253, 194, 9, 205, 128, 68, 152, 98] }
server  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [249, 186, 29, 108, 73, 122, 97, 50, 176, 179, 34, 133, 155, 245, 38, 47, 239], stateless_reset_token: [58, 202, 122, 91, 87, 112, 103, 212, 239, 124, 223, 112, 25, 117, 159, 61] }
server  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [243, 226, 49, 43, 21, 5, 26, 93, 149, 242, 32, 214, 218, 180, 15, 150, 102], stateless_reset_token: [39, 37, 235, 54, 136, 133, 187, 251, 218, 125, 149, 75, 50, 127, 147, 255] }
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  |   -> RX Padding { len: 721 }
server  | 1.100 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 612, tv_nsec: 774269753 }
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG Building Handshake dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c) scid Some(CID [10]: d99f964a8c46760fc608)
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1 type=Handshake pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 68
server  |   TX -> Ack { largest_acknowledged: 1079053506, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] Drop packet number space hs
server  | 1.100 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.100 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=0 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ack { largest_acknowledged: 1079053506, 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: [190, 158, 183, 234, 212, 176, 79, 68, 75, 105], stateless_reset_token: [125, 203, 191, 141, 150, 53, 90, 81, 88, 159, 20, 199, 85, 183, 174, 171] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [156, 254, 157, 169, 62, 107, 123, 165, 32, 93], stateless_reset_token: [246, 208, 234, 203, 156, 112, 208, 160, 3, 21, 38, 142, 60, 11, 205, 14] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [160, 88, 201, 143, 18, 239, 219, 187, 87, 135], stateless_reset_token: [5, 14, 94, 229, 13, 161, 246, 79, 167, 134, 35, 149, 173, 75, 65, 199] }
server  |   TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [89, 183, 167, 8, 165, 60, 80, 23, 9, 1], stateless_reset_token: [58, 120, 249, 165, 196, 158, 62, 204, 218, 145, 94, 232, 227, 254, 72, 224] }
server  |   TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [193, 215, 26, 54, 188, 104, 172, 3, 181, 255], stateless_reset_token: [31, 206, 136, 162, 177, 232, 152, 30, 139, 70, 93, 255, 199, 34, 215, 110] }
server  |   TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [69, 204, 93, 132, 236, 47, 142, 123, 4, 212], stateless_reset_token: [102, 232, 204, 12, 64, 146, 82, 8, 94, 210, 83, 139, 249, 133, 62, 235] }
server  |   TX -> Padding { len: 1033 }
server  | 1.100 DEBUG packet_sent this=0x5650a1af7b20, pn=0, ps=1264
server  | 1.100 DEBUG ECN probing: sent 2 probes
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.100 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.100 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.100 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1296 }
server  | 1.100 DEBUG packet_sent this=0x5650a1af7b20, pn=1, ps=1332
server  | 1.100 DEBUG ECN probing: sent 3 probes
server  | 1.101 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.101 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.101 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.101 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 1.217969ms
server  | 1.101 DEBUG Setting timeout of 1.217969ms
server  | 1.101 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] send session ticket 407500129fc9d577d43f35e97a8504f23875e3b9dff40104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0ad99f964a8c46760fc60811146b3343cf0a8a8ada6b3343cf00000001ff00001d6ab200c0000000ff02de1a0243e8200100686921
server  | 1.102 DEBUG Path = 'yezyqtevix'
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.102 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.102 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 135.869µs
server  | 1.102 DEBUG Setting timeout of 135.869µs
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1079053507 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 1406
server  |   -> RX Ping
server  |   -> RX Padding { len: 1374 }
server  | 1.102 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 612, tv_nsec: 776274304 }
server  | 1.102 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 612, tv_nsec: 776274304 }
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.102 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=2 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 50
server  |   TX -> Ack { largest_acknowledged: 1079053507, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) }
server  | 1.102 DEBUG ECN probing: sent 4 probes
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.102 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.102 DEBUG CRYPTO for ap offset=0, len=165
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=3 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 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.102 DEBUG packet_sent this=0x5650a1af7b20, pn=3, ps=1232
server  | 1.102 DEBUG ECN probing: sent 5 probes
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.102 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.102 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 1.779628ms
server  | 1.102 DEBUG Setting timeout of 1.779628ms
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.102 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.102 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.102 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 1.753789ms
server  | 1.102 DEBUG Setting timeout of 1.753789ms
server  | 1.105 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.105 DEBUG CRYPTO for ap offset=165, len=156
server  | 1.105 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=4 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 241
server  |   TX -> Crypto { offset: 165, len: 156 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 8, 10, 136, 26, 179, 182, 66, 160, 132, 181, 151, 46, 127, 246, 240, 159, 111, 222, 183, 14, 44, 153, 87, 185, 4, 185, 136, 61, 43, 227, 189, 236, 177, 16, 29, 33] }
server  | 1.105 DEBUG packet_sent this=0x5650a1af7b20, pn=4, ps=241
server  | 1.105 DEBUG ECN probing: sent 6 probes
server  | 1.105 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.105 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 119.731844ms
server  | 1.105 DEBUG Setting timeout of 119.731844ms
server  | 1.105 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.105 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.105 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 119.706487ms
server  | 1.105 DEBUG Setting timeout of 119.706487ms
server  | 1.134 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1079053508 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 1444
server  |   -> RX Ping
server  |   -> RX Padding { len: 1415 }
server  | 1.134 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 612, tv_nsec: 809054158 }
server  | 1.134 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 612, tv_nsec: 809054158 }
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=5 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 50
server  |   TX -> Ack { largest_acknowledged: 1079053508, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
server  | 1.135 DEBUG ECN probing: sent 7 probes
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.135 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 90.199732ms
server  | 1.135 DEBUG Setting timeout of 90.199732ms
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1079053509 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 39
server  |   -> RX Ack { largest_acknowledged: 2, ack_delay: 5, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
server  |   -> RX Padding { len: 3 }
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] Rx ACK space=ap, ranges=[0..=2]
server  | 1.135 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2
server  | 1.135 DEBUG on_packets_acked this=0x5650a1af7b20, limited=1, bytes_in_flight=1473, cwnd=12320, state=SlowStart, new_acked=2596
server  | 1.135 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.135 DEBUG PMTUD started with probe size 1420
server  | 1.135 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.135 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=6 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Padding { len: 1336 }
server  | 1.135 DEBUG packet_sent this=0x5650a1af7b20, pn=6, ps=1372
server  | 1.135 DEBUG ECN probing: sent 8 probes
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.135 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] delay duration 109.800181ms
server  | 1.135 DEBUG Setting timeout of 109.800181ms
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=1079053510 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 39
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  |   -> RX Padding { len: 7 }
server  | 1.135 INFO [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 613, tv_nsec: 139164553 } }
server  | 1.135 DEBUG [pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828] Path validated Instant { tv_sec: 612, tv_nsec: 809454008 }
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.135 DEBUG Building Short dcid Some(CID [17]: e1e22028730438e9780ec5090f97029b6c)
server  | 1.135 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 612, tv_nsec: 809454008 }
server  | 1.135 DEBUG [Server 9fc9d577d43f35e97a8504f23875e3b9dff4] pn=7 type=Short pri-path:e1e22028730438e9780ec5090f97029b6c [::]:443->[::ffff:193.167.0.100]:40828 IpTos(Cs0, Ect0) len 54
server  |   TX -> Ack { largest_acknowledged: 1079053510, ack_delay: 0, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 28, reason_phrase: "" }
server  | 1.135 DEBUG ECN probing: sent 9 probes
server  | 1.135 DEBUG Setting timeout of 329.619544ms
server  | 1.135 DEBUG Setting timeout of 329.61218ms

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:29:59,476 Using the client's key log file.
2025-04-30 10:29:59,488 
2025-04-30 10:29:59,489 Using the client's key log file.
2025-04-30 10:29:59,489 Using the client's key log file.
2025-04-30 10:29:59,499 
2025-04-30 10:29:59,499 Using the client's key log file.
2025-04-30 10:30:00,652 Check of downloaded files succeeded.