2025-04-30 11:53:30,105 Generated random file: kfynnuzoti of size: 5120
2025-04-30 11:53:30,106 Generated random file: nkjgsnzrun of size: 10240
2025-04-30 11:53:30,106 Requests: https://server6:443/kfynnuzoti https://server6:443/nkjgsnzrun
2025-04-30 11:53:30,164 
2025-04-30 11:53:30,165 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_8hvn4qlz/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_3yyew7b3/ DOWNLOADS=/tmp/download_m39nz9_f/ SERVER_LOGS=/tmp/logs_server_h8f7x4wc CLIENT_LOGS=/tmp/logs_client_bmay1jgm 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://server6:443/kfynnuzoti https://server6:443/nkjgsnzrun"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 11:53:47,220  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
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  | Setting up routes...
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
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 transfer ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
server  | + P12CERT=/tmp/tmp.kstzLyErcR
server  | + mkdir -p /neqo/db
server  | + certutil -N -d sql:/neqo/db --empty-password
server  | + openssl pkcs12 -export -nodes -in /certs/cert.pem -inkey /certs/priv.key -name cert -passout pass: -out /tmp/tmp.kstzLyErcR
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.kstzLyErcR -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  |             79:95:6c:aa:8c:81:57:25:26:5e:0b:83:b6:85:56:96:
server  |             b9:96:ff:ab
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:30 2025
server  |             Not After : Sat May 10 11:53:30 2025
server  |         Subject: "O=interop runner leaf"
server  |         Subject Public Key Info:
server  |             Public Key Algorithm: X9.62 elliptic curve public key
server  |                 Args:
server  |                     06:08:2a:86:48:ce:3d:03:01:07
server  |             EC Public Key:
server  |                 PublicValue:
server  |                     04:74:ea:fb:96:7c:2f:1f:03:a5:3a:19:61:99:23:45:
server  |                     d9:89:4b:1b:7d:69:9b:a6:60:3f:1c:42:b8:b1:87:c1:
server  |                     0c:e1:ae:5d:6b:0d:ee:b8:80:9e:1e:d9:52:1f:0f:84:
server  |                     55:fe:b9:54:01:53:4f:ed:e8:9a:d3:d4:83:65:ac:68:
server  |                     36
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  |                 9f:a6:9c:a6:11:f2:46:ef:6b:8f:fd:43:c7:c1:dc:a6:
server  |                 6e:fb:c4:7f
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 69:7c:ed:ce:b8:06:23:ad:62:c7:3d:ec:7f:57:ab:ed:
server  |                 79:84:4b:90
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:44:02:20:4d:a6:14:85:93:2c:d9:83:59:2b:a6:1b:
server  |         33:81:06:fd:ab:3c:23:53:8a:05:d7:e5:d5:1c:92:3e:
server  |         47:fa:a9:ce:02:20:5d:28:bf:dd:bc:f5:45:e4:46:a1:
server  |         6b:87:6e:13:00:59:42:5e:95:7d:b0:d4:64:3c:b8:14:
server  |         5f:13:41:93:cb:7d
server  |     Fingerprint (SHA-256):
server  |         3D:0E:7B:F8:CB:8D:D5:B7:B8:4C:FB:36:B8:E2:52:93:7E:20:91:A4:85:A1:46:6C:C9:EB:6F:AB:7E:93:FE:EE
server  |     Fingerprint (SHA1):
server  |         E1:31:89:35:61:AF:C6:D9:3F:1E:2F:0A:F2:B2:D2:C5:10:2C:03:04
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  | + '[' transfer = connectionmigration ']'
server  | + RUST_LOG=debug
server  | + RUST_BACKTRACE=1
server  | + neqo-server --cc cubic --qns-test transfer --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.772 DEBUG [Server] Unsupported version: 57414954
server  | 0.772 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:45563 IpTos(Cs0, NotEct) len 15
sim     | server:443 is available after 1.026180954s
server  | 0.773 DEBUG [Server] Unsupported version: 57414954
server  | 0.773 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:45563 IpTos(Cs0, NotEct) len 15
server  | 0.773 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.773 DEBUG [Server] Unsupported version: 57414954
server  | 0.773 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:45563 IpTos(Cs0, NotEct) len 15
server  | 0.773 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
client  | Connecting to server6
client  | Client params (before files):-test:D -timeout:50000 -sslkeylogfile:/logs/keys.log 
client  | Sending request: GET /kfynnuzoti

