2025-04-30 11:55:26,493 Generated random file: vpgofcjauo of size: 5120 2025-04-30 11:55:26,493 Generated random file: cpakzbette of size: 10240 2025-04-30 11:55:26,493 Requests: https://server4:443/vpgofcjauo https://server4:443/cpakzbette 2025-04-30 11:55:26,552 2025-04-30 11:55:26,552 Command: WAITFORSERVER=server:443 CERTS=/tmp/certs_35dmzsvz/ TESTCASE_SERVER=resumption TESTCASE_CLIENT=resumption WWW=/tmp/www_pyvh9wop/ DOWNLOADS=/tmp/download_7iw1kl40/ SERVER_LOGS=/tmp/logs_server_9on6uatv CLIENT_LOGS=/tmp/logs_client_f3aiukrd SCENARIO="simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25" CLIENT=ghcr.io/mozilla/neqo-qns:latest SERVER=martenseemann/quic-go-interop:latest REQUESTS="https://server4:443/vpgofcjauo https://server4:443/cpakzbette" docker compose --env-file empty.env up --abort-on-container-exit --timeout 1 sim client server 2025-04-30 11:55:39,259 Container sim Created 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 resumption ']' client | + '[' -n /logs/qlog/ ']' client | + case "$ROLE" in client | + /wait-for-it.sh sim:57832 -s -t 30 server | Using commit: e4bb2dbd5557c9417b30cf9fcd9032fd6fea5366 server | Running QUIC server. client | wait-for-it.sh: waiting 30 seconds for sim:57832 sim | server:443 is available after 1.058689225s sim | Using scenario: simple-p2p --delay=15ms --bandwidth=10Mbps --queue=25 sim | tcpdump: listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes sim | tcpdump: listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes client | wait-for-it.sh: sim:57832 is available after 1 seconds client | + OPTIONS=(--cc cubic --qns-test "$TESTCASE" --qlog-dir "$QLOGDIR" --output-dir /downloads) client | + '[' 'https://server4:443/vpgofcjauo https://server4:443/cpakzbette' ']' client | + mapfile -d ' ' -t URLS client | + OPTIONS+=("${URLS[@]}") client | + RUST_LOG=debug client | + RUST_BACKTRACE=1 client | + neqo-client --cc cubic --qns-test resumption --qlog-dir /logs/qlog/ --output-dir /downloads https://server4:443/vpgofcjauo 'https://server4:443/cpakzbette client | ' client | ++ tee -i -a /logs/client.log client | 0.000 DEBUG Logging initialized client | 0.001 DEBUG Default socket send buffer size is 212992 client | 0.001 DEBUG Default socket receive buffer size is 1048576, not changing client | 0.001 INFO hq-interop Client connecting: 0.0.0.0:50776 -> 193.167.100.100:443 client | 0.001 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=bed684b29d73d4f4e68d 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:50776->193.167.100.100:443] Make permanent client | 0.001 DEBUG [unv-path:bed684b29d73d4f4e68d 0.0.0.0:50776->193.167.100.100:443] set as primary path client | 0.001 DEBUG [pri-unv-path:bed684b29d73d4f4e68d 0.0.0.0:50776->193.167.100.100:443] Path validated Instant { tv_sec: 291, tv_nsec: 486242081 } client | 0.001 DEBUG [Client bed684b29d73d4f4e68d] client_start client | 0.001 DEBUG Writing transport parameters, msg=1 client | 0.001 DEBUG [Agent 0x55f680f35f20] state -> InProgress client | 0.001 DEBUG [Client bed684b29d73d4f4e68d] State change from Init -> WaitInitial client | 0.001 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.001 DEBUG Building Initial dcid Some(CID [10]: bed684b29d73d4f4e68d) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=0, len=1211 client | 0.002 DEBUG [Client bed684b29d73d4f4e68d] pn=0 type=Initial pri-path:bed684b29d73d4f4e68d 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1211 } client | 0.002 DEBUG packet_sent this=0x55f680f49630, pn=0, ps=1252 client | 0.002 DEBUG ECN probing: sent 1 probes client | 0.002 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.002 DEBUG Building Initial dcid Some(CID [10]: bed684b29d73d4f4e68d) scid Some(CID [0]: ) client | 0.002 DEBUG CRYPTO for in offset=1211, len=328 client | 0.002 DEBUG [Client bed684b29d73d4f4e68d] pn=1 type=Initial pri-path:bed684b29d73d4f4e68d 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 370 client | TX -> Crypto { offset: 1211, len: 328 } client | 0.002 DEBUG [Client bed684b29d73d4f4e68d] pad Initial from 370 to PLPMTU 1252 client | 0.002 DEBUG packet_sent this=0x55f680f49630, pn=1, ps=1252 client | 0.002 DEBUG ECN probing: sent 2 probes client | 0.002 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [10]: bed684b29d73d4f4e68d) 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 bed684b29d73d4f4e68d] delay duration 3.920704ms client | 0.002 DEBUG Setting timeout of 3.920704ms client | 0.002 DEBUG StateChange(WaitInitial) client | 0.002 WARN Cannot create stream ConnectionState client | 0.002 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 255, pto: None, probe: EnumSet(), paced: true } client | 0.002 DEBUG Building Initial dcid Some(CID [10]: bed684b29d73d4f4e68d) 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 bed684b29d73d4f4e68d] delay duration 3.8973ms client | 0.002 DEBUG Setting timeout of 3.8973ms client | 0.007 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.007 DEBUG Building Initial dcid Some(CID [10]: bed684b29d73d4f4e68d) 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 bed684b29d73d4f4e68d] delay duration 294.821659ms client | 0.007 DEBUG Setting timeout of 294.821659ms client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] pn=0 type=Initial pri-path:bed684b29d73d4f4e68d 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 40 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] Rx ACK space=in, ranges=[0..=0] client | 0.039 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.039 DEBUG on_packets_acked this=0x55f680f49630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.039 DEBUG Acked crypto frame space=in offset=0 length=1211 client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] Changing to use Server CID=b5b43d13 client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] State change from WaitInitial -> WaitVersion client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] delay duration 75.627727ms client | 0.039 DEBUG Setting timeout of 75.627727ms client | 0.039 WARN Unhandled event StateChange(WaitVersion) client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG Building Initial dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.039 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.039 DEBUG [Client bed684b29d73d4f4e68d] delay duration 75.594595ms client | 0.039 DEBUG Setting timeout of 75.594595ms client | 0.040 DEBUG [Client bed684b29d73d4f4e68d] pn=1 type=Initial pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 403 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX Padding { len: 269 } client | -> RX Crypto { offset: 0, len: 90 } client | 0.040 DEBUG [Client bed684b29d73d4f4e68d] Rx ACK space=in, ranges=[0..=1] client | 0.040 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.040 DEBUG on_packets_acked this=0x55f680f49630, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.040 DEBUG Acked crypto frame space=in offset=1211 length=328 client | 0.040 DEBUG Read Ok(90) bytes client | 0.041 DEBUG Write secret available for Handshake: SymKey [32]: 380efa4c7b3f47a5a9e976375f9e446542c66c25789a4ce0c6a2ae9f34598046 client | 0.041 DEBUG Read secret available for Handshake: SymKey [32]: d51e8ff58ded6cf38ad00d1a29d7dd11b2c9f0ff9d7ddb458b1f609ab59bf5cb client | 0.041 DEBUG [Agent 0x55f680f35f20] state -> InProgress client | 0.041 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.041 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.041 DEBUG [Crypto] Handshake keys installed client | 0.041 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 525821720 } client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] State change from WaitVersion -> Handshaking client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] pn=0 type=Handshake pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 738 client | -> RX Crypto { offset: 0, len: 703 } client | 0.041 DEBUG Read Ok(703) bytes client | 0.041 DEBUG [Agent 0x55f680f35f20] state -> AuthenticationPending client | 0.041 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 525821720 } client | 0.041 DEBUG saving datagram of 139 bytes client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Initial dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] pn=2 type=Initial pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 37 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 146, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.041 DEBUG Building Handshake dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] pn=0 type=Handshake pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 73 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 146, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] Drop packet number space in client | 0.041 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.041 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.041 DEBUG ECN probing: sent 3 probes client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG Building Handshake dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.041 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.041 DEBUG [Client bed684b29d73d4f4e68d] delay duration 94.989172ms client | 0.041 DEBUG Setting timeout of 94.989172ms client | 0.041 DEBUG StateChange(Handshaking) client | 0.041 WARN Cannot create stream ConnectionState client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] Authenticated Ok client | 0.042 DEBUG Write secret available for ApplicationData: SymKey [32]: 4283ef9799c7a4b8b73559bedaa3cc63abd4c9a34ccd2d4ce1f2dae1c54dbad6 client | 0.042 DEBUG Read secret available for ApplicationData: SymKey [32]: 91309467e1f4d4c343a6838d6b5c877cbedac153877e8506eb3906760718222e client | 0.042 DEBUG [Agent 0x55f680f35f20] SSL_AuthCertificateComplete: Ok(()) client | 0.042 DEBUG [Agent 0x55f680f35f20] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] TLS connection complete client | 0.042 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG [Crypto] Application write key installed client | 0.042 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.042 DEBUG [Crypto] application read keys installed client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] State change from Handshaking -> Connected client | 0.042 INFO [Client bed684b29d73d4f4e68d] Connection established client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] process saved for epoch ApplicationData client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] pn=0 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 139 client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [96, 92, 152, 242], stateless_reset_token: [212, 13, 94, 22, 72, 254, 214, 217, 220, 2, 191, 99, 41, 24, 32, 201] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [67, 81, 89, 21], stateless_reset_token: [74, 100, 206, 176, 226, 227, 67, 35, 80, 198, 76, 214, 185, 199, 119, 255] } client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [84, 99, 188, 88], stateless_reset_token: [174, 189, 62, 19, 150, 253, 50, 91, 117, 151, 135, 28, 220, 234, 8, 111] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [93, 21, 160, 17], stateless_reset_token: [89, 141, 32, 173, 198, 234, 138, 171, 106, 201, 171, 68, 249, 113, 210, 160] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [130, 239, 190, 128], stateless_reset_token: [231, 160, 116, 60, 34, 135, 128, 156, 131, 7, 154, 166, 132, 143, 75, 30] } client | 0.042 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 545821720 } client | 0.042 DEBUG stream BiDi creatable client | 0.042 INFO Created stream 0 for https://server4/vpgofcjauo client | 0.042 INFO Saving https://server4/vpgofcjauo to "/downloads/vpgofcjauo" client | 0.042 DEBUG stream UniDi creatable client | 0.042 DEBUG StateChange(Connected) client | 0.042 DEBUG stream 0 writable client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG Building Handshake dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.042 DEBUG CRYPTO for hs offset=0, len=36 client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] pn=1 type=Handshake pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 69 client | TX -> Crypto { offset: 0, len: 36 } client | 0.042 DEBUG packet_sent this=0x55f680f49630, pn=1, ps=69 client | 0.042 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] pn=0 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 111 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.042 DEBUG packet_sent this=0x55f680f49630, pn=0, ps=42 client | 0.042 DEBUG ECN probing: sent 4 probes client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG Building Handshake dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.042 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.042 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.042 DEBUG [Client bed684b29d73d4f4e68d] delay duration 18.137969ms client | 0.042 DEBUG Setting timeout of 18.137969ms client | 0.061 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.061 DEBUG Building Handshake dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.061 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.061 DEBUG [Client bed684b29d73d4f4e68d] pn=1 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 28 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 2620, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.061 DEBUG ECN probing: sent 5 probes client | 0.061 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.061 DEBUG Building Handshake dcid Some(CID [4]: b5b43d13) scid Some(CID [0]: ) client | 0.061 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.061 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.061 DEBUG [Client bed684b29d73d4f4e68d] delay duration 75.854617ms client | 0.061 DEBUG Setting timeout of 75.854617ms client | 0.073 DEBUG [Client bed684b29d73d4f4e68d] pn=1 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 259 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 50, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | -> RX Crypto { offset: 0, len: 138 } client | -> RX HandshakeDone client | -> RX NewToken { token: [207, 217, 61, 144, 182, 143, 174, 87, 111, 36, 12, 254, 53, 100, 67, 92, 138, 59, 178, 108, 166, 80, 239, 70, 235, 144, 218, 51, 105, 166, 68, 55, 20, 180, 183, 32, 10, 65, 106, 246, 186, 179, 105, 111, 226, 223, 77, 228, 227, 87, 36, 119, 87, 17, 250, 42, 123, 82, 11, 109, 140, 168, 154, 221, 83, 66, 181, 216, 111, 227, 37, 110, 253, 167, 247, 9, 107, 41, 236, 109, 125, 42, 125, 105, 22, 56] } client | 0.073 DEBUG [Client bed684b29d73d4f4e68d] Rx ACK space=ap, ranges=[0..=0] client | 0.073 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.073 DEBUG on_packets_acked this=0x55f680f49630, limited=1, bytes_in_flight=69, cwnd=12520, state=SlowStart, new_acked=42 client | 0.073 DEBUG Read Ok(138) bytes client | 0.074 DEBUG [0x55f680f35f20] Got resumption token [818]: 02000633fd97e273..a6b5db9285795bce client | 0.074 DEBUG [Agent 0x55f680f35f20] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: false, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.074 DEBUG setting max_stream_data to 524288 client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] State change from Connected -> Confirmed client | 0.074 DEBUG PMTUD started with probe size 1380 client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] Drop packet number space hs client | 0.074 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] No preferred address to migrate to client | 0.074 DEBUG resumption token [997]: 0000000124405400..a6b5db9285795bce client | 0.074 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 578952411 } client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.074 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] pn=2 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1329 } client | 0.074 DEBUG packet_sent this=0x55f680f49630, pn=2, ps=1352 client | 0.074 DEBUG ECN probing: sent 6 probes client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.597056ms client | 0.074 DEBUG Setting timeout of 19.597056ms client | 0.074 DEBUG stream 0 complete client | 0.074 DEBUG stream BiDi creatable client | 0.074 DEBUG stream UniDi creatable client | 0.074 WARN Unhandled event StateChange(Confirmed) client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.074 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.556471ms client | 0.074 DEBUG Setting timeout of 19.556471ms client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] pn=2 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 0, len: >>1259, fin: false } client | 0.074 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 560079431 } client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.074 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.074 DEBUG [Client bed684b29d73d4f4e68d] pn=3 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | 0.074 DEBUG ECN probing: sent 7 probes client | 0.075 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client bed684b29d73d4f4e68d] delay duration 111.417713ms client | 0.075 DEBUG Setting timeout of 111.417713ms client | 0.075 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.075 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.075 DEBUG [Client bed684b29d73d4f4e68d] delay duration 111.387646ms client | 0.075 DEBUG Setting timeout of 111.387646ms client | 0.076 DEBUG [Client bed684b29d73d4f4e68d] pn=3 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 1259, len: >>1257, fin: false } client | 0.076 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 581172604 } client | 0.076 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.972929ms client | 0.076 DEBUG Setting timeout of 19.972929ms client | 0.076 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.076 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.076 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.947041ms client | 0.076 DEBUG Setting timeout of 19.947041ms client | 0.077 DEBUG [Client bed684b29d73d4f4e68d] pn=4 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 2516, len: >>1257, fin: false } client | 0.077 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 562235221 } client | 0.077 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.077 DEBUG [Client bed684b29d73d4f4e68d] pn=4 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 3, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | 0.077 DEBUG ECN probing: sent 8 probes client | 0.077 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client bed684b29d73d4f4e68d] delay duration 109.241766ms client | 0.077 DEBUG Setting timeout of 109.241766ms client | 0.077 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.077 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.077 DEBUG [Client bed684b29d73d4f4e68d] delay duration 109.213704ms client | 0.077 DEBUG Setting timeout of 109.213704ms client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] pn=5 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 3773, len: >>1257, fin: false } client | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 583275173 } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.977388ms client | 0.078 DEBUG Setting timeout of 19.977388ms client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.96266ms client | 0.078 DEBUG Setting timeout of 19.96266ms client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] pn=6 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 113 client | -> RX Stream { stream_id: 0, offset: 5030, len: >>90, fin: false } client | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 563416469 } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] pn=5 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 7, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } client | 0.078 DEBUG ECN probing: sent 9 probes client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] delay duration 108.033386ms client | 0.078 DEBUG Setting timeout of 108.033386ms client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] pn=7 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 23 client | -> RX Stream { stream_id: 0, offset: 5120, len: >>0, fin: true } client | 0.078 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 583583852 } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.976436ms client | 0.078 DEBUG Setting timeout of 19.976436ms client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.078 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] delay duration 19.932503ms client | 0.078 DEBUG Setting timeout of 19.932503ms client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 291, tv_nsec: 900722811 } } client | 0.078 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 291, tv_nsec: 900722811 } }) client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.078 DEBUG Building Short dcid Some(CID [4]: b5b43d13) client | 0.078 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 291, tv_nsec: 563676085 } client | 0.078 DEBUG [Client bed684b29d73d4f4e68d] pn=6 type=Short pri-path:b5b43d13 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 41 client | TX -> Ack { largest_acknowledged: 7, ack_delay: 11, first_ack_range: 7, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 7, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.078 DEBUG ECN probing: sent 10 probes client | 0.078 DEBUG ECN probing concluded with 10 probes sent client | 0.078 DEBUG Setting timeout of 336.988407ms client | 0.416 DEBUG [Client bed684b29d73d4f4e68d] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 291, tv_nsec: 900722811 } } -> Closed(Application(0)) client | 0.416 INFO Closing timer expired client | 0.416 DEBUG Output::None client | 0.416 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.416 DEBUG Timer fired while closed client | 0.416 DEBUG Output::None client | 0.416 DEBUG [CryptoStates] Creating initial cipher state v=Version1, role=Client dcid=c81908d2811a69f4 client | 0.416 DEBUG Making Write Initial CryptoDxState, v=Version1 cipher=4865 client | 0.416 DEBUG Making Read Initial CryptoDxState, v=Version1 cipher=4865 client | 0.416 DEBUG Outbound interface eth0 for destination 193.167.100.100 has MTU 1500 client | 0.416 DEBUG [unv-path 0.0.0.0:50776->193.167.100.100:443] Make permanent client | 0.416 DEBUG [unv-path:c81908d2811a69f4 0.0.0.0:50776->193.167.100.100:443] set as primary path client | 0.416 DEBUG [pri-unv-path:c81908d2811a69f4 0.0.0.0:50776->193.167.100.100:443] Path validated Instant { tv_sec: 291, tv_nsec: 901458456 } client | 0.416 INFO [Client c81908d2811a69f4] resumption token [997]: 0000000124405400..a6b5db9285795bce client | 0.416 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.416 DEBUG Overwrite initial version Version1 ==> Version1 client | 0.416 DEBUG [Client c81908d2811a69f4] client_start client | 0.417 DEBUG Writing transport parameters, msg=1 client | 0.417 DEBUG [Agent 0x55f680f4bc10] state -> InProgress client | 0.417 DEBUG [Client c81908d2811a69f4] State change from Init -> WaitInitial client | 0.417 DEBUG stream BiDi creatable client | 0.417 WARN Cannot create stream ConnectionState client | 0.417 DEBUG stream UniDi creatable client | 0.417 DEBUG StateChange(WaitInitial) client | 0.417 WARN Cannot create stream ConnectionState client | 0.417 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.417 DEBUG Building Initial dcid Some(CID [8]: c81908d2811a69f4) scid Some(CID [0]: ) client | 0.417 DEBUG CRYPTO for in offset=0, len=1126 client | 0.417 DEBUG [Client c81908d2811a69f4] pn=0 type=Initial pri-path:c81908d2811a69f4 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1252 client | TX -> Crypto { offset: 0, len: 1126 } client | 0.417 DEBUG packet_sent this=0x55f680f49630, pn=0, ps=1252 client | 0.417 DEBUG ECN probing: sent 1 probes client | 0.417 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.417 DEBUG Building Initial dcid Some(CID [8]: c81908d2811a69f4) scid Some(CID [0]: ) client | 0.417 DEBUG CRYPTO for in offset=1126, len=581 client | 0.417 DEBUG [Client c81908d2811a69f4] pn=1 type=Initial pri-path:c81908d2811a69f4 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 708 client | TX -> Crypto { offset: 1126, len: 581 } client | 0.417 DEBUG [Client c81908d2811a69f4] pad Initial from 708 to PLPMTU 1252 client | 0.417 DEBUG packet_sent this=0x55f680f49630, pn=1, ps=1252 client | 0.417 DEBUG ECN probing: sent 2 probes client | 0.417 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.417 DEBUG Building Initial dcid Some(CID [8]: c81908d2811a69f4) scid Some(CID [0]: ) client | 0.417 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.417 DEBUG [Client c81908d2811a69f4] delay duration 107.908962ms client | 0.417 DEBUG Setting timeout of 107.908962ms client | 0.449 DEBUG [Client c81908d2811a69f4] pn=0 type=Initial pri-path:c81908d2811a69f4 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 40 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 0, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | 0.449 DEBUG [Client c81908d2811a69f4] Rx ACK space=in, ranges=[0..=0] client | 0.449 DEBUG [LossRecovery] ACK for Initial - largest_acked=0 client | 0.449 DEBUG on_packets_acked this=0x55f680f49630, limited=1, bytes_in_flight=1252, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.449 DEBUG Acked crypto frame space=in offset=0 length=1126 client | 0.449 DEBUG [Client c81908d2811a69f4] Changing to use Server CID=8c0f224b client | 0.449 DEBUG [Client c81908d2811a69f4] State change from WaitInitial -> WaitVersion client | 0.449 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG Building Initial dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.449 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG [Client c81908d2811a69f4] delay duration 64.291033ms client | 0.449 DEBUG Setting timeout of 64.291033ms client | 0.449 WARN Unhandled event StateChange(WaitVersion) client | 0.449 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG Building Initial dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.449 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.449 DEBUG [Client c81908d2811a69f4] delay duration 64.264254ms client | 0.449 DEBUG Setting timeout of 64.264254ms client | 0.451 DEBUG [Client c81908d2811a69f4] pn=1 type=Initial pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 953 client | -> RX Ack { largest_acknowledged: 1, ack_delay: 0, first_ack_range: 1, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | -> RX Padding { len: 813 } client | -> RX Crypto { offset: 0, len: 96 } client | 0.451 DEBUG [Client c81908d2811a69f4] Rx ACK space=in, ranges=[0..=1] client | 0.451 DEBUG [LossRecovery] ACK for Initial - largest_acked=1 client | 0.451 DEBUG on_packets_acked this=0x55f680f49630, limited=1, bytes_in_flight=0, cwnd=12520, state=SlowStart, new_acked=1252 client | 0.451 DEBUG Acked crypto frame space=in offset=1126 length=581 client | 0.451 DEBUG Read Ok(96) bytes client | 0.451 DEBUG Write secret available for Handshake: SymKey [32]: d04f2af5560241364095631eee6cb90b5c364b1ca75a972f5639050ec3930884 client | 0.451 DEBUG Read secret available for Handshake: SymKey [32]: 59861cbfc7c1ea03ff87782234c251c59e5e69d716c8fc9a6c1ef3de5a94b71d client | 0.451 DEBUG [Agent 0x55f680f4bc10] state -> InProgress client | 0.451 DEBUG Making Write Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.451 DEBUG Making Read Handshake CryptoDxState, v=Version1 cipher=4865 client | 0.451 DEBUG [Crypto] Handshake keys installed client | 0.451 DEBUG [Recvd-in] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 936460684 } client | 0.451 DEBUG [Client c81908d2811a69f4] State change from WaitVersion -> Handshaking client | 0.451 DEBUG [Client c81908d2811a69f4] pn=0 type=Handshake pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 188 client | -> RX Crypto { offset: 0, len: 153 } client | 0.451 DEBUG Read Ok(153) bytes client | 0.451 DEBUG Write secret available for ApplicationData: SymKey [32]: 363fdc802057a7966ce56a7829b51100afcfe3cf90101fe758c2713783ce2bbf client | 0.451 DEBUG Read secret available for ApplicationData: SymKey [32]: bbc5920a8fdb2f80485f5e1b2d8ed88caf0032ec60d4a59091878273dbcbf292 client | 0.451 DEBUG [Agent 0x55f680f4bc10] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.451 DEBUG [Client c81908d2811a69f4] TLS connection complete client | 0.451 DEBUG Making Write ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.452 DEBUG [Crypto] Application write key installed client | 0.452 DEBUG Making Read ApplicationData CryptoDxState, v=Version1 cipher=4865 client | 0.452 DEBUG [Crypto] application read keys installed client | 0.452 DEBUG [Client c81908d2811a69f4] State change from Handshaking -> Connected client | 0.452 INFO [Client c81908d2811a69f4] Connection established client | 0.452 DEBUG [Recvd-hs] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 936460684 } client | 0.452 DEBUG [Client c81908d2811a69f4] pn=0 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 139 client | -> RX NewConnectionId { sequence_number: 2, retire_prior: 0, connection_id: [15, 129, 230, 125], stateless_reset_token: [239, 126, 205, 106, 194, 171, 48, 164, 18, 73, 52, 196, 188, 218, 107, 65] } client | -> RX NewConnectionId { sequence_number: 4, retire_prior: 0, connection_id: [228, 97, 86, 2], stateless_reset_token: [55, 13, 118, 13, 115, 235, 230, 26, 140, 39, 127, 8, 182, 99, 6, 111] } client | -> RX NewConnectionId { sequence_number: 3, retire_prior: 0, connection_id: [65, 6, 94, 59], stateless_reset_token: [229, 249, 198, 194, 146, 23, 22, 211, 93, 244, 49, 230, 225, 109, 196, 117] } client | -> RX NewConnectionId { sequence_number: 1, retire_prior: 0, connection_id: [106, 136, 235, 238], stateless_reset_token: [52, 5, 85, 51, 250, 149, 174, 224, 253, 159, 214, 163, 106, 119, 139, 144] } client | -> RX NewConnectionId { sequence_number: 5, retire_prior: 0, connection_id: [233, 14, 219, 174], stateless_reset_token: [237, 239, 255, 49, 162, 167, 5, 69, 86, 72, 205, 172, 135, 36, 235, 217] } client | 0.452 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 956460684 } client | 0.452 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.452 DEBUG Building Initial dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.452 DEBUG [Client c81908d2811a69f4] pn=2 type=Initial pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 124 client | TX -> Ack { largest_acknowledged: 1, ack_delay: 104, first_ack_range: 1, ack_ranges: [], ecn_count: None } client | 0.452 DEBUG Building Handshake dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.452 DEBUG CRYPTO for hs offset=0, len=36 client | 0.452 DEBUG [Client c81908d2811a69f4] pn=0 type=Handshake pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 199 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 104, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | TX -> Crypto { offset: 0, len: 36 } client | 0.452 DEBUG packet_sent this=0x55f680f49630, pn=0, ps=75 client | 0.452 DEBUG [Client c81908d2811a69f4] Drop packet number space in client | 0.452 DEBUG [LossRecovery] Reset loss recovery state for Initial client | 0.452 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.452 WARN [LossRecovery] ignoring in-2 from dropped space client | 0.452 DEBUG ECN probing: sent 3 probes client | 0.452 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.452 DEBUG Building Handshake dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.452 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.452 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.452 DEBUG [Client c81908d2811a69f4] delay duration 19.043752ms client | 0.452 DEBUG Setting timeout of 19.043752ms client | 0.452 DEBUG StateChange(Handshaking) client | 0.452 INFO Created stream 0 for https://server4/cpakzbette client | 0.452 INFO Saving https://server4/cpakzbette to "/downloads/cpakzbette" client | 0.452 DEBUG stream BiDi creatable client | 0.452 DEBUG stream UniDi creatable client | 0.452 DEBUG StateChange(Connected) client | 0.452 DEBUG stream 0 writable client | 0.452 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.452 DEBUG Building Handshake dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.452 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.452 DEBUG [Client c81908d2811a69f4] pn=0 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 42 client | TX -> Stream { stream_id: 0, offset: 0, len: 17, fin: true } client | 0.452 DEBUG packet_sent this=0x55f680f49630, pn=0, ps=42 client | 0.452 DEBUG ECN probing: sent 4 probes client | 0.452 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.452 DEBUG Building Handshake dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.452 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.452 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.452 DEBUG [Client c81908d2811a69f4] delay duration 18.837797ms client | 0.452 DEBUG Setting timeout of 18.837797ms client | 0.472 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.472 DEBUG Building Handshake dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.472 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.472 DEBUG [Client c81908d2811a69f4] pn=1 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 28 client | TX -> Ack { largest_acknowledged: 0, ack_delay: 2656, first_ack_range: 0, ack_ranges: [], ecn_count: None } client | 0.472 DEBUG ECN probing: sent 5 probes client | 0.472 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.472 DEBUG Building Handshake dcid Some(CID [4]: 8c0f224b) scid Some(CID [0]: ) client | 0.472 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.472 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.472 DEBUG [Client c81908d2811a69f4] delay duration 61.826247ms client | 0.472 DEBUG Setting timeout of 61.826247ms client | 0.483 DEBUG [Client c81908d2811a69f4] pn=1 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 259 client | -> RX Ack { largest_acknowledged: 0, ack_delay: 26, first_ack_range: 0, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 1, Ce: 0})) } client | -> RX NewToken { token: [102, 111, 106, 217, 214, 246, 125, 252, 39, 218, 112, 113, 195, 97, 119, 235, 253, 193, 127, 26, 197, 95, 68, 86, 31, 220, 4, 218, 212, 0, 135, 174, 17, 145, 123, 169, 142, 80, 247, 72, 119, 187, 149, 133, 81, 66, 23, 50, 47, 160, 28, 239, 108, 24, 203, 94, 90, 81, 114, 214, 59, 204, 240, 249, 85, 189, 148, 99, 41, 131, 143, 55, 183, 50, 158, 66, 73, 177, 19, 82, 12, 241, 23, 67, 23, 24] } client | -> RX Crypto { offset: 0, len: 138 } client | -> RX HandshakeDone client | 0.483 DEBUG [Client c81908d2811a69f4] Rx ACK space=ap, ranges=[0..=0] client | 0.483 DEBUG [LossRecovery] ACK for ApplicationData - largest_acked=0 client | 0.483 DEBUG on_packets_acked this=0x55f680f49630, limited=1, bytes_in_flight=75, cwnd=12520, state=SlowStart, new_acked=42 client | 0.483 DEBUG Read Ok(138) bytes client | 0.483 DEBUG [0x55f680f4bc10] Got resumption token [818]: 02000633fd97e8b5..cd15220dadbf1c38 client | 0.483 DEBUG [Agent 0x55f680f4bc10] state -> Complete(SecretAgentInfo { version: 772, cipher: 4865, group: 29, resumed: true, early_data: false, ech_accepted: false, alpn: Some("hq-interop"), signature_scheme: 1027 }) client | 0.483 DEBUG setting max_stream_data to 524288 client | 0.483 DEBUG resumption token [995]: 0000000120405200..cd15220dadbf1c38 client | 0.483 DEBUG [Client c81908d2811a69f4] State change from Connected -> Confirmed client | 0.483 DEBUG PMTUD started with probe size 1380 client | 0.483 DEBUG [Client c81908d2811a69f4] Drop packet number space hs client | 0.483 DEBUG [LossRecovery] Reset loss recovery state for Handshake client | 0.483 DEBUG [Client c81908d2811a69f4] No preferred address to migrate to client | 0.483 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 988910552 } client | 0.483 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.483 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.483 DEBUG Sending PMTUD probe of size 1380, count 1 client | 0.483 DEBUG [Client c81908d2811a69f4] pn=2 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1352 client | TX -> Ping client | TX -> Padding { len: 1329 } client | 0.484 DEBUG packet_sent this=0x55f680f49630, pn=2, ps=1352 client | 0.484 DEBUG ECN probing: sent 6 probes client | 0.484 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.484 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG [Client c81908d2811a69f4] delay duration 19.704627ms client | 0.484 DEBUG Setting timeout of 19.704627ms client | 0.484 DEBUG stream 0 complete client | 0.484 DEBUG stream BiDi creatable client | 0.484 DEBUG stream UniDi creatable client | 0.484 WARN Unhandled event StateChange(Confirmed) client | 0.484 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.484 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG [Client c81908d2811a69f4] delay duration 19.671836ms client | 0.484 DEBUG Setting timeout of 19.671836ms client | 0.484 DEBUG [Client c81908d2811a69f4] pn=2 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 0, len: >>1259, fin: false } client | 0.484 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 969934795 } client | 0.484 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.484 DEBUG [Client c81908d2811a69f4] pn=3 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 2, ack_delay: 3, first_ack_range: 2, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 2, Ce: 0})) } client | 0.484 DEBUG ECN probing: sent 7 probes client | 0.484 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.484 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG [Client c81908d2811a69f4] delay duration 95.767838ms client | 0.484 DEBUG Setting timeout of 95.767838ms client | 0.484 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.484 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.484 DEBUG [Client c81908d2811a69f4] delay duration 95.742491ms client | 0.484 DEBUG Setting timeout of 95.742491ms client | 0.485 DEBUG [Client c81908d2811a69f4] pn=3 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 1259, len: >>1257, fin: false } client | 0.485 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 990979989 } client | 0.485 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.485 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.485 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.485 DEBUG [Client c81908d2811a69f4] delay duration 19.961588ms client | 0.485 DEBUG Setting timeout of 19.961588ms client | 0.485 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.485 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.485 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.485 DEBUG [Client c81908d2811a69f4] delay duration 19.938515ms client | 0.485 DEBUG Setting timeout of 19.938515ms client | 0.486 DEBUG [Client c81908d2811a69f4] pn=4 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 2516, len: >>1257, fin: false } client | 0.486 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 972039239 } client | 0.486 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.486 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.486 DEBUG [Client c81908d2811a69f4] pn=4 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 4, ack_delay: 2, first_ack_range: 4, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 4, Ce: 0})) } client | 0.486 DEBUG ECN probing: sent 8 probes client | 0.486 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.486 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.486 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.486 DEBUG [Client c81908d2811a69f4] delay duration 93.685475ms client | 0.486 DEBUG Setting timeout of 93.685475ms client | 0.486 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.486 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.486 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.486 DEBUG [Client c81908d2811a69f4] delay duration 93.658485ms client | 0.486 DEBUG Setting timeout of 93.658485ms client | 0.487 DEBUG [Client c81908d2811a69f4] pn=5 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 3773, len: >>1257, fin: false } client | 0.487 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 993082472 } client | 0.487 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.487 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.487 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.487 DEBUG [Client c81908d2811a69f4] delay duration 19.976306ms client | 0.487 DEBUG Setting timeout of 19.976306ms client | 0.487 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.487 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.487 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.487 DEBUG [Client c81908d2811a69f4] delay duration 19.961618ms client | 0.487 DEBUG Setting timeout of 19.961618ms client | 0.488 DEBUG [Client c81908d2811a69f4] pn=6 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 5030, len: >>1257, fin: false } client | 0.488 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 974131053 } client | 0.489 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.489 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.489 DEBUG [Client c81908d2811a69f4] pn=5 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 6, ack_delay: 2, first_ack_range: 6, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 6, Ce: 0})) } client | 0.489 DEBUG ECN probing: sent 9 probes client | 0.489 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.489 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.489 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.489 DEBUG [Client c81908d2811a69f4] delay duration 91.595806ms client | 0.489 DEBUG Setting timeout of 91.595806ms client | 0.489 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.489 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.489 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.489 DEBUG [Client c81908d2811a69f4] delay duration 91.570458ms client | 0.489 DEBUG Setting timeout of 91.570458ms client | 0.490 DEBUG [Client c81908d2811a69f4] pn=7 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 6287, len: >>1257, fin: false } client | 0.490 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 995176878 } client | 0.490 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.490 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.490 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.490 DEBUG [Client c81908d2811a69f4] delay duration 19.977207ms client | 0.490 DEBUG Setting timeout of 19.977207ms client | 0.490 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.490 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.490 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.490 DEBUG [Client c81908d2811a69f4] delay duration 19.958763ms client | 0.490 DEBUG Setting timeout of 19.958763ms client | 0.491 DEBUG [Client c81908d2811a69f4] pn=8 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 7544, len: >>1257, fin: false } client | 0.491 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 976226310 } client | 0.491 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.491 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.491 DEBUG [Client c81908d2811a69f4] pn=6 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 30 client | TX -> Ack { largest_acknowledged: 8, ack_delay: 6, first_ack_range: 8, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 8, Ce: 0})) } client | 0.491 DEBUG ECN probing: sent 10 probes client | 0.491 DEBUG ECN probing concluded with 10 probes sent client | 0.491 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.491 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.491 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.491 DEBUG [Client c81908d2811a69f4] delay duration 89.456366ms client | 0.491 DEBUG Setting timeout of 89.456366ms client | 0.491 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.491 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.491 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.491 DEBUG [Client c81908d2811a69f4] delay duration 89.429235ms client | 0.491 DEBUG Setting timeout of 89.429235ms client | 0.492 DEBUG [Client c81908d2811a69f4] pn=9 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 1280 client | -> RX Stream { stream_id: 0, offset: 8801, len: >>1257, fin: false } client | 0.492 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 997276323 } client | 0.492 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.492 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG [Client c81908d2811a69f4] delay duration 19.975154ms client | 0.492 DEBUG Setting timeout of 19.975154ms client | 0.492 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.492 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG [Client c81908d2811a69f4] delay duration 19.954595ms client | 0.492 DEBUG Setting timeout of 19.954595ms client | 0.492 DEBUG [Client c81908d2811a69f4] pn=10 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, Ect0) len 205 client | -> RX Stream { stream_id: 0, offset: 10058, len: >>182, fin: true } client | 0.492 DEBUG [Recvd-ap] Set ACK timer to Instant { tv_sec: 291, tv_nsec: 977493900 } client | 0.492 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.492 DEBUG [Client c81908d2811a69f4] pn=7 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 30 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 4, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } client | 0.492 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.492 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG [Client c81908d2811a69f4] delay duration 88.211238ms client | 0.492 DEBUG Setting timeout of 88.211238ms client | 0.492 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.492 DEBUG TX blocked, profile=SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG [Client c81908d2811a69f4] delay duration 88.125868ms client | 0.492 DEBUG Setting timeout of 88.125868ms client | 0.492 DEBUG [Client c81908d2811a69f4] State change from Confirmed -> Closing { error: Application(0), timeout: Instant { tv_sec: 292, tv_nsec: 267702707 } } client | 0.492 WARN Unhandled event StateChange(Closing { error: Application(0), timeout: Instant { tv_sec: 292, tv_nsec: 267702707 } }) client | 0.492 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.492 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.492 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 291, tv_nsec: 977700286 } client | 0.492 DEBUG [Client c81908d2811a69f4] pn=8 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 41 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 25, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.492 DEBUG Setting timeout of 289.890312ms client | 0.523 DEBUG [Client c81908d2811a69f4] output_path send_profile SendProfile { limit: 1252, pto: None, probe: EnumSet(), paced: false } client | 0.523 DEBUG Building Short dcid Some(CID [4]: 8c0f224b) client | 0.523 DEBUG [Recvd-ap] immediate_ack at Instant { tv_sec: 292, tv_nsec: 8187253 } client | 0.523 DEBUG [Client c81908d2811a69f4] pn=9 type=Short pri-path:8c0f224b 0.0.0.0:50776->193.167.100.100:443 IpTos(Cs0, NotEct) len 42 client | TX -> Ack { largest_acknowledged: 10, ack_delay: 3836, first_ack_range: 10, ack_ranges: [], ecn_count: Some(Count({NotEct: 0, Ect1: 0, Ect0: 10, Ce: 0})) } client | TX -> ConnectionClose { error_code: Application(0), frame_type: 0, reason_phrase: "kthxbye!" } client | 0.523 DEBUG Setting timeout of 259.404807ms client | 0.523 DEBUG Setting timeout of 259.389969ms client | 0.783 DEBUG [Client c81908d2811a69f4] State change from Closing { error: Application(0), timeout: Instant { tv_sec: 292, tv_nsec: 267702707 } } -> Closed(Application(0)) client | 0.783 INFO Closing timer expired client | 0.783 DEBUG Output::None client | 0.783 WARN Unhandled event StateChange(Closed(Application(0))) client | 0.783 DEBUG Timer fired while closed client | 0.783 DEBUG Output::None client exited with code 0 Aborting on container exit... Container client Stopping Container server Stopping Container client Stopped Container server Stopped Container sim Stopping Container sim Stopped 2025-04-30 11:55:39,356 Using the client's key log file. 2025-04-30 11:55:39,366 2025-04-30 11:55:39,367 Using the client's key log file. 2025-04-30 11:55:39,367 Using the client's key log file. 2025-04-30 11:55:39,376 2025-04-30 11:55:39,377 Using the client's key log file. 2025-04-30 11:55:39,377 Using the client's key log file. 2025-04-30 11:55:40,262 Check of downloaded files succeeded.