2025-09-12 02:34:57,065 Generated random file: jflxxufrmt of size: 5120 2025-09-12 02:34:57,065 Requests: https://server4:443/jflxxufrmt 2025-09-12 02:34:57,442 2025-09-12 02:34:57,442 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_sk69rdlq/ TESTCASE_SERVER=transfer TESTCASE_CLIENT=transfer WWW=/tmp/www_y5qfos9e/ DOWNLOADS=/tmp/download_h0ogrxlz/ SERVER_LOGS=/tmp/logs_server_i0w89qzc CLIENT_LOGS=/tmp/logs_client_3ak6onfj SCENARIO="droplist --delay=15ms --bandwidth=10Mbps --queue=25 --drops_to_server=2,3,4,5,6,7" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=cloudflare/quiche-qns:latest REQUESTS="https://server4:443/jflxxufrmt" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-09-12 02:35:17,073 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... server | 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 | 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 transfer ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | supported server | ## Starting quiche server... server | ## Server params: server | ## Test case: transfer client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 500.961672ms sim | Using scenario: droplist --delay=15ms --bandwidth=10Mbps --queue=25 --drops_to_server=2,3,4,5,6,7 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/jflxxufrmt ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test transfer --qlog-dir /logs/qlog/ --output-dir /downloads 'https://server4:443/jflxxufrmt client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is Ok(212992) client | 0.001 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.001 INFO hq-interop Client connecting: 0.0.0.0:42037 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=367111a6ab14cdfa79 client | 0.001 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 min_pn=20 client | 0.001 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 0.001 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.001 DEBUG [unv-path 0.0.0.0:42037->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:367111a6ab14cdfa79 0.0.0.0:42037->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:367111a6ab14cdfa79 0.0.0.0:42037->193.167.100.100:443] Path validated Instant { tv_sec: 1245, tv_nsec: 704658413 } client | 0.001 DEBUG [Client 367111a6ab14cdfa79] client_start client | 0.002 DEBUG Writing transport parameters, msg=1 client | 0.002 DEBUG [Agent 0x55568d710500] state -> InProgress client | 0.002 DEBUG [Client 367111a6ab14cdfa79] State change from Init -> WaitInitial client | 0.002 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 367111a6ab14cdfa79) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1212 client | 0.002 DEBUG [Client 367111a6ab14cdfa79] pn=20 type=Initial pri-path:367111a6ab14cdfa79 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1252 client | TX -> Crypto { offset: 0, len: 1212 } client | 0.002 DEBUG packet_sent this=0x55568d723af0, pn=20, ps=1252 client | 0.002 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 367111a6ab14cdfa79) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1212, len=328 client | 0.002 DEBUG [Client 367111a6ab14cdfa79] pn=21 type=Initial pri-path:367111a6ab14cdfa79 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 369 client | TX -> Crypto { offset: 1212, len: 328 } client | 0.002 DEBUG [Client 367111a6ab14cdfa79] pad Initial from 369 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x55568d723af0, pn=21, ps=1252 client | 0.002 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 367111a6ab14cdfa79) 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 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 367111a6ab14cdfa79) 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 367111a6ab14cdfa79] delay duration 3.794843ms client | 0.002 DEBUG Setting timeout of 3.794843ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [9]: 367111a6ab14cdfa79) 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 367111a6ab14cdfa79] delay duration 3.760499ms client | 0.002 DEBUG Setting timeout of 3.760499ms client | 0.007 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [9]: 367111a6ab14cdfa79) 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 367111a6ab14cdfa79] delay duration 294.273032ms client | 0.007 DEBUG Setting timeout of 294.273032ms sim | Dropping packet 2 (1252 bytes) from 193.167.0.100 client | 0.040 DEBUG [Client 367111a6ab14cdfa79] pn=0 type=Initial pri-path:367111a6ab14cdfa79 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 52 client | -> RX Ack { largest_acknowledged: 20, ack_delay: 10, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.040 DEBUG [Client 367111a6ab14cdfa79] Rx ACK space=in, ranges=[20..=20] client | 0.040 DEBUG [recovery::Loss] ACK for Initial - largest_acked=20 client | 0.040 DEBUG on_packets_acked this=0x55568d723af0, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.040 DEBUG Acked crypto frame space=in offset=0 length=1212 client | 0.040 DEBUG [Client 367111a6ab14cdfa79] Changing to use Server CID=d4139d4dc2b855b192689ecb32a04b38b12a5fea client | 0.040 DEBUG [Client 367111a6ab14cdfa79] State change from WaitInitial -> WaitVersion client | 0.040 DEBUG saving ApplicationData datagram of 1148 bytes client | 0.040 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.040 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG [Client 367111a6ab14cdfa79] delay duration 76.717647ms client | 0.040 DEBUG Setting timeout of 76.717647ms client | 0.040 WARN Unhandled event StateChange(WaitVersion) client | 0.040 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.040 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.040 DEBUG [Client 367111a6ab14cdfa79] delay duration 76.683583ms client | 0.040 DEBUG Setting timeout of 76.683583ms client | 0.118 DEBUG [recovery::Loss] PTO timer fired for Initial client | 0.118 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 0.118 INFO Lost crypto frame space=in offset=1212 length=328 client | 0.118 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.118 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.118 DEBUG CRYPTO for in offset=1212, len=328 client | 0.118 DEBUG [Client 367111a6ab14cdfa79] pn=22 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 380 client | TX -> Crypto { offset: 1212, len: 328 } client | 0.118 DEBUG [Client 367111a6ab14cdfa79] pad Initial from 380 to PLPMTU 1252 client | 0.118 DEBUG packet_sent this=0x55568d723af0, pn=22, ps=1252 client | 0.118 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.118 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.118 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.118 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.118 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.118 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.118 DEBUG [Client 367111a6ab14cdfa79] delay duration 230.192234ms client | 0.118 DEBUG Setting timeout of 230.192234ms sim | Dropping packet 3 (1252 bytes) from 193.167.0.100 client | 0.350 DEBUG [recovery::Loss] PTO timer fired for Initial client | 0.350 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 0.350 INFO Lost crypto frame space=in offset=1212 length=328 client | 0.350 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.350 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.350 DEBUG CRYPTO for in offset=1212, len=328 client | 0.350 DEBUG [Client 367111a6ab14cdfa79] pn=23 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 380 client | TX -> Crypto { offset: 1212, len: 328 } client | 0.350 DEBUG [Client 367111a6ab14cdfa79] pad Initial from 380 to PLPMTU 1252 client | 0.350 DEBUG packet_sent this=0x55568d723af0, pn=23, ps=1252 client | 0.350 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.350 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.350 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.350 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.350 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.350 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.350 DEBUG [Client 367111a6ab14cdfa79] delay duration 460.658199ms client | 0.350 DEBUG Setting timeout of 460.658199ms sim | Dropping packet 4 (1252 bytes) from 193.167.0.100 client | 0.812 DEBUG [recovery::Loss] PTO timer fired for Initial client | 0.812 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 0.812 INFO Lost crypto frame space=in offset=1212 length=328 client | 0.812 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 0.812 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.812 DEBUG CRYPTO for in offset=1212, len=328 client | 0.812 DEBUG [Client 367111a6ab14cdfa79] pn=24 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 380 client | TX -> Crypto { offset: 1212, len: 328 } client | 0.812 DEBUG [Client 367111a6ab14cdfa79] pad Initial from 380 to PLPMTU 1252 client | 0.812 DEBUG packet_sent this=0x55568d723af0, pn=24, ps=1252 client | 0.812 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.812 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.812 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 0.812 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.812 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 0.812 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.812 DEBUG [Client 367111a6ab14cdfa79] delay duration 921.550085ms client | 0.812 DEBUG Setting timeout of 921.550085ms sim | Dropping packet 5 (1252 bytes) from 193.167.0.100 client | 1.735 DEBUG [recovery::Loss] PTO timer fired for Initial client | 1.735 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 1.735 INFO Lost crypto frame space=in offset=1212 length=328 client | 1.735 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 1.735 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 1.735 DEBUG CRYPTO for in offset=1212, len=328 client | 1.735 DEBUG [Client 367111a6ab14cdfa79] pn=25 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 380 client | TX -> Crypto { offset: 1212, len: 328 } client | 1.735 DEBUG [Client 367111a6ab14cdfa79] pad Initial from 380 to PLPMTU 1252 client | 1.735 DEBUG packet_sent this=0x55568d723af0, pn=25, ps=1252 client | 1.735 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.735 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 1.735 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 1.735 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.735 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 1.735 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 1.735 DEBUG [Client 367111a6ab14cdfa79] delay duration 1.843260879s client | 1.735 DEBUG Setting timeout of 1.843260879s sim | Dropping packet 6 (1252 bytes) from 193.167.0.100 client | 3.580 DEBUG [recovery::Loss] PTO timer fired for Initial client | 3.580 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 3.580 INFO Lost crypto frame space=in offset=1212 length=328 client | 3.580 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 3.580 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 3.580 DEBUG CRYPTO for in offset=1212, len=328 client | 3.580 DEBUG [Client 367111a6ab14cdfa79] pn=26 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 380 client | TX -> Crypto { offset: 1212, len: 328 } client | 3.580 DEBUG [Client 367111a6ab14cdfa79] pad Initial from 380 to PLPMTU 1252 client | 3.580 DEBUG packet_sent this=0x55568d723af0, pn=26, ps=1252 client | 3.580 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 3.580 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 3.580 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 3.580 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.580 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 3.580 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 3.580 DEBUG [Client 367111a6ab14cdfa79] delay duration 3.68667769s client | 3.580 DEBUG Setting timeout of 3.68667769s sim | Dropping packet 7 (1252 bytes) from 193.167.0.100 client | 7.268 DEBUG [recovery::Loss] PTO timer fired for Initial client | 7.268 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 7.268 INFO Lost crypto frame space=in offset=1212 length=328 client | 7.268 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(Initial), paced: false } client | 7.268 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.268 DEBUG CRYPTO for in offset=1212, len=328 client | 7.268 DEBUG [Client 367111a6ab14cdfa79] pn=27 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 380 client | TX -> Crypto { offset: 1212, len: 328 } client | 7.268 DEBUG [Client 367111a6ab14cdfa79] pad Initial from 380 to PLPMTU 1252 client | 7.268 DEBUG packet_sent this=0x55568d723af0, pn=27, ps=1252 client | 7.268 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 7.268 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.268 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: Some(Initial), probe: EnumSet(), paced: false } client | 7.268 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.268 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.268 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.268 DEBUG [Client 367111a6ab14cdfa79] delay duration 7.373593635s client | 7.268 DEBUG Setting timeout of 7.373593635s client | 7.301 DEBUG [Client 367111a6ab14cdfa79] pn=1 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 148 client | -> RX Ack { largest_acknowledged: 27, ack_delay: 51, first_ack_range: 0, ack_ranges: [AckRange { gap: 5, range: 0 }], ecn_count: None } client | -> RX Crypto { offset: 0, len: 90 } client | 7.301 DEBUG [Client 367111a6ab14cdfa79] Rx ACK space=in, ranges=[27..=27, 20..=20] client | 7.301 DEBUG [recovery::Loss] ACK for Initial - largest_acked=27 client | 7.301 DEBUG packet_lost this=0x55568d723af0, pn=21, ps=1252 client | 7.301 DEBUG packet_lost this=0x55568d723af0, pn=22, ps=1252 client | 7.301 DEBUG packet_lost this=0x55568d723af0, pn=23, ps=1252 client | 7.301 DEBUG packet_lost this=0x55568d723af0, pn=24, ps=1252 client | 7.301 DEBUG packet_lost this=0x55568d723af0, pn=25, ps=1252 client | 7.301 DEBUG packet_lost this=0x55568d723af0, pn=26, ps=1252 client | 7.301 INFO [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] Cong event -> recovery; cwnd 8764, ssthresh 8764 client | 7.301 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] state -> RecoveryStart client | 7.301 INFO [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/8764 ssthresh 8764] persistent congestion client | 7.301 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 1252/2504 ssthresh 8764] state -> PersistentCongestion client | 7.301 DEBUG on_packets_lost this=0x55568d723af0, bytes_in_flight=1252, cwnd=2504, state=PersistentCongestion client | 7.302 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/2504 ssthresh 8764] slow start += 0 client | 7.302 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 0/2504 ssthresh 8764] on_packets_acked this=0x55568d723af0, limited=0, bytes_in_flight=0, cwnd=2504, state=PersistentCongestion, new_acked=0 client | 7.302 DEBUG Acked crypto frame space=in offset=1212 length=328 client | 7.302 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 7.302 INFO Lost crypto frame space=in offset=1212 length=328 client | 7.302 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 7.302 INFO Lost crypto frame space=in offset=1212 length=328 client | 7.302 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 7.302 INFO Lost crypto frame space=in offset=1212 length=328 client | 7.302 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 7.302 INFO Lost crypto frame space=in offset=1212 length=328 client | 7.302 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 7.302 INFO Lost crypto frame space=in offset=1212 length=328 client | 7.302 DEBUG [Client 367111a6ab14cdfa79] Lost: Crypto(CryptoRecoveryToken { space: Initial, offset: 1212, length: 328 }) client | 7.302 INFO Lost crypto frame space=in offset=1212 length=328 client | 7.302 DEBUG Write secret available for Handshake: SymKey [32]: a58bf6d6f1fd94e4ea1c60a1eb29fa35884625ba3a7f8ae3d19c690be986aa83 client | 7.302 DEBUG Read secret available for Handshake: SymKey [32]: 0e6282da36543a198614fa62532a8473c08ffb8218bc1f1578d7079a2054044e client | 7.302 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.302 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 7.302 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 7.302 DEBUG [Crypto] Handshake keys installed client | 7.302 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 5267486 } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] State change from WaitVersion -> Handshaking client | 7.302 DEBUG [Client 367111a6ab14cdfa79] pn=2 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1052 client | -> RX Crypto { offset: 0, len: 1002 } client | 7.302 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.302 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 5267486 } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG Building Initial dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.302 DEBUG [Client 367111a6ab14cdfa79] pn=28 type=Initial pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 53 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 95, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 7.302 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.302 DEBUG [Client 367111a6ab14cdfa79] pn=0 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 105 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 95, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] Drop packet number space in client | 7.302 DEBUG [recovery::Loss] Reset loss recovery state for Initial client | 7.302 INFO [recovery::Loss] ignoring in-28 from dropped space client | 7.302 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.302 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] delay duration 100.442622ms client | 7.302 DEBUG Setting timeout of 100.442622ms client | 7.302 DEBUG StateChange(Handshaking) client | 7.302 WARN Cannot create stream ConnectionState client | 7.302 DEBUG stream BiDi creatable client | 7.302 WARN Cannot create stream ConnectionState client | 7.302 DEBUG stream UniDi creatable client | 7.302 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.302 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] delay duration 100.404391ms client | 7.302 DEBUG Setting timeout of 100.404391ms client | 7.302 DEBUG [Client 367111a6ab14cdfa79] pn=3 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 1002, len: 1149 } client | 7.302 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.302 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 6212752 } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.302 DEBUG [Client 367111a6ab14cdfa79] pn=1 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 3, ack_delay: 4, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.302 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] delay duration 100.293754ms client | 7.302 DEBUG Setting timeout of 100.293754ms client | 7.302 DEBUG stream BiDi creatable client | 7.302 WARN Cannot create stream ConnectionState client | 7.302 DEBUG stream UniDi creatable client | 7.302 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.302 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.302 DEBUG [Client 367111a6ab14cdfa79] delay duration 100.269489ms client | 7.302 DEBUG Setting timeout of 100.269489ms client | 7.303 DEBUG [Client 367111a6ab14cdfa79] pn=4 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 2151, len: 1149 } client | 7.303 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.303 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 7175511 } client | 7.303 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.303 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.303 DEBUG [Client 367111a6ab14cdfa79] pn=2 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 5, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | 7.303 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.303 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.303 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.303 DEBUG [Client 367111a6ab14cdfa79] delay duration 99.324403ms client | 7.303 DEBUG Setting timeout of 99.324403ms client | 7.303 DEBUG stream BiDi creatable client | 7.303 WARN Cannot create stream ConnectionState client | 7.303 DEBUG stream UniDi creatable client | 7.303 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.303 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.303 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.303 DEBUG [Client 367111a6ab14cdfa79] delay duration 99.29608ms client | 7.303 DEBUG Setting timeout of 99.29608ms client | 7.304 DEBUG [Client 367111a6ab14cdfa79] pn=5 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 3300, len: 1149 } client | 7.304 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.304 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 8160200 } client | 7.304 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.304 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.304 DEBUG [Client 367111a6ab14cdfa79] pn=3 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 5, ack_delay: 4, first_ack_range: 3, ack_ranges: [], ecn_count: None } client | 7.304 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.304 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.304 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.304 DEBUG [Client 367111a6ab14cdfa79] delay duration 98.354701ms client | 7.304 DEBUG Setting timeout of 98.354701ms client | 7.304 DEBUG stream BiDi creatable client | 7.304 WARN Cannot create stream ConnectionState client | 7.304 DEBUG stream UniDi creatable client | 7.304 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.304 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.304 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.304 DEBUG [Client 367111a6ab14cdfa79] delay duration 98.325016ms client | 7.304 DEBUG Setting timeout of 98.325016ms client | 7.305 DEBUG [Client 367111a6ab14cdfa79] pn=6 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 4449, len: 1149 } client | 7.305 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.305 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 9120965 } client | 7.305 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.305 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.305 DEBUG [Client 367111a6ab14cdfa79] pn=4 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 7, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | 7.305 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.305 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.305 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.305 DEBUG [Client 367111a6ab14cdfa79] delay duration 97.36326ms client | 7.305 DEBUG Setting timeout of 97.36326ms client | 7.305 DEBUG stream BiDi creatable client | 7.305 WARN Cannot create stream ConnectionState client | 7.305 DEBUG stream UniDi creatable client | 7.305 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.305 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.305 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.305 DEBUG [Client 367111a6ab14cdfa79] delay duration 97.325178ms client | 7.305 DEBUG Setting timeout of 97.325178ms client | 7.306 DEBUG [Client 367111a6ab14cdfa79] pn=7 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 5598, len: 1149 } client | 7.306 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.306 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 10137722 } client | 7.306 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.306 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.306 DEBUG [Client 367111a6ab14cdfa79] pn=5 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 7, ack_delay: 3, first_ack_range: 5, ack_ranges: [], ecn_count: None } client | 7.306 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.306 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.306 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.306 DEBUG [Client 367111a6ab14cdfa79] delay duration 96.377189ms client | 7.306 DEBUG Setting timeout of 96.377189ms client | 7.306 DEBUG stream BiDi creatable client | 7.306 WARN Cannot create stream ConnectionState client | 7.306 DEBUG stream UniDi creatable client | 7.306 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.306 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.306 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.306 DEBUG [Client 367111a6ab14cdfa79] delay duration 96.346763ms client | 7.306 DEBUG Setting timeout of 96.346763ms client | 7.306 DEBUG [Client 367111a6ab14cdfa79] pn=8 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 260 client | -> RX Crypto { offset: 6747, len: 209 } client | 7.306 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.306 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 10303845 } client | 7.306 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.306 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.306 DEBUG [Client 367111a6ab14cdfa79] pn=6 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 3, first_ack_range: 6, ack_ranges: [], ecn_count: None } client | 7.307 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.307 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.307 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.307 DEBUG [Client 367111a6ab14cdfa79] delay duration 96.211788ms client | 7.307 DEBUG Setting timeout of 96.211788ms client | 7.307 DEBUG stream BiDi creatable client | 7.307 WARN Cannot create stream ConnectionState client | 7.307 DEBUG stream UniDi creatable client | 7.307 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.307 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.307 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.307 DEBUG [Client 367111a6ab14cdfa79] delay duration 96.174839ms client | 7.307 DEBUG Setting timeout of 96.174839ms client | 7.334 DEBUG [Client 367111a6ab14cdfa79] pn=9 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 6956, len: 1149 } client | 7.334 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.334 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 37773933 } client | 7.334 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.334 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.334 DEBUG [Client 367111a6ab14cdfa79] pn=7 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 9, ack_delay: 5, first_ack_range: 7, ack_ranges: [], ecn_count: None } client | 7.334 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.334 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.334 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.334 DEBUG [Client 367111a6ab14cdfa79] delay duration 68.722554ms client | 7.334 DEBUG Setting timeout of 68.722554ms client | 7.334 DEBUG stream BiDi creatable client | 7.334 WARN Cannot create stream ConnectionState client | 7.334 DEBUG stream UniDi creatable client | 7.334 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.334 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.334 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.334 DEBUG [Client 367111a6ab14cdfa79] delay duration 68.689142ms client | 7.334 DEBUG Setting timeout of 68.689142ms client | 7.335 DEBUG [Client 367111a6ab14cdfa79] pn=10 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1200 client | -> RX Crypto { offset: 8105, len: 1149 } client | 7.335 DEBUG [Agent 0x55568d710500] state -> InProgress client | 7.335 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 38754405 } client | 7.335 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.335 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.335 DEBUG [Client 367111a6ab14cdfa79] pn=8 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 51 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 3, first_ack_range: 8, ack_ranges: [], ecn_count: None } client | 7.335 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.335 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.335 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.335 DEBUG [Client 367111a6ab14cdfa79] delay duration 67.756319ms client | 7.335 DEBUG Setting timeout of 67.756319ms client | 7.335 DEBUG stream BiDi creatable client | 7.335 WARN Cannot create stream ConnectionState client | 7.335 DEBUG stream UniDi creatable client | 7.335 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.335 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.335 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.335 DEBUG [Client 367111a6ab14cdfa79] delay duration 67.728457ms client | 7.335 DEBUG Setting timeout of 67.728457ms client | 7.336 DEBUG [Client 367111a6ab14cdfa79] pn=11 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 744 client | -> RX Crypto { offset: 9254, len: 693 } client | 7.336 DEBUG [Agent 0x55568d710500] state -> AuthenticationPending client | 7.336 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 39357118 } client | 7.336 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.336 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.336 DEBUG [Client 367111a6ab14cdfa79] pn=9 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 52 client | TX -> Ack { largest_acknowledged: 11, ack_delay: 107, first_ack_range: 9, ack_ranges: [], ecn_count: None } client | 7.336 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.336 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.336 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.336 DEBUG [Client 367111a6ab14cdfa79] delay duration 66.328264ms client | 7.336 DEBUG Setting timeout of 66.328264ms client | 7.336 DEBUG [Client 367111a6ab14cdfa79] Authenticated Ok client | 7.336 DEBUG Write secret available for ApplicationData: SymKey [32]: d9d4821ec7a492c890e464fafea7f07f042f19f3faced6e025757a602a400f34 client | 7.336 DEBUG Read secret available for ApplicationData: SymKey [32]: e36b33df0faacc0aaa193554789767134cb13d1fef98230dd898f374f01ae9a7 client | 7.337 DEBUG [Agent 0x55568d710500] SSL_AuthCertificateComplete: Ok(()) client | 7.337 DEBUG [Agent 0x55568d710500] 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 | 7.337 DEBUG [Client 367111a6ab14cdfa79] TLS connection complete client | 7.337 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 7.337 DEBUG [Crypto] Application write key installed client | 7.337 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 min_pn=0 client | 7.337 DEBUG [Crypto] application read keys installed client | 7.337 DEBUG [Client 367111a6ab14cdfa79] State change from Handshaking -> Connected client | 7.337 INFO [Client 367111a6ab14cdfa79] Connection established client | 7.337 DEBUG [Client 367111a6ab14cdfa79] process saved for epoch ApplicationData client | 7.337 WARN Crypto operation failed Nss { name: "SEC_ERROR_BAD_DATA", code: -8190, desc: "security library: received bad data." } client | 7.337 DEBUG [Client ...] Dropped received packet: Decryption failure; Total: 1 client | 7.337 DEBUG stream BiDi creatable client | 7.337 INFO Created stream 0 for https://server4/jflxxufrmt client | 7.337 INFO Saving https://server4/jflxxufrmt to "/downloads/jflxxufrmt" client | 7.337 DEBUG stream UniDi creatable client | 7.337 DEBUG StateChange(Connected) client | 7.337 DEBUG stream 0 writable client | 7.337 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.337 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.337 DEBUG CRYPTO for hs offset=0, len=36 client | 7.337 DEBUG [Client 367111a6ab14cdfa79] pn=10 type=Handshake pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 85 client | TX -> Crypto { offset: 0, len: 36 } client | 7.337 DEBUG packet_sent this=0x55568d723af0, pn=10, ps=85 client | 7.337 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.337 DEBUG [Client 367111a6ab14cdfa79] pn=0 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 143 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 7.337 DEBUG packet_sent this=0x55568d723af0, pn=0, ps=58 client | 7.337 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.337 DEBUG Building Handshake dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) scid Some(CID [0]: ) client | 7.337 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.337 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.337 DEBUG [Client 367111a6ab14cdfa79] delay duration 100.480203ms client | 7.337 DEBUG Setting timeout of 100.480203ms client | 7.369 DEBUG [Client 367111a6ab14cdfa79] pn=12 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1350 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 7, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [3, 53, 236, 198, 98, 223, 214, 211, 241, 13, 153, 149, 28, 152, 158, 129, 183, 52, 26, 203], stateless_reset_token: [145, 178, 130, 235, 190, 37, 157, 16, 50, 47, 69, 185, 244, 154, 59, 71] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [188, 164, 185, 176, 18, 141, 186, 144, 60, 115, 16, 219, 50, 158, 241, 37, 152, 90, 146, 247], stateless_reset_token: [105, 233, 70, 240, 67, 240, 85, 222, 223, 160, 176, 33, 76, 23, 79, 130] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [226, 153, 151, 50, 190, 196, 143, 192, 83, 174, 41, 164, 72, 30, 32, 198, 81, 22, 1, 0], stateless_reset_token: [90, 233, 14, 255, 83, 33, 228, 201, 172, 94, 162, 237, 207, 177, 22, 237] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [93, 138, 29, 33, 130, 92, 225, 36, 27, 135, 177, 64, 44, 127, 209, 168, 135, 158, 50, 36], stateless_reset_token: [138, 104, 210, 192, 110, 226, 5, 215, 58, 146, 106, 112, 81, 27, 94, 235] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [19, 182, 170, 4, 120, 80, 90, 122, 146, 15, 144, 58, 89, 171, 121, 44, 141, 86, 135, 121], stateless_reset_token: [136, 168, 116, 3, 35, 40, 116, 136, 95, 161, 216, 14, 137, 239, 109, 191] } client | -> RX NewConnectionId { sequence_number: 6, retire_prior: 0, connection_id: [131, 42, 220, 205, 238, 128, 123, 104, 70, 244, 126, 101, 142, 24, 86, 243, 170, 173, 116, 0], stateless_reset_token: [178, 167, 11, 76, 22, 23, 191, 98, 201, 64, 199, 80, 68, 197, 2, 25] } client | -> RX NewConnectionId { sequence_number: 7, retire_prior: 0, connection_id: [122, 240, 180, 46, 162, 151, 43, 47, 25, 230, 23, 10, 25, 78, 158, 188, 163, 89, 19, 240], stateless_reset_token: [133, 146, 214, 111, 148, 174, 200, 126, 9, 28, 77, 213, 167, 82, 67, 121] } client | -> RX HandshakeDone client | -> RX Crypto { offset: 0, len: 396 } client | -> RX Stream { stream_id: 0, offset: 0, len: 641, fin: false } client | 7.369 DEBUG [Client 367111a6ab14cdfa79] Rx ACK space=ap, ranges=[0..=0] client | 7.369 DEBUG [recovery::Loss] ACK for ApplicationData - largest_acked=0 client | 7.369 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 85/2562 ssthresh 8764] slow start += 58 client | 7.369 DEBUG [Cubic [last_max_cwnd: 12520, k: 0, w_max: 0, ca_epoch_start: None] CongCtrl 85/2562 ssthresh 8764] on_packets_acked this=0x55568d723af0, limited=0, bytes_in_flight=85, cwnd=2562, state=SlowStart, new_acked=58 client | 7.369 DEBUG [Client 367111a6ab14cdfa79] State change from Connected -> Confirmed client | 7.369 DEBUG PMTUD started with probe size 1380 client | 7.369 DEBUG [Client 367111a6ab14cdfa79] Drop packet number space hs client | 7.369 DEBUG [recovery::Loss] Reset loss recovery state for Handshake client | 7.369 DEBUG [Client 367111a6ab14cdfa79] No preferred address to migrate to client | 7.369 DEBUG [0x55568d710500] Got resumption token [5931]: 0200063e918070e8..8ee4ff77c175ce53 client | 7.369 DEBUG [0x55568d710500] Got resumption token [5931]: 0200063e918070e8..316fe5d8d5e55b2c client | 7.369 DEBUG [Agent 0x55568d710500] 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 | 7.369 DEBUG setting max_stream_data to 1000000 client | 7.369 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 72658058 } client | 7.369 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 7.369 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.369 DEBUG Sending PMTUD probe of size 1380, count 1 client | 7.369 DEBUG [Client 367111a6ab14cdfa79] pn=1 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, Ect0) len 1352 client | TX -> Ack { largest_acknowledged: 12, ack_delay: 37, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Ping client | TX -> Padding { len: 1308 } client | 7.369 DEBUG packet_sent this=0x55568d723af0, pn=1, ps=1352 client | 7.369 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.369 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.369 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.369 DEBUG ECN probing: sent 1 probes client | 7.369 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.369 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.369 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.369 DEBUG [Client 367111a6ab14cdfa79] delay duration 114.825777ms client | 7.369 DEBUG Setting timeout of 114.825777ms client | 7.369 DEBUG stream 0 complete client | 7.369 WARN Unhandled event StateChange(Confirmed) client | 7.369 DEBUG stream BiDi creatable client | 7.369 DEBUG stream UniDi creatable client | 7.369 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.369 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.369 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.369 DEBUG [Client 367111a6ab14cdfa79] delay duration 114.794799ms client | 7.369 DEBUG Setting timeout of 114.794799ms client | 7.370 DEBUG [Client 367111a6ab14cdfa79] pn=13 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1350 client | -> RX Stream { stream_id: 0, offset: 641, len: 1326, fin: false } client | 7.370 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 93734239 } client | 7.370 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.370 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.370 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.370 DEBUG [Client 367111a6ab14cdfa79] delay duration 19.961979ms client | 7.370 DEBUG Setting timeout of 19.961979ms client | 7.370 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.370 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.370 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.370 DEBUG [Client 367111a6ab14cdfa79] delay duration 19.935039ms client | 7.370 DEBUG Setting timeout of 19.935039ms client | 7.371 DEBUG [Client 367111a6ab14cdfa79] pn=14 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1350 client | -> RX Stream { stream_id: 0, offset: 1967, len: 1326, fin: false } client | 7.371 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 74820788 } client | 7.371 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.371 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.371 DEBUG [Client 367111a6ab14cdfa79] pn=2 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 14, ack_delay: 4, first_ack_range: 2, ack_ranges: [], ecn_count: None } client | 7.371 DEBUG ECN probing: sent 2 probes client | 7.371 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.371 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.371 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.371 DEBUG [Client 367111a6ab14cdfa79] delay duration 113.003914ms client | 7.371 DEBUG Setting timeout of 113.003914ms client | 7.371 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.371 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.371 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.371 DEBUG [Client 367111a6ab14cdfa79] delay duration 112.984357ms client | 7.371 DEBUG Setting timeout of 112.984357ms client | 7.372 DEBUG [Client 367111a6ab14cdfa79] pn=15 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 1350 client | -> RX Stream { stream_id: 0, offset: 3293, len: 1326, fin: false } client | 7.372 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 95931814 } client | 7.372 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.372 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.372 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.372 DEBUG [Client 367111a6ab14cdfa79] delay duration 19.973551ms client | 7.372 DEBUG Setting timeout of 19.973551ms client | 7.372 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.372 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.372 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.372 DEBUG [Client 367111a6ab14cdfa79] delay duration 19.951429ms client | 7.372 DEBUG Setting timeout of 19.951429ms client | 7.373 DEBUG [Client 367111a6ab14cdfa79] pn=16 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, NotEct) len 525 client | -> RX Stream { stream_id: 0, offset: 4619, len: 501, fin: true } client | 7.373 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 1253, tv_nsec: 76361326 } client | 7.373 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.373 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.373 DEBUG [Client 367111a6ab14cdfa79] pn=3 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, Ect0) len 43 client | TX -> Ack { largest_acknowledged: 16, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | 7.373 DEBUG ECN probing: sent 3 probes client | 7.373 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.373 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.373 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.373 DEBUG [Client 367111a6ab14cdfa79] delay duration 111.468966ms client | 7.373 DEBUG Setting timeout of 111.468966ms client | 7.373 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.373 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.373 DEBUG TX blocked, profile=SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.373 DEBUG [Client 367111a6ab14cdfa79] delay duration 111.428421ms client | 7.373 DEBUG Setting timeout of 111.428421ms client | 7.373 DEBUG [Client 367111a6ab14cdfa79] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 1253, tv_nsec: 421337291 } } client | 7.373 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 1253, tv_nsec: 421337291 } }) client | 7.373 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.373 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.373 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 1253, tv_nsec: 76512008 } client | 7.373 DEBUG [Client 367111a6ab14cdfa79] pn=4 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, Ect0) len 54 client | TX -> Ack { largest_acknowledged: 16, ack_delay: 18, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.373 DEBUG ECN probing: sent 4 probes client | 7.373 DEBUG Setting timeout of 344.755924ms client | 7.401 DEBUG [Client 367111a6ab14cdfa79] output_path send_profile SendProfile { limit: 1210, pto: None, probe: EnumSet(), paced: false } client | 7.401 DEBUG Building Short dcid Some(CID [20]: d4139d4dc2b855b192689ecb32a04b38b12a5fea) client | 7.401 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 1253, tv_nsec: 104705266 } client | 7.401 DEBUG [Client 367111a6ab14cdfa79] pn=5 type=Short pri-path:d4139d4dc2b855b192689ecb32a04b38b12a5fea 0.0.0.0:42037->193.167.100.100:443 Tos(Cs0, Ect0) len 55 client | TX -> Ack { largest_acknowledged: 16, ack_delay: 3542, first_ack_range: 4, ack_ranges: [], ecn_count: None } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 7.401 DEBUG ECN probing: sent 5 probes client | 7.401 DEBUG Setting timeout of 316.554059ms client | 7.401 DEBUG Setting timeout of 316.541055ms client | 7.719 DEBUG [Client 367111a6ab14cdfa79] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 1253, tv_nsec: 421337291 } } -> Closed(Application(0)) client | 7.719 INFO Closing timer expired client | 7.719 DEBUG Output::None client | 7.719 WARN Unhandled event StateChange(Closed(Application(0))) client | 7.719 DEBUG Timer fired while closed client | 7.719 DEBUG Output::None client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-09-12 02:35:17,166 Using the client's key log file. 2025-09-12 02:35:17,177 2025-09-12 02:35:17,178 Using the client's key log file. 2025-09-12 02:35:17,178 Using the client's key log file. 2025-09-12 02:35:17,188 2025-09-12 02:35:17,188 Using the client's key log file. 2025-09-12 02:35:17,189 Using the client's key log file. 2025-09-12 02:35:17,683 Check of downloaded files succeeded. 2025-09-12 02:35:17,931 Server sent 9947 bytes in Handshake CRYPTO frames. 2025-09-12 02:35:18,226 Received a 1252 byte Initial packet from the client. Amplification limit: 3756 2025-09-12 02:35:18,227 Received a 1200 byte Handshake packet from the server. Total: 1200 2025-09-12 02:35:18,227 Received a 1252 byte Initial packet from the client. Amplification limit: 7512 2025-09-12 02:35:18,227 Received a 1200 byte Handshake packet from the server. Total: 2400 2025-09-12 02:35:18,227 Received a 1200 byte Handshake packet from the server. Total: 3600 2025-09-12 02:35:18,227 Received a 1200 byte Handshake packet from the server. Total: 4800 2025-09-12 02:35:18,227 Received a 1200 byte Handshake packet from the server. Total: 6000 2025-09-12 02:35:18,227 Received a 1200 byte Handshake packet from the server. Total: 7200 2025-09-12 02:35:18,227 Received a 1200 byte Handshake packet from the server. Total: 8400 2025-09-12 02:35:18,227 Server violated the amplification limit, but stayed within 3-4x amplification. Letting it slide. 2025-09-12 02:35:18,227 Received a 260 byte Handshake packet from the server. Total: 8660 2025-09-12 02:35:18,227 Server violated the amplification limit, but stayed within 3-4x amplification. Letting it slide. 2025-09-12 02:35:18,227 Received a 105 byte Initial packet from the client. Amplification limit: 7827