client  | Sending request: GET /nkjgsnzrun

server  | 0.993 DEBUG [Server] Handle initial
server  | 0.993 INFO AddressValidation: no token; accepting
server  | 0.993 INFO [Server] Accept connection CID [8]: eefaf083f34fa38f
server  | 0.993 DEBUG Overwrite initial version Version1 ==> Version1
server  | 0.995 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500
server  | 0.995 INFO [Server ...] Received valid Initial packet with scid CID [0]:  dcid CID [8]: eefaf083f34fa38f
server  | 0.995 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=eefaf083f34fa38f
server  | 0.995 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 0.995 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 0.995 DEBUG [Server eefaf083f34fa38f] State change from Init -> WaitInitial
server  | 0.995 DEBUG [Server eefaf083f34fa38f] pn=0 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 1200
server  |   -> RX Crypto { offset: 0, len: 290 }
server  |   -> RX Padding { len: 868 }
server  | 0.995 DEBUG Read Ok(290) bytes
server  | 0.995 DEBUG 0-RTT: no token, no 0-RTT
server  | 0.995 DEBUG Read secret available for Handshake: SymKey [32]: 14788ce7bd78305e424905501216ff1c3e8e87230f8fd1ef523a079602285e3b
server  | 0.995 DEBUG Write secret available for Handshake: SymKey [32]: 6d6dd6b236f0b8a1a7494ececea612d50a06ad56cda7f2db83b967582de7cb98
server  | 0.995 DEBUG Writing transport parameters, msg=8
server  | 0.996 DEBUG Read secret available for ApplicationData: SymKey [32]: 9acab1736a12b388de829098b5cb0a8633f7ee219d1deb117924d447a3e5b39c
server  | 0.996 DEBUG Write secret available for ApplicationData: SymKey [32]: a54d7eb49f0b549abfe1b95a237026c12670f7980f52ebffde5993f8deb28112
server  | 0.996 DEBUG [Agent 0x5623f78181d0] state -> InProgress
server  | 0.996 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
server  | 0.996 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
server  | 0.996 DEBUG [Crypto] Handshake keys installed
server  | 0.996 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 0.996 DEBUG [Crypto] Application write key installed
server  | 0.996 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 547150197 }
server  | 0.996 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:36699] Make permanent
server  | 0.996 DEBUG [unv-path: [::]:443->[fd00:cafe:cafe::100]:36699] set as primary path
server  | 0.996 DEBUG [Server eefaf083f34fa38f] State change from WaitInitial -> Handshaking
server  | 0.996 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.996 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 44fb741a47bed1c84845)
server  | 0.996 DEBUG CRYPTO for in offset=0, len=90
server  | 0.996 DEBUG [Server eefaf083f34fa38f] pn=0 type=Initial pri-unv-path: [::]:443->[fd00:cafe:cafe::100]:36699 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  | 0.996 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 44fb741a47bed1c84845)
server  | 0.996 DEBUG CRYPTO for hs offset=0, len=724
server  | 0.996 DEBUG [Server eefaf083f34fa38f] pn=0 type=Handshake pri-unv-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 900
server  |   TX -> Crypto { offset: 0, len: 724 }
server  | 0.996 DEBUG packet_sent this=0x5623f7817b40, pn=0, ps=764
server  | 0.996 DEBUG Building Short dcid Some(CID [0]: )
server  | 0.996 DEBUG [Server eefaf083f34fa38f] pad Initial from 900 to PLPMTU 1232
server  | 0.996 DEBUG packet_sent this=0x5623f7817b40, pn=0, ps=468
server  | 0.996 DEBUG ECN probing: sent 1 probes
server  | 0.996 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.996 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 44fb741a47bed1c84845)
server  | 0.996 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 44fb741a47bed1c84845)
server  | 0.996 DEBUG Building Short dcid Some(CID [0]: )
server  | 0.996 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.996 DEBUG [Server eefaf083f34fa38f] delay duration 297.12117ms
server  | 0.996 DEBUG Setting timeout of 297.12117ms
server  | 0.996 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.996 DEBUG Building Initial dcid Some(CID [0]: ) scid Some(CID [10]: 44fb741a47bed1c84845)
server  | 0.996 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 44fb741a47bed1c84845)
server  | 0.996 DEBUG Building Short dcid Some(CID [0]: )
server  | 0.996 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 0.996 DEBUG [Server eefaf083f34fa38f] delay duration 297.091435ms
server  | 0.996 DEBUG Setting timeout of 297.091435ms
server  | 1.028 DEBUG [Server eefaf083f34fa38f] Drop packet number space in
server  | 1.028 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.028 INFO [pri-unv-path: [::]:443->[fd00:cafe:cafe::100]:36699] discarding a packet without an RTT estimate; guessing RTT=35.217149ms
server  | 1.028 DEBUG [Server eefaf083f34fa38f] pn=1 type=Handshake pri-unv-path: [::]:443->[fd00:cafe:cafe::100]:36699 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.029 DEBUG [Server eefaf083f34fa38f] Rx ACK space=hs, ranges=[0..=0]
server  | 1.029 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.029 DEBUG on_packets_acked this=0x5623f7817b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=764
server  | 1.029 DEBUG Acked crypto frame space=hs offset=0 length=724
server  | 1.029 DEBUG Read Ok(36) bytes
server  | 1.029 DEBUG [Agent 0x5623f78181d0] 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.029 DEBUG [Server eefaf083f34fa38f] TLS connection complete
server  | 1.029 DEBUG [pri-unv-path: [::]:443->[fd00:cafe:cafe::100]:36699] Path validated Instant { tv_sec: 724, tv_nsec: 582367346 }
server  | 1.029 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.029 DEBUG [Crypto] application read keys installed
server  | 1.029 DEBUG [Server eefaf083f34fa38f] State change from Handshaking -> Connected
server  | 1.029 DEBUG [Server eefaf083f34fa38f] State change from Connected -> Confirmed
server  | 1.029 DEBUG PMTUD started with probe size 1380
server  | 1.029 INFO [Server eefaf083f34fa38f] Connection established
server  | 1.029 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 582367346 }
server  | 1.029 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.029 DEBUG Building Handshake dcid Some(CID [0]: ) scid Some(CID [10]: 44fb741a47bed1c84845)
server  | 1.029 DEBUG [Server eefaf083f34fa38f] pn=1 type=Handshake pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 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.029 DEBUG [Server eefaf083f34fa38f] Drop packet number space hs
server  | 1.029 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.029 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.029 DEBUG [Server eefaf083f34fa38f] pn=0 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [58, 207, 27, 25, 7, 171, 110, 201, 4, 140], stateless_reset_token: [190, 223, 8, 242, 99, 47, 232, 115, 7, 110, 183, 194, 102, 70, 126, 217] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [21, 44, 2, 203, 119, 139, 91, 6, 91, 30], stateless_reset_token: [250, 130, 250, 76, 197, 187, 153, 61, 144, 203, 11, 85, 208, 56, 253, 123] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [116, 158, 186, 141, 78, 158, 214, 17, 245, 60], stateless_reset_token: [80, 21, 84, 176, 205, 5, 166, 1, 17, 165, 28, 129, 197, 130, 211, 245] }
server  |   TX -> Padding { len: 1182 }
server  | 1.029 DEBUG packet_sent this=0x5623f7817b40, pn=0, ps=1291
server  | 1.029 DEBUG ECN probing: sent 2 probes
server  | 1.029 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.029 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.029 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.029 DEBUG [Server eefaf083f34fa38f] pn=1 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1313 }
server  | 1.029 DEBUG packet_sent this=0x5623f7817b40, pn=1, ps=1332
server  | 1.029 DEBUG ECN probing: sent 3 probes
server  | 1.029 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.029 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.029 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.029 DEBUG [Server eefaf083f34fa38f] delay duration 1.474366ms
server  | 1.029 DEBUG Setting timeout of 1.474366ms
server  | 1.030 DEBUG [Server eefaf083f34fa38f] send session ticket 40630008eefaf083f34fa38f0104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a44fb741a47bed1c84845110c000000012a7aea6a000000016ab200c0000000ff02de1a0243e8200100686921
server  | 1.030 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.030 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.030 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.030 DEBUG [Server eefaf083f34fa38f] delay duration 538.593µs
server  | 1.030 DEBUG Setting timeout of 538.593µs
server  | 1.030 DEBUG [Server eefaf083f34fa38f] pn=2 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 1232
server  |   -> RX Ping
server  |   -> RX Stream { stream_id: 0, offset: 0, len: 17, fin: true }
server  |   -> RX Stream { stream_id: 4, offset: 0, len: 17, fin: true }
server  |   -> RX Padding { len: 1158 }
server  | 1.030 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 724, tv_nsec: 583849982 }
server  | 1.030 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 583849982 }
server  | 1.030 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.030 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.030 DEBUG [Server eefaf083f34fa38f] pn=2 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 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.030 DEBUG ECN probing: sent 4 probes
server  | 1.030 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.030 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.030 DEBUG CRYPTO for ap offset=0, len=305
server  | 1.030 DEBUG [Server eefaf083f34fa38f] pn=3 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 372
server  |   TX -> Crypto { offset: 0, len: 305 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 221, 8, 218, 76, 38, 204, 171, 248, 4, 194, 37, 12, 82, 19, 105, 252, 194, 12, 210, 151, 39, 54, 124, 248, 7, 146, 143, 117, 233, 69, 80, 110, 76, 9, 86, 253] }
server  | 1.030 DEBUG packet_sent this=0x5623f7817b40, pn=3, ps=372
server  | 1.030 DEBUG ECN probing: sent 5 probes
server  | 1.030 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.030 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.030 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.030 DEBUG [Server eefaf083f34fa38f] delay duration 113.981754ms
server  | 1.030 DEBUG Setting timeout of 113.981754ms
server  | 1.030 DEBUG Path = 'kfynnuzoti'
server  | 1.030 DEBUG Path = 'nkjgsnzrun'
server  | 1.030 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.030 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.030 DEBUG [Server eefaf083f34fa38f] pn=4 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 0, len: >>1212, fin: false }
server  | 1.030 DEBUG packet_sent this=0x5623f7817b40, pn=4, ps=1232
server  | 1.030 DEBUG ECN probing: sent 6 probes
server  | 1.030 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.030 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.030 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.030 DEBUG [Server eefaf083f34fa38f] delay duration 1.713007ms
server  | 1.030 DEBUG Setting timeout of 1.713007ms
server  | 1.033 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.033 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.033 DEBUG [Server eefaf083f34fa38f] pn=5 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 1212, len: >>1210, fin: false }
server  | 1.033 DEBUG packet_sent this=0x5623f7817b40, pn=5, ps=1232
server  | 1.033 DEBUG ECN probing: sent 7 probes
server  | 1.033 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.033 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.033 DEBUG [Server eefaf083f34fa38f] pn=6 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 2422, len: >>1210, fin: false }
server  | 1.033 DEBUG packet_sent this=0x5623f7817b40, pn=6, ps=1232
server  | 1.033 DEBUG ECN probing: sent 8 probes
server  | 1.034 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG [Server eefaf083f34fa38f] delay duration 1.659337ms
server  | 1.034 DEBUG Setting timeout of 1.659337ms
server  | 1.034 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.034 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.034 DEBUG [Server eefaf083f34fa38f] delay duration 1.614214ms
server  | 1.034 DEBUG Setting timeout of 1.614214ms
server  | 1.036 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.036 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.036 DEBUG [Server eefaf083f34fa38f] pn=7 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 3632, len: >>1210, fin: false }
server  | 1.036 DEBUG packet_sent this=0x5623f7817b40, pn=7, ps=1232
server  | 1.036 DEBUG ECN probing: sent 9 probes
server  | 1.036 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.036 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.036 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.036 DEBUG [Server eefaf083f34fa38f] delay duration 1.228578ms
server  | 1.036 DEBUG Setting timeout of 1.228578ms
server  | 1.036 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.036 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.036 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.036 DEBUG [Server eefaf083f34fa38f] delay duration 1.207939ms
server  | 1.036 DEBUG Setting timeout of 1.207939ms
server  | 1.038 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.038 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.038 DEBUG [Server eefaf083f34fa38f] pn=8 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 4842, len: 278, fin: true }
server  |   TX -> Stream { stream_id: 4, offset: 0, len: >>928, fin: false }
server  | 1.038 DEBUG packet_sent this=0x5623f7817b40, pn=8, ps=1232
server  | 1.038 DEBUG ECN probing: sent 10 probes
server  | 1.038 DEBUG ECN probing concluded with 10 probes sent
server  | 1.038 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.038 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.038 DEBUG [Server eefaf083f34fa38f] pn=9 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 928, len: >>1210, fin: false }
server  | 1.038 DEBUG packet_sent this=0x5623f7817b40, pn=9, ps=1232
server  | 1.038 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.038 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG [Server eefaf083f34fa38f] delay duration 1.715311ms
server  | 1.038 DEBUG Setting timeout of 1.715311ms
server  | 1.038 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.038 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG [Server eefaf083f34fa38f] delay duration 1.695785ms
server  | 1.038 DEBUG Setting timeout of 1.695785ms
server  | 1.041 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.041 DEBUG [Server eefaf083f34fa38f] pn=10 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 2138, len: >>1210, fin: false }
server  | 1.041 DEBUG packet_sent this=0x5623f7817b40, pn=10, ps=1232
server  | 1.041 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 701, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.041 DEBUG [Server eefaf083f34fa38f] pn=11 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 701
server  |   TX -> Stream { stream_id: 4, offset: 3348, len: >>679, fin: false }
server  | 1.041 DEBUG packet_sent this=0x5623f7817b40, pn=11, ps=701
server  | 1.041 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.041 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG [Server eefaf083f34fa38f] delay duration 113.983688ms
server  | 1.041 DEBUG Setting timeout of 113.983688ms
server  | 1.041 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.041 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG [Server eefaf083f34fa38f] delay duration 113.961857ms
server  | 1.041 DEBUG Setting timeout of 113.961857ms
client  | kfynnuzoti: Wrote 1212 bytes.(0 ms/0 ms/0 ms)
client  | kfynnuzoti: Wrote 1210 bytes.(2 ms/2 ms/2 ms)
client  | kfynnuzoti: Wrote 1210 bytes.(3 ms/1 ms/-1 ms)
client  | kfynnuzoti: Wrote 1210 bytes.(4 ms/1 ms/0 ms)
client  | kfynnuzoti: Wrote 278 bytes.(6 ms/2 ms/1 ms)
client  | kfynnuzoti: Completed download! (6 ms)
client  | nkjgsnzrun: Wrote 928 bytes.(0 ms/0 ms/0 ms)
client  | nkjgsnzrun: Wrote 1210 bytes.(1 ms/1 ms/1 ms)
client  | nkjgsnzrun: Wrote 1210 bytes.(3 ms/2 ms/1 ms)
client  | nkjgsnzrun: Wrote 679 bytes.(3 ms/0 ms/-2 ms)
server  | 1.062 DEBUG [Server eefaf083f34fa38f] pn=3 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 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.062 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[0..=1]
server  | 1.062 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=1
server  | 1.062 INFO ECN validation succeeded, path is capable
server  | 1.062 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9697/14943 ssthresh 18446744073709551615] slow start += 2623
server  | 1.062 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9697/14943 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=9697, cwnd=14943, state=SlowStart, new_acked=2623
server  | 1.062 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.062 DEBUG PMTUD started with probe size 1420
server  | 1.062 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.062 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.062 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.062 DEBUG [Server eefaf083f34fa38f] pn=12 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Stream { stream_id: 4, offset: 4027, len: >>1349, fin: false }
server  | 1.062 DEBUG packet_sent this=0x5623f7817b40, pn=12, ps=1372
server  | 1.062 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.062 DEBUG [Server eefaf083f34fa38f] pn=13 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 5376, len: >>1310, fin: false }
server  | 1.062 DEBUG packet_sent this=0x5623f7817b40, pn=13, ps=1332
server  | 1.062 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.062 DEBUG [Server eefaf083f34fa38f] pn=14 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 6686, len: >>1310, fin: false }
server  | 1.062 DEBUG packet_sent this=0x5623f7817b40, pn=14, ps=1332
server  | 1.062 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.062 DEBUG [Server eefaf083f34fa38f] pn=15 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1210
server  |   TX -> Stream { stream_id: 4, offset: 7996, len: >>1188, fin: false }
server  | 1.062 DEBUG packet_sent this=0x5623f7817b40, pn=15, ps=1210
server  | 1.062 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.062 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG [Server eefaf083f34fa38f] delay duration 103.014139ms
server  | 1.062 DEBUG Setting timeout of 103.014139ms
server  | 1.062 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.062 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.062 DEBUG [Server eefaf083f34fa38f] delay duration 102.883675ms
server  | 1.062 DEBUG Setting timeout of 102.883675ms
server  | 1.063 DEBUG [Server eefaf083f34fa38f] pn=4 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 1312
server  |   -> RX Ping
server  |   -> RX Padding { len: 1280 }
server  | 1.063 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 724, tv_nsec: 616572058 }
server  | 1.063 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 616572058 }
server  | 1.063 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.063 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.063 DEBUG [Server eefaf083f34fa38f] pn=16 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 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.063 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.063 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.063 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.063 DEBUG [Server eefaf083f34fa38f] delay duration 102.152604ms
server  | 1.063 DEBUG Setting timeout of 102.152604ms
server  | 1.063 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.063 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.063 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.063 DEBUG [Server eefaf083f34fa38f] delay duration 102.12904ms
server  | 1.063 DEBUG Setting timeout of 102.12904ms
server  | 1.063 DEBUG [Server eefaf083f34fa38f] pn=5 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 50
server  |   -> RX Ack { largest_acknowledged: 4, ack_delay: 0, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16778428 }
server  |   -> RX MaxStreamData { stream_id: StreamId(0), maximum_stream_data: 66748 }
server  | 1.063 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[0..=4]
server  | 1.063 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4
server  | 1.063 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 13339/16547 ssthresh 18446744073709551615] slow start += 1604
server  | 1.063 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 13339/16547 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=13339, cwnd=16547, state=SlowStart, new_acked=1604
server  | 1.063 DEBUG Acked crypto frame space=ap offset=0 length=305
server  | 1.063 DEBUG setting max_stream_data to 66748
server  | 1.063 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 636982027 }
server  | 1.063 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.063 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.063 DEBUG [Server eefaf083f34fa38f] pn=17 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 1080
server  |   TX -> Stream { stream_id: 4, offset: 9184, len: 1056, fin: true }
server  | 1.063 DEBUG packet_sent this=0x5623f7817b40, pn=17, ps=1080
server  | 1.063 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.063 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.063 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.063 DEBUG [Server eefaf083f34fa38f] delay duration 1.256353ms
server  | 1.063 DEBUG Setting timeout of 1.256353ms
server  | 1.063 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.063 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.063 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.063 DEBUG [Server eefaf083f34fa38f] delay duration 1.232298ms
server  | 1.063 DEBUG Setting timeout of 1.232298ms
server  | 1.066 DEBUG [Server eefaf083f34fa38f] pn=6 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 50
server  |   -> RX Ack { largest_acknowledged: 6, ack_delay: 0, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16780848 }
server  |   -> RX MaxStreamData { stream_id: StreamId(0), maximum_stream_data: 69168 }
server  | 1.066 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[0..=6]
server  | 1.066 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6
server  | 1.066 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11955/19011 ssthresh 18446744073709551615] slow start += 2464
server  | 1.066 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11955/19011 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=11955, cwnd=19011, state=SlowStart, new_acked=2464
server  | 1.066 DEBUG setting max_stream_data to 69168
server  | 1.066 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 619733738 }
server  | 1.066 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.066 DEBUG [Server eefaf083f34fa38f] pn=18 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 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.066 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG [Server eefaf083f34fa38f] delay duration 85.003919ms
server  | 1.066 DEBUG Setting timeout of 85.003919ms
server  | 1.066 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.066 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.066 DEBUG [Server eefaf083f34fa38f] delay duration 84.979243ms
server  | 1.066 DEBUG Setting timeout of 84.979243ms
server  | 1.069 DEBUG [Server eefaf083f34fa38f] pn=7 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 50
server  |   -> RX Ack { largest_acknowledged: 8, ack_delay: 0, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16783264 }
server  |   -> RX MaxStreamData { stream_id: StreamId(4), maximum_stream_data: 66464 }
server  | 1.069 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[0..=8]
server  | 1.069 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8
server  | 1.069 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9491/21475 ssthresh 18446744073709551615] slow start += 2464
server  | 1.069 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9491/21475 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=9491, cwnd=21475, state=SlowStart, new_acked=2464
server  | 1.069 DEBUG setting max_stream_data to 66464
server  | 1.069 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 643339421 }
server  | 1.069 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.069 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.069 DEBUG [Server eefaf083f34fa38f] pn=19 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, Ect0) len 20
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  | 1.069 DEBUG packet_sent this=0x5623f7817b40, pn=19, ps=21
server  | 1.070 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.070 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG [Server eefaf083f34fa38f] delay duration 19.880126ms
server  | 1.070 DEBUG Setting timeout of 19.880126ms
server  | 1.070 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.070 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.070 DEBUG [Server eefaf083f34fa38f] delay duration 19.849188ms
server  | 1.070 DEBUG Setting timeout of 19.849188ms
server  | 1.073 DEBUG [Server eefaf083f34fa38f] pn=8 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 50
server  |   -> RX Ack { largest_acknowledged: 10, ack_delay: 0, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16785684 }
server  |   -> RX MaxStreamData { stream_id: StreamId(4), maximum_stream_data: 68884 }
server  | 1.073 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[0..=10]
server  | 1.073 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=10
server  | 1.073 WARN ECN validation failed, no ECT(0) packets were newly acked
server  | 1.073 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7048/23939 ssthresh 18446744073709551615] slow start += 2464
server  | 1.073 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 7048/23939 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=7048, cwnd=23939, state=SlowStart, new_acked=2464
server  | 1.073 DEBUG setting max_stream_data to 68884
server  | 1.073 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 626468810 }
server  | 1.073 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.073 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.073 DEBUG [Server eefaf083f34fa38f] pn=20 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 23
server  |   TX -> Ack { largest_acknowledged: 8, ack_delay: 0, first_ack_range: 6, ack_ranges: [], ecn_count: None }
server  | 1.073 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.073 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.073 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.073 DEBUG [Server eefaf083f34fa38f] delay duration 76.488591ms
server  | 1.073 DEBUG Setting timeout of 76.488591ms
server  | 1.073 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.073 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.073 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.073 DEBUG [Server eefaf083f34fa38f] delay duration 76.457583ms
server  | 1.073 DEBUG Setting timeout of 76.457583ms
client  | nkjgsnzrun: Wrote 1349 bytes.(24 ms/21 ms/21 ms)
client  | nkjgsnzrun: Wrote 1310 bytes.(25 ms/1 ms/-20 ms)
client  | nkjgsnzrun: Wrote 1310 bytes.(26 ms/1 ms/0 ms)
client  | nkjgsnzrun: Wrote 1188 bytes.(27 ms/1 ms/0 ms)
client  | nkjgsnzrun: Wrote 1056 bytes.(28 ms/1 ms/0 ms)
client  | nkjgsnzrun: Completed download! (28 ms)
server  | 1.093 DEBUG [Server eefaf083f34fa38f] pn=9 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 50
server  |   -> RX Ack { largest_acknowledged: 12, ack_delay: 0, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16787712 }
server  |   -> RX MaxStreamData { stream_id: StreamId(4), maximum_stream_data: 70912 }
server  | 1.093 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[0..=12]
server  | 1.094 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=12
server  | 1.094 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4975/26012 ssthresh 18446744073709551615] slow start += 2073
server  | 1.094 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 4975/26012 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=4975, cwnd=26012, state=SlowStart, new_acked=2073
server  | 1.094 DEBUG PMTUD probe of size 1420 succeeded
server  | 1.094 DEBUG PMTUD started with probe size 1470
server  | 1.094 DEBUG PLPMTU changed from 1332 to 1372, updating pacer
server  | 1.094 DEBUG setting max_stream_data to 70912
server  | 1.094 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 667401582 }
server  | 1.094 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.094 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.094 DEBUG Sending PMTUD probe of size 1470, count 1
server  | 1.094 DEBUG [Server eefaf083f34fa38f] pn=21 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 1422
server  |   TX -> Ping
server  |   TX -> Padding { len: 1403 }
server  | 1.094 DEBUG packet_sent this=0x5623f7817b40, pn=21, ps=1422
server  | 1.094 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.094 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.094 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.094 DEBUG [Server eefaf083f34fa38f] delay duration 19.896335ms
server  | 1.094 DEBUG Setting timeout of 19.896335ms
server  | 1.094 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.094 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.094 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.094 DEBUG [Server eefaf083f34fa38f] delay duration 19.878482ms
server  | 1.094 DEBUG Setting timeout of 19.878482ms
server  | 1.096 DEBUG [Server eefaf083f34fa38f] pn=10 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 50
server  |   -> RX Ack { largest_acknowledged: 14, ack_delay: 0, first_ack_range: 14, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 12, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16790332 }
server  |   -> RX MaxStreamData { stream_id: StreamId(4), maximum_stream_data: 73532 }
server  | 1.096 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[0..=14]
server  | 1.096 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=14
server  | 1.096 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3733/28676 ssthresh 18446744073709551615] slow start += 2664
server  | 1.096 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3733/28676 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=3733, cwnd=28676, state=SlowStart, new_acked=2664
server  | 1.096 DEBUG setting max_stream_data to 73532
server  | 1.096 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 649574261 }
server  | 1.096 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.096 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.096 DEBUG [Server eefaf083f34fa38f] pn=22 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 23
server  |   TX -> Ack { largest_acknowledged: 10, ack_delay: 0, first_ack_range: 8, ack_ranges: [], ecn_count: None }
server  | 1.096 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.096 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.096 DEBUG [Server eefaf083f34fa38f] delay duration 70.252589ms
server  | 1.096 DEBUG Setting timeout of 70.252589ms
server  | 1.096 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.096 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.096 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.096 DEBUG [Server eefaf083f34fa38f] delay duration 70.228724ms
server  | 1.096 DEBUG Setting timeout of 70.228724ms
server  | 1.098 DEBUG [Server eefaf083f34fa38f] pn=11 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 1392
server  |   -> RX Ping
server  |   -> RX Padding { len: 1360 }
server  | 1.098 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 724, tv_nsec: 651698638 }
server  | 1.098 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 651698638 }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG [Server eefaf083f34fa38f] pn=23 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 23
server  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 0, first_ack_range: 9, ack_ranges: [], ecn_count: None }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] delay duration 68.13917ms
server  | 1.098 DEBUG Setting timeout of 68.13917ms
server  | 1.098 DEBUG [Server eefaf083f34fa38f] pn=12 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 44
server  |   -> RX Ack { largest_acknowledged: 18, ack_delay: 0, first_ack_range: 11, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 16, Ce: 0})) }
server  |   -> RX MaxData { maximum_data: 16792576 }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] Rx ACK space=ap, ranges=[7..=18]
server  | 1.098 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=18
server  | 1.098 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1443/30966 ssthresh 18446744073709551615] slow start += 2290
server  | 1.098 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1443/30966 ssthresh 18446744073709551615] on_packets_acked this=0x5623f7817b40, limited=0, bytes_in_flight=1443, cwnd=30966, state=SlowStart, new_acked=2290
server  | 1.098 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 724, tv_nsec: 671820157 }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG [Server eefaf083f34fa38f] pn=24 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 20
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 18 }
server  | 1.098 DEBUG packet_sent this=0x5623f7817b40, pn=24, ps=21
server  | 1.098 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] delay duration 19.900684ms
server  | 1.098 DEBUG Setting timeout of 19.900684ms
server  | 1.098 DEBUG [Server eefaf083f34fa38f] pn=13 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 34
server  |   -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" }
server  | 1.098 INFO [Server eefaf083f34fa38f] ConnectionClose received. Error code: Application(0) frame type 0 reason 
server  | 1.098 DEBUG [Server eefaf083f34fa38f] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 724, tv_nsec: 863567843 } }
server  | 1.098 DEBUG [pri-path: [::]:443->[fd00:cafe:cafe::100]:36699] Path validated Instant { tv_sec: 724, tv_nsec: 651944390 }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.098 DEBUG Building Short dcid Some(CID [0]: )
server  | 1.098 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 724, tv_nsec: 651944390 }
server  | 1.098 DEBUG [Server eefaf083f34fa38f] pn=25 type=Short pri-path: [::]:443->[fd00:cafe:cafe::100]:36699 IpTos(Cs0, NotEct) len 27
server  |   TX -> Ack { largest_acknowledged: 13, ack_delay: 0, first_ack_range: 11, ack_ranges: [], ecn_count: None }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" }
server  | 1.098 DEBUG Setting timeout of 211.541129ms
server  | 1.098 DEBUG Setting timeout of 211.534206ms
client  | 
client  |       TARGET  VHDCRZSQUMBGA2E    VERSION   ALPN
client  |  ============================================
client  |      server6  --D------------  0x00000001  hq-interop
client  | 
client  | Total execution time: 0.145s
client  | 
server  | 1.311 DEBUG [Server eefaf083f34fa38f] State change from Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 724, tv_nsec: 863567843 } } -> Closed(Transport(PeerApplicationError(0)))
server  | 1.311 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:53:47,316 Using the client's key log file.
2025-04-30 11:53:47,325 
2025-04-30 11:53:47,326 Using the client's key log file.
2025-04-30 11:53:47,326 Using the client's key log file.
2025-04-30 11:53:47,334 
2025-04-30 11:53:47,335 Using the client's key log file.
2025-04-30 11:53:47,895 Check of downloaded files succeeded.
2025-04-30 11:53:48,462 Check of downloaded files succeeded.