2025-04-30 08:49:31,001 Generated random file: aiauyhkmuf of size: 5120
2025-04-30 08:49:31,002 Generated random file: expaiilfgo of size: 10240
2025-04-30 08:49:31,002 Requests: https://server6:443/aiauyhkmuf https://server6:443/expaiilfgo
2025-04-30 08:49:31,063 
2025-04-30 08:49:31,063 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_zonzf0ta/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_mdp1x5fg/ DOWNLOADS=/tmp/download_7tmek705/ SERVER_LOGS=/tmp/logs_server_2ej5s21c CLIENT_LOGS=/tmp/logs_client_zhkqn1cn SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=privateoctopus/picoquic:latest SERVER=ghcr.io/mozilla/neqo-qns:latest REQUESTS="https://server6:443/aiauyhkmuf https://server6:443/expaiilfgo"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 08:49:43,144  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 the simulation with setup.sh
server  | Setting up routes...
client  | 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  | 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 IPv4 address is 193.167.100.100
client  | Endpoint's IPv4 address is 193.167.0.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::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 transfer ']'
server  | + '[' -n /logs/qlog/ ']'
server  | + case "$ROLE" in
server  | + DB=/neqo/db
server  | + CERT=cert
server  | ++ mktemp
client  | Setup.sh completed
client  | Waiting for  the simulator to start
server  | + P12CERT=/tmp/tmp.idvLJXK2Ch
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.idvLJXK2Ch
server  | Warning: output encryption option -nodes ignored with -export
server  | + pk12util -d sql:/neqo/db -i /tmp/tmp.idvLJXK2Ch -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  |             03:17:ea:8f:2e:36:1e:93:bd:8a:87:d3:1f:84:cf:66:
server  |             65:60:a9:ee
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 08:49:31 2025
server  |             Not After : Sat May 10 08:49:31 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:e5:12:12:32:26:4f:8f:77:ae:a5:19:ae:1a:86:15:
server  |                     c1:65:d0:53:2d:c1:3d:de:5b:ba:fe:dc:dd:6b:29:79:
server  |                     83:b1:c3:cd:dd:43:39:72:fc:dd:79:4c:32:64:3e:6c:
server  |                     54:5d:49:08:87:22:aa:6f:d8:1b:d2:63:e2:04:8b:16:
server  |                     32
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  |                 db:e5:fb:40:90:42:f6:64:cc:70:5d:43:72:46:d0:7d:
server  |                 be:ec:2b:c7
server  | 
server  |             Name: Certificate Authority Key Identifier
server  |             Key ID:
server  |                 c1:07:ee:10:96:29:93:18:5a:29:1a:7a:23:fb:c9:b7:
server  |                 4d:b6:9f:3f
server  | 
server  |     Signature Algorithm: X9.62 ECDSA signature with SHA256
server  |     Signature:
server  |         30:46:02:21:00:8a:c9:9e:82:e5:40:78:b1:21:20:0c:
server  |         09:94:cb:2c:97:02:d6:0c:2c:06:93:a3:f3:80:98:fa:
server  |         40:cc:1e:c1:e2:02:21:00:e5:05:af:a8:e6:cf:53:52:
server  |         13:d1:f0:ee:7c:09:0f:55:c6:90:02:d3:b4:9b:38:53:
server  |         d6:44:34:32:aa:60:cd:52
server  |     Fingerprint (SHA-256):
server  |         43:D9:5A:0F:B3:D9:98:CD:83:4F:D8:58:58:19:2F:F1:9A:0E:D9:B0:ED:A7:0F:60:71:AE:4F:02:7E:58:2E:0C
server  |     Fingerprint (SHA1):
server  |         75:24:FD:4D:D3:A4:E5:98:60:4F:7D:E4:D4:19:32:76:D0:95:A2:7A
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.817 DEBUG [Server] Unsupported version: 57414954
server  | 0.817 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:44368 IpTos(Cs0, NotEct) len 15
server  | 0.817 DEBUG [Server] Unsupported version: 57414954
server  | 0.817 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:44368 IpTos(Cs0, NotEct) len 15
server  | 0.817 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
server  | 0.817 DEBUG [Server] Unsupported version: 57414954
server  | 0.817 DEBUG [Server] type=VersionNegotiation path: [::]:443->[::ffff:193.167.100.2]:44368 IpTos(Cs0, NotEct) len 15
server  | 0.817 ERROR failed to create NeqoQlog: IoError(Os { code: 17, kind: AlreadyExists, message: "File exists" })
sim     | server:443 is available after 1.063471906s
sim     | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: tcpdump: listening on eth0listening on eth1, link-type EN10MB (Ethernet), link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | , snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | Starting picoquic client for test: transfer
client  | Starting picoquic client ...
client  | Parsing server name from first request: https://server6:443/aiauyhkmuf
client  | Server set to: server6
client  | Requests:  https://server6:443/aiauyhkmuf https://server6:443/expaiilfgo
client  | parsing <https://server6:443/aiauyhkmuf> as <aiauyhkmuf>
client  | parsing <https://server6:443/expaiilfgo> as <expaiilfgo>
client  | Starting Picoquic (v1.1.26.1) connection to server = server6, port = 443
client  | No token file present. Will create one as <demo_token_store.bin>.
client  | Testing scenario: <-:/aiauyhkmuf;-:/expaiilfgo;>
client  | Max stream id bidir remote before start = 0 (0)
client  | Starting client connection. Version = 1, I-CID: 17bceaadee5b3205
client  | Max stream id bidir remote after start = -4 (0)
client  | Waiting for packets.
server  | 1.002 DEBUG [Server] Handle initial
server  | 1.002 INFO AddressValidation: no token; accepting
server  | 1.002 INFO [Server] Accept connection CID [8]: 17bceaadee5b3205
server  | 1.002 DEBUG Overwrite initial version Version1 ==> Version1
server  | 1.004 DEBUG Outbound interface eth0 for destination fd00:cafe:cafe::100 has MTU 1500
server  | 1.004 INFO [Server ...] Received valid Initial packet with scid CID [8]: 09e83234c60e5ef7 dcid CID [8]: 17bceaadee5b3205
server  | 1.004 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Server dcid=17bceaadee5b3205
server  | 1.004 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.004 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865
server  | 1.004 DEBUG [Server 17bceaadee5b3205] State change from Init -> WaitInitial
server  | 1.004 DEBUG [Server 17bceaadee5b3205] pn=115587 type=Initial unv-path [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 1232
server  |   -> RX Ping
server  |   -> RX Crypto { offset: 0, len: 285 }
server  |   -> RX Padding { len: 896 }
server  | 1.004 DEBUG unmark 0-length range at 0
server  | 1.004 DEBUG [Recvd-in] immediate_ack at Instant { tv_sec: 647, tv_nsec: 521158190 }
server  | 1.004 DEBUG Read Ok(285) bytes
server  | 1.004 DEBUG 0-RTT: no token, no 0-RTT
server  | 1.005 DEBUG Read secret available for Handshake: SymKey [32]: 73c9744a01d850df33622577dc97efa7d3289898e1bb292b00051c0e970502ff
server  | 1.005 DEBUG Write secret available for Handshake: SymKey [32]: 339e7b4a44097dc815d255eff57e561d98ade33c637ccb2339c3943da8c71245
server  | 1.005 DEBUG Writing transport parameters, msg=8
server  | 1.005 DEBUG Read secret available for ApplicationData: SymKey [32]: 11b69029094b8f5b37160e3ee1e9675adaa42881cd3e1d9eb12ace5a46a2e4d3
server  | 1.005 DEBUG Write secret available for ApplicationData: SymKey [32]: 39b3b8cb96fc8b639cdc4f50396d7d52a13e85e81d87fec3d904af9bc27b45b4
server  | 1.005 DEBUG [Agent 0x555d8d1331d0] state -> InProgress
server  | 1.005 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.005 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
server  | 1.005 DEBUG [Crypto] Handshake keys installed
server  | 1.005 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.005 DEBUG [Crypto] Application write key installed
server  | 1.005 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 647, tv_nsec: 521158190 }
server  | 1.005 DEBUG [unv-path [::]:443->[fd00:cafe:cafe::100]:57911] Make permanent
server  | 1.005 DEBUG [unv-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911] set as primary path
server  | 1.005 DEBUG [Server 17bceaadee5b3205] State change from WaitInitial -> Handshaking
server  | 1.005 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.005 DEBUG Building Initial dcid Some(CID [8]: 09e83234c60e5ef7) scid Some(CID [10]: 345f1faade0c2ddbc3c6)
server  | 1.005 DEBUG CRYPTO for in offset=0, len=123
server  | 1.005 DEBUG [Server 17bceaadee5b3205] pn=0 type=Initial pri-unv-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 183
server  |   TX -> Ack { largest_acknowledged: 115587, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) }
server  |   TX -> Crypto { offset: 0, len: 123 }
server  | 1.005 DEBUG Building Handshake dcid Some(CID [8]: 09e83234c60e5ef7) scid Some(CID [10]: 345f1faade0c2ddbc3c6)
server  | 1.005 DEBUG CRYPTO for hs offset=0, len=721
server  | 1.005 DEBUG [Server 17bceaadee5b3205] pn=0 type=Handshake pri-unv-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 952
server  |   TX -> Crypto { offset: 0, len: 721 }
server  | 1.005 DEBUG packet_sent this=0x555d8d132b40, pn=0, ps=769
server  | 1.005 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.005 DEBUG [Server 17bceaadee5b3205] pad Initial from 952 to PLPMTU 1232
server  | 1.005 DEBUG packet_sent this=0x555d8d132b40, pn=0, ps=463
server  | 1.005 DEBUG ECN probing: sent 1 probes
server  | 1.005 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.005 DEBUG Building Initial dcid Some(CID [8]: 09e83234c60e5ef7) scid Some(CID [10]: 345f1faade0c2ddbc3c6)
server  | 1.005 DEBUG Building Handshake dcid Some(CID [8]: 09e83234c60e5ef7) scid Some(CID [10]: 345f1faade0c2ddbc3c6)
server  | 1.005 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.005 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.005 DEBUG [Server 17bceaadee5b3205] delay duration 296.375757ms
server  | 1.005 DEBUG Setting timeout of 296.375757ms
server  | 1.005 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.005 DEBUG Building Initial dcid Some(CID [8]: 09e83234c60e5ef7) scid Some(CID [10]: 345f1faade0c2ddbc3c6)
server  | 1.005 DEBUG Building Handshake dcid Some(CID [8]: 09e83234c60e5ef7) scid Some(CID [10]: 345f1faade0c2ddbc3c6)
server  | 1.005 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.005 DEBUG TX blocked, profile=SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.005 DEBUG [Server 17bceaadee5b3205] delay duration 296.342244ms
server  | 1.005 DEBUG Setting timeout of 296.342244ms
client  | Client port (AF=10): 14306.
client  | Negotiated ALPN: hq-interop
client  | Almost ready!
client  | 
client  | Connection established. Version = 1, I-CID: 17bceaadee5b3205, verified: 1
client  | Opening stream 0 to GET /aiauyhkmuf
client  | Opening stream 4 to GET /expaiilfgo
server  | 1.038 DEBUG [Server 17bceaadee5b3205] Drop packet number space in
server  | 1.038 DEBUG [LossRecovery] Reset loss recovery state for Initial
server  | 1.038 INFO [pri-unv-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911] discarding a packet without an RTT estimate; guessing RTT=35.762259ms
server  | 1.038 DEBUG [Server 17bceaadee5b3205] pn=0 type=Handshake pri-unv-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 94
server  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 39, 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.038 DEBUG [Server 17bceaadee5b3205] Rx ACK space=hs, ranges=[0..=0]
server  | 1.038 DEBUG [LossRecovery] ACK for Handshake - largest_acked=0
server  | 1.038 DEBUG on_packets_acked this=0x555d8d132b40, limited=1, bytes_in_flight=0, cwnd=12320, state=SlowStart, new_acked=769
server  | 1.038 DEBUG Acked crypto frame space=hs offset=0 length=721
server  | 1.038 DEBUG Read Ok(36) bytes
server  | 1.038 DEBUG [Agent 0x555d8d1331d0] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 23, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
server  | 1.038 DEBUG [Server 17bceaadee5b3205] TLS connection complete
server  | 1.038 DEBUG [pri-unv-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911] Path validated Instant { tv_sec: 647, tv_nsec: 556920449 }
server  | 1.038 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
server  | 1.038 DEBUG [Crypto] application read keys installed
server  | 1.038 DEBUG [Server 17bceaadee5b3205] State change from Handshaking -> Connected
server  | 1.038 DEBUG [Server 17bceaadee5b3205] State change from Connected -> Confirmed
server  | 1.038 DEBUG PMTUD started with probe size 1380
server  | 1.038 INFO [Server 17bceaadee5b3205] Connection established
server  | 1.038 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 647, tv_nsec: 556920449 }
server  | 1.038 DEBUG [Server 17bceaadee5b3205] pn=0 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 311
server  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [22, 157, 119, 52, 32, 204, 113, 219], stateless_reset_token: [52, 199, 250, 121, 130, 162, 78, 63, 107, 145, 244, 136, 110, 29, 201, 180] }
server  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [155, 245, 246, 85, 103, 147, 15, 157], stateless_reset_token: [193, 19, 154, 133, 45, 33, 248, 185, 43, 16, 46, 43, 42, 214, 198, 214] }
server  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [154, 48, 26, 147, 61, 161, 223, 67], stateless_reset_token: [30, 168, 107, 149, 196, 193, 28, 149, 164, 185, 3, 242, 97, 128, 9, 178] }
server  |   -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [81, 148, 0, 217, 75, 189, 172, 34], stateless_reset_token: [12, 207, 221, 56, 250, 83, 221, 128, 116, 23, 78, 37, 106, 175, 198, 156] }
server  |   -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [102, 146, 160, 172, 185, 163, 19, 238], stateless_reset_token: [109, 105, 26, 216, 17, 26, 178, 61, 234, 174, 212, 135, 88, 220, 76, 115] }
server  |   -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [102, 36, 132, 194, 12, 97, 81, 3], stateless_reset_token: [43, 89, 169, 47, 83, 73, 213, 95, 33, 118, 127, 62, 208, 11, 189, 127] }
server  |   -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [245, 98, 9, 179, 180, 134, 8, 84], stateless_reset_token: [118, 185, 190, 38, 44, 186, 201, 145, 163, 18, 247, 213, 72, 161, 111, 233] }
server  |   -> RX Padding { len: 87 }
server  | 1.038 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 647, tv_nsec: 576920449 }
server  | 1.038 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.038 DEBUG Building Handshake dcid Some(CID [8]: 09e83234c60e5ef7) scid Some(CID [10]: 345f1faade0c2ddbc3c6)
server  | 1.038 DEBUG [Server 17bceaadee5b3205] pn=1 type=Handshake pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 52
server  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 1, Ect0: 0, Ce: 0})) }
server  | 1.038 DEBUG [Server 17bceaadee5b3205] Drop packet number space hs
server  | 1.038 DEBUG [LossRecovery] Reset loss recovery state for Handshake
server  | 1.038 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.038 DEBUG [Server 17bceaadee5b3205] pn=0 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1332
server  |   TX -> HandshakeDone
server  |   TX -> NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [111, 158, 248, 72, 21, 204, 46, 184, 123, 127], stateless_reset_token: [41, 39, 84, 3, 206, 154, 142, 252, 83, 63, 230, 51, 15, 78, 191, 25] }
server  |   TX -> NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [40, 239, 9, 140, 200, 95, 243, 28, 140, 77], stateless_reset_token: [148, 23, 166, 244, 115, 12, 121, 77, 100, 142, 72, 220, 36, 162, 50, 22] }
server  |   TX -> NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [8, 131, 8, 206, 192, 52, 141, 189, 123, 227], stateless_reset_token: [183, 157, 215, 107, 19, 100, 189, 193, 169, 214, 47, 220, 100, 86, 10, 68] }
server  |   TX -> NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [234, 148, 221, 60, 129, 125, 55, 54, 205, 224], stateless_reset_token: [206, 99, 158, 142, 66, 151, 251, 140, 235, 241, 246, 68, 160, 160, 148, 162] }
server  |   TX -> NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [79, 57, 182, 126, 213, 88, 72, 192, 164, 130], stateless_reset_token: [32, 67, 184, 255, 186, 198, 117, 44, 157, 232, 78, 166, 154, 125, 224, 228] }
server  |   TX -> NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [193, 203, 205, 192, 202, 47, 40, 99, 65, 216], stateless_reset_token: [144, 26, 169, 181, 92, 38, 125, 55, 226, 175, 252, 1, 178, 243, 10, 0] }
server  |   TX -> NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [253, 46, 45, 170, 113, 21, 122, 55, 113, 171], stateless_reset_token: [248, 176, 148, 215, 243, 112, 114, 171, 143, 228, 200, 55, 155, 243, 18, 98] }
server  |   TX -> Padding { len: 1043 }
server  | 1.038 DEBUG packet_sent this=0x555d8d132b40, pn=0, ps=1280
server  | 1.038 DEBUG ECN probing: sent 2 probes
server  | 1.038 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.038 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.038 DEBUG Sending PMTUD probe of size 1380, count 1
server  | 1.038 DEBUG [Server 17bceaadee5b3205] pn=1 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Ping
server  |   TX -> Padding { len: 1305 }
server  | 1.038 DEBUG packet_sent this=0x555d8d132b40, pn=1, ps=1332
server  | 1.038 DEBUG ECN probing: sent 3 probes
server  | 1.038 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.038 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG [Server 17bceaadee5b3205] delay duration 1.409075ms
server  | 1.038 DEBUG Setting timeout of 1.409075ms
server  | 1.038 DEBUG [Server 17bceaadee5b3205] pn=1 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 183
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: 115 }
server  | 1.038 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 647, tv_nsec: 557541098 }
server  | 1.038 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.038 DEBUG [Server 17bceaadee5b3205] pn=2 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 34
server  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 2, Ect0: 0, Ce: 0})) }
server  | 1.038 DEBUG ECN probing: sent 4 probes
server  | 1.038 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.038 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.038 DEBUG [Server 17bceaadee5b3205] delay duration 1.349556ms
server  | 1.038 DEBUG Setting timeout of 1.349556ms
server  | 1.039 DEBUG [Server 17bceaadee5b3205] send session ticket 4063000817bceaadee5b32050104800075300408ffffffffffffffff0504801000000604801000000704801000000801100901100b01140e01080f0a345f1faade0c2ddbc3c6110c000000016a3aba9a000000016ab200c0000000ff02de1a0243e8200100686921
server  | 1.039 DEBUG Path = 'aiauyhkmuf'
server  | 1.039 DEBUG Path = 'expaiilfgo'
server  | 1.039 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.039 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.039 DEBUG [Server 17bceaadee5b3205] delay duration 233.904µs
server  | 1.039 DEBUG Setting timeout of 233.904µs
server  | 1.041 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.041 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.041 DEBUG [Server 17bceaadee5b3205] pn=3 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 0, len: >>1204, fin: false }
server  | 1.041 DEBUG packet_sent this=0x555d8d132b40, pn=3, ps=1232
server  | 1.041 DEBUG ECN probing: sent 5 probes
server  | 1.041 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.042 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.042 DEBUG [Server 17bceaadee5b3205] pn=4 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 1204, len: >>1202, fin: false }
server  | 1.042 DEBUG packet_sent this=0x555d8d132b40, pn=4, ps=1232
server  | 1.042 DEBUG ECN probing: sent 6 probes
server  | 1.042 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.042 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.042 DEBUG [Server 17bceaadee5b3205] delay duration 1.504763ms
server  | 1.042 DEBUG Setting timeout of 1.504763ms
server  | 1.042 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.042 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.042 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.042 DEBUG [Server 17bceaadee5b3205] delay duration 1.485046ms
server  | 1.042 DEBUG Setting timeout of 1.485046ms
server  | 1.044 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.044 DEBUG [Server 17bceaadee5b3205] pn=5 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 2406, len: >>1202, fin: false }
server  | 1.044 DEBUG packet_sent this=0x555d8d132b40, pn=5, ps=1232
server  | 1.044 DEBUG ECN probing: sent 7 probes
server  | 1.044 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.044 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.044 DEBUG [Server 17bceaadee5b3205] delay duration 1.108254ms
server  | 1.044 DEBUG Setting timeout of 1.108254ms
server  | 1.044 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.044 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.044 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.044 DEBUG [Server 17bceaadee5b3205] delay duration 1.070653ms
server  | 1.044 DEBUG Setting timeout of 1.070653ms
server  | 1.046 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.046 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.046 DEBUG [Server 17bceaadee5b3205] pn=6 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 3608, len: >>1202, fin: false }
server  | 1.046 DEBUG packet_sent this=0x555d8d132b40, pn=6, ps=1232
server  | 1.046 DEBUG ECN probing: sent 8 probes
server  | 1.046 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.046 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.046 DEBUG [Server 17bceaadee5b3205] pn=7 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 0, offset: 4810, len: 310, fin: true }
server  |   TX -> Stream { stream_id: 4, offset: 0, len: >>888, fin: false }
server  | 1.046 DEBUG packet_sent this=0x555d8d132b40, pn=7, ps=1232
server  | 1.046 DEBUG ECN probing: sent 9 probes
server  | 1.046 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.046 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.046 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.046 DEBUG [Server 17bceaadee5b3205] delay duration 1.714896ms
server  | 1.046 DEBUG Setting timeout of 1.714896ms
server  | 1.046 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.046 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.046 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
server  | 1.046 DEBUG [Server 17bceaadee5b3205] delay duration 1.691843ms
server  | 1.046 DEBUG Setting timeout of 1.691843ms
server  | 1.049 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.049 DEBUG [Server 17bceaadee5b3205] pn=8 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 888, len: >>1202, fin: false }
server  | 1.049 DEBUG packet_sent this=0x555d8d132b40, pn=8, ps=1232
server  | 1.049 DEBUG ECN probing: sent 10 probes
server  | 1.049 DEBUG ECN probing concluded with 10 probes sent
server  | 1.049 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1232, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.049 DEBUG [Server 17bceaadee5b3205] pn=9 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, NotEct) len 1232
server  |   TX -> Stream { stream_id: 4, offset: 2090, len: >>1202, fin: false }
server  | 1.049 DEBUG packet_sent this=0x555d8d132b40, pn=9, ps=1232
server  | 1.049 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1084, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.049 DEBUG [Server 17bceaadee5b3205] pn=10 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, NotEct) len 1084
server  |   TX -> Stream { stream_id: 4, offset: 3292, len: >>1054, fin: false }
server  | 1.049 DEBUG packet_sent this=0x555d8d132b40, pn=10, ps=1084
server  | 1.049 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.049 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG [Server 17bceaadee5b3205] delay duration 99.36127ms
server  | 1.049 DEBUG Setting timeout of 99.36127ms
server  | 1.049 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.049 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.049 DEBUG [Server 17bceaadee5b3205] delay duration 99.34475ms
server  | 1.049 DEBUG Setting timeout of 99.34475ms
client  | Stream 0 ended after 5120 bytes
server  | 1.071 DEBUG [Server 17bceaadee5b3205] pn=2 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 55
server  |   -> RX Ack { largest_acknowledged: 2, ack_delay: 2, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
server  |   -> RX Padding { len: 19 }
server  | 1.071 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=2]
server  | 1.071 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=2
server  | 1.071 INFO ECN validation succeeded, path is capable
server  | 1.071 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9708/14932 ssthresh 18446744073709551615] slow start += 2612
server  | 1.071 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 9708/14932 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=9708, cwnd=14932, state=SlowStart, new_acked=2612
server  | 1.071 DEBUG PMTUD probe of size 1380 succeeded
server  | 1.071 DEBUG PMTUD started with probe size 1420
server  | 1.071 DEBUG PLPMTU changed from 1232 to 1332, updating pacer
server  | 1.071 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.071 DEBUG Sending PMTUD probe of size 1420, count 1
server  | 1.071 DEBUG [Server 17bceaadee5b3205] pn=11 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1372
server  |   TX -> Ping
server  |   TX -> Stream { stream_id: 4, offset: 4346, len: >>1341, fin: false }
server  | 1.071 DEBUG packet_sent this=0x555d8d132b40, pn=11, ps=1372
server  | 1.071 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.071 DEBUG [Server 17bceaadee5b3205] pn=12 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 5687, len: >>1302, fin: false }
server  | 1.071 DEBUG packet_sent this=0x555d8d132b40, pn=12, ps=1332
server  | 1.071 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.071 DEBUG [Server 17bceaadee5b3205] pn=13 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1332
server  |   TX -> Stream { stream_id: 4, offset: 6989, len: >>1302, fin: false }
server  | 1.071 DEBUG packet_sent this=0x555d8d132b40, pn=13, ps=1332
server  | 1.071 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1188, pto: None, probe: EnumSet(), paced: false }
server  | 1.071 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.071 DEBUG [Server 17bceaadee5b3205] pn=14 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1188
server  |   TX -> Stream { stream_id: 4, offset: 8291, len: >>1158, fin: false }
server  | 1.071 DEBUG packet_sent this=0x555d8d132b40, pn=14, ps=1188
server  | 1.072 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.072 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.072 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.072 DEBUG [Server 17bceaadee5b3205] delay duration 88.271704ms
server  | 1.072 DEBUG Setting timeout of 88.271704ms
server  | 1.072 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.072 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.072 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: false }
server  | 1.072 DEBUG [Server 17bceaadee5b3205] delay duration 88.249522ms
server  | 1.072 DEBUG Setting timeout of 88.249522ms
server  | 1.074 DEBUG [Server 17bceaadee5b3205] pn=3 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 55
server  |   -> RX Ack { largest_acknowledged: 4, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 5, Ce: 0})) }
server  |   -> RX Padding { len: 19 }
server  | 1.074 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=4]
server  | 1.074 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=4
server  | 1.074 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12468/17396 ssthresh 18446744073709551615] slow start += 2464
server  | 1.074 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 12468/17396 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=12468, cwnd=17396, state=SlowStart, new_acked=2464
server  | 1.074 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.074 DEBUG CRYPTO for ap offset=0, len=305
server  | 1.074 DEBUG [Server 17bceaadee5b3205] pn=15 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 1177
server  |   TX -> Stream { stream_id: 4, offset: 9449, len: 791, fin: true }
server  |   TX -> Crypto { offset: 0, len: 305 }
server  |   TX -> NewToken { token: [173, 154, 139, 141, 134, 1, 0, 157, 218, 161, 80, 151, 24, 125, 243, 60, 111, 223, 135, 158, 152, 128, 201, 94, 251, 53, 181, 254, 123, 77, 114, 78, 218, 177, 5, 209, 15, 181, 222, 249, 5, 58, 226] }
server  | 1.074 DEBUG packet_sent this=0x555d8d132b40, pn=15, ps=1177
server  | 1.074 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG [Server 17bceaadee5b3205] delay duration 80.137293ms
server  | 1.074 DEBUG Setting timeout of 80.137293ms
server  | 1.074 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.074 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.074 DEBUG [Server 17bceaadee5b3205] delay duration 80.112157ms
server  | 1.074 DEBUG Setting timeout of 80.112157ms
server  | 1.078 DEBUG [Server 17bceaadee5b3205] pn=4 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 55
server  |   -> RX Ack { largest_acknowledged: 6, ack_delay: 4, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) }
server  |   -> RX Padding { len: 19 }
server  | 1.078 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=6]
server  | 1.078 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=6
server  | 1.078 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11181/19860 ssthresh 18446744073709551615] slow start += 2464
server  | 1.078 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 11181/19860 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=11181, cwnd=19860, state=SlowStart, new_acked=2464
server  | 1.078 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server 17bceaadee5b3205] delay duration 70.938607ms
server  | 1.078 DEBUG Setting timeout of 70.938607ms
server  | 1.078 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.078 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.078 DEBUG [Server 17bceaadee5b3205] delay duration 70.878044ms
server  | 1.078 DEBUG Setting timeout of 70.878044ms
server  | 1.081 DEBUG [Server 17bceaadee5b3205] pn=5 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 55
server  |   -> RX Ack { largest_acknowledged: 8, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) }
server  |   -> RX Padding { len: 19 }
server  | 1.081 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=8]
server  | 1.081 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=8
server  | 1.081 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8717/22324 ssthresh 18446744073709551615] slow start += 2464
server  | 1.081 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 8717/22324 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=8717, cwnd=22324, state=SlowStart, new_acked=2464
server  | 1.081 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.081 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.081 DEBUG [Server 17bceaadee5b3205] pn=16 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect0) len 28
server  |   TX -> MaxStreams { stream_type: BiDi, maximum_streams: 17 }
server  | 1.081 DEBUG packet_sent this=0x555d8d132b40, pn=16, ps=29
server  | 1.081 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.081 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.081 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.081 DEBUG [Server 17bceaadee5b3205] delay duration 69.69356ms
server  | 1.081 DEBUG Setting timeout of 69.69356ms
server  | 1.081 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.081 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.081 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.081 DEBUG [Server 17bceaadee5b3205] delay duration 69.667712ms
server  | 1.081 DEBUG Setting timeout of 69.667712ms
server  | 1.083 DEBUG [Server 17bceaadee5b3205] pn=6 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 55
server  |   -> RX Ack { largest_acknowledged: 10, ack_delay: 3, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 9, Ce: 0})) }
server  |   -> RX Padding { len: 19 }
server  | 1.083 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=10]
server  | 1.083 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=10
server  | 1.083 WARN ECN validation failed, no ECT(0) packets were newly acked
server  | 1.083 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6430/24640 ssthresh 18446744073709551615] slow start += 2316
server  | 1.083 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6430/24640 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=6430, cwnd=24640, state=SlowStart, new_acked=2316
server  | 1.083 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.083 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.083 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.083 DEBUG [Server 17bceaadee5b3205] delay duration 62.301316ms
server  | 1.083 DEBUG Setting timeout of 62.301316ms
server  | 1.083 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.083 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.083 DEBUG TX blocked, profile=SendProfile { limit: 1332, pto: None, probe: EnumSet(), paced: false }
server  | 1.083 DEBUG [Server 17bceaadee5b3205] delay duration 62.237908ms
server  | 1.083 DEBUG Setting timeout of 62.237908ms
client  | Stream 4 ended after 10240 bytes
client  | All done, Closing the connection.
server  | 1.104 DEBUG [Server 17bceaadee5b3205] pn=7 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 55
server  |   -> RX Ack { largest_acknowledged: 12, ack_delay: 4, first_ack_range: 12, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 11, Ce: 0})) }
server  |   -> RX Padding { len: 19 }
server  | 1.104 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=12]
server  | 1.104 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=12
server  | 1.104 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3726/27344 ssthresh 18446744073709551615] slow start += 2704
server  | 1.104 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 3726/27344 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=3726, cwnd=27344, state=SlowStart, new_acked=2704
server  | 1.104 DEBUG PMTUD probe of size 1420 succeeded
server  | 1.104 DEBUG PMTUD started with probe size 1470
server  | 1.104 DEBUG PLPMTU changed from 1332 to 1372, updating pacer
server  | 1.104 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.104 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.104 DEBUG Sending PMTUD probe of size 1470, count 1
server  | 1.104 DEBUG [Server 17bceaadee5b3205] pn=17 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, NotEct) len 1422
server  |   TX -> Ping
server  |   TX -> Padding { len: 1395 }
server  | 1.104 DEBUG packet_sent this=0x555d8d132b40, pn=17, ps=1422
server  | 1.104 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.104 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.104 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.104 DEBUG [Server 17bceaadee5b3205] delay duration 60.386275ms
server  | 1.104 DEBUG Setting timeout of 60.386275ms
server  | 1.104 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.104 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.104 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.104 DEBUG [Server 17bceaadee5b3205] delay duration 60.36234ms
server  | 1.104 DEBUG Setting timeout of 60.36234ms
server  | 1.106 DEBUG [Server 17bceaadee5b3205] pn=8 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 55
server  |   -> RX Ack { largest_acknowledged: 14, ack_delay: 2, first_ack_range: 14, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 13, Ce: 0})) }
server  |   -> RX Padding { len: 19 }
server  | 1.106 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=14]
server  | 1.106 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=14
server  | 1.106 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2628/29864 ssthresh 18446744073709551615] slow start += 2520
server  | 1.106 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 2628/29864 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=2628, cwnd=29864, state=SlowStart, new_acked=2520
server  | 1.106 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.106 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG [Server 17bceaadee5b3205] delay duration 55.024771ms
server  | 1.106 DEBUG Setting timeout of 55.024771ms
server  | 1.106 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.106 DEBUG TX blocked, profile=SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.106 DEBUG [Server 17bceaadee5b3205] delay duration 54.963587ms
server  | 1.106 DEBUG Setting timeout of 54.963587ms
server  | 1.107 DEBUG [Server 17bceaadee5b3205] pn=9 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, Ect1) len 39
server  |   -> RX Ack { largest_acknowledged: 15, ack_delay: 7, first_ack_range: 15, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 14, Ce: 0})) }
server  |   -> RX ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "" }
server  | 1.107 DEBUG [Server 17bceaadee5b3205] Rx ACK space=ap, ranges=[0..=15]
server  | 1.107 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=15
server  | 1.107 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1451/31041 ssthresh 18446744073709551615] slow start += 1177
server  | 1.107 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1451/31041 ssthresh 18446744073709551615] on_packets_acked this=0x555d8d132b40, limited=0, bytes_in_flight=1451, cwnd=31041, state=SlowStart, new_acked=1177
server  | 1.107 DEBUG Acked crypto frame space=ap offset=0 length=305
server  | 1.107 INFO [Server 17bceaadee5b3205] ConnectionClose received. Error code: Application(0) frame type 0 reason 
server  | 1.107 DEBUG [Server 17bceaadee5b3205] State change from Confirmed -> Draining { error: Transport(PeerApplicationError(0)), timeout: Instant { tv_sec: 647, tv_nsec: 790319773 } }
server  | 1.107 DEBUG [pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911] Path validated Instant { tv_sec: 647, tv_nsec: 626497966 }
server  | 1.107 DEBUG [Server 17bceaadee5b3205] output_path send_profile SendProfile { limit: 1372, pto: None, probe: EnumSet(), paced: false }
server  | 1.107 DEBUG Building Short dcid Some(CID [8]: 09e83234c60e5ef7)
server  | 1.107 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 647, tv_nsec: 626497966 }
server  | 1.107 DEBUG [Server 17bceaadee5b3205] pn=18 type=Short pri-path:09e83234c60e5ef7 [::]:443->[fd00:cafe:cafe::100]:57911 IpTos(Cs0, NotEct) len 38
server  |   TX -> Ack { largest_acknowledged: 9, ack_delay: 0, first_ack_range: 9, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 10, Ect0: 0, Ce: 0})) }
server  |   TX -> ConnectionClose { error_code: Transport(0), frame_type: 29, reason_phrase: "" }
server  | 1.107 DEBUG Setting timeout of 163.693407ms
server  | 1.107 DEBUG Setting timeout of 163.67879ms
client  | Received a request to close the connection.
client  | The connection is closed!
client  | Address Discovery mode: 0 / 0 (0:0)
client  | Quic Bit was greased by the client.
client  | Quic Bit was greased by the server.
client  | ECN was received (ect0: 15, ect1: 0, ce: 0).
client  | ECN was acknowledged (ect0: 0, ect1: 2, ce: 0).
client  | Received 15360 bytes in 0.146113 seconds, 0.840993 Mbps.
client  | Sent 34 bytes in 0.146113 seconds, 0.001862 Mbps.
client  | max_data_local: 1048576
client  | max_stream_data_local: 2097152
client  | max_data_remote: 4611686018427387903
client  | max_stream_data_remote: 1048576
client  | ack_delay_remote: 1000 ... 4123
client  | max_ack_gap_remote: 2
client  | ack_delay_local: 25000 ... 25000
client  | max_ack_gap_local: 2
client  | max_mtu_sent: 1232
client  | max_mtu_received: 1422
client  | System call duration max: 5
client  | System call duration smoothed: 0
client  | System call duration deviation: 0
client  | Received ticket from server6 (hq-interop):
client  | ticket time = 1746002972797, kx = 17, suite = 1301, 301 ticket, 32 secret.
client  | lifetime = 172800, age_add = 4a4e1ab9, 2 nonce, 274 ticket, 12 extensions.
client  | ticket extensions: 60138 (0 bytes),42(ED: ffffffff),
client  | Client exit with code = 0

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 08:49:43,244 Using the client's key log file.
2025-04-30 08:49:43,256 
2025-04-30 08:49:43,257 Using the client's key log file.
2025-04-30 08:49:43,257 Using the client's key log file.
2025-04-30 08:49:43,267 
2025-04-30 08:49:43,268 Using the client's key log file.
2025-04-30 08:49:43,845 Check of downloaded files succeeded.
2025-04-30 08:49:44,416 Check of downloaded files succeeded.