2025-09-11 21:22:18,248 Generated random file: gljduvxuzz of size: 5120
2025-09-11 21:22:18,249 Generated random file: ourjcnnxdl of size: 10240
2025-09-11 21:22:18,249 Requests: https://server4:443/gljduvxuzz https://server4:443/ourjcnnxdl
2025-09-11 21:22:18,307 
2025-09-11 21:22:18,308 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_3wo9ea0j/ TESTCASE_SERVER=resumption TESTCASE_CLIENT=resumption WWW=/tmp/www_qxu9_4wz/ DOWNLOADS=/tmp/download_vxmv1qlx/ SERVER_LOGS=/tmp/logs_server_cqh21p5l CLIENT_LOGS=/tmp/logs_client_g9dsej1z SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/alibaba/xquic/xquic-interop:latest REQUESTS="https://server4:443/gljduvxuzz https://server4:443/ourjcnnxdl"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-09-11 21:22:30,990  Container client  Recreate
 Container server  Recreate
 Container client  Recreated
 Container server  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
server  | Setting up routes...
server  | Actual changes:
server  | tx-checksum-ip-generic: off
server  | tx-tcp-segmentation: off [not requested]
server  | tx-tcp-ecn-segmentation: off [not requested]
server  | tx-tcp-mangleid-segmentation: off [not requested]
server  | tx-tcp6-segmentation: off [not requested]
server  | tx-udp-segmentation: off [not requested]
server  | tx-checksum-sctp: off
server  | Endpoint's IPv4 address is 193.167.100.100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
client  | Setting up routes...
client  | Actual changes:
client  | tx-checksum-ip-generic: off
client  | tx-tcp-segmentation: off [not requested]
client  | tx-tcp-ecn-segmentation: off [not requested]
client  | tx-tcp-mangleid-segmentation: off [not requested]
client  | tx-tcp6-segmentation: off [not requested]
client  | tx-udp-segmentation: off [not requested]
client  | tx-checksum-sctp: off
client  | Endpoint's IPv4 address is 193.167.0.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | ./demo_server -l d -L /logs/server.log -p 443 -D /www -k /logs/keys.log -i -M
server  | option log level :d
server  | option log directory :/logs/server.log
server  | option port :443
server  | option read dir :/www
server  | option key output file: /logs/keys.log
server  | set interop mode
server  | option multipath enabled
server  | /logs/keys.log 4
client  | + export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
client  | + PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/neqo/bin
client  | + '[' -n resumption ']'
client  | + '[' -n /logs/qlog/ ']'
client  | + case "$ROLE" in
client  | + /wait-for-it.sh sim:57832 -s -t 30
server  | create ipv4 socket fd: 9
server  | create ipv6 socket fd: 10
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
sim     | server:443 is available after 501.207046ms
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  | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads)
client  | + '[' 'https://server4:443/gljduvxuzz https://server4:443/ourjcnnxdl' ']'
client  | + mapfile -d ' ' -t URLS
client  | + OPTIONS+=("${URLS[@]}")
client  | + RUST_LOG=debug
client  | + RUST_BACKTRACE=1
client  | + neqo-client --cc cubic --qns-test resumption --qlog-dir /logs/qlog/ --output-dir /downloads https://server4:443/gljduvxuzz 'https://server4:443/ourjcnnxdl
client  | '
client  | ++ tee -i -a /logs/client.log
client  | 0.000 DEBUG Logging initialized
client  | 0.001 DEBUG Default socket send buffer size is Ok(212992)
client  | 0.001 DEBUG Default socket receive buffer size is 1048576, not changing
client  | 0.001 INFO hq-interop Client connecting: 0.0.0.0:48400 -> 193.167.100.100:443
client  | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=dee57de5478475c2a9697103ff252fda45
client  | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=96
client  | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500
client  | 0.001 DEBUG [unv-path 0.0.0.0:48400->193.167.100.100:443] Make permanent
client  | 0.001 DEBUG [unv-path:dee57de5478475c2a9697103ff252fda45 0.0.0.0:48400->193.167.100.100:443] set as primary path
client  | 0.001 DEBUG [pri-unv-path:dee57de5478475c2a9697103ff252fda45 0.0.0.0:48400->193.167.100.100:443] Path validated Instant { tv_sec: 512, tv_nsec: 196531543 }
client  | 0.001 DEBUG [Client dee57de5478475c2a9697103ff252fda45] client_start
client  | 0.002 DEBUG Writing transport parameters, msg=1
client  | 0.002 DEBUG [Agent 0x556f30a95420] state -> InProgress
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] State change from Init -> WaitInitial
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: dee57de5478475c2a9697103ff252fda45) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=0, len=1204
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=96 type=Initial pri-path:dee57de5478475c2a9697103ff252fda45 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1252
client  |   TX -> Crypto { offset: 0, len: 1204 }
client  | 0.002 DEBUG packet_sent this=0x556f30aa8be0, pn=96, ps=1252
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: dee57de5478475c2a9697103ff252fda45) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=1204, len=336
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=97 type=Initial pri-path:dee57de5478475c2a9697103ff252fda45 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 385
client  |   TX -> Crypto { offset: 1204, len: 336 }
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pad Initial from 385 to PLPMTU 1252
client  | 0.002 DEBUG packet_sent this=0x556f30aa8be0, pn=97, ps=1252
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: dee57de5478475c2a9697103ff252fda45) scid Some(CID [0]: )
client  | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: dee57de5478475c2a9697103ff252fda45) scid Some(CID [0]: )
client  | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 3.757935ms
client  | 0.002 DEBUG Setting timeout of 3.757935ms
client  | 0.002 DEBUG StateChange(WaitInitial)
client  | 0.002 WARN Cannot create stream ConnectionState
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [17]: dee57de5478475c2a9697103ff252fda45) scid Some(CID [0]: )
client  | 0.002 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 3.718382ms
client  | 0.002 DEBUG Setting timeout of 3.718382ms
client  | 0.007 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.007 DEBUG Building Initial dcid Some(CID [17]: dee57de5478475c2a9697103ff252fda45) scid Some(CID [0]: )
client  | 0.007 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.007 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 294.253441ms
client  | 0.007 DEBUG Setting timeout of 294.253441ms
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=0 type=Initial pri-path:dee57de5478475c2a9697103ff252fda45 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 49
client  |   -> RX Ack { largest_acknowledged: 96, ack_delay: 76, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] Rx ACK space=in, ranges=[96..=96]
client  | 0.039 DEBUG [recovery::Loss] ACK for Initial - largest_acked=96
client  | 0.039 DEBUG on_packets_acked this=0x556f30aa8be0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252
client  | 0.039 DEBUG Acked crypto frame space=in offset=0 length=1204
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] Changing to use Server CID=350dbdaa1d1c1c5fef6fe213
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] State change from WaitInitial -> WaitVersion
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG Building Initial dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 75.671463ms
client  | 0.039 DEBUG Setting timeout of 75.671463ms
client  | 0.039 WARN Unhandled event StateChange(WaitVersion)
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG Building Initial dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.039 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 75.632531ms
client  | 0.039 DEBUG Setting timeout of 75.632531ms
client  | 0.041 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=1 type=Initial pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1200
client  |   -> RX Crypto { offset: 0, len: 90 }
client  |   -> RX Padding { len: 1064 }
client  | 0.041 DEBUG Write secret available for Handshake: SymKey [32]: d02cff592af7ca072181572ed4c7be1f083d4f2dd3e465c94176ad0a1b4acaf5
client  | 0.041 DEBUG Read secret available for Handshake: SymKey [32]: ca38e6c798f9dda4d190b96d139944d785e1a80d66565f9d963a82bc37198bb2
client  | 0.041 DEBUG [Agent 0x556f30a95420] state -> InProgress
client  | 0.041 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.041 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.041 DEBUG [Crypto] Handshake keys installed
client  | 0.041 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 236846651 }
client  | 0.041 DEBUG [Client dee57de5478475c2a9697103ff252fda45] State change from WaitVersion -> Handshaking
client  | 0.041 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.041 DEBUG Building Initial dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.041 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=98 type=Initial pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 44
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 61, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  | 0.041 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.041 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pad Initial from 44 to PLPMTU 1252
client  | 0.041 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.041 DEBUG Building Initial dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.041 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Initial dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.042 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 73.376765ms
client  | 0.042 DEBUG Setting timeout of 73.376765ms
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=0 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 192
client  |   -> RX Crypto { offset: 0, len: 147 }
client  | 0.042 DEBUG [Agent 0x556f30a95420] state -> InProgress
client  | 0.042 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 237476222 }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Initial dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.042 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=0 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 43
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 4, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] Drop packet number space in
client  | 0.042 DEBUG [recovery::Loss] Reset loss recovery state for Initial
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 113.575617ms
client  | 0.042 DEBUG Setting timeout of 113.575617ms
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=1 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 516
client  |   -> RX Crypto { offset: 147, len: 470 }
client  | 0.042 DEBUG [Agent 0x556f30a95420] state -> AuthenticationPending
client  | 0.042 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 237611994 }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=1 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 43
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 16, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 113.373812ms
client  | 0.042 DEBUG Setting timeout of 113.373812ms
client  | 0.042 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=2 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 125
client  |   -> RX Crypto { offset: 617, len: 79 }
client  | 0.043 DEBUG [Agent 0x556f30a95420] state -> AuthenticationPending
client  | 0.043 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 237811125 }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=2 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 44
client  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 76, first_ack_range: 2, ack_ranges: [], ecn_count: None }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 112.688257ms
client  | 0.043 DEBUG Setting timeout of 112.688257ms
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=3 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 81
client  |   -> RX Crypto { offset: 696, len: 36 }
client  | 0.043 DEBUG [Agent 0x556f30a95420] state -> AuthenticationPending
client  | 0.043 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 238499755 }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=3 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 43
client  |   TX -> Ack { largest_acknowledged: 3, ack_delay: 6, first_ack_range: 3, ack_ranges: [], ecn_count: None }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 112.547154ms
client  | 0.043 DEBUG Setting timeout of 112.547154ms
client  | 0.043 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 1
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=4 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 39
client  |   TX -> Ping
client  | 0.043 DEBUG packet_sent this=0x556f30aa8be0, pn=4, ps=41
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 113.591958ms
client  | 0.043 DEBUG Setting timeout of 113.591958ms
client  | 0.043 DEBUG StateChange(Handshaking)
client  | 0.043 WARN Cannot create stream ConnectionState
client  | 0.043 DEBUG stream BiDi creatable
client  | 0.043 WARN Cannot create stream ConnectionState
client  | 0.043 DEBUG stream UniDi creatable
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] Authenticated Ok
client  | 0.043 DEBUG Write secret available for ApplicationData: SymKey [32]: 961463ddb092bbba607da5f81be9088caa939ac29654d01e13c27854abe3c203
client  | 0.043 DEBUG Read secret available for ApplicationData: SymKey [32]: 9199609419a87d75403d24722ef754251c973126342e83ff6a3fbda14c5198c7
client  | 0.043 DEBUG [Agent 0x556f30a95420] SSL_AuthCertificateComplete: Ok(())
client  | 0.043 DEBUG [Agent 0x556f30a95420] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] TLS connection complete
client  | 0.043 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.043 DEBUG [Crypto] Application write key installed
client  | 0.043 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.043 DEBUG [Crypto] application read keys installed
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] State change from Handshaking -> Connected
client  | 0.043 INFO [Client dee57de5478475c2a9697103ff252fda45] Connection established
client  | 0.043 DEBUG stream BiDi creatable
client  | 0.043 INFO Created stream 0 for https://server4/gljduvxuzz
client  | 0.043 INFO Saving https://server4/gljduvxuzz to "/downloads/gljduvxuzz"
client  | 0.043 DEBUG stream UniDi creatable
client  | 0.043 DEBUG StateChange(Connected)
client  | 0.043 DEBUG stream 0 writable
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG CRYPTO for hs offset=0, len=36
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=5 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 77
client  |   TX -> Crypto { offset: 0, len: 36 }
client  | 0.043 DEBUG packet_sent this=0x556f30aa8be0, pn=5, ps=77
client  | 0.043 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=0 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 127
client  |   TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true }
client  | 0.043 DEBUG packet_sent this=0x556f30aa8be0, pn=0, ps=50
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.043 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.043 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.043 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 113.546464ms
client  | 0.043 DEBUG Setting timeout of 113.546464ms
server  | xqc_hq_parse_req|247||hq recv CR LF|
client  | 0.074 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=4 type=Handshake pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 46
client  |   -> RX Ack { largest_acknowledged: 4, ack_delay: 12, first_ack_range: 4, ack_ranges: [], ecn_count: None }
client  | 0.074 DEBUG [Client dee57de5478475c2a9697103ff252fda45] Rx ACK space=hs, ranges=[0..=4]
client  | 0.074 DEBUG [recovery::Loss] ACK for Handshake - largest_acked=4
client  | 0.074 DEBUG on_packets_acked this=0x556f30aa8be0, limited=1, bytes_in_flight=127, cwnd=12520, state=SlowStart, new_acked=41
client  | 0.074 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.074 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 69.440729ms
client  | 0.074 DEBUG Setting timeout of 69.440729ms
client  | 0.074 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG Building Handshake dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213) scid Some(CID [0]: )
client  | 0.074 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.074 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 69.40413ms
client  | 0.074 DEBUG Setting timeout of 69.40413ms
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=0 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 22
client  |   -> RX HandshakeDone
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] State change from Connected -> Confirmed
client  | 0.075 DEBUG PMTUD started with probe size 1380
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] Drop packet number space hs
client  | 0.075 DEBUG [recovery::Loss] Reset loss recovery state for Handshake
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] No preferred address to migrate to
client  | 0.075 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 290941519 }
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.075 DEBUG Sending PMTUD probe of size 1380, count 1
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=1 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 1352
client  |   TX -> Ping
client  |   TX -> Padding { len: 1321 }
client  | 0.075 DEBUG packet_sent this=0x556f30aa8be0, pn=1, ps=1352
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG ECN probing: sent 1 probes
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.800459ms
client  | 0.075 DEBUG Setting timeout of 19.800459ms
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=7 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 32
client  |   -> RX NewToken { token: [0, 193, 167, 0, 100, 104, 204, 120, 11] }
client  | 0.075 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 271166257 }
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=2 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 37
client  |   TX -> Ack { largest_acknowledged: 7, ack_delay: 2, first_ack_range: 0, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  | 0.075 DEBUG ECN probing: sent 2 probes
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 125.18792ms
client  | 0.075 DEBUG Setting timeout of 125.18792ms
client  | 0.075 WARN Unhandled event StateChange(Confirmed)
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 125.164817ms
client  | 0.075 DEBUG Setting timeout of 125.164817ms
client  | 0.075 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=8 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 282
client  |   -> RX Crypto { offset: 0, len: 257 }
client  | 0.076 DEBUG [0x556f30a95420] Got resumption token [920]: 0200063e8d21df80..ce194ce4a420872f
client  | 0.076 DEBUG [Agent 0x556f30a95420] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
client  | 0.076 DEBUG setting max_stream_data to 16777216
client  | 0.076 DEBUG resumption token [1033]: 0000000125406000..ce194ce4a420872f
client  | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 291358927 }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.825565ms
client  | 0.076 DEBUG Setting timeout of 19.825565ms
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=9 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 283
client  |   -> RX Crypto { offset: 257, len: 257 }
client  | 0.076 DEBUG [0x556f30a95420] Got resumption token [920]: 0200063e8d21df81..dc027983a47d570b
client  | 0.076 DEBUG [Agent 0x556f30a95420] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
client  | 0.076 DEBUG setting max_stream_data to 16777216
client  | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 271557156 }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=3 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 37
client  |   TX -> Ack { largest_acknowledged: 9, ack_delay: 8, first_ack_range: 2, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  | 0.076 DEBUG ECN probing: sent 3 probes
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 124.757036ms
client  | 0.076 DEBUG Setting timeout of 124.757036ms
client  | 0.076 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 2
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 124.729395ms
client  | 0.076 DEBUG Setting timeout of 124.729395ms
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=10 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 53
client  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [55, 131, 135, 239, 111, 94, 90, 26, 91, 71, 116, 81], stateless_reset_token: [48, 125, 97, 229, 180, 79, 5, 97, 83, 64, 72, 181, 117, 60, 44, 148] }
client  | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 291731731 }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.94093ms
client  | 0.076 DEBUG Setting timeout of 19.94093ms
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=11 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 53
client  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [213, 60, 184, 222, 141, 159, 205, 55, 135, 95, 73, 123], stateless_reset_token: [47, 160, 244, 84, 246, 64, 41, 179, 94, 212, 45, 79, 100, 229, 116, 85] }
client  | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 271815256 }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=4 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 37
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 2, first_ack_range: 4, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  | 0.076 DEBUG ECN probing: sent 4 probes
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 124.539281ms
client  | 0.076 DEBUG Setting timeout of 124.539281ms
client  | 0.076 DEBUG stream BiDi creatable
client  | 0.076 DEBUG stream UniDi creatable
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.076 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 124.515517ms
client  | 0.076 DEBUG Setting timeout of 124.515517ms
client  | 0.077 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=12 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 0, len: 1191, fin: false }
client  | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 292761566 }
client  | 0.077 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.971958ms
client  | 0.077 DEBUG Setting timeout of 19.971958ms
client  | 0.077 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.077 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.948684ms
client  | 0.077 DEBUG Setting timeout of 19.948684ms
client  | 0.078 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=13 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 1191, len: 1189, fin: false }
client  | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 273763145 }
client  | 0.078 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.078 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=5 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 37
client  |   TX -> Ack { largest_acknowledged: 13, ack_delay: 3, first_ack_range: 6, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  | 0.078 DEBUG ECN probing: sent 5 probes
client  | 0.078 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 122.601401ms
client  | 0.078 DEBUG Setting timeout of 122.601401ms
client  | 0.078 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.078 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 122.572918ms
client  | 0.078 DEBUG Setting timeout of 122.572918ms
client  | 0.079 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=14 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 2380, len: 1189, fin: false }
client  | 0.079 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 294752605 }
client  | 0.079 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.079 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.079 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.969242ms
client  | 0.079 DEBUG Setting timeout of 19.969242ms
client  | 0.079 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.079 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.079 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.079 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.953533ms
client  | 0.079 DEBUG Setting timeout of 19.953533ms
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=15 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 3569, len: 1189, fin: false }
client  | 0.080 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 275745793 }
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=6 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 37
client  |   TX -> Ack { largest_acknowledged: 15, ack_delay: 2, first_ack_range: 8, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  | 0.080 DEBUG ECN probing: sent 6 probes
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 120.62765ms
client  | 0.080 DEBUG Setting timeout of 120.62765ms
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 120.598726ms
client  | 0.080 DEBUG Setting timeout of 120.598726ms
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=16 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 389
client  |   -> RX Stream { stream_id: 0, offset: 4758, len: 362, fin: true }
client  | 0.080 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 296096790 }
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.971377ms
client  | 0.080 DEBUG Setting timeout of 19.971377ms
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.080 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] delay duration 19.918118ms
client  | 0.080 DEBUG Setting timeout of 19.918118ms
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 652370920 } }
client  | 0.080 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 652370920 } })
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.080 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.080 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 276214189 }
client  | 0.080 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=7 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 48
client  |   TX -> Ack { largest_acknowledged: 16, ack_delay: 14, first_ack_range: 9, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.080 DEBUG ECN probing: sent 7 probes
client  | 0.080 DEBUG Setting timeout of 376.099665ms
client  | 0.099 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.099 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.099 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 295349009 }
client  | 0.099 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=8 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 49
client  |   TX -> Ack { largest_acknowledged: 16, ack_delay: 2406, first_ack_range: 9, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.099 DEBUG ECN probing: sent 8 probes
client  | 0.100 DEBUG Setting timeout of 356.96228ms
client  | 0.100 DEBUG Setting timeout of 356.954926ms
client  | 0.111 DEBUG [Client dee57de5478475c2a9697103ff252fda45] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.111 DEBUG Building Short dcid Some(CID [12]: 350dbdaa1d1c1c5fef6fe213)
client  | 0.111 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 306976135 }
client  | 0.111 DEBUG [Client dee57de5478475c2a9697103ff252fda45] pn=9 type=Short pri-path:350dbdaa1d1c1c5fef6fe213 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, Ect0) len 49
client  |   TX -> Ack { largest_acknowledged: 16, ack_delay: 3859, first_ack_range: 9, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.111 DEBUG ECN probing: sent 9 probes
client  | 0.111 DEBUG Setting timeout of 345.283377ms
client  | 0.111 DEBUG Setting timeout of 345.271636ms
server  | send_count:16, lost_count:0, tlp_count:0, recv_count:18, srtt:33000 early_data_flag:0, conn_err:0, ack_info:#9-0#0-0#0-0#v0429, path_info:0/1/0/a/0,1,1,1,0,0,0,0,0,0,0,22,22,18,5120,0,17,i32,4,36,49,0,9,103,0,4,35,48,40004,7,72,0,4,36,49,0,8,91,0,4,9,40000,18,72,4,373,80,16,37,4,11,4,17,60,0-2,0-2,0-0,0-0,0-0,0-33,0-8335,0-5780,0-16,0-18,0-0,0-0,0-0,0-0,0-0,0-0,0-0,0-0
client  | 0.458 DEBUG [Client dee57de5478475c2a9697103ff252fda45] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 652370920 } } -> Closed(Application(0))
client  | 0.458 INFO Closing timer expired
client  | 0.458 DEBUG Output::None
client  | 0.458 WARN Unhandled event StateChange(Closed(Application(0)))
client  | 0.458 DEBUG Timer fired while closed
client  | 0.458 DEBUG Output::None
client  | 0.458 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=712bdc99dc3437b2
client  | 0.458 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=20
client  | 0.458 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.458 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500
client  | 0.458 DEBUG [unv-path 0.0.0.0:48400->193.167.100.100:443] Make permanent
client  | 0.458 DEBUG [unv-path:712bdc99dc3437b2 0.0.0.0:48400->193.167.100.100:443] set as primary path
client  | 0.458 DEBUG [pri-unv-path:712bdc99dc3437b2 0.0.0.0:48400->193.167.100.100:443] Path validated Instant { tv_sec: 512, tv_nsec: 653928186 }
client  | 0.458 INFO [Client 712bdc99dc3437b2] resumption token [1033]: 0000000125406000..ce194ce4a420872f
client  | 0.458 DEBUG Overwrite initial version Version1 ==> Version1
client  | 0.458 DEBUG Overwrite initial version Version1 ==> Version1
client  | 0.458 DEBUG [Client 712bdc99dc3437b2] client_start
client  | 0.459 DEBUG Writing transport parameters, msg=1
client  | 0.459 DEBUG Write secret available for ZeroRtt: SymKey [32]: cb0475672222112829f3731b699999eb6629b1701dad4b89e8b0beec7418a308
client  | 0.459 DEBUG [Agent 0x556f30ac5020] state -> InProgress
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] State change from Init -> WaitInitial
client  | 0.459 DEBUG Making Write ZeroRtt CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] Enabled 0-RTT
client  | 0.459 DEBUG stream BiDi creatable
client  | 0.459 INFO Created stream 0 for https://server4/ourjcnnxdl
client  | 0.459 INFO Saving https://server4/ourjcnnxdl to "/downloads/ourjcnnxdl"
client  | 0.459 DEBUG stream UniDi creatable
client  | 0.459 DEBUG StateChange(WaitInitial)
client  | 0.459 DEBUG stream 0 writable
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.459 DEBUG Building Initial dcid Some(CID [8]: 712bdc99dc3437b2) scid Some(CID [0]: )
client  | 0.459 DEBUG CRYPTO for in offset=0, len=1204
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] pn=20 type=Initial pri-path:712bdc99dc3437b2 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1252
client  |   TX -> Crypto { offset: 0, len: 1204 }
client  | 0.459 DEBUG packet_sent this=0x556f30aa8be0, pn=20, ps=1252
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.459 DEBUG Building Initial dcid Some(CID [8]: 712bdc99dc3437b2) scid Some(CID [0]: )
client  | 0.459 DEBUG CRYPTO for in offset=1204, len=611
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] pn=21 type=Initial pri-path:712bdc99dc3437b2 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 660
client  |   TX -> Crypto { offset: 1204, len: 611 }
client  | 0.459 DEBUG Building ZeroRtt dcid Some(CID [8]: 712bdc99dc3437b2) scid Some(CID [0]: )
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] pn=0 type=ZeroRtt pri-path:712bdc99dc3437b2 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 714
client  |   TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true }
client  | 0.459 DEBUG packet_sent this=0x556f30aa8be0, pn=0, ps=54
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] pad Initial from 714 to PLPMTU 1252
client  | 0.459 DEBUG packet_sent this=0x556f30aa8be0, pn=21, ps=1198
client  | 0.459 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.459 DEBUG Building Initial dcid Some(CID [8]: 712bdc99dc3437b2) scid Some(CID [0]: )
client  | 0.459 DEBUG Building ZeroRtt dcid Some(CID [8]: 712bdc99dc3437b2) scid Some(CID [0]: )
client  | 0.459 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.460 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.460 DEBUG Building Initial dcid Some(CID [8]: 712bdc99dc3437b2) scid Some(CID [0]: )
client  | 0.460 DEBUG Building ZeroRtt dcid Some(CID [8]: 712bdc99dc3437b2) scid Some(CID [0]: )
client  | 0.460 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.460 DEBUG [Client 712bdc99dc3437b2] delay duration 110.79578ms
client  | 0.460 DEBUG Setting timeout of 110.79578ms
server  | xqc_hq_parse_req|247||hq recv CR LF|
client  | 0.491 DEBUG [Client 712bdc99dc3437b2] pn=0 type=Initial pri-path:712bdc99dc3437b2 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 56
client  |   -> RX Ack { largest_acknowledged: 20, ack_delay: 55, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.492 DEBUG [Client 712bdc99dc3437b2] Rx ACK space=in, ranges=[20..=20]
client  | 0.492 DEBUG [recovery::Loss] ACK for Initial - largest_acked=20
client  | 0.492 DEBUG on_packets_acked this=0x556f30aa8be0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252
client  | 0.492 DEBUG Acked crypto frame space=in offset=0 length=1204
client  | 0.492 DEBUG [Client 712bdc99dc3437b2] Changing to use Server CID=df9201ec4e25ac93f7c23a11
client  | 0.492 DEBUG [Client 712bdc99dc3437b2] State change from WaitInitial -> WaitVersion
client  | 0.492 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.492 DEBUG Building Initial dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.492 DEBUG Building ZeroRtt dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.492 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.492 DEBUG [Client 712bdc99dc3437b2] delay duration 64.109647ms
client  | 0.492 DEBUG Setting timeout of 64.109647ms
client  | 0.492 WARN Unhandled event StateChange(WaitVersion)
client  | 0.492 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.492 DEBUG Building Initial dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.492 DEBUG Building ZeroRtt dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.492 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.492 DEBUG [Client 712bdc99dc3437b2] delay duration 64.066316ms
client  | 0.492 DEBUG Setting timeout of 64.066316ms
client  | 0.494 DEBUG [Client 712bdc99dc3437b2] pn=1 type=Initial pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1200
client  |   -> RX Crypto { offset: 0, len: 96 }
client  |   -> RX Padding { len: 1049 }
client  | 0.494 DEBUG Write secret available for Handshake: SymKey [32]: 1fe866c6dc2f3a77e2ec305cb3c5cf8546c74c4d96ad66a28f8fb22365046839
client  | 0.494 DEBUG Read secret available for Handshake: SymKey [32]: 568f69a66ab548164b123cfc925a2fa2df6e73efab23617f68ac9f249359dfae
client  | 0.494 DEBUG [Agent 0x556f30ac5020] state -> InProgress
client  | 0.494 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.494 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.494 DEBUG [Crypto] Handshake keys installed
client  | 0.494 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 689866464 }
client  | 0.494 DEBUG [Client 712bdc99dc3437b2] State change from WaitVersion -> Handshaking
client  | 0.494 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.494 DEBUG Building Initial dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.494 DEBUG [Client 712bdc99dc3437b2] pn=22 type=Initial pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 53
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 60, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  | 0.494 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.494 DEBUG Building ZeroRtt dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.494 DEBUG [Client 712bdc99dc3437b2] pad Initial from 53 to PLPMTU 1252
client  | 0.494 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Initial dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building ZeroRtt dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Initial dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building ZeroRtt dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] delay duration 61.103736ms
client  | 0.495 DEBUG Setting timeout of 61.103736ms
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] pn=0 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 187
client  |   -> RX Crypto { offset: 0, len: 142 }
client  | 0.495 DEBUG [Agent 0x556f30ac5020] state -> InProgress
client  | 0.495 DEBUG setting max_stream_data to 16777216
client  | 0.495 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 690476158 }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Initial dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] pn=0 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 43
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 5, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] Drop packet number space in
client  | 0.495 DEBUG [recovery::Loss] Reset loss recovery state for Initial
client  | 0.495 DEBUG Building ZeroRtt dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building ZeroRtt dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] delay duration 96.202972ms
client  | 0.495 DEBUG Setting timeout of 96.202972ms
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] pn=1 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 81
client  |   -> RX Crypto { offset: 142, len: 36 }
client  | 0.495 DEBUG Write secret available for ApplicationData: SymKey [32]: 4919daca47844f75309cd04b13bab7eb0f8e806f374c6c3ef2be8ef93d7c5f94
client  | 0.495 DEBUG Read secret available for ApplicationData: SymKey [32]: 188e625bf3b7285d1911e76ee67be00386064a2ca2839f14a0abc1a67d3cfc14
client  | 0.495 DEBUG [Agent 0x556f30ac5020] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: true, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 })
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] TLS connection complete
client  | 0.495 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.495 DEBUG [Crypto] Application write key installed
client  | 0.495 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0
client  | 0.495 DEBUG [Crypto] application read keys installed
client  | 0.495 DEBUG setting max_stream_data to 16777216
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] State change from Handshaking -> Connected
client  | 0.495 INFO [Client 712bdc99dc3437b2] Connection established
client  | 0.495 DEBUG setting max_stream_data to 16777216
client  | 0.495 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 690642648 }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG CRYPTO for hs offset=0, len=36
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] pn=1 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 82
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 49, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> Crypto { offset: 0, len: 36 }
client  | 0.495 DEBUG packet_sent this=0x556f30aa8be0, pn=1, ps=82
client  | 0.495 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.495 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] delay duration 96.177903ms
client  | 0.495 DEBUG Setting timeout of 96.177903ms
client  | 0.495 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 1
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.495 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] delay duration 96.14414ms
client  | 0.495 DEBUG Setting timeout of 96.14414ms
client  | 0.495 DEBUG StateChange(Handshaking)
client  | 0.495 DEBUG stream BiDi creatable
client  | 0.495 DEBUG stream UniDi creatable
client  | 0.495 DEBUG StateChange(Connected)
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.495 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] delay duration 96.100329ms
client  | 0.495 DEBUG Setting timeout of 96.100329ms
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] pn=0 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 0, len: 1191, fin: false }
client  | 0.495 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 711341520 }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.495 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.495 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.495 DEBUG [Client 712bdc99dc3437b2] delay duration 19.972669ms
client  | 0.495 DEBUG Setting timeout of 19.972669ms
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.496 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.496 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.496 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] delay duration 19.940329ms
client  | 0.496 DEBUG Setting timeout of 19.940329ms
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] pn=1 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 1191, len: 1189, fin: false }
client  | 0.496 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 692184598 }
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.496 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.496 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] pn=1 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 35
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 2, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.496 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.496 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.496 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] delay duration 95.074471ms
client  | 0.496 DEBUG Setting timeout of 95.074471ms
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.496 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.496 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.496 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.496 DEBUG [Client 712bdc99dc3437b2] delay duration 95.044986ms
client  | 0.496 DEBUG Setting timeout of 95.044986ms
client  | 0.497 DEBUG [Client 712bdc99dc3437b2] pn=2 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 2380, len: 1189, fin: false }
client  | 0.497 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 713178747 }
client  | 0.497 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.497 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.497 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.497 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.497 DEBUG [Client 712bdc99dc3437b2] delay duration 19.974152ms
client  | 0.497 DEBUG Setting timeout of 19.974152ms
client  | 0.497 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.497 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.497 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.497 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.497 DEBUG [Client 712bdc99dc3437b2] delay duration 19.950808ms
client  | 0.497 DEBUG Setting timeout of 19.950808ms
client  | 0.498 DEBUG [Client 712bdc99dc3437b2] pn=3 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 3569, len: 1189, fin: false }
client  | 0.498 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 694173368 }
client  | 0.498 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.498 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.498 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.498 DEBUG [Client 712bdc99dc3437b2] pn=2 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 35
client  |   TX -> Ack { largest_acknowledged: 3, ack_delay: 3, first_ack_range: 3, ack_ranges: [], ecn_count: None }
client  | 0.498 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.498 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.498 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.498 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.498 DEBUG [Client 712bdc99dc3437b2] delay duration 93.07958ms
client  | 0.498 DEBUG Setting timeout of 93.07958ms
client  | 0.498 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.498 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.498 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.498 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.498 DEBUG [Client 712bdc99dc3437b2] delay duration 93.045867ms
client  | 0.498 DEBUG Setting timeout of 93.045867ms
client  | 0.499 DEBUG [Client 712bdc99dc3437b2] pn=4 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 4758, len: 1189, fin: false }
client  | 0.499 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 715171103 }
client  | 0.499 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.499 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.499 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.499 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.499 DEBUG [Client 712bdc99dc3437b2] delay duration 19.974142ms
client  | 0.499 DEBUG Setting timeout of 19.974142ms
client  | 0.499 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.499 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.499 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.499 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.499 DEBUG [Client 712bdc99dc3437b2] delay duration 19.950057ms
client  | 0.499 DEBUG Setting timeout of 19.950057ms
client  | 0.500 DEBUG [Client 712bdc99dc3437b2] pn=5 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 5947, len: 1189, fin: false }
client  | 0.500 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 696170242 }
client  | 0.500 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.500 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.500 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.500 DEBUG [Client 712bdc99dc3437b2] pn=3 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 35
client  |   TX -> Ack { largest_acknowledged: 5, ack_delay: 3, first_ack_range: 5, ack_ranges: [], ecn_count: None }
client  | 0.500 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.500 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.500 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.500 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.500 DEBUG [Client 712bdc99dc3437b2] delay duration 91.084489ms
client  | 0.500 DEBUG Setting timeout of 91.084489ms
client  | 0.500 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.500 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.500 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.500 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.500 DEBUG [Client 712bdc99dc3437b2] delay duration 91.062789ms
client  | 0.500 DEBUG Setting timeout of 91.062789ms
client  | 0.501 DEBUG [Client 712bdc99dc3437b2] pn=6 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 7136, len: 1189, fin: false }
client  | 0.501 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 717162698 }
client  | 0.501 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.501 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.501 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.501 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.501 DEBUG [Client 712bdc99dc3437b2] delay duration 19.97306ms
client  | 0.501 DEBUG Setting timeout of 19.97306ms
client  | 0.501 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.501 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.501 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.501 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.501 DEBUG [Client 712bdc99dc3437b2] delay duration 19.949256ms
client  | 0.501 DEBUG Setting timeout of 19.949256ms
client  | 0.502 DEBUG [Client 712bdc99dc3437b2] pn=10 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 1216
client  |   -> RX Stream { stream_id: 0, offset: 8325, len: 1189, fin: false }
client  | 0.502 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 698164030 }
client  | 0.502 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.502 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.502 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.502 DEBUG [Client 712bdc99dc3437b2] pn=4 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 37
client  |   TX -> Ack { largest_acknowledged: 10, ack_delay: 3, first_ack_range: 0, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  | 0.502 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.502 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.502 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.502 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.502 DEBUG [Client 712bdc99dc3437b2] delay duration 89.09061ms
client  | 0.502 DEBUG Setting timeout of 89.09061ms
client  | 0.502 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.502 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.502 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.502 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.502 DEBUG [Client 712bdc99dc3437b2] delay duration 89.063269ms
client  | 0.502 DEBUG Setting timeout of 89.063269ms
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] pn=11 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 753
client  |   -> RX Stream { stream_id: 0, offset: 9514, len: 726, fin: true }
client  | 0.503 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 512, tv_nsec: 718787370 }
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.503 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.503 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.503 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] delay duration 19.974303ms
client  | 0.503 DEBUG Setting timeout of 19.974303ms
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.503 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.503 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.503 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] delay duration 19.915313ms
client  | 0.503 DEBUG Setting timeout of 19.915313ms
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] State change from Connected -> Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 987761216 } }
client  | 0.503 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 987761216 } })
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.503 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.503 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 512, tv_nsec: 698906471 }
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] pn=2 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 48
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 1032, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" }
client  | 0.503 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.503 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 698906471 }
client  | 0.503 DEBUG [Client 712bdc99dc3437b2] pn=5 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 96
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 14, first_ack_range: 1, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.503 DEBUG Setting timeout of 288.731626ms
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.527 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.527 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 512, tv_nsec: 722889601 }
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] pn=3 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 48
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 4030, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" }
client  | 0.527 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.527 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 722889601 }
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] pn=6 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 97
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 3012, first_ack_range: 1, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.527 DEBUG Setting timeout of 264.726175ms
client  | 0.527 DEBUG Setting timeout of 264.711708ms
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.527 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.527 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723177276 }
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] pn=4 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 48
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 4066, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" }
client  | 0.527 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.527 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723177276 }
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] pn=7 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 97
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 3048, first_ack_range: 1, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.527 DEBUG Setting timeout of 264.397533ms
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.527 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.527 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723375866 }
client  | 0.527 DEBUG [Client 712bdc99dc3437b2] pn=5 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 48
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 4091, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" }
client  | 0.528 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.528 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723375866 }
client  | 0.528 DEBUG [Client 712bdc99dc3437b2] pn=8 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 97
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 3073, first_ack_range: 1, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.528 DEBUG Setting timeout of 264.306875ms
client  | 0.528 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.528 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.528 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723474759 }
client  | 0.528 DEBUG [Client 712bdc99dc3437b2] pn=6 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 48
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 4104, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" }
client  | 0.528 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.528 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723474759 }
client  | 0.528 DEBUG [Client 712bdc99dc3437b2] pn=9 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 97
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 3085, first_ack_range: 1, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.528 DEBUG Setting timeout of 264.213631ms
client  | 0.528 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.528 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.528 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723558225 }
client  | 0.528 DEBUG [Client 712bdc99dc3437b2] pn=7 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 48
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 4114, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" }
client  | 0.528 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.528 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 723558225 }
client  | 0.528 DEBUG [Client 712bdc99dc3437b2] pn=10 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 97
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 3096, first_ack_range: 1, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.528 DEBUG Setting timeout of 264.115258ms
client  | 0.528 DEBUG Setting timeout of 264.107584ms
client  | 0.534 DEBUG [Client 712bdc99dc3437b2] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.534 DEBUG Building Handshake dcid Some(CID [12]: df9201ec4e25ac93f7c23a11) scid Some(CID [0]: )
client  | 0.534 DEBUG [Recvd-hs] immediate_ack at Instant { tv_sec: 512, tv_nsec: 729566521 }
client  | 0.534 DEBUG [Client 712bdc99dc3437b2] pn=8 type=Handshake pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 48
client  |   TX -> Ack { largest_acknowledged: 1, ack_delay: 4865, first_ack_range: 1, ack_ranges: [], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Transport(12), frame_type: 0, reason_phrase: "" }
client  | 0.534 DEBUG Building Short dcid Some(CID [12]: df9201ec4e25ac93f7c23a11)
client  | 0.534 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 512, tv_nsec: 729566521 }
client  | 0.534 DEBUG [Client 712bdc99dc3437b2] pn=11 type=Short pri-path:df9201ec4e25ac93f7c23a11 0.0.0.0:48400->193.167.100.100:443 Tos(Cs0, NotEct) len 97
client  |   TX -> Ack { largest_acknowledged: 11, ack_delay: 3847, first_ack_range: 1, ack_ranges: [AckRange { gap: 2, range: 6 }], ecn_count: None }
client  |   TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" }
client  | 0.534 DEBUG Setting timeout of 258.107463ms
client  | 0.534 DEBUG Setting timeout of 258.094929ms
server  | send_count:16, lost_count:0, tlp_count:0, recv_count:16, srtt:34410 early_data_flag:1, conn_err:12, ack_info:#11-0#0-0#0-0#v0429, path_info:0/1/0/a/0,1,1,1,0,0,0,0,0,0,0,20,26,16,10240,0,17,i32,2,27,97,0,8,73,0,4,36,97,0,11,73,0,4,36,97,0,10,67,0,4,37,4000,15,36,4,9,40000,16,42,4,37,4000,14,36,0-2,0-2,0-0,0-0,0-0,0-34,0-12543,0-4701,0-16,0-16,0-0,0-0,0-0,0-0,0-0,0-0,0-0,0-0
client  | 0.793 DEBUG [Client 712bdc99dc3437b2] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 512, tv_nsec: 987761216 } } -> Closed(Application(0))
client  | 0.793 INFO Closing timer expired
client  | 0.793 DEBUG Output::None
client  | 0.793 WARN Unhandled event StateChange(Closed(Application(0)))
client  | 0.793 DEBUG Timer fired while closed
client  | 0.793 DEBUG Output::None

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-09-11 21:22:31,079 Using the client's key log file.
2025-09-11 21:22:31,089 
2025-09-11 21:22:31,090 Using the client's key log file.
2025-09-11 21:22:31,090 Using the client's key log file.
2025-09-11 21:22:31,098 
2025-09-11 21:22:31,099 Using the client's key log file.
2025-09-11 21:22:31,099 Using the client's key log file.
2025-09-11 21:22:31,878 Check of downloaded files succeeded.