2025-04-30 11:53:48,743 Generated random file: lipgjmcajs of size: 1024
2025-04-30 11:53:48,743 Requests: https://server4:443/lipgjmcajs
2025-04-30 11:53:48,801 
2025-04-30 11:53:48,802 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_nossa5g6/ TESTCASE_SERVER=v2 TESTCASE_CLIENT=v2 WWW=/tmp/www_3jdenee5/ DOWNLOADS=/tmp/download_u7mam4iz/ SERVER_LOGS=/tmp/logs_server_qx96u_xf CLIENT_LOGS=/tmp/logs_client_iqj3if40 SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/microsoft/msquic/qns:main SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server4:443/lipgjmcajs"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 11:54:05,798  Container sim  Created
 Container client  Recreate
 Container server  Recreate
 Container server  Recreated
 Container client  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
client  | Setting up routes...
client  | Actual changes:
server  | Setting up routes...
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]
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
client  | Endpoint's IPv4 address is 193.167.0.100
server  | Endpoint's IPv4 address is 193.167.100.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
server  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
server  | + '[' -n v2 ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.lUQfgbtjnk
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.lUQfgbtjnk
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.lUQfgbtjnk -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  |             7a:0f:ec:8a:fa:32:7e:ed:d4:b4:db:be:c1:71:fe:8b:
server  |             6d:7f:30:b1
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 11:53:48 2025
server  |             Not After : Sat May 10 11:53:48 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:0c:11:8b:63:81:35:2e:36:f2:24:33:c4:a4:2d:54:
server  |                     41:01:5a:24:d4:a8:47:c0:d3:5f:1c:b2:11:f3:40:fb:
server  |                     54:bd:ec:41:b5:10:92:9d:1e:99:b9:96:86:b1:e2:b3:
server  |                     ac:85:1c:19:48:ad:2c:0f:e1:b2:76:3f:e2:6a:17:30:
server  |                     5a
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  |                 6b:76:bc:ef:c4:41:c2:21:72:af:98:5c:e4:35:cb:ae:
server  |                 8f:49:24:c5
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 e1:f8:ec:0a:e4:64:86:df:1c:aa:a6:bf:65:f9:fa:bb:
server  |                 7a:c8:c9:22
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:45:02:21:00:fc:f5:98:11:7d:fd:e7:1d:39:3a:86:
server  |         04:be:94:a5:b3:d5:fe:ad:a7:90:ca:da:f9:eb:fb:38:
server  |         df:db:8a:d7:81:02:20:4f:52:f9:2e:c9:00:c5:f1:73:
server  |         cd:27:7a:44:bd:9b:0d:63:9f:d2:05:1c:60:3d:50:4e:
server  |         1c:ee:71:97:ab:37:c0
server  |     Fingerprint (SHA-256):
server  |         14:D3:21:4F:B9:6B:DA:FB:66:31:43:2D:49:DF:9D:AF:18:E8:35:98:B4:A5:C9:33:8D:88:38:FA:DA:2B:4E:42
server  |     Fingerprint (SHA1):
server  |         09:92:04:C2:AE:6A:93:56:FD:78:CC:2B:D4:FD:B6:87:27:05:B2:90
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
sim     | server:443 is available after 1.048022868s
server  | 0.790 DEBUG [Server] Unsupported version: 57414954
server  | 0.790 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:35076 IpTos(Cs0, NotEct) len 23
server  | 0.791 DEBUG [Server] Unsupported version: 57414954
server  | 0.791 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:35076 IpTos(Cs0, NotEct) len 23
server  | 0.791 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.791 DEBUG [Server] Unsupported version: 57414954
server  | 0.791 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:35076 IpTos(Cs0, NotEct) len 23
server  | 0.791 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  | Connecting to server4
client  | Client params (before files):-test:2 -sslkeylogfile:/logs/keys.log 
server  | 1.008 DEBUG [Server] Handle initial
server  | 1.008 INFO AddressValidation: no token; accepting
server  | 1.008 INFO [Server] Accept connection CID [8]: af9a52d117690beb
server  | 1.008 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.010 DEBUG Outbound interface eth0 for destination ::ffff:193.167.0.100 has MTU 1500
server  | 1.010 INFO [Server ...] Received valid Initial packet with scid CID [0]:  dcid CID [8]: af9a52d117690beb
server  | 1.010 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=af9a52d117690beb
server  | 1.010 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.010 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.010 DEBUG [Server af9a52d117690beb] State change from Init -> WaitInitial
server  | 1.010 DEBUG [Server af9a52d117690beb] pn=0 type=Initial unv-path [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 1220
server  |   -> RX Crypto { offset: 0, len: 311 }
server  |   -> RX Padding { len: 867 }
server  | 1.010 DEBUG Read Ok(311) bytes
server  | 1.010 INFO Compatible upgrade Version1 ==> Version2
server  | 1.010 DEBUG Overwrite initial version Version1 ==> Version2
server  | 1.010 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.010 DEBUG Read secret available for Handshake: SymKey [32]: 5de3d61a551e54446fc67bd1a3e59bea719a21ff54d4a295af20d60bc1b96495
server  | 1.010 DEBUG Write secret available for Handshake: SymKey [32]: c0e34a6ffdac318ff57571e61ae8d54ce7e4a106d7aec9417dc7daab21dbd4b3
server  | 1.010 DEBUG Writing transport parameters, msg=8
server  | 1.011 DEBUG Read secret available for ApplicationData: SymKey [32]: 4f545d0a22ae85668045cf6d29f7a5c07db34011d208f5ac15ab31577909704e
server  | 1.011 DEBUG Write secret available for ApplicationData: SymKey [32]: fe566192ece3f4ad309661c0ca402fb72c8890f89e7e4c4474f94dd023d6c32a
server  | 1.011 DEBUG [Agent 0x55e218b111e0] state -> InProgress
server  | 1.011 DEBUG [CryptoStates] Creating initial cipher state v=Version2, role=Server dcid=af9a52d117690beb
server  | 1.011 DEBUG Making Write Initial CryptoDxState, v=Version2 cipher=4865
server  | 1.011 DEBUG Making Read Initial CryptoDxState, v=Version2 cipher=4865
server  | 1.011 DEBUG [Server af9a52d117690beb] Compatible upgrade Version1 ==> Version2
server  | 1.011 DEBUG Making Write Handshake CryptoDxState, v=Version2 cipher=4865
server  | 1.011 DEBUG Making Read Handshake CryptoDxState, v=Version2 cipher=4865
server  | 1.011 DEBUG [Crypto] Handshake keys installed
server  | 1.011 DEBUG Making Write ApplicationData CryptoDxState, v=Version2 cipher=4865
server  | 1.011 DEBUG [Crypto] Application write key installed
server  | 1.011 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 743, tv_nsec: 167954039 }
server  | 1.011 DEBUG [unv-path [::]:443->[::ffff:193.167.0.100]:60190] Make permanent
server  | 1.011 DEBUG [unv-path: [::]:443->[::ffff:193.167.0.100]:60190] set as primary path
server  | 1.011 DEBUG [Server af9a52d117690beb] State change from WaitInitial -> Handshaking
server  | 1.011 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.011 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: a24037b2e8d05ceb6ac4)
server  | 1.011 DEBUG CRYPTO for in offset=0, len=90
server  | 1.011 DEBUG [Server af9a52d117690beb] pn=0 type=Initial pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 136
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  |   TX -> Crypto { offset: 0, len: 90 }
server  | 1.011 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: a24037b2e8d05ceb6ac4)
server  | 1.011 DEBUG CRYPTO for hs offset=0, len=734
server  | 1.011 DEBUG [Server af9a52d117690beb] pn=0 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 910
server  |   TX -> Crypto { offset: 0, len: 734 }
server  | 1.011 DEBUG packet_sent this=0x55e218b10b20, pn=0, ps=774
server  | 1.011 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.011 DEBUG [Server af9a52d117690beb] pad Initial from 910 to PLPMTU 1232
server  | 1.011 DEBUG packet_sent this=0x55e218b10b20, pn=0, ps=458
server  | 1.011 DEBUG ECN probing: sent 1 probes
server  | 1.011 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.011 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: a24037b2e8d05ceb6ac4)
server  | 1.011 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: a24037b2e8d05ceb6ac4)
server  | 1.011 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.011 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.011 DEBUG [Server af9a52d117690beb] delay duration 296.906588ms
server  | 1.011 DEBUG Setting timeout of 296.906588ms
server  | 1.011 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.011 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: a24037b2e8d05ceb6ac4)
server  | 1.011 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: a24037b2e8d05ceb6ac4)
server  | 1.011 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.011 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.011 DEBUG [Server af9a52d117690beb] delay duration 296.872084ms
server  | 1.011 DEBUG Setting timeout of 296.872084ms
client  | Sending request: GET /lipgjmcajs

server  | 1.043 DEBUG [Server af9a52d117690beb] Drop packet number space in
server  | 1.043 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.043 INFO [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60190] discarding a packet without an RTT estimate; guessing RTT=35.319653ms
server  | 1.043 DEBUG [Server af9a52d117690beb] pn=1 type=Handshake pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 86
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 1, 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.043 DEBUG [Server af9a52d117690beb] Rx ACK space=hs, ranges=[0..=0]
server  | 1.043 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.043 DEBUG on_packets_acked this=0x55e218b10b20, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=774
server  | 1.043 DEBUG Acked crypto frame space=hs offset=0 length=734
server  | 1.043 DEBUG Read Ok(36) bytes
server  | 1.044 DEBUG [Agent 0x55e218b111e0] 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.044 DEBUG [Server af9a52d117690beb] TLS connection complete
server  | 1.044 DEBUG [pri-unv-path: [::]:443->[::ffff:193.167.0.100]:60190] Path validated Instant { tv_sec: 743, tv_nsec: 203273692 }
server  | 1.044 DEBUG Making Read ApplicationData CryptoDxState, v=Version2 cipher=4865
server  | 1.044 DEBUG [Crypto] application read keys installed
server  | 1.044 DEBUG [Server af9a52d117690beb] State change from Handshaking -> Connected
server  | 1.044 DEBUG [Server af9a52d117690beb] State change from Connected -> Confirmed
server  | 1.044 DEBUG PMTUD started with probe size 1380
server  | 1.044 INFO [Server af9a52d117690beb] Connection established
server  | 1.044 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 743, tv_nsec: 203273692 }
server  | 1.044 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: a24037b2e8d05ceb6ac4)
server  | 1.044 DEBUG [Server af9a52d117690beb] pn=1 type=Handshake pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 41
server  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 1.044 DEBUG [Server af9a52d117690beb] Drop packet number space hs
server  | 1.044 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.044 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.044 DEBUG [Server af9a52d117690beb] pn=0 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [23, 156, 155, 64, 28, 157, 13, 234, 74, 179], stateless_reset_token: [183, 183, 95, 41, 90, 60, 215, 173, 13, 213, 216, 29, 24, 232, 34, 22] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [31, 170, 191, 33, 190, 187, 104, 150, 189, 109], stateless_reset_token: [175, 6, 153, 169, 208, 184, 238, 61, 169, 187, 167, 166, 83, 236, 141, 116] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [149, 100, 149, 125, 19, 174, 245, 227, 239, 49], stateless_reset_token: [71, 143, 50, 20, 164, 237, 247, 218, 73, 65, 71, 193, 40, 114, 54, 126] }
server  |   TX -> Padding { len: 1182 }
server  | 1.044 DEBUG packet_sent this=0x55e218b10b20, pn=0, ps=1291
server  | 1.044 DEBUG ECN probing: sent 2 probes
server  | 1.044 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.044 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.044 DEBUG [Server af9a52d117690beb] pn=1 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1313 }
server  | 1.044 DEBUG packet_sent this=0x55e218b10b20, pn=1, ps=1332
server  | 1.044 DEBUG ECN probing: sent 3 probes
server  | 1.044 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.044 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.044 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.044 DEBUG [Server af9a52d117690beb] delay duration 1.492955ms
server  | 1.044 DEBUG Setting timeout of 1.492955ms
server  | 1.045 DEBUG [Server af9a52d117690beb] send session ticket 406b0008af9a52d117690beb0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0aa24037b2e8d05ceb6ac411146b3343cf7a8acaca6b3343cf00000001ff00001d6ab200c0000000ff02de1a0243e8200100686921
server  | 1.045 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.045 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.045 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.045 DEBUG [Server af9a52d117690beb] delay duration 499.515µs
server  | 1.045 DEBUG Setting timeout of 499.515µs
server  | 1.045 DEBUG [Server af9a52d117690beb] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 1252
server  |   -> RX Ping
server  |   -> RX Padding { len: 1220 }
server  | 1.045 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 743, tv_nsec: 204804057 }
server  | 1.045 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 743, tv_nsec: 204804057 }
server  | 1.045 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.045 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.045 DEBUG [Server af9a52d117690beb] pn=2 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 23
server  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: None }
server  | 1.045 DEBUG ECN probing: sent 4 probes
server  | 1.045 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.045 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.045 DEBUG CRYPTO for ap offset=0, len=321
server  | 1.045 DEBUG [Server af9a52d117690beb] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 388
server  |   TX -> Crypto { offset: 0, len: 321 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 177, 201, 222, 8, 97, 57, 202, 178, 135, 82, 90, 188, 187, 152, 194, 221, 246, 1, 218, 169, 4, 40, 32, 161, 64, 83, 169, 252, 233, 35, 190, 24, 61, 190, 45, 233] }
server  | 1.045 DEBUG packet_sent this=0x55e218b10b20, pn=3, ps=388
server  | 1.045 DEBUG ECN probing: sent 5 probes
server  | 1.045 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.045 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.045 DEBUG [Server af9a52d117690beb] delay duration 114.125466ms
server  | 1.045 DEBUG Setting timeout of 114.125466ms
server  | 1.045 DEBUG [Server af9a52d117690beb] pn=3 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 35
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 0, fin: false }
server  | 1.045 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 743, tv_nsec: 225087506 }
server  | 1.045 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.045 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.045 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.045 DEBUG [Server af9a52d117690beb] delay duration 20ms
server  | 1.045 DEBUG Setting timeout of 20ms
server  | 1.045 DEBUG [Server af9a52d117690beb] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 52
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  | 1.045 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 743, tv_nsec: 205246695 }
server  | 1.045 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.045 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.045 DEBUG [Server af9a52d117690beb] pn=4 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 23
server  |   TX -> Ack { largest_acknowledged: 4, ack_delay: 0, first_ack_range: 2, ack_ranges: [], ecn_count: None }
server  | 1.045 DEBUG ECN probing: sent 6 probes
server  | 1.046 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.046 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.046 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.046 DEBUG [Server af9a52d117690beb] delay duration 113.721438ms
server  | 1.046 DEBUG Setting timeout of 113.721438ms
server  | 1.046 DEBUG Path = 'lipgjmcajs'
server  | 1.046 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.046 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.046 DEBUG [Server af9a52d117690beb] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 1046
server  |   TX -> Stream { stream_id: 0, offset: 0, len: 1024, fin: true }
server  | 1.046 DEBUG packet_sent this=0x55e218b10b20, pn=5, ps=1046
server  | 1.046 DEBUG ECN probing: sent 7 probes
server  | 1.046 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.046 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.046 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.046 DEBUG [Server af9a52d117690beb] delay duration 1.713264ms
server  | 1.046 DEBUG Setting timeout of 1.713264ms
server  | 1.049 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.049 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG [Server af9a52d117690beb] delay duration 111.159841ms
server  | 1.049 DEBUG Setting timeout of 111.159841ms
server  | 1.049 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.049 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG [Server af9a52d117690beb] delay duration 111.135245ms
server  | 1.049 DEBUG Setting timeout of 111.135245ms
client  | lipgjmcajs: Wrote 1024 bytes.(0 ms/0 ms/0 ms)
client  | lipgjmcajs: Completed download! (0 ms)
server  | 1.076 DEBUG [Server af9a52d117690beb] pn=5 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 39
server  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) }
server  | 1.076 DEBUG [Server af9a52d117690beb] Rx ACK space=ap, ranges=[0..=1]
server  | 1.076 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1
server  | 1.076 DEBUG on_packets_acked this=0x55e218b10b20, limited=1, bytes_in_flight=1434, cwnd=12320, state=SlowStart, new_acked=2623
server  | 1.076 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.076 DEBUG PMTUD started with probe size 1420
server  | 1.076 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.076 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.076 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.076 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.076 DEBUG [Server af9a52d117690beb] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Padding { len: 1353 }
server  | 1.076 DEBUG packet_sent this=0x55e218b10b20, pn=6, ps=1372
server  | 1.076 DEBUG ECN probing: sent 8 probes
server  | 1.076 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.076 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.076 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.076 DEBUG [Server af9a52d117690beb] delay duration 103.370109ms
server  | 1.076 DEBUG Setting timeout of 103.370109ms
server  | 1.076 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.076 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.076 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.076 DEBUG [Server af9a52d117690beb] delay duration 103.345443ms
server  | 1.076 DEBUG Setting timeout of 103.345443ms
server  | 1.077 DEBUG [Server af9a52d117690beb] pn=6 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 1332
server  |   -> RX Ping
server  |   -> RX Padding { len: 1300 }
server  | 1.077 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 743, tv_nsec: 237333894 }
server  | 1.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 743, tv_nsec: 237333894 }
server  | 1.077 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.077 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.077 DEBUG [Server af9a52d117690beb] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 23
server  |   TX -> Ack { largest_acknowledged: 6, ack_delay: 0, first_ack_range: 4, ack_ranges: [], ecn_count: None }
server  | 1.077 DEBUG ECN probing: sent 9 probes
server  | 1.078 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server af9a52d117690beb] delay duration 102.287554ms
server  | 1.078 DEBUG Setting timeout of 102.287554ms
server  | 1.078 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server af9a52d117690beb] delay duration 102.263549ms
server  | 1.078 DEBUG Setting timeout of 102.263549ms
server  | 1.078 DEBUG [Server af9a52d117690beb] pn=7 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 44
server  |   -> RX Ack { largest_acknowledged: 5, ack_delay: 0, first_ack_range: 5, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16778240 }
server  | 1.078 DEBUG [Server af9a52d117690beb] Rx ACK space=ap, ranges=[0..=5]
server  | 1.078 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=5
server  | 1.078 DEBUG on_packets_acked this=0x55e218b10b20, limited=1, bytes_in_flight=1372, cwnd=12320, state=SlowStart, new_acked=1434
server  | 1.078 DEBUG Acked crypto frame space=ap offset=0 length=321
server  | 1.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 743, tv_nsec: 257548858 }
server  | 1.078 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG [Server af9a52d117690beb] pn=8 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, Ect0) len 20
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  | 1.078 DEBUG packet_sent this=0x55e218b10b20, pn=8, ps=21
server  | 1.078 DEBUG ECN probing: sent 10 probes
server  | 1.078 DEBUG ECN probing concluded with 10 probes sent
server  | 1.078 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server af9a52d117690beb] delay duration 19.884134ms
server  | 1.078 DEBUG Setting timeout of 19.884134ms
server  | 1.078 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server af9a52d117690beb] delay duration 19.863184ms
server  | 1.078 DEBUG Setting timeout of 19.863184ms
server  | 1.078 DEBUG [Server af9a52d117690beb] pn=8 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 34
server  |   -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" }
server  | 1.078 INFO [Server af9a52d117690beb] ConnectionClose received. Error code: Application(0) frame type 0 reason 
server  | 1.078 DEBUG [Server af9a52d117690beb] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 743, tv_nsec: 524046457 } }
server  | 1.078 DEBUG [pri-path: [::]:443->[::ffff:193.167.0.100]:60190] Path validated Instant { tv_sec: 743, tv_nsec: 237757075 }
server  | 1.078 DEBUG [Server af9a52d117690beb] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.078 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 743, tv_nsec: 237757075 }
server  | 1.078 DEBUG [Server af9a52d117690beb] pn=9 type=Short pri-path: [::]:443->[::ffff:193.167.0.100]:60190 IpTos(Cs0, NotEct) len 27
server  |   TX -> Ack { largest_acknowledged: 8, ack_delay: 0, first_ack_range: 6, ack_ranges: [], ecn_count: None }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" }
server  | 1.078 DEBUG Setting timeout of 286.135093ms
server  | 1.078 DEBUG Setting timeout of 286.127298ms
client  | 
client  |       TARGET  VHDCRZSQUMBGA2E    VERSION   ALPN
client  |  ============================================
client  |      server4  -------------2-  0x6B3343CF  hq-interop
client  | 
client  | Total execution time: 0.108s
client  | 
server  | 1.365 DEBUG [Server af9a52d117690beb] State change from Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 743, tv_nsec: 524046457 } } -> Closed(Transport(PeerApplicationError(0)))
server  | 1.365 INFO Closing timer expired
client  | Client complete.
client  | Script complete.

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 11:54:05,892 Using the client's key log file.
2025-04-30 11:54:05,901 
2025-04-30 11:54:05,901 Using the client's key log file.
2025-04-30 11:54:05,901 Using the client's key log file.
2025-04-30 11:54:05,909 
2025-04-30 11:54:05,910 Using the client's key log file.
2025-04-30 11:54:07,026 Check of downloaded files succeeded.