2025-04-30 12:23:37,111 Generated random file: segakevxya of size: 1024
2025-04-30 12:23:37,111 Requests: https://server4:443/segakevxya
2025-04-30 12:23:37,170 
2025-04-30 12:23:37,171 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_g5r9n7fb/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_fg7uhemr/ DOWNLOADS=/tmp/download_5x_jtjxa/ SERVER_LOGS=/tmp/logs_server__tlrsl0q CLIENT_LOGS=/tmp/logs_client_p8s_pg6q SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=litespeedtech/lsquic-qir:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/segakevxya"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 12:23:49,268  Container sim  Recreate
 Container sim  Recreated
 Container server  Recreate
 Container client  Recreate
 Container client  Recreated
 Container server  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
server  | Setting up routes...
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
server  | Endpoint's IPv4 address is 193.167.100.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
server  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + '[' -n handshake ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.FowF4IY4rb
server  | + mkdir -p /neqo/db
server  | + certutil -N -d sql:/neqo/db --empty-password
client  | Setting up routes...
client  | Actual changes:
client  | tx-checksumming: off
client  | 	tx-checksum-ip-generic: off
client  | 	tx-checksum-sctp: off
client  | tcp-segmentation-offload: off
client  | 	tx-tcp-segmentation: off [requested on]
client  | 	tx-tcp-ecn-segmentation: off [requested on]
client  | 	tx-tcp-mangleid-segmentation: off [requested on]
client  | 	tx-tcp6-segmentation: off [requested on]
client  | tx-udp-segmentation: off [requested on]
client  | Endpoint's IPv4 address is 193.167.0.100
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.FowF4IY4rb
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.FowF4IY4rb -W ''
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
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  |             03:07:95:aa:e7:ee:3d:8f:a9:9d:53:d5:52:b2:79:8d:
server  |             c3:36:87:e4
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 12:23:37 2025
server  |             Not After : Sat May 10 12:23:37 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:21:ea:66:f1:f4:ea:a9:6a:f2:50:78:f2:31:c3:96:
server  |                     be:a1:03:ad:94:94:77:1b:d6:1e:0a:e4:11:b8:43:d1:
server  |                     d1:e6:0e:f5:1a:fe:13:fc:31:38:bd:15:58:c6:35:4f:
server  |                     d3:4f:12:02:25:80:fe:4a:a2:2a:03:36:cb:b1:21:fb:
server  |                     c3
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  |                 51:74:b6:cc:9c:51:66:8f:e0:77:95:52:1a:e2:a7:1f:
server  |                 6f:88:06:73
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 21:b9:4d:ca:7e:9f:67:f1:e6:d5:38:9d:d4:81:49:6a:
server  |                 f3:8c:a6:4f
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:45:02:20:0a:19:ac:c4:ab:9e:86:1d:68:8a:58:f1:
server  |         14:05:37:f6:e8:a8:ca:48:da:bb:ca:24:f5:fa:d6:b1:
server  |         07:78:af:be:02:21:00:a9:5a:1f:2a:28:8c:4e:f5:f7:
server  |         64:1a:cd:e0:98:4c:81:c6:95:53:8e:62:b2:28:74:53:
server  |         79:2a:3f:71:cd:8c:ed
server  |     Fingerprint (SHA-256):
server  |         E3:AA:7C:93:61:0F:3D:1C:FA:A3:23:25:74:12:12:B1:42:B6:4B:BB:9F:3F:AD:F0:4E:07:BF:FD:94:C0:6F:8F
server  |     Fingerprint (SHA1):
server  |         7C:43:D3:53:E3:9A:10:4A:8D:AD:72:97:C7:9E:B5:2C:F6:08:6C:86
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  | + '[' handshake = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test handshake --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.819 DEBUG [Server] Unsupported version: 57414954
server  | 0.819 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:51255 IpTos(Cs0, NotEct) len 15
sim     | server:443 is available after 1.053332493s
server  | 0.819 DEBUG [Server] Unsupported version: 57414954
server  | 0.819 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:51255 IpTos(Cs0, NotEct) len 15
server  | 0.819 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.819 DEBUG [Server] Unsupported version: 57414954
server  | 0.819 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:51255 IpTos(Cs0, NotEct) len 15
server  | 0.819 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  | TEST_PARAMS:
client  | REQUESTS: 'https://server4:443/segakevxya'
client  | paths: -p /segakevxya
client  | server: server4
client  | port: 443
client  | CLIENT_PARAMS:
server  | 1.016 DEBUG [Server] Handle initial
server  | 1.016 INFO AddressValidation: no token; accepting
server  | 1.016 INFO [Server] Accept connection CID [9]: d1205b0345204ad86a
server  | 1.016 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.018 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.018 INFO [Server ...] Received valid Initial packet with scid CID [8]: 4d88c199b423e529 dcid CID [9]: d1205b0345204ad86a
server  | 1.018 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=d1205b0345204ad86a
server  | 1.018 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.018 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.018 DEBUG [Server d1205b0345204ad86a] State change from Init -> WaitInitial
server  | 1.018 DEBUG [Server d1205b0345204ad86a] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect1) len 1200
server  |   -> RX Crypto { offset: 0, len: 248 }
server  |   -> RX Padding { len: 904 }
server  | 1.018 DEBUG Read Ok(248) bytes
server  | 1.018 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.018 DEBUG Read secret available for Handshake: SymKey [32]: 1b83230cbb3867bafa6cef07cbf026bcea6d882aa286766478b4a52449d556e2
server  | 1.018 DEBUG Write secret available for Handshake: SymKey [32]: bee47eeea4867ad95c7d9d1bce224be195819b89dae5580c1f6dda5ceb5e60e0
server  | 1.018 DEBUG Writing transport parameters, msg=8
server  | 1.019 DEBUG Read secret available for ApplicationData: SymKey [32]: a4f7055fb1e66fe32b6892db387f96913ef194f004feed0e7f5817e59a345f00
server  | 1.019 DEBUG Write secret available for ApplicationData: SymKey [32]: 97bc2fbc8ea4069b6fe7da3b7127d6ae2b99608599f663c180a9cbd109dda4c0
server  | 1.019 DEBUG [Agent 0x5585ec1241d0] state -> InProgress
server  | 1.019 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.019 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.019 DEBUG [Crypto] Handshake keys installed
server  | 1.019 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.019 DEBUG [Crypto] Application write key installed
server  | 1.019 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 287, tv_nsec: 198078201 }
server  | 1.019 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:49900] Make permanent
server  | 1.019 DEBUG [unv-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900] set as primary path
server  | 1.019 DEBUG [Server d1205b0345204ad86a] State change from WaitInitial -> Handshaking
server  | 1.019 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.019 DEBUG Building Initial dcid Some(CID [8]: 4d88c199b423e529) scid Some(CID [10]: bf3ed24b973670d07676)
server  | 1.019 DEBUG CRYPTO for in offset=0, len=90
server  | 1.019 DEBUG [Server d1205b0345204ad86a] pn=0 type=Initial pri-unv-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 147
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) }
server  |   TX -> Crypto { offset: 0, len: 90 }
server  | 1.019 DEBUG Building Handshake dcid Some(CID [8]: 4d88c199b423e529) scid Some(CID [10]: bf3ed24b973670d07676)
server  | 1.019 DEBUG CRYPTO for hs offset=0, len=724
server  | 1.019 DEBUG [Server d1205b0345204ad86a] pn=0 type=Handshake pri-unv-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 919
server  |   TX -> Crypto { offset: 0, len: 724 }
server  | 1.019 DEBUG packet_sent this=0x5585ec123b40, pn=0, ps=772
server  | 1.019 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.019 DEBUG [Server d1205b0345204ad86a] pad Initial from 919 to PLPMTU 1232
server  | 1.019 DEBUG packet_sent this=0x5585ec123b40, pn=0, ps=460
server  | 1.019 DEBUG ECN probing: sent 1 probes
server  | 1.019 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.019 DEBUG Building Initial dcid Some(CID [8]: 4d88c199b423e529) scid Some(CID [10]: bf3ed24b973670d07676)
server  | 1.019 DEBUG Building Handshake dcid Some(CID [8]: 4d88c199b423e529) scid Some(CID [10]: bf3ed24b973670d07676)
server  | 1.019 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.019 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.019 DEBUG [Server d1205b0345204ad86a] delay duration 297.10249ms
server  | 1.019 DEBUG Setting timeout of 297.10249ms
server  | 1.019 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.019 DEBUG Building Initial dcid Some(CID [8]: 4d88c199b423e529) scid Some(CID [10]: bf3ed24b973670d07676)
server  | 1.019 DEBUG Building Handshake dcid Some(CID [8]: 4d88c199b423e529) scid Some(CID [10]: bf3ed24b973670d07676)
server  | 1.019 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.019 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.019 DEBUG [Server d1205b0345204ad86a] delay duration 297.051645ms
server  | 1.019 DEBUG Setting timeout of 297.051645ms
server  | 1.053 DEBUG [Server d1205b0345204ad86a] pn=1 type=Initial pri-unv-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect1) len 1035
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 201, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   -> RX Padding { len: 983 }
server  | 1.053 DEBUG [Server d1205b0345204ad86a] Rx ACK space=in, ranges=[0..=0]
server  | 1.053 DEBUG [LossRecovery] ACK for Initial - largest_acked=0
server  | 1.053 DEBUG on_packets_acked this=0x5585ec123b40, limited=1, bytes_in_flight=772, cwnd=12320, state=SlowStart, new_acked=460
server  | 1.053 DEBUG Acked crypto frame space=in offset=0 length=90
server  | 1.053 DEBUG [pri-unv-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900] Path validated Instant { tv_sec: 287, tv_nsec: 235184201 }
server  | 1.053 DEBUG [Server d1205b0345204ad86a] Drop packet number space in
server  | 1.053 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.053 DEBUG [Server d1205b0345204ad86a] pn=2 type=Handshake pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect1) len 89
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 97, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   -> RX Crypto { offset: 0, len: 36 }
server  | 1.053 DEBUG [Server d1205b0345204ad86a] Rx ACK space=hs, ranges=[0..=0]
server  | 1.053 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.053 DEBUG on_packets_acked this=0x5585ec123b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=772
server  | 1.053 DEBUG Acked crypto frame space=hs offset=0 length=724
server  | 1.053 DEBUG Read Ok(36) bytes
server  | 1.053 DEBUG [Agent 0x5585ec1241d0] 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.053 DEBUG [Server d1205b0345204ad86a] TLS connection complete
server  | 1.053 DEBUG [pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900] Path validated Instant { tv_sec: 287, tv_nsec: 235184201 }
server  | 1.053 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.053 DEBUG [Crypto] application read keys installed
server  | 1.053 DEBUG [Server d1205b0345204ad86a] State change from Handshaking -> Connected
server  | 1.053 DEBUG [Server d1205b0345204ad86a] State change from Connected -> Confirmed
server  | 1.053 DEBUG PMTUD started with probe size 1380
server  | 1.053 INFO [Server d1205b0345204ad86a] Connection established
server  | 1.053 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 287, tv_nsec: 235184201 }
server  | 1.053 DEBUG [Server d1205b0345204ad86a] pn=3 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect1) len 76
server  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [72, 179, 233, 103, 105, 118, 67, 221], stateless_reset_token: [0, 114, 80, 73, 16, 152, 134, 116, 230, 8, 232, 83, 217, 172, 234, 161] }
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  | 1.053 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 287, tv_nsec: 235184201 }
server  | 1.053 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.053 DEBUG Building Handshake dcid Some(CID [8]: 4d88c199b423e529) scid Some(CID [10]: bf3ed24b973670d07676)
server  | 1.053 DEBUG [Server d1205b0345204ad86a] pn=1 type=Handshake pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 52
server  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) }
server  | 1.053 DEBUG [Server d1205b0345204ad86a] Drop packet number space hs
server  | 1.053 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.053 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.054 DEBUG [Server d1205b0345204ad86a] pn=0 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ack { largest_acknowledged: 3, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) }
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [89, 122, 188, 100, 226, 19, 116, 235, 165, 237], stateless_reset_token: [46, 99, 230, 181, 74, 114, 112, 183, 185, 35, 28, 110, 45, 138, 142, 247] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [116, 175, 247, 222, 48, 50, 15, 89, 237, 75], stateless_reset_token: [229, 14, 16, 77, 175, 23, 155, 184, 134, 183, 234, 254, 176, 182, 27, 216] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [60, 131, 191, 24, 95, 88, 17, 253, 166, 12], stateless_reset_token: [206, 74, 218, 19, 45, 10, 173, 122, 115, 96, 63, 21, 130, 127, 174, 111] }
server  |   TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [106, 45, 146, 93, 122, 108, 166, 94, 120, 144], stateless_reset_token: [192, 144, 220, 205, 97, 240, 245, 190, 235, 43, 183, 252, 203, 246, 85, 178] }
server  |   TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [124, 90, 172, 79, 234, 51, 82, 8, 47, 228], stateless_reset_token: [12, 37, 203, 244, 179, 203, 63, 86, 243, 43, 178, 31, 220, 150, 183, 30] }
server  |   TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [100, 16, 78, 196, 120, 22, 167, 97, 240, 66], stateless_reset_token: [202, 220, 241, 77, 240, 89, 194, 86, 153, 190, 155, 140, 61, 130, 36, 172] }
server  |   TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [218, 244, 2, 134, 229, 139, 213, 2, 91, 233], stateless_reset_token: [229, 129, 71, 218, 123, 188, 55, 200, 42, 245, 85, 21, 216, 99, 168, 34] }
server  |   TX -> AckFrequency { seqno: 0, tolerance: 2, delay: 10000, ignore_order: false }
server  |   TX -> Padding { len: 1028 }
server  | 1.054 DEBUG packet_sent this=0x5585ec123b40, pn=0, ps=1280
server  | 1.054 DEBUG ECN probing: sent 2 probes
server  | 1.054 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.054 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.054 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.054 DEBUG [Server d1205b0345204ad86a] pn=1 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1305 }
server  | 1.054 DEBUG packet_sent this=0x5585ec123b40, pn=1, ps=1332
server  | 1.054 DEBUG ECN probing: sent 3 probes
server  | 1.054 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.054 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.054 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.054 DEBUG [Server d1205b0345204ad86a] delay duration 1.477302ms
server  | 1.054 DEBUG Setting timeout of 1.477302ms
server  | 1.055 DEBUG [Server d1205b0345204ad86a] send session ticket 40640009d1205b0345204ad86a0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0abf3ed24b973670d07676110c000000013a2a6aaa000000016ab200c0000000ff02de1a0243e8200100686921
server  | 1.055 DEBUG Path = 'segakevxya'
server  | 1.055 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.055 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.055 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.055 DEBUG [Server d1205b0345204ad86a] delay duration 419.323µs
server  | 1.055 DEBUG Setting timeout of 419.323µs
server  | 1.056 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.056 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.056 DEBUG CRYPTO for ap offset=0, len=174
server  | 1.056 DEBUG [Server d1205b0345204ad86a] pn=2 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 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.056 DEBUG packet_sent this=0x5585ec123b40, pn=2, ps=1232
server  | 1.056 DEBUG ECN probing: sent 4 probes
server  | 1.056 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.056 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.056 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.056 DEBUG [Server d1205b0345204ad86a] delay duration 1.096901ms
server  | 1.056 DEBUG Setting timeout of 1.096901ms
server  | 1.056 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.056 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.056 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.056 DEBUG [Server d1205b0345204ad86a] delay duration 1.075161ms
server  | 1.056 DEBUG Setting timeout of 1.075161ms
server  | 1.058 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.058 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.058 DEBUG CRYPTO for ap offset=174, len=131
server  | 1.058 DEBUG [Server d1205b0345204ad86a] pn=3 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 207
server  |   TX -> Crypto { offset: 174, len: 131 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 102, 114, 186, 100, 167, 175, 171, 106, 129, 173, 81, 48, 201, 206, 169, 62, 177, 77, 234, 113, 65, 151, 19, 217, 145, 137, 243, 83, 110, 114, 184, 226, 3, 212, 240, 101] }
server  | 1.058 DEBUG packet_sent this=0x5585ec123b40, pn=3, ps=207
server  | 1.058 DEBUG ECN probing: sent 5 probes
server  | 1.058 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.058 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.058 DEBUG [Server d1205b0345204ad86a] delay duration 117.684088ms
server  | 1.058 DEBUG Setting timeout of 117.684088ms
server  | 1.058 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.058 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.058 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.058 DEBUG [Server d1205b0345204ad86a] delay duration 117.660373ms
server  | 1.058 DEBUG Setting timeout of 117.660373ms
client  | /logs/4D88C199B423E529.keys
client  | /logs/keys.log exists
server  | 1.086 DEBUG [Server d1205b0345204ad86a] pn=4 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect1) len 34
server  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 6, first_ack_range: 1, ack_ranges: [], ecn_count: None }
server  | 1.086 DEBUG [Server d1205b0345204ad86a] Rx ACK space=ap, ranges=[0..=1]
server  | 1.086 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1
server  | 1.086 DEBUG on_packets_acked this=0x5585ec123b40, limited=1, bytes_in_flight=1439, cwnd=12320, state=SlowStart, new_acked=2612
server  | 1.086 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.086 DEBUG PMTUD started with probe size 1420
server  | 1.086 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.086 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.086 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.086 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.086 DEBUG [Server d1205b0345204ad86a] pn=4 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Padding { len: 1345 }
server  | 1.086 DEBUG packet_sent this=0x5585ec123b40, pn=4, ps=1372
server  | 1.086 DEBUG ECN probing: sent 6 probes
server  | 1.087 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.087 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG [Server d1205b0345204ad86a] delay duration 92.514405ms
server  | 1.087 DEBUG Setting timeout of 92.514405ms
server  | 1.087 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.087 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.087 DEBUG [Server d1205b0345204ad86a] delay duration 92.492313ms
server  | 1.087 DEBUG Setting timeout of 92.492313ms
server  | 1.087 DEBUG [Server d1205b0345204ad86a] pn=5 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect1) len 34
server  |   -> RX Ack { largest_acknowledged: 2, ack_delay: 6, first_ack_range: 2, ack_ranges: [], ecn_count: None }
server  | 1.088 DEBUG [Server d1205b0345204ad86a] Rx ACK space=ap, ranges=[0..=2]
server  | 1.088 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2
server  | 1.088 DEBUG on_packets_acked this=0x5585ec123b40, limited=1, bytes_in_flight=1579, cwnd=12320, state=SlowStart, new_acked=1232
server  | 1.088 DEBUG Acked crypto frame space=ap offset=0 length=174
server  | 1.088 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.088 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.088 DEBUG [Server d1205b0345204ad86a] pn=5 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 28
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  | 1.088 DEBUG packet_sent this=0x5585ec123b40, pn=5, ps=29
server  | 1.088 DEBUG ECN probing: sent 7 probes
server  | 1.088 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.088 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.088 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.088 DEBUG [Server d1205b0345204ad86a] delay duration 85.328297ms
server  | 1.088 DEBUG Setting timeout of 85.328297ms
server  | 1.088 DEBUG [Server d1205b0345204ad86a] pn=6 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect1) len 32
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  | 1.088 INFO [Server d1205b0345204ad86a] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 1.088 DEBUG [Server d1205b0345204ad86a] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 287, tv_nsec: 526108783 } }
server  | 1.088 DEBUG [pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900] Path validated Instant { tv_sec: 287, tv_nsec: 269735233 }
server  | 1.088 DEBUG [Server d1205b0345204ad86a] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.088 DEBUG Building Short dcid Some(CID [8]: 4d88c199b423e529)
server  | 1.088 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 287, tv_nsec: 269735233 }
server  | 1.088 DEBUG [Server d1205b0345204ad86a] pn=6 type=Short pri-path:4d88c199b423e529 [::]:443->[::ffff:193.167.0.100]:49900 IpTos(Cs0, Ect0) len 38
server  |   TX -> Ack { largest_acknowledged: 6, 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: 28, reason_phrase: "" }
server  | 1.088 DEBUG ECN probing: sent 8 probes
server  | 1.088 DEBUG Setting timeout of 256.029796ms
server  | 1.088 DEBUG Setting timeout of 256.020228ms

client exited with code 0
Aborting on container exit...
 Container server  Stopping
 Container client  Stopping
 Container client  Stopped
 Container server  Stopped
 Container sim  Stopping
 Container sim  Stopped

2025-04-30 12:23:49,367 Using the client's key log file.
2025-04-30 12:23:49,376 
2025-04-30 12:23:49,376 Using the client's key log file.
2025-04-30 12:23:49,376 Using the client's key log file.
2025-04-30 12:23:49,384 
2025-04-30 12:23:49,384 Using the client's key log file.
2025-04-30 12:23:49,384 Using selector: EpollSelector
2025-04-30 12:23:49,768 Check of downloaded files succeeded.