2025-04-30 11:54:14,299 Generated random file: dshmwxhghd of size: 1024 2025-04-30 11:54:14,299 Requests: https://server4:443/dshmwxhghd 2025-04-30 11:54:14,359 2025-04-30 11:54:14,359 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_es4yc13p/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_eryf3oa7/ DOWNLOADS=/tmp/download_7_zr2ona/ SERVER_LOGS=/tmp/logs_server_u4zy6rbl CLIENT_LOGS=/tmp/logs_client_6rv7emtn SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=martenseemann/quic-go-interop:latest REQUESTS="https://server4:443/dshmwxhghd" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 11:54:39,051 Container sim Recreate Container sim Recreated Container server Recreate Container client Recreate Container server Recreated Container client Recreated Attaching to client, server, sim sim | waiting 10s for server:443 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 | Setting up routes... server | Actual changes: server | tx-checksum-ip-generic: off server | tx-tcp-segmentation: off [not requested] server | tx-tcp-ecn-segmentation: off [not requested] server | tx-tcp-mangleid-segmentation: off [not requested] server | tx-tcp6-segmentation: off [not requested] server | tx-udp-segmentation: off [not requested] server | tx-checksum-sctp: off client | + 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 handshake ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | Endpoint's IPv4 address is 193.167.100.100 server | Endpoint's IPv6 address is fd00:cafe:cafe:100::100 client | wait-for-it.sh: waiting 30 seconds for sim:57832 server | Using commit: e4bb2dbd5557c9417b30cf9fcd9032fd6fea5366 server | Running QUIC server. sim | server:443 is available after 1.039890017s sim | Using scenario: simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25 sim | tcpdump: tcpdump: listening on eth0listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | , 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/dshmwxhghd ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test handshake --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/dshmwxhghd client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is 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:60527 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=bab57fb96fd3e00a client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 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:60527->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443] Path validated Instant { tv_sec: 219, tv_nsec: 343151936 } client | 0.001 DEBUG [Client bab57fb96fd3e00a] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x5596ae37a270] state -> InProgress client | 0.002 DEBUG [Client bab57fb96fd3e00a] State change from Init -> WaitInitial client | 0.002 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1213 client | 0.002 DEBUG [Client bab57fb96fd3e00a] pn=0 type=Initial pri-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.002 DEBUG packet_sent this=0x5596ae38d970, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1213, len=326 client | 0.002 DEBUG [Client bab57fb96fd3e00a] pn=1 type=Initial pri-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.002 DEBUG [Client bab57fb96fd3e00a] pad Initial from 366 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x5596ae38d970, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) 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 bab57fb96fd3e00a] delay duration 3.872193ms client | 0.002 DEBUG Setting timeout of 3.872193ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) 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 bab57fb96fd3e00a] delay duration 3.848399ms client | 0.002 DEBUG Setting timeout of 3.848399ms client | 0.007 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) 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 bab57fb96fd3e00a] delay duration 294.824063ms client | 0.007 DEBUG Setting timeout of 294.824063ms client | 0.303 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.303 DEBUG [Client bab57fb96fd3e00a] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1213 }) client | 0.303 INFO Lost crypto frame space=in offset=0 length=1213 client | 0.303 DEBUG [Client bab57fb96fd3e00a] Lost: EcnEct0 client | 0.303 DEBUG [Client bab57fb96fd3e00a] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 0.303 INFO Lost crypto frame space=in offset=1213 length=326 client | 0.303 DEBUG [Client bab57fb96fd3e00a] Lost: EcnEct0 client | 0.303 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.303 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.303 DEBUG CRYPTO for in offset=0, len=1213 client | 0.303 DEBUG [Client bab57fb96fd3e00a] pn=2 type=Initial pri-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.303 DEBUG packet_sent this=0x5596ae38d970, pn=2, ps=1252 client | 0.303 DEBUG ECN probing: sent 3 probes client | 0.304 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.304 DEBUG CRYPTO for in offset=1213, len=326 client | 0.304 DEBUG [Client bab57fb96fd3e00a] pn=3 type=Initial pri-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.304 DEBUG [Client bab57fb96fd3e00a] pad Initial from 366 to PLPMTU 1252 client | 0.304 DEBUG packet_sent this=0x5596ae38d970, pn=3, ps=1252 client | 0.304 DEBUG ECN probing: sent 4 probes client | 0.304 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.304 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.304 DEBUG [Client bab57fb96fd3e00a] delay duration 599.891036ms client | 0.304 DEBUG Setting timeout of 599.891036ms client | 0.905 DEBUG [LossRecovery] PTO timer fired for Initial client | 0.905 DEBUG [Client bab57fb96fd3e00a] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1213 }) client | 0.905 INFO Lost crypto frame space=in offset=0 length=1213 client | 0.905 DEBUG [Client bab57fb96fd3e00a] Lost: EcnEct0 client | 0.905 DEBUG ECN validation failed, all 3 initial marked packets were lost client | 0.905 DEBUG [Client bab57fb96fd3e00a] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1213, length: 326 }) client | 0.905 INFO Lost crypto frame space=in offset=1213 length=326 client | 0.905 DEBUG [Client bab57fb96fd3e00a] Lost: EcnEct0 client | 0.905 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.905 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.905 DEBUG CRYPTO for in offset=0, len=1213 client | 0.905 DEBUG [Client bab57fb96fd3e00a] pn=4 type=Initial pri-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1213 } client | 0.905 DEBUG packet_sent this=0x5596ae38d970, pn=4, ps=1252 client | 0.906 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.906 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.906 DEBUG CRYPTO for in offset=1213, len=326 client | 0.906 DEBUG [Client bab57fb96fd3e00a] pn=5 type=Initial pri-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 366 client | TX -> Crypto { offset: 1213, len: 326 } client | 0.906 DEBUG [Client bab57fb96fd3e00a] pad Initial from 366 to PLPMTU 1252 client | 0.906 DEBUG packet_sent this=0x5596ae38d970, pn=5, ps=1252 client | 0.906 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.906 DEBUG Building Initial dcid Some(CID [8]: bab57fb96fd3e00a) scid Some(CID [0]: ) client | 0.906 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.906 DEBUG [Client bab57fb96fd3e00a] delay duration 1.199904451s client | 0.906 DEBUG Setting timeout of 1.199904451s client | 1.509 DEBUG [Client bab57fb96fd3e00a] pn=0 type=Initial pri-path:bab57fb96fd3e00a 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 40 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 1.509 DEBUG [Client bab57fb96fd3e00a] Rx ACK space=in, ranges=[0..=0] client | 1.509 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 1.509 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6260/13772 ssthresh 18446744073709551615] slow start += 1252 client | 1.509 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 6260/13772 ssthresh 18446744073709551615] on_packets_acked this=0x5596ae38d970, limited=0, bytes_in_flight=6260, cwnd=13772, state=SlowStart, new_acked=1252 client | 1.509 DEBUG Acked crypto frame space=in offset=0 length=1213 client | 1.509 DEBUG [Client bab57fb96fd3e00a] Changing to use Server CID=19580223 client | 1.509 DEBUG [Client bab57fb96fd3e00a] State change from WaitInitial -> WaitVersion client | 1.509 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.509 DEBUG Building Initial dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.509 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.509 DEBUG [Client bab57fb96fd3e00a] delay duration 3.919970095s client | 1.509 DEBUG Setting timeout of 3.919970095s client | 1.509 WARN Unhandled event StateChange(WaitVersion) client | 1.509 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.509 DEBUG Building Initial dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.509 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.509 DEBUG [Client bab57fb96fd3e00a] delay duration 3.919913469s client | 1.509 DEBUG Setting timeout of 3.919913469s client | 1.511 DEBUG [Client bab57fb96fd3e00a] pn=1 type=Initial pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 409 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX Padding { len: 275 } client | -> RX Crypto { offset: 0, len: 90 } client | 1.511 DEBUG [Client bab57fb96fd3e00a] Rx ACK space=in, ranges=[0..=1] client | 1.511 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 1.511 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] slow start += 1252 client | 1.511 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] on_packets_acked this=0x5596ae38d970, limited=0, bytes_in_flight=5008, cwnd=15024, state=SlowStart, new_acked=1252 client | 1.511 DEBUG Acked crypto frame space=in offset=1213 length=326 client | 1.511 DEBUG Read Ok(90) bytes client | 1.511 DEBUG Write secret available for Handshake: SymKey [32]: a27b0b3b710f92853523ceedc0cb5e30bf87702fc6f81c83843966bde5ce347f client | 1.511 DEBUG Read secret available for Handshake: SymKey [32]: e30133952c7c3418123b7fae37145d4e443b07bc4d5817b1692fdb548d935fd1 client | 1.511 DEBUG [Agent 0x5596ae37a270] state -> InProgress client | 1.511 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 1.511 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 1.511 DEBUG [Crypto] Handshake keys installed client | 1.511 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 220, tv_nsec: 852968588 } client | 1.511 DEBUG [Client bab57fb96fd3e00a] State change from WaitVersion -> Handshaking client | 1.511 DEBUG [Client bab57fb96fd3e00a] pn=0 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 732 client | -> RX Crypto { offset: 0, len: 697 } client | 1.511 DEBUG Read Ok(697) bytes client | 1.512 DEBUG [Agent 0x5596ae37a270] state -> AuthenticationPending client | 1.512 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 220, tv_nsec: 852968588 } client | 1.512 DEBUG saving datagram of 139 bytes client | 1.512 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Initial dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.512 DEBUG [Client bab57fb96fd3e00a] pn=6 type=Initial pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 37 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 147, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 1.512 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.512 DEBUG [Client bab57fb96fd3e00a] pn=0 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 73 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 147, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.512 DEBUG [Client bab57fb96fd3e00a] Drop packet number space in client | 1.512 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 1.512 WARN [LossRecovery] ignoring in-6 from dropped space client | 1.512 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG [Client bab57fb96fd3e00a] delay duration 3.770518962s client | 1.512 DEBUG Setting timeout of 3.770518962s client | 1.512 DEBUG StateChange(Handshaking) client | 1.512 WARN Cannot create stream ConnectionState client | 1.512 DEBUG [Client bab57fb96fd3e00a] Authenticated Ok client | 1.512 DEBUG Write secret available for ApplicationData: SymKey [32]: aa252f8d496ef9c5d5790a6ceb616d7a35f0a2719f72c85cdbf3c6f067677dfb client | 1.512 DEBUG Read secret available for ApplicationData: SymKey [32]: 9e2914a822a774c0b9220641a682240c8f03f2dcb225c75925e7b6f045329bf8 client | 1.512 DEBUG [Agent 0x5596ae37a270] SSL_AuthCertificateComplete: Ok(()) client | 1.512 DEBUG [Agent 0x5596ae37a270] 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 | 1.512 DEBUG [Client bab57fb96fd3e00a] TLS connection complete client | 1.512 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 1.512 DEBUG [Crypto] Application write key installed client | 1.512 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 1.512 DEBUG [Crypto] application read keys installed client | 1.512 DEBUG [Client bab57fb96fd3e00a] State change from Handshaking -> Connected client | 1.512 INFO [Client bab57fb96fd3e00a] Connection established client | 1.512 DEBUG [Client bab57fb96fd3e00a] process saved for epoch ApplicationData client | 1.512 DEBUG [Client bab57fb96fd3e00a] pn=0 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 139 client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [23, 51, 134, 200], stateless_reset_token: [212, 89, 224, 113, 14, 181, 161, 200, 69, 14, 108, 178, 74, 158, 139, 89] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [255, 183, 200, 128], stateless_reset_token: [20, 136, 30, 87, 153, 30, 164, 43, 77, 140, 176, 131, 102, 253, 87, 102] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [54, 219, 237, 143], stateless_reset_token: [130, 142, 24, 200, 133, 155, 36, 206, 169, 9, 69, 218, 124, 45, 18, 5] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [131, 11, 37, 3], stateless_reset_token: [0, 46, 228, 82, 5, 160, 234, 172, 214, 218, 163, 114, 219, 3, 189, 225] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [254, 85, 104, 84], stateless_reset_token: [96, 101, 61, 87, 110, 82, 212, 227, 14, 124, 248, 124, 98, 238, 69, 82] } client | 1.512 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 220, tv_nsec: 872968588 } client | 1.512 DEBUG stream BiDi creatable client | 1.512 INFO Created stream 0 for https://server4/dshmwxhghd client | 1.512 INFO Saving https://server4/dshmwxhghd to "/downloads/dshmwxhghd" client | 1.512 DEBUG stream UniDi creatable client | 1.512 DEBUG StateChange(Connected) client | 1.512 DEBUG stream 0 writable client | 1.512 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.512 DEBUG CRYPTO for hs offset=0, len=36 client | 1.512 DEBUG [Client bab57fb96fd3e00a] pn=1 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 69 client | TX -> Crypto { offset: 0, len: 36 } client | 1.512 DEBUG packet_sent this=0x5596ae38d970, pn=1, ps=69 client | 1.512 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.512 DEBUG [Client bab57fb96fd3e00a] pn=0 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 111 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 1.512 DEBUG packet_sent this=0x5596ae38d970, pn=0, ps=42 client | 1.512 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.512 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.512 DEBUG [Client bab57fb96fd3e00a] delay duration 18.141562ms client | 1.512 DEBUG Setting timeout of 18.141562ms client | 1.531 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.531 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.531 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.532 DEBUG [Client bab57fb96fd3e00a] pn=1 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 28 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 2623, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 1.532 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.532 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.532 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.532 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.532 DEBUG [Client bab57fb96fd3e00a] delay duration 3.751280544s client | 1.532 DEBUG Setting timeout of 3.751280544s client | 1.711 WARN [Client ...] Dropped received packet: Decryption failure; Total: 1 client | 1.711 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.711 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.711 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.711 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.711 DEBUG [Client bab57fb96fd3e00a] delay duration 3.571743045s client | 1.711 DEBUG Setting timeout of 3.571743045s client | 1.711 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.711 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.711 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.711 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.711 DEBUG [Client bab57fb96fd3e00a] delay duration 3.571711366s client | 1.711 DEBUG Setting timeout of 3.571711366s client | 1.712 WARN [Client ...] Dropped received packet: Decryption failure; Total: 2 client | 1.712 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.712 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.712 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.712 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.712 DEBUG [Client bab57fb96fd3e00a] delay duration 3.570790933s client | 1.712 DEBUG Setting timeout of 3.570790933s client | 1.712 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.712 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.712 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.712 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.712 DEBUG [Client bab57fb96fd3e00a] delay duration 3.570774432s client | 1.712 DEBUG Setting timeout of 3.570774432s client | 1.805 WARN [Client ...] Dropped received packet: Decryption failure; Total: 3 client | 1.805 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.805 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.805 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.805 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.805 DEBUG [Client bab57fb96fd3e00a] delay duration 3.477653322s client | 1.805 DEBUG Setting timeout of 3.477653322s client | 1.805 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.805 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.805 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.805 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.805 DEBUG [Client bab57fb96fd3e00a] delay duration 3.477626161s client | 1.805 DEBUG Setting timeout of 3.477626161s client | 1.806 WARN [Client ...] Dropped received packet: Decryption failure; Total: 4 client | 1.806 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.806 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.806 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG [Client bab57fb96fd3e00a] delay duration 3.476767556s client | 1.806 DEBUG Setting timeout of 3.476767556s client | 1.806 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.806 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.806 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.806 DEBUG [Client bab57fb96fd3e00a] delay duration 3.476738582s client | 1.806 DEBUG Setting timeout of 3.476738582s client | 1.911 DEBUG [Client bab57fb96fd3e00a] pn=1 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 732 client | -> RX Crypto { offset: 0, len: 697 } client | 1.911 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 221, tv_nsec: 253649618 } client | 1.911 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.911 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.911 DEBUG CRYPTO for hs offset=0, len=36 client | 1.911 DEBUG [Client bab57fb96fd3e00a] pn=2 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 74 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 6, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 1.911 DEBUG packet_sent this=0x5596ae38d970, pn=2, ps=74 client | 1.911 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.911 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.911 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.911 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.911 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.911 DEBUG [Client bab57fb96fd3e00a] delay duration 3.770530794s client | 1.911 DEBUG Setting timeout of 3.770530794s client | 1.911 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.911 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.911 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.911 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.911 DEBUG [Client bab57fb96fd3e00a] delay duration 3.770493454s client | 1.911 DEBUG Setting timeout of 3.770493454s client | 1.912 DEBUG [Client bab57fb96fd3e00a] pn=2 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 732 client | -> RX Crypto { offset: 0, len: 697 } client | 1.912 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 221, tv_nsec: 254191990 } client | 1.912 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.912 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.912 DEBUG CRYPTO for hs offset=0, len=36 client | 1.912 DEBUG [Client bab57fb96fd3e00a] pn=3 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 74 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 1.912 DEBUG packet_sent this=0x5596ae38d970, pn=3, ps=74 client | 1.912 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.912 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.912 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.912 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.912 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.912 DEBUG [Client bab57fb96fd3e00a] delay duration 3.770547866s client | 1.912 DEBUG Setting timeout of 3.770547866s client | 1.912 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.912 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 1.912 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 1.912 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.912 DEBUG [Client bab57fb96fd3e00a] delay duration 3.77051256s client | 1.912 DEBUG Setting timeout of 3.77051256s client | 2.407 WARN [Client ...] Dropped received packet: Decryption failure; Total: 5 client | 2.407 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.407 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.407 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.407 DEBUG [Client bab57fb96fd3e00a] delay duration 3.274927008s client | 2.407 DEBUG Setting timeout of 3.274927008s client | 2.408 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.408 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.408 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.408 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.408 DEBUG [Client bab57fb96fd3e00a] delay duration 3.274879189s client | 2.408 DEBUG Setting timeout of 3.274879189s client | 2.408 WARN [Client ...] Dropped received packet: Decryption failure; Total: 6 client | 2.408 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.408 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.408 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.408 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.408 DEBUG [Client bab57fb96fd3e00a] delay duration 3.274191181s client | 2.408 DEBUG Setting timeout of 3.274191181s client | 2.408 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.408 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.408 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.408 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.408 DEBUG [Client bab57fb96fd3e00a] delay duration 3.274168118s client | 2.408 DEBUG Setting timeout of 3.274168118s client | 2.512 WARN [Client ...] Dropped received packet: Decryption failure; Total: 7 client | 2.512 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.512 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.512 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.512 DEBUG [Client bab57fb96fd3e00a] delay duration 3.17065175s client | 2.512 DEBUG Setting timeout of 3.17065175s client | 2.512 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.512 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.512 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.512 DEBUG [Client bab57fb96fd3e00a] delay duration 3.170607708s client | 2.512 DEBUG Setting timeout of 3.170607708s client | 2.513 WARN [Client ...] Dropped received packet: Decryption failure; Total: 8 client | 2.513 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.513 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.513 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.513 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.513 DEBUG [Client bab57fb96fd3e00a] delay duration 3.169766586s client | 2.513 DEBUG Setting timeout of 3.169766586s client | 2.513 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.513 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 2.513 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 2.513 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 2.513 DEBUG [Client bab57fb96fd3e00a] delay duration 3.169742811s client | 2.513 DEBUG Setting timeout of 3.169742811s client | 3.013 DEBUG [Client bab57fb96fd3e00a] pn=3 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 732 client | -> RX Crypto { offset: 0, len: 697 } client | 3.013 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 355858029 } client | 3.013 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.013 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 3.013 DEBUG CRYPTO for hs offset=0, len=36 client | 3.014 DEBUG [Client bab57fb96fd3e00a] pn=4 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 74 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 11, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 3.014 DEBUG packet_sent this=0x5596ae38d970, pn=4, ps=74 client | 3.014 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.014 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 3.014 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.014 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG [Client bab57fb96fd3e00a] delay duration 3.770489436s client | 3.014 DEBUG Setting timeout of 3.770489436s client | 3.014 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 3.014 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.014 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG [Client bab57fb96fd3e00a] delay duration 3.770451045s client | 3.014 DEBUG Setting timeout of 3.770451045s client | 3.014 DEBUG [Client bab57fb96fd3e00a] pn=4 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 732 client | -> RX Crypto { offset: 0, len: 697 } client | 3.014 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 356312324 } client | 3.014 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 3.014 DEBUG CRYPTO for hs offset=0, len=36 client | 3.014 DEBUG [Client bab57fb96fd3e00a] pn=5 type=Handshake pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 74 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 3.014 DEBUG packet_sent this=0x5596ae38d970, pn=5, ps=74 client | 3.014 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.014 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG Building Handshake dcid Some(CID [4]: 19580223) scid Some(CID [0]: ) client | 3.014 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.014 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.014 DEBUG [Client bab57fb96fd3e00a] delay duration 3.770275606s client | 3.014 DEBUG Setting timeout of 3.770275606s client | 3.014 DEBUG [Client bab57fb96fd3e00a] pn=2 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 373 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 29, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [23, 51, 134, 200], stateless_reset_token: [212, 89, 224, 113, 14, 181, 161, 200, 69, 14, 108, 178, 74, 158, 139, 89] } client | -> RX NewToken { token: [201, 43, 35, 248, 228, 220, 244, 98, 41, 219, 19, 189, 172, 27, 36, 37, 247, 146, 127, 172, 99, 150, 70, 95, 138, 239, 162, 120, 79, 148, 97, 149, 66, 12, 88, 129, 239, 220, 252, 82, 227, 105, 181, 140, 1, 122, 144, 233, 78, 254, 30, 245, 156, 78, 156, 0, 231, 192, 174, 90, 8, 47, 165, 249, 79, 51, 170, 131, 181, 58, 46, 145, 159, 209, 70, 6, 107, 181, 178, 77, 80, 20, 159, 206, 172, 118] } client | -> RX HandshakeDone client | -> RX Crypto { offset: 0, len: 135 } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [255, 183, 200, 128], stateless_reset_token: [20, 136, 30, 87, 153, 30, 164, 43, 77, 140, 176, 131, 102, 253, 87, 102] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [131, 11, 37, 3], stateless_reset_token: [0, 46, 228, 82, 5, 160, 234, 172, 214, 218, 163, 114, 219, 3, 189, 225] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [54, 219, 237, 143], stateless_reset_token: [130, 142, 24, 200, 133, 155, 36, 206, 169, 9, 69, 218, 124, 45, 18, 5] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [254, 85, 104, 84], stateless_reset_token: [96, 101, 61, 87, 110, 82, 212, 227, 14, 124, 248, 124, 98, 238, 69, 82] } client | 3.014 DEBUG [Client bab57fb96fd3e00a] Rx ACK space=ap, ranges=[0..=0] client | 3.014 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 3.014 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 365/15066 ssthresh 18446744073709551615] slow start += 42 client | 3.014 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 365/15066 ssthresh 18446744073709551615] on_packets_acked this=0x5596ae38d970, limited=0, bytes_in_flight=365, cwnd=15066, state=SlowStart, new_acked=42 client | 3.014 DEBUG [Client bab57fb96fd3e00a] State change from Connected -> Confirmed client | 3.014 DEBUG PMTUD started with probe size 1380 client | 3.014 DEBUG [Client bab57fb96fd3e00a] Drop packet number space hs client | 3.014 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 3.014 DEBUG [Client bab57fb96fd3e00a] No preferred address to migrate to client | 3.014 DEBUG Read Ok(135) bytes client | 3.015 DEBUG [0x5596ae37a270] Got resumption token [814]: 02000633fd93c282..2efc9e87eef08f19 client | 3.015 DEBUG [Agent 0x5596ae37a270] 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 | 3.015 DEBUG setting max_stream_data to 524288 client | 3.015 DEBUG resumption token [992]: 0000000145e34052..2efc9e87eef08f19 client | 3.015 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 356737249 } client | 3.015 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.015 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.015 DEBUG Sending PMTUD probe of size 1380, count 1 client | 3.015 DEBUG [Client bab57fb96fd3e00a] pn=2 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 39, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | TX -> Ping client | TX -> Padding { len: 1319 } client | 3.015 DEBUG packet_sent this=0x5596ae38d970, pn=2, ps=1352 client | 3.015 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.015 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.015 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.015 DEBUG [Client bab57fb96fd3e00a] delay duration 7.572689ms client | 3.015 DEBUG Setting timeout of 7.572689ms client | 3.015 DEBUG [Client bab57fb96fd3e00a] pn=3 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 368 client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [255, 183, 200, 128], stateless_reset_token: [20, 136, 30, 87, 153, 30, 164, 43, 77, 140, 176, 131, 102, 253, 87, 102] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [254, 85, 104, 84], stateless_reset_token: [96, 101, 61, 87, 110, 82, 212, 227, 14, 124, 248, 124, 98, 238, 69, 82] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [23, 51, 134, 200], stateless_reset_token: [212, 89, 224, 113, 14, 181, 161, 200, 69, 14, 108, 178, 74, 158, 139, 89] } client | -> RX Crypto { offset: 0, len: 135 } client | -> RX NewToken { token: [201, 43, 35, 248, 228, 220, 244, 98, 41, 219, 19, 189, 172, 27, 36, 37, 247, 146, 127, 172, 99, 150, 70, 95, 138, 239, 162, 120, 79, 148, 97, 149, 66, 12, 88, 129, 239, 220, 252, 82, 227, 105, 181, 140, 1, 122, 144, 233, 78, 254, 30, 245, 156, 78, 156, 0, 231, 192, 174, 90, 8, 47, 165, 249, 79, 51, 170, 131, 181, 58, 46, 145, 159, 209, 70, 6, 107, 181, 178, 77, 80, 20, 159, 206, 172, 118] } client | -> RX HandshakeDone client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [131, 11, 37, 3], stateless_reset_token: [0, 46, 228, 82, 5, 160, 234, 172, 214, 218, 163, 114, 219, 3, 189, 225] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [54, 219, 237, 143], stateless_reset_token: [130, 142, 24, 200, 133, 155, 36, 206, 169, 9, 69, 218, 124, 45, 18, 5] } client | 3.015 INFO NewTokenState discarding duplicate NEW_TOKEN client | 3.015 DEBUG PMTUD started with probe size 1420 client | 3.015 DEBUG [Client bab57fb96fd3e00a] No preferred address to migrate to client | 3.015 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 377156925 } client | 3.015 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.015 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.015 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.015 DEBUG [Client bab57fb96fd3e00a] delay duration 7.48807ms client | 3.015 DEBUG Setting timeout of 7.48807ms client | 3.015 DEBUG stream 0 complete client | 3.015 WARN Unhandled event StateChange(Confirmed) client | 3.015 DEBUG stream BiDi creatable client | 3.015 DEBUG stream UniDi creatable client | 3.015 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.015 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.015 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.015 DEBUG [Client bab57fb96fd3e00a] delay duration 7.463124ms client | 3.015 DEBUG Setting timeout of 7.463124ms client | 3.016 DEBUG [Client bab57fb96fd3e00a] pn=4 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 1366 client | -> RX Padding { len: 1346 } client | -> RX Ping client | 3.016 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 222, tv_nsec: 358074252 } client | 3.016 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 358074252 } client | 3.016 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.016 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.016 DEBUG [Client bab57fb96fd3e00a] pn=3 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 32 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 4, first_ack_range: 2, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) } client | 3.016 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.016 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.016 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.016 DEBUG [Client bab57fb96fd3e00a] delay duration 8.07419ms client | 3.016 DEBUG Setting timeout of 8.07419ms client | 3.016 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.016 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.016 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.016 DEBUG [Client bab57fb96fd3e00a] delay duration 8.050816ms client | 3.016 DEBUG Setting timeout of 8.050816ms client | 3.016 DEBUG [Client bab57fb96fd3e00a] pn=5 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, Ect0) len 1045 client | -> RX Stream { stream_id: 0, offset: 0, len: >>1024, fin: true } client | 3.016 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 222, tv_nsec: 378933813 } client | 3.017 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.017 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.017 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.017 DEBUG [Client bab57fb96fd3e00a] delay duration 7.331357ms client | 3.017 DEBUG Setting timeout of 7.331357ms client | 3.017 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.017 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.017 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.017 DEBUG [Client bab57fb96fd3e00a] delay duration 7.25808ms client | 3.017 DEBUG Setting timeout of 7.25808ms client | 3.017 DEBUG [Client bab57fb96fd3e00a] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 232, tv_nsec: 67630876 } } client | 3.017 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 232, tv_nsec: 67630876 } }) client | 3.017 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 3.017 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.017 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 222, tv_nsec: 359083493 } client | 3.017 DEBUG [Client bab57fb96fd3e00a] pn=4 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 43 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 18, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.017 DEBUG Setting timeout of 9.708485948s client | 3.414 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.414 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.414 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 222, tv_nsec: 756564014 } client | 3.414 DEBUG [Client bab57fb96fd3e00a] pn=5 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 49703, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.414 DEBUG Setting timeout of 9.310868531s client | 3.414 DEBUG Setting timeout of 9.310850337s client | 3.415 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.415 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 3.415 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 222, tv_nsec: 757274892 } client | 3.415 DEBUG [Client bab57fb96fd3e00a] pn=6 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 49792, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 3.415 DEBUG Setting timeout of 9.310281304s client | 3.415 DEBUG Setting timeout of 9.310269062s client | 4.214 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.214 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 4.214 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 223, tv_nsec: 556854477 } client | 4.214 DEBUG [Client bab57fb96fd3e00a] pn=7 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 149740, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.215 DEBUG Setting timeout of 8.510646846s client | 4.215 DEBUG Setting timeout of 8.51063291s client | 4.215 DEBUG [Client bab57fb96fd3e00a] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 4.215 DEBUG Building Short dcid Some(CID [4]: 19580223) client | 4.215 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 223, tv_nsec: 557684281 } client | 4.215 DEBUG [Client bab57fb96fd3e00a] pn=8 type=Short pri-path:19580223 0.0.0.0:60527->193.167.100.100:443 IpTos(Cs0, NotEct) len 46 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 149843, first_ack_range: 3, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 4.215 DEBUG Setting timeout of 8.509882976s client | 4.215 DEBUG Setting timeout of 8.509870172s client | 12.726 DEBUG [Client bab57fb96fd3e00a] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 232, tv_nsec: 67630876 } } -> Closed(Application(0)) client | 12.726 INFO Closing timer expired client | 12.726 DEBUG Output::None client | 12.726 WARN Unhandled event StateChange(Closed(Application(0))) client | 12.726 DEBUG Timer fired while closed client | 12.726 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-04-30 11:54:39,147 Using the client's key log file. 2025-04-30 11:54:39,156 2025-04-30 11:54:39,156 Using the client's key log file. 2025-04-30 11:54:39,157 Using the client's key log file. 2025-04-30 11:54:39,165 2025-04-30 11:54:39,165 Using the client's key log file. 2025-04-30 11:54:39,462 Check of downloaded files succeeded. 2025-04-30 11:54:40,697 Check of downloaded files succeeded.