2025-04-30 13:36:16,410 Generated random file: awybornwvb of size: 1024
2025-04-30 13:36:16,410 Requests: https://server4:443/awybornwvb
2025-04-30 13:36:16,468 
2025-04-30 13:36:16,468 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_dt47swvt/ TESTCASE_SERVER=handshake TESTCASE_CLIENT=handshake WWW=/tmp/www_lyg62pk2/ DOWNLOADS=/tmp/download_luu_t7dd/ SERVER_LOGS=/tmp/logs_server_d5erwlln CLIENT_LOGS=/tmp/logs_client_xeu7b7_k SCENARIO="simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=ghcr.io/aws/s2n-quic/s2n-quic-qns:latest REQUESTS="https://server4:443/awybornwvb"  docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 
2025-04-30 13:36:42,847  Container sim  Recreate
 Container sim  Recreated
 Container client  Recreate
 Container server  Recreate
 Container server  Recreated
 Container client  Recreated
Attaching to client, server, sim
sim     | waiting 10s for server:443
client  | Setting up routes...
client  | Actual changes:
client  | tx-checksum-ip-generic: off
client  | tx-tcp-segmentation: off [not requested]
client  | tx-tcp-ecn-segmentation: off [not requested]
client  | tx-tcp-mangleid-segmentation: off [not requested]
client  | tx-tcp6-segmentation: off [not requested]
client  | tx-udp-segmentation: off [not requested]
client  | tx-checksum-sctp: off
server  | 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  | Endpoint's IPv4 address is 193.167.0.100
server  | Endpoint's IPv4 address is 193.167.100.100
client  | Endpoint's IPv6 address is fd00:cafe:cafe::100
server  | Endpoint's IPv6 address is fd00:cafe:cafe:100::100
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  | x86_64
client  | wait-for-it.sh: waiting 30 seconds for sim:57832
server  | Server listening on port 443
sim     | server:443 is available after 1.052705309s
sim     | Using scenario: simple-p2p --delay=750ms --bandwidth=10Mbps --queue=25
sim     | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
sim     | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
client  | wait-for-it.sh: sim:57832 is available after 1 seconds
client  | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads)
client  | + '[' https://server4:443/awybornwvb ']'
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/awybornwvb
client  | '
client  | ++ tee -i -a /logs/client.log
client  | 0.000 DEBUG Logging initialized
client  | 0.000 DEBUG Default socket send buffer size is 212992
client  | 0.000 DEBUG Default socket receive buffer size is 1048576, not changing
client  | 0.000 INFO hq-interop Client connecting: 0.0.0.0:57253 -> 193.167.100.100:443
client  | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=a44cb64ce58f9353c5f12b1f3e
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:57253->193.167.100.100:443] Make permanent
client  | 0.001 DEBUG [unv-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443] set as primary path
client  | 0.001 DEBUG [pri-unv-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443] Path validated Instant { tv_sec: 340, tv_nsec: 416943247 }
client  | 0.001 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] client_start
client  | 0.001 DEBUG Writing transport parameters, msg=1
client  | 0.001 DEBUG [Agent 0x564df96c4270] state -> InProgress
client  | 0.001 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] State change from Init -> WaitInitial
client  | 0.001 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.001 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.001 DEBUG CRYPTO for in offset=0, len=1208
client  | 0.001 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=0 type=Initial pri-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252
client  |   TX -> Crypto { offset: 0, len: 1208 }
client  | 0.001 DEBUG packet_sent this=0x564df96d7970, pn=0, ps=1252
client  | 0.001 DEBUG ECN probing: sent 1 probes
client  | 0.002 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.002 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.002 DEBUG CRYPTO for in offset=1208, len=331
client  | 0.002 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=1 type=Initial pri-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 376
client  |   TX -> Crypto { offset: 1208, len: 331 }
client  | 0.002 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pad Initial from 376 to PLPMTU 1252
client  | 0.002 DEBUG packet_sent this=0x564df96d7970, pn=1, ps=1252
client  | 0.002 DEBUG ECN probing: sent 2 probes
client  | 0.002 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) 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 a44cb64ce58f9353c5f12b1f3e] delay duration 3.870433ms
client  | 0.002 DEBUG Setting timeout of 3.870433ms
client  | 0.002 DEBUG StateChange(WaitInitial)
client  | 0.002 WARN Cannot create stream ConnectionState
client  | 0.002 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 0.002 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) 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 a44cb64ce58f9353c5f12b1f3e] delay duration 3.846488ms
client  | 0.002 DEBUG Setting timeout of 3.846488ms
client  | 0.007 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.007 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) 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 a44cb64ce58f9353c5f12b1f3e] delay duration 294.806022ms
client  | 0.007 DEBUG Setting timeout of 294.806022ms
client  | 0.303 DEBUG [LossRecovery] PTO timer fired for Initial
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1208 })
client  | 0.303 INFO Lost crypto frame space=in offset=0 length=1208
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: EcnEct0
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1208, length: 331 })
client  | 0.303 INFO Lost crypto frame space=in offset=1208 length=331
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: EcnEct0
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false }
client  | 0.303 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.303 DEBUG CRYPTO for in offset=0, len=1208
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=2 type=Initial pri-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252
client  |   TX -> Crypto { offset: 0, len: 1208 }
client  | 0.303 DEBUG packet_sent this=0x564df96d7970, pn=2, ps=1252
client  | 0.303 DEBUG ECN probing: sent 3 probes
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.303 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.303 DEBUG CRYPTO for in offset=1208, len=331
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=3 type=Initial pri-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 376
client  |   TX -> Crypto { offset: 1208, len: 331 }
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pad Initial from 376 to PLPMTU 1252
client  | 0.303 DEBUG packet_sent this=0x564df96d7970, pn=3, ps=1252
client  | 0.303 DEBUG ECN probing: sent 4 probes
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.303 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.303 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.303 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 599.894045ms
client  | 0.303 DEBUG Setting timeout of 599.894045ms
client  | 0.905 DEBUG [LossRecovery] PTO timer fired for Initial
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 0, length: 1208 })
client  | 0.905 INFO Lost crypto frame space=in offset=0 length=1208
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: EcnEct0
client  | 0.905 DEBUG ECN validation failed, all 3 initial marked packets were lost
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1208, length: 331 })
client  | 0.905 INFO Lost crypto frame space=in offset=1208 length=331
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Lost: EcnEct0
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false }
client  | 0.905 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.905 DEBUG CRYPTO for in offset=0, len=1208
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=4 type=Initial pri-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 1252
client  |   TX -> Crypto { offset: 0, len: 1208 }
client  | 0.905 DEBUG packet_sent this=0x564df96d7970, pn=4, ps=1252
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.905 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.905 DEBUG CRYPTO for in offset=1208, len=331
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=5 type=Initial pri-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 376
client  |   TX -> Crypto { offset: 1208, len: 331 }
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pad Initial from 376 to PLPMTU 1252
client  | 0.905 DEBUG packet_sent this=0x564df96d7970, pn=5, ps=1252
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.905 DEBUG Building Initial dcid Some(CID [13]: a44cb64ce58f9353c5f12b1f3e) scid Some(CID [0]: )
client  | 0.905 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 0.905 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 1.199923586s
client  | 0.906 DEBUG Setting timeout of 1.199923586s
client  | 1.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=0 type=Initial pri-path:a44cb64ce58f9353c5f12b1f3e 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 146
client  |   -> RX Ack { largest_acknowledged: 1, ack_delay: 1806, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) }
client  |   -> RX Crypto { offset: 0, len: 90 }
client  | 1.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Rx ACK space=in, ranges=[0..=1]
client  | 1.512 DEBUG [LossRecovery] ACK for Initial - largest_acked=1
client  | 1.512 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] slow start += 2504
client  | 1.512 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 5008/15024 ssthresh 18446744073709551615] on_packets_acked this=0x564df96d7970, limited=0, bytes_in_flight=5008, cwnd=15024, state=SlowStart, new_acked=2504
client  | 1.512 DEBUG Acked crypto frame space=in offset=1208 length=331
client  | 1.512 DEBUG Acked crypto frame space=in offset=0 length=1208
client  | 1.512 DEBUG Read Ok(90) bytes
client  | 1.512 DEBUG Write secret available for Handshake: SymKey [32]: b897d699fb4233baa9a95016ea0dd1ae60b795600898eb10f6b7b8508e81b436
client  | 1.512 DEBUG Read secret available for Handshake: SymKey [32]: 812e3866f344f0ad7b39cacdba24312c846f5e4e8aea0aa1d9322bbf6e343916
client  | 1.512 DEBUG [Agent 0x564df96c4270] state -> InProgress
client  | 1.512 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865
client  | 1.512 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865
client  | 1.513 DEBUG [Crypto] Handshake keys installed
client  | 1.513 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 341, tv_nsec: 928327385 }
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Changing to use Server CID=fc89f449f341bd60374b83b15fd365ca
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] State change from WaitInitial -> Handshaking
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=0 type=Handshake pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 1086
client  |   -> RX Crypto { offset: 0, len: 690 }
client  |   -> RX Padding { len: 350 }
client  | 1.513 DEBUG Read Ok(690) bytes
client  | 1.513 DEBUG [Agent 0x564df96c4270] state -> AuthenticationPending
client  | 1.513 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 341, tv_nsec: 928327385 }
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.513 DEBUG Building Initial dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=6 type=Initial pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 52
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 186, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
client  | 1.513 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=0 type=Handshake pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 103
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 186, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Drop packet number space in
client  | 1.513 DEBUG [LossRecovery] Reset loss recovery state for Initial
client  | 1.513 WARN [LossRecovery] ignoring in-6 from dropped space
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.513 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.513 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.530870522s
client  | 1.513 DEBUG Setting timeout of 4.530870522s
client  | 1.514 DEBUG StateChange(Handshaking)
client  | 1.514 WARN Cannot create stream ConnectionState
client  | 1.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Authenticated Ok
client  | 1.514 DEBUG Write secret available for ApplicationData: SymKey [32]: 095c84c338f8a4ac5648a8e4d1030ba439cb12d3058bbac5efc497f26650dd2a
client  | 1.514 DEBUG Read secret available for ApplicationData: SymKey [32]: 62ad07c03928bc04aa607e2fb4037235b0f9b98a950b21db21a7917d99760766
client  | 1.514 DEBUG [Agent 0x564df96c4270] SSL_AuthCertificateComplete: Ok(())
client  | 1.514 DEBUG [Agent 0x564df96c4270] 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.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] TLS connection complete
client  | 1.514 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865
client  | 1.514 DEBUG [Crypto] Application write key installed
client  | 1.514 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865
client  | 1.514 DEBUG [Crypto] application read keys installed
client  | 1.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] State change from Handshaking -> Connected
client  | 1.514 INFO [Client a44cb64ce58f9353c5f12b1f3e] Connection established
client  | 1.514 DEBUG stream BiDi creatable
client  | 1.514 INFO Created stream 0 for https://server4/awybornwvb
client  | 1.514 INFO Saving https://server4/awybornwvb to "/downloads/awybornwvb"
client  | 1.514 DEBUG stream UniDi creatable
client  | 1.514 DEBUG StateChange(Connected)
client  | 1.514 DEBUG stream 0 writable
client  | 1.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.514 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.514 DEBUG CRYPTO for hs offset=0, len=36
client  | 1.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=1 type=Handshake pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 81
client  |   TX -> Crypto { offset: 0, len: 36 }
client  | 1.514 DEBUG packet_sent this=0x564df96d7970, pn=1, ps=81
client  | 1.514 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 1.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=0 type=Short pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 135
client  |   TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true }
client  | 1.514 DEBUG packet_sent this=0x564df96d7970, pn=0, ps=54
client  | 1.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.514 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.514 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 1.514 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.514 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.530896911s
client  | 1.514 DEBUG Setting timeout of 4.530896911s
client  | 1.807 WARN [Client ...] Dropped received packet: Decryption failure; Total: 1
client  | 1.807 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.807 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.807 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.807 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.238164983s
client  | 1.807 DEBUG Setting timeout of 4.238164983s
client  | 1.807 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.807 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.807 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 1.807 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.807 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.2381315s
client  | 1.807 DEBUG Setting timeout of 4.2381315s
client  | 1.808 WARN [Client ...] Dropped received packet: Decryption failure; Total: 2
client  | 1.808 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.808 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.808 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 1.808 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.808 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.237218921s
client  | 1.808 DEBUG Setting timeout of 4.237218921s
client  | 1.808 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.808 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 1.808 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 1.808 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 1.808 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.237190729s
client  | 1.808 DEBUG Setting timeout of 4.237190729s
client  | 2.409 WARN [Client ...] Dropped received packet: Decryption failure; Total: 3
client  | 2.409 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.409 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.409 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.409 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.409 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 3.635843442s
client  | 2.409 DEBUG Setting timeout of 3.635843442s
client  | 2.409 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.409 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.409 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.409 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.409 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 3.635801524s
client  | 2.409 DEBUG Setting timeout of 3.635801524s
client  | 2.410 WARN [Client ...] Dropped received packet: Decryption failure; Total: 4
client  | 2.410 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.410 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.410 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.410 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.410 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 3.635023523s
client  | 2.410 DEBUG Setting timeout of 3.635023523s
client  | 2.410 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.410 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.410 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.410 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.410 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 3.635006771s
client  | 2.410 DEBUG Setting timeout of 3.635006771s
client  | 2.512 WARN [Client ...] Dropped received packet: Decryption failure; Total: 5
client  | 2.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=2 type=Handshake pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 1052
client  |   -> RX Crypto { offset: 0, len: 690 }
client  |   -> RX Padding { len: 316 }
client  | 2.512 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 342, tv_nsec: 928464107 }
client  | 2.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.512 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.512 DEBUG CRYPTO for hs offset=0, len=36
client  | 2.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=2 type=Handshake pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 91
client  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 6, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) }
client  |   TX -> Crypto { offset: 0, len: 36 }
client  | 2.512 DEBUG packet_sent this=0x564df96d7970, pn=2, ps=91
client  | 2.512 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.512 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.512 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.530897954s
client  | 2.512 DEBUG Setting timeout of 4.530897954s
client  | 2.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.512 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.512 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.512 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.512 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.530861826s
client  | 2.512 DEBUG Setting timeout of 4.530861826s
client  | 2.513 WARN [Client ...] Dropped received packet: Decryption failure; Total: 6
client  | 2.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=4 type=Handshake pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 1052
client  |   -> RX Crypto { offset: 0, len: 690 }
client  |   -> RX Padding { len: 316 }
client  | 2.513 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 342, tv_nsec: 929391819 }
client  | 2.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.513 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.513 DEBUG CRYPTO for hs offset=0, len=36
client  | 2.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=3 type=Handshake pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 93
client  |   TX -> Ack { largest_acknowledged: 4, ack_delay: 3, first_ack_range: 0, ack_ranges: [AckRange { gap: 0, range: 0 }, AckRange { gap: 0, range: 0 }], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
client  |   TX -> Crypto { offset: 0, len: 36 }
client  | 2.513 DEBUG packet_sent this=0x564df96d7970, pn=3, ps=93
client  | 2.513 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.513 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.513 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.513 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.530937588s
client  | 2.513 DEBUG Setting timeout of 4.530937588s
client  | 2.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.513 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 2.513 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 2.513 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 2.513 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.530904976s
client  | 2.513 DEBUG Setting timeout of 4.530904976s
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=0 type=Short pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 1452
client  |   -> RX Ping
client  |   -> RX Padding { len: 1433 }
client  | 3.018 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 343, tv_nsec: 434210276 }
client  | 3.018 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 343, tv_nsec: 434210276 }
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 3.018 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 3.018 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=1 type=Short pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 42
client  |   TX -> Ack { largest_acknowledged: 0, ack_delay: 9, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) }
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 3.018 DEBUG Building Handshake dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca) scid Some(CID [0]: )
client  | 3.018 DEBUG Building Short dcid Some(CID [16]: fc89f449f341bd60374b83b15fd365ca)
client  | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.025974498s
client  | 3.018 DEBUG Setting timeout of 4.025974498s
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=1 type=Short pri-path:fc89f449f341bd60374b83b15fd365ca 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 133
client  |   -> RX Ack { largest_acknowledged: 0, ack_delay: 72, first_ack_range: 0, ack_ranges: [], ecn_count: None }
client  |   -> RX HandshakeDone
client  |   -> RX NewConnectionId { sequence_number: 1, retire_prior: 1, connection_id: [231, 183, 64, 242, 51, 189, 219, 180, 19, 132, 134, 225, 16, 120, 250, 6], stateless_reset_token: [140, 233, 140, 61, 14, 112, 33, 196, 157, 178, 149, 228, 63, 105, 135, 245] }
client  |   -> RX NewConnectionId { sequence_number: 2, retire_prior: 1, connection_id: [24, 82, 67, 231, 218, 39, 137, 129, 105, 85, 156, 229, 8, 178, 163, 123], stateless_reset_token: [254, 176, 87, 93, 15, 222, 5, 156, 168, 214, 216, 57, 102, 95, 15, 104] }
client  |   -> RX NewConnectionId { sequence_number: 3, retire_prior: 1, connection_id: [210, 144, 224, 229, 87, 189, 57, 7, 117, 44, 253, 178, 24, 157, 121, 50], stateless_reset_token: [76, 227, 32, 18, 21, 154, 64, 221, 43, 211, 66, 238, 125, 112, 225, 81] }
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Rx ACK space=ap, ranges=[0..=0]
client  | 3.018 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0
client  | 3.018 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 265/15078 ssthresh 18446744073709551615] slow start += 54
client  | 3.018 DEBUG [Cubic [last_max_cwnd: 0, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 265/15078 ssthresh 18446744073709551615] on_packets_acked this=0x564df96d7970, limited=0, bytes_in_flight=265, cwnd=15078, state=SlowStart, new_acked=54
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] State change from Connected -> Confirmed
client  | 3.018 DEBUG PMTUD started with probe size 1380
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] Drop packet number space hs
client  | 3.018 DEBUG [LossRecovery] Reset loss recovery state for Handshake
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] No preferred address to migrate to
client  | 3.018 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 343, tv_nsec: 454492456 }
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false }
client  | 3.018 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.018 DEBUG Sending PMTUD probe of size 1380, count 1
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=2 type=Short pri-path:e7b740f233bddbb4138486e11078fa06 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 1352
client  |   TX -> Ping
client  |   TX -> RetireConnectionId { sequence_number: 0 }
client  |   TX -> Padding { len: 1315 }
client  | 3.018 DEBUG packet_sent this=0x564df96d7970, pn=2, ps=1352
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.018 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.61798ms
client  | 3.018 DEBUG Setting timeout of 4.61798ms
client  | 3.018 DEBUG stream 0 complete
client  | 3.018 WARN Unhandled event StateChange(Confirmed)
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.018 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.018 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.018 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 4.579888ms
client  | 3.018 DEBUG Setting timeout of 4.579888ms
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=2 type=Short pri-path:e7b740f233bddbb4138486e11078fa06 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 1047
client  |   -> RX HandshakeDone
client  |   -> RX Stream { stream_id: 0, offset: 0, len: 1024, fin: false }
client  | 3.019 DEBUG PMTUD started with probe size 1420
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] No preferred address to migrate to
client  | 3.019 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 343, tv_nsec: 435184856 }
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=3 type=Short pri-path:e7b740f233bddbb4138486e11078fa06 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 42
client  |   TX -> Ack { largest_acknowledged: 2, ack_delay: 11, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 3, Ce: 0})) }
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.019 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 6.081142ms
client  | 3.019 DEBUG Setting timeout of 6.081142ms
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=3 type=Short pri-path:e7b740f233bddbb4138486e11078fa06 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, Ect0) len 43
client  |   -> RX HandshakeDone
client  |   -> RX Stream { stream_id: 0, offset: 1024, len: 0, fin: true }
client  |   -> RX Padding { len: 19 }
client  | 3.019 DEBUG PMTUD started with probe size 1472
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] No preferred address to migrate to
client  | 3.019 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 343, tv_nsec: 455446427 }
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.019 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 6.006772ms
client  | 3.019 DEBUG Setting timeout of 6.006772ms
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.019 DEBUG TX blocked, profile=SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] delay duration 5.943463ms
client  | 3.019 DEBUG Setting timeout of 5.943463ms
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 354, tv_nsec: 854465256 } }
client  | 3.019 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 354, tv_nsec: 854465256 } })
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true }
client  | 3.019 DEBUG Building Short dcid Some(CID [16]: e7b740f233bddbb4138486e11078fa06)
client  | 3.019 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 343, tv_nsec: 435570731 }
client  | 3.019 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] pn=4 type=Short pri-path:e7b740f233bddbb4138486e11078fa06 0.0.0.0:57253->193.167.100.100:443 IpTos(Cs0, NotEct) len 53
client  |   TX -> Ack { largest_acknowledged: 3, ack_delay: 15, first_ack_range: 3, ack_ranges: [], 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.019 DEBUG Setting timeout of 11.418816669s
server  | error while accepting stream: The connection was closed on the application level with error application::Error(0) by the remote endpoint
client  | 14.439 DEBUG [Client a44cb64ce58f9353c5f12b1f3e] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 354, tv_nsec: 854465256 } } -> Closed(Application(0))
client  | 14.439 INFO Closing timer expired
client  | 14.439 DEBUG Output::None
client  | 14.439 WARN Unhandled event StateChange(Closed(Application(0)))
client  | 14.439 DEBUG Timer fired while closed
client  | 14.439 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 13:36:42,940 Using the client's key log file.
2025-04-30 13:36:42,949 
2025-04-30 13:36:42,950 Using the client's key log file.
2025-04-30 13:36:42,950 Using the client's key log file.
2025-04-30 13:36:42,957 
2025-04-30 13:36:42,958 Using the client's key log file.
2025-04-30 13:36:43,246 Check of downloaded files succeeded.
2025-04-30 13:36:44,406 Check of downloaded files succeeded.