2025-04-30 10:22:10,151 Generated random file: wssugyblsh of size: 1024
2025-04-30 10:22:10,151 Requests: https://server4:443/wssugyblsh
2025-04-30 10:22:10,208 
2025-04-30 10:22:10,208 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_yq_490fx/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_1ln0qc4q/ DOWNLOADS=/tmp/download_tnbrfb3c/ SERVER_LOGS=/tmp/logs_server_x2pybg3d CLIENT_LOGS=/tmp/logs_client_4mypi8qc 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/wssugyblsh"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 10:22:22,410  Container sim  Recreate
 Container sim  Recreated
 Container server  Recreate
 Container client  Recreate
 Container server  Recreated
 Container client  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
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  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
client  | Endpoint's IPv4 address is 193.167.0.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::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.AbP6SYl7Nr
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.AbP6SYl7Nr
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.AbP6SYl7Nr -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  |             66:07:ce:f9:41:9a:6d:0f:08:cf:56:fc:fd:e2:43:e4:
server  |             85:7b:72:f9
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:22:10 2025
server  |             Not After : Sat May 10 10:22:10 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:80:74:77:dc:c0:36:d5:53:d2:41:ed:07:df:20:89:
server  |                     cc:b4:b5:5d:17:5f:8e:a3:62:b1:e3:e2:d8:26:5a:42:
server  |                     4f:12:5f:1a:23:7b:ef:f9:f8:c5:85:37:9f:cf:e1:7e:
server  |                     8d:46:43:d9:06:72:fe:d3:c1:2b:e5:79:9c:03:89:7e:
server  |                     71
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  |                 c0:07:a4:8d:a5:e8:df:8e:80:25:63:a5:96:22:7c:36:
server  |                 1b:35:e1:40
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 25:fd:ec:3e:6a:0b:40:7d:19:a9:d0:22:2f:70:a6:03:
server  |                 9d:de:b0:37
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:45:02:21:00:b9:a7:d8:00:e9:a4:2a:2b:b7:53:de:
server  |         c0:4a:ae:f1:0b:db:cd:80:8e:e3:55:5d:25:bb:35:23:
server  |         f5:71:da:cc:1b:02:20:3b:42:c4:57:3e:bd:a2:5d:13:
server  |         d0:e2:e9:40:00:cf:b8:32:25:32:c7:57:8a:c1:1b:92:
server  |         45:05:9b:79:ec:c1:6f
server  |     Fingerprint (SHA-256):
server  |         48:D6:7E:84:24:D5:C4:D9:08:F6:3E:B0:E0:B9:8E:1E:65:B4:69:BD:5C:34:E3:40:77:62:24:6C:84:F7:B5:40
server  |     Fingerprint (SHA1):
server  |         2A:64:B8:A7:67:65:F9:59:E7:02:62:79:74:BA:A0:E8:E3:13:75:75
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.774 DEBUG [Server] Unsupported version: 57414954
server  | 0.774 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52502 IpTos(Cs0, NotEct) len 15
server  | 0.775 DEBUG [Server] Unsupported version: 57414954
sim     | server:443 is available after 1.019493099s
server  | 0.775 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52502 IpTos(Cs0, NotEct) len 15
server  | 0.775 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.775 DEBUG [Server] Unsupported version: 57414954
server  | 0.775 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:52502 IpTos(Cs0, NotEct) len 15
server  | 0.775 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: listening on 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.057 DEBUG [Server] Handle initial
server  | 1.057 INFO AddressValidation: no token; accepting
server  | 1.057 INFO [Server] Accept connection CID [18]: 11728d6167e573583e7c8f98fe2f8504b850
server  | 1.057 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.059 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.059 INFO [Server ...] Received valid Initial packet with scid CID [17]: 410ee45ff69690cb98521dfd9d924ec03b dcid CID [18]: 11728d6167e573583e7c8f98fe2f8504b850
server  | 1.059 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=11728d6167e573583e7c8f98fe2f8504b850
server  | 1.059 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.059 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.059 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] State change from Init -> WaitInitial
server  | 1.059 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329678 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 1200
server  |   -> RX Crypto { offset: 0, len: 263 }
server  |   -> RX Padding { len: 866 }
server  | 1.059 DEBUG Read Ok(263) bytes
server  | 1.059 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.059 DEBUG Read secret available for Handshake: SymKey [32]: b4059d59d12cc00763a336a7ac1fb56dccb4c7c542b415205e38578947e871f9
server  | 1.059 DEBUG Write secret available for Handshake: SymKey [32]: e4df1b99dbf1c14f3fe3263a1f2199054450c55e241639091ed5151d97f0bf04
server  | 1.059 DEBUG Writing transport parameters, msg=8
server  | 1.060 DEBUG Read secret available for ApplicationData: SymKey [32]: 480c96bcd9ff0b02ae43c24a55d2c280e22f9bd59fdcb708485b243d9dbbe74f
server  | 1.060 DEBUG Write secret available for ApplicationData: SymKey [32]: b183b1d3ab319dedda409ede9c07990374408ca654e7ad0d1a715efd1ef2b1f7
server  | 1.060 DEBUG [Agent 0x563d023491d0] state -> InProgress
server  | 1.060 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.060 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.060 DEBUG [Crypto] Handshake keys installed
server  | 1.060 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.060 DEBUG [Crypto] Application write key installed
server  | 1.060 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 155, tv_nsec: 781928526 }
server  | 1.060 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:39608] Make permanent
server  | 1.060 DEBUG [unv-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608] set as primary path
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] State change from WaitInitial -> Handshaking
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.060 DEBUG Building Initial dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b) scid Some(CID [10]: c031891b7834c444d2ea)
server  | 1.060 DEBUG CRYPTO for in offset=0, len=90
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=0 type=Initial pri-unv-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 163
server  |   TX -> Ack { largest_acknowledged: 1416329678, 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.060 DEBUG Building Handshake dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b) scid Some(CID [10]: c031891b7834c444d2ea)
server  | 1.060 DEBUG CRYPTO for hs offset=0, len=736
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=0 type=Handshake pri-unv-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 956
server  |   TX -> Crypto { offset: 0, len: 736 }
server  | 1.060 DEBUG packet_sent this=0x563d02348b40, pn=0, ps=793
server  | 1.060 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pad Initial from 956 to PLPMTU 1232
server  | 1.060 DEBUG packet_sent this=0x563d02348b40, pn=0, ps=439
server  | 1.060 DEBUG ECN probing: sent 1 probes
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.060 DEBUG Building Initial dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b) scid Some(CID [10]: c031891b7834c444d2ea)
server  | 1.060 DEBUG Building Handshake dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b) scid Some(CID [10]: c031891b7834c444d2ea)
server  | 1.060 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.060 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 296.836243ms
server  | 1.060 DEBUG Setting timeout of 296.836243ms
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.060 DEBUG Building Initial dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b) scid Some(CID [10]: c031891b7834c444d2ea)
server  | 1.060 DEBUG Building Handshake dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b) scid Some(CID [10]: c031891b7834c444d2ea)
server  | 1.060 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.060 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.060 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 296.803471ms
server  | 1.060 DEBUG Setting timeout of 296.803471ms
server  | 1.094 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329679 type=Initial pri-unv-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 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.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] Rx ACK space=in, ranges=[0..=0]
server  | 1.095 DEBUG [LossRecovery] ACK for Initial - largest_acked=0
server  | 1.095 DEBUG on_packets_acked this=0x563d02348b40, limited=1, bytes_in_flight=793, cwnd=12320, state=SlowStart, new_acked=439
server  | 1.095 DEBUG Acked crypto frame space=in offset=0 length=90
server  | 1.095 DEBUG [pri-unv-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608] Path validated Instant { tv_sec: 155, tv_nsec: 819390217 }
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] Drop packet number space in
server  | 1.095 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329678 type=Handshake pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 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.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] Rx ACK space=hs, ranges=[0..=0]
server  | 1.095 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.095 DEBUG on_packets_acked this=0x563d02348b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=793
server  | 1.095 DEBUG Acked crypto frame space=hs offset=0 length=736
server  | 1.095 DEBUG Read Ok(36) bytes
server  | 1.095 DEBUG [Agent 0x563d023491d0] 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.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] TLS connection complete
server  | 1.095 DEBUG [pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608] Path validated Instant { tv_sec: 155, tv_nsec: 819390217 }
server  | 1.095 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.095 DEBUG [Crypto] application read keys installed
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] State change from Handshaking -> Connected
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] State change from Connected -> Confirmed
server  | 1.095 DEBUG PMTUD started with probe size 1380
server  | 1.095 INFO [Server 11728d6167e573583e7c8f98fe2f8504b850] Connection established
server  | 1.095 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 155, tv_nsec: 819390217 }
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329678 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 1031
server  |   -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [248, 104, 78, 144, 208, 12, 166, 199, 162, 155, 37, 43, 78, 46, 179, 220, 90], stateless_reset_token: [28, 197, 205, 218, 30, 177, 59, 190, 19, 158, 20, 134, 75, 113, 126, 17] }
server  |   -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [4, 249, 59, 180, 212, 147, 243, 219, 37, 122, 176, 80, 132, 216, 134, 13, 161], stateless_reset_token: [160, 255, 156, 183, 182, 221, 18, 2, 95, 74, 238, 45, 148, 203, 159, 198] }
server  |   -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [21, 246, 224, 229, 64, 213, 105, 141, 40, 43, 20, 11, 41, 146, 215, 60, 188], stateless_reset_token: [217, 53, 16, 12, 42, 204, 112, 86, 186, 72, 88, 166, 58, 189, 41, 166] }
server  |   -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [131, 94, 87, 237, 44, 95, 196, 93, 129, 122, 60, 91, 63, 135, 156, 227, 224], stateless_reset_token: [200, 42, 248, 79, 140, 149, 86, 72, 219, 134, 62, 102, 8, 231, 202, 116] }
server  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [102, 213, 70, 83, 55, 253, 29, 241, 128, 147, 138, 195, 147, 75, 121, 195, 82], stateless_reset_token: [168, 29, 27, 196, 203, 30, 205, 135, 217, 157, 102, 76, 83, 138, 175, 238] }
server  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [117, 145, 14, 108, 61, 237, 245, 161, 151, 204, 138, 167, 34, 39, 216, 143, 187], stateless_reset_token: [113, 76, 41, 114, 57, 131, 45, 127, 240, 110, 206, 98, 155, 168, 104, 113] }
server  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [162, 18, 15, 116, 52, 226, 7, 195, 205, 54, 95, 49, 214, 128, 77, 24, 206], stateless_reset_token: [171, 76, 41, 47, 104, 52, 219, 149, 212, 105, 89, 173, 194, 160, 88, 206] }
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  |   -> RX Padding { len: 721 }
server  | 1.095 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 155, tv_nsec: 819390217 }
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.095 DEBUG Building Handshake dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b) scid Some(CID [10]: c031891b7834c444d2ea)
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1 type=Handshake pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 68
server  |   TX -> Ack { largest_acknowledged: 1416329678, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] Drop packet number space hs
server  | 1.095 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.095 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=0 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ack { largest_acknowledged: 1416329678, 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: [114, 67, 221, 204, 42, 197, 165, 194, 195, 170], stateless_reset_token: [222, 8, 249, 20, 151, 12, 20, 75, 87, 242, 246, 193, 224, 25, 166, 212] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [44, 32, 149, 12, 193, 194, 167, 179, 64, 92], stateless_reset_token: [70, 214, 232, 141, 75, 161, 30, 42, 55, 110, 113, 187, 205, 199, 64, 144] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [124, 67, 29, 247, 131, 180, 112, 66, 47, 116], stateless_reset_token: [75, 96, 63, 62, 82, 25, 155, 132, 37, 21, 240, 138, 227, 6, 133, 75] }
server  |   TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [115, 212, 189, 111, 238, 24, 238, 27, 242, 200], stateless_reset_token: [90, 34, 151, 210, 170, 4, 222, 22, 127, 242, 67, 203, 245, 229, 199, 54] }
server  |   TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [65, 119, 202, 92, 223, 214, 190, 145, 71, 86], stateless_reset_token: [83, 169, 111, 230, 152, 81, 218, 91, 89, 243, 167, 136, 146, 99, 225, 236] }
server  |   TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [54, 127, 99, 242, 26, 160, 250, 186, 189, 95], stateless_reset_token: [17, 108, 195, 58, 73, 164, 51, 231, 235, 73, 154, 253, 116, 159, 152, 187] }
server  |   TX -> Padding { len: 1033 }
server  | 1.095 DEBUG packet_sent this=0x563d02348b40, pn=0, ps=1264
server  | 1.095 DEBUG ECN probing: sent 2 probes
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.095 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.095 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1296 }
server  | 1.095 DEBUG packet_sent this=0x563d02348b40, pn=1, ps=1332
server  | 1.095 DEBUG ECN probing: sent 3 probes
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.095 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.095 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.095 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 1.286877ms
server  | 1.095 DEBUG Setting timeout of 1.286877ms
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] send session ticket 406d001211728d6167e573583e7c8f98fe2f8504b8500104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0ac031891b7834c444d2ea110c000000017a7a7a5a000000016ab200c0000000ff02de1a0243e8200100686921
server  | 1.096 DEBUG Path = 'wssugyblsh'
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.096 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 299.644µs
server  | 1.096 DEBUG Setting timeout of 299.644µs
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329679 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 1406
server  |   -> RX Ping
server  |   -> RX Padding { len: 1374 }
server  | 1.096 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 155, tv_nsec: 821199022 }
server  | 1.096 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 155, tv_nsec: 821199022 }
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.096 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=2 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 50
server  |   TX -> Ack { largest_acknowledged: 1416329679, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) }
server  | 1.096 DEBUG ECN probing: sent 4 probes
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.096 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.096 DEBUG CRYPTO for ap offset=0, len=165
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=3 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 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=0x563d02348b40, pn=3, ps=1232
server  | 1.096 DEBUG ECN probing: sent 5 probes
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.096 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 1.811969ms
server  | 1.096 DEBUG Setting timeout of 1.811969ms
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.096 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.096 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 1.792453ms
server  | 1.096 DEBUG Setting timeout of 1.792453ms
server  | 1.099 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.099 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.099 DEBUG CRYPTO for ap offset=165, len=156
server  | 1.099 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=4 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 241
server  |   TX -> Crypto { offset: 165, len: 156 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 228, 144, 60, 114, 96, 244, 195, 56, 180, 220, 10, 89, 169, 152, 73, 25, 170, 24, 135, 57, 15, 131, 95, 168, 39, 38, 141, 125, 17, 55, 70, 229, 130, 35, 87, 143] }
server  | 1.099 DEBUG packet_sent this=0x563d02348b40, pn=4, ps=241
server  | 1.099 DEBUG ECN probing: sent 6 probes
server  | 1.099 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.099 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.099 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.099 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 118.546571ms
server  | 1.099 DEBUG Setting timeout of 118.546571ms
server  | 1.099 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.099 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.099 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.099 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 118.522837ms
server  | 1.099 DEBUG Setting timeout of 118.522837ms
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329680 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 1444
server  |   -> RX Ping
server  |   -> RX Padding { len: 1415 }
server  | 1.129 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 155, tv_nsec: 854046982 }
server  | 1.129 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 155, tv_nsec: 854046982 }
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.129 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=5 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 50
server  |   TX -> Ack { largest_acknowledged: 1416329680, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
server  | 1.129 DEBUG ECN probing: sent 7 probes
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.129 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.129 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 87.869735ms
server  | 1.129 DEBUG Setting timeout of 87.869735ms
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329681 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 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.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] Rx ACK space=ap, ranges=[0..=2]
server  | 1.129 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2
server  | 1.129 DEBUG on_packets_acked this=0x563d02348b40, limited=1, bytes_in_flight=1473, cwnd=12320, state=SlowStart, new_acked=2596
server  | 1.129 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.129 DEBUG PMTUD started with probe size 1420
server  | 1.129 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.129 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.129 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=6 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Padding { len: 1336 }
server  | 1.129 DEBUG packet_sent this=0x563d02348b40, pn=6, ps=1372
server  | 1.129 DEBUG ECN probing: sent 8 probes
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.129 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.129 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] delay duration 108.356506ms
server  | 1.129 DEBUG Setting timeout of 108.356506ms
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=1416329682 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 39
server  |   -> RX ConnectionClose { error_code: Transport(0), frame_type: 0, reason_phrase: "" }
server  |   -> RX Padding { len: 7 }
server  | 1.129 INFO [Server 11728d6167e573583e7c8f98fe2f8504b850] ConnectionClose received. Error code: Transport(0) frame type 0 reason 
server  | 1.129 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] State change from Confirmed -> Draining { error: Transport(PeerError(0)), timeout: Instant { tv_sec: 156, tv_nsec: 179770859 } }
server  | 1.130 DEBUG [pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608] Path validated Instant { tv_sec: 155, tv_nsec: 854386680 }
server  | 1.130 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.130 DEBUG Building Short dcid Some(CID [17]: 410ee45ff69690cb98521dfd9d924ec03b)
server  | 1.130 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 155, tv_nsec: 854386680 }
server  | 1.130 DEBUG [Server 11728d6167e573583e7c8f98fe2f8504b850] pn=7 type=Short pri-path:410ee45ff69690cb98521dfd9d924ec03b [::]:443->[::ffff:193.167.0.100]:39608 IpTos(Cs0, Ect0) len 54
server  |   TX -> Ack { largest_acknowledged: 1416329682, 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.130 DEBUG ECN probing: sent 9 probes
server  | 1.130 DEBUG Setting timeout of 325.294391ms
server  | 1.130 DEBUG Setting timeout of 325.286266ms

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:22:22,507 Using the client's key log file.
2025-04-30 10:22:22,516 
2025-04-30 10:22:22,517 Using the client's key log file.
2025-04-30 10:22:22,517 Using the client's key log file.
2025-04-30 10:22:22,525 
2025-04-30 10:22:22,526 Using the client's key log file.
2025-04-30 10:22:22,526 Using selector: EpollSelector
2025-04-30 10:22:22,826 Check of downloaded files succeeded.