[2025-09-12T05:03:14.606209830Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T05:03:14.606484791Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:49984 with scid cff6ef48c2116283bd23f91ad82e64241d4634c4 [2025-09-12T05:03:14.606524285Z TRACE quiche::tls] cff6ef48c2116283bd23f91ad82e64241d4634c4 write message lvl=Initial len=266 [2025-09-12T05:03:14.606540525Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Initial version=1 dcid=20d153120bd3bfda9c67fde3f72f19a1 scid=cff6ef48c2116283bd23f91ad82e64241d4634c4 len=270 pn=0 [2025-09-12T05:03:14.606543471Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm CRYPTO off=0 len=266 [2025-09-12T05:03:14.606556405Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=998.934669ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 514, tv_nsec: 604559575 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 604559575 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 514, tv_nsec: 604559575 }, next_time: Instant { tv_sec: 514, tv_nsec: 604559575 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.606609343Z TRACE quiche_apps::client] written 1200 [2025-09-12T05:03:14.643203971Z TRACE quiche_apps::client] got 111 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.643227234Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Retry version=1 dcid=cff6ef48c2116283bd23f91ad82e64241d4634c4 scid=9653a477ab6f01b8 token=56d68044567f265fec19d79c5726a40c0bf91e7e7605a790367be1e0e4a820a926ac92f961eac0332a2cd689736bc958c33c52ea2f721b4833cbc4f5 [2025-09-12T05:03:14.643250658Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 dropped epoch 0 state [2025-09-12T05:03:14.643258924Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 111 bytes [2025-09-12T05:03:14.643263001Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.643265546Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.643301162Z TRACE quiche::tls] cff6ef48c2116283bd23f91ad82e64241d4634c4 write message lvl=Initial len=266 [2025-09-12T05:03:14.643314958Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Initial version=1 dcid=9653a477ab6f01b8 scid=cff6ef48c2116283bd23f91ad82e64241d4634c4 token=56d68044567f265fec19d79c5726a40c0bf91e7e7605a790367be1e0e4a820a926ac92f961eac0332a2cd689736bc958c33c52ea2f721b4833cbc4f5 len=270 pn=1 [2025-09-12T05:03:14.643318094Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm CRYPTO off=0 len=266 [2025-09-12T05:03:14.643328723Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=998.943465ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=385 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 514, tv_nsec: 641340459 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 641340459 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 514, tv_nsec: 641340459 }, next_time: Instant { tv_sec: 514, tv_nsec: 641340459 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.643380700Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.643386140Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.676134190Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.676151312Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Initial version=1 dcid=cff6ef48c2116283bd23f91ad82e64241d4634c4 scid=e1692333eed053bd token= len=116 pn=0 [2025-09-12T05:03:14.676163434Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm ACK delay=40 blocks=[1..1] ecn_counts=None [2025-09-12T05:03:14.676169145Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 packet newly acked 1 [2025-09-12T05:03:14.676174745Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm CRYPTO off=0 len=90 [2025-09-12T05:03:14.676277977Z TRACE quiche::tls] cff6ef48c2116283bd23f91ad82e64241d4634c4 set write secret lvl=Handshake [2025-09-12T05:03:14.676288286Z TRACE quiche::tls] cff6ef48c2116283bd23f91ad82e64241d4634c4 set read secret lvl=Handshake [2025-09-12T05:03:14.676321158Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Handshake version=1 dcid=cff6ef48c2116283bd23f91ad82e64241d4634c4 scid=e1692333eed053bd len=1009 pn=0 [2025-09-12T05:03:14.676328361Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm CRYPTO off=0 len=743 [2025-09-12T05:03:14.676561044Z TRACE quiche::tls] cff6ef48c2116283bd23f91ad82e64241d4634c4 write message lvl=Handshake len=36 [2025-09-12T05:03:14.676566324Z TRACE quiche::tls] cff6ef48c2116283bd23f91ad82e64241d4634c4 set write secret lvl=OneRTT [2025-09-12T05:03:14.676574610Z TRACE quiche::tls] cff6ef48c2116283bd23f91ad82e64241d4634c4 set read secret lvl=OneRTT [2025-09-12T05:03:14.676591822Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(20d153120bd3bfda9c67fde3f72f19a1), max_idle_timeout: 30000, stateless_reset_token: Some(132671881631908677759895293687426098997), max_udp_payload_size: 1472, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1250000, initial_max_stream_data_bidi_remote: 1250000, initial_max_stream_data_uni: 1250000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 5, initial_source_connection_id: Some(e1692333eed053bd), retry_source_connection_id: Some(9653a477ab6f01b8), max_datagram_frame_size: Some(65535), unknown_params: None } [2025-09-12T05:03:14.676603543Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm PADDING len=245 [2025-09-12T05:03:14.676616598Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1200 bytes [2025-09-12T05:03:14.676622068Z TRACE quiche_apps::client] got 234 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.676625665Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=cff6ef48c2116283bd23f91ad82e64241d4634c4 key_phase=false len=213 pn=0 [2025-09-12T05:03:14.676631255Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[0d, 49, 99, 15, fb, 62, ba, 2f] reset_token=[91, 73, 37, c9, 08, f6, 29, 70, 20, 4f, cd, 12, e6, d0, 1e, 7c] [2025-09-12T05:03:14.676637216Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[a2, 48, 1a, 52, ad, 44, 56, d5] reset_token=[39, 4a, eb, 79, 8a, 99, 5c, 28, 27, 77, a3, ed, bf, 4a, 42, 3d] [2025-09-12T05:03:14.676646814Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[85, 4d, d1, e3, fd, bc, f6, 30] reset_token=[53, bf, ca, 5e, 87, a5, c3, 9e, 95, 00, 64, 92, 83, d1, bd, 10] [2025-09-12T05:03:14.676651422Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[c1, b3, af, 58, 68, 49, 5f, 7e] reset_token=[dd, d8, 25, 34, 38, 17, e5, db, 8d, e1, 22, b3, 23, 22, ea, ae] [2025-09-12T05:03:14.676656201Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[4c, 88, 66, 27, 32, f8, aa, dd] reset_token=[6a, df, 01, f9, 43, 94, 47, df, 9b, c4, 4f, 3c, 9e, fc, 25, a4] [2025-09-12T05:03:14.676660680Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[c0, a1, 48, 84, 0b, 13, 2c, 40] reset_token=[9a, 5a, 5c, fb, 7b, 95, 5f, 10, 4b, 55, 6f, f8, 6f, c4, 01, a3] [2025-09-12T05:03:14.676665058Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[80, 73, 3a, 36, 8e, ad, b8, 19] reset_token=[c9, fd, bf, da, bf, bb, 09, 4d, b4, f8, 69, 44, 57, 13, 3a, 94] [2025-09-12T05:03:14.676672982Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 234 bytes [2025-09-12T05:03:14.676676459Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.676678954Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.676686828Z DEBUG quiche_apps::common] sending HTTP request "GET /ygnocfimpi\r\n" [2025-09-12T05:03:14.676750887Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Initial version=1 dcid=e1692333eed053bd scid=cff6ef48c2116283bd23f91ad82e64241d4634c4 token=56d68044567f265fec19d79c5726a40c0bf91e7e7605a790367be1e0e4a820a926ac92f961eac0332a2cd689736bc958c33c52ea2f721b4833cbc4f5 len=6 pn=2 [2025-09-12T05:03:14.676754755Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=75 blocks=[0..0] ecn_counts=None [2025-09-12T05:03:14.676763551Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=98.012099ms latest_rtt=32.875848ms srtt=32.875848ms min_rtt=32.875848ms rttvar=16.437924ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 385, delivered_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { bandwidth: 93.68 Kbps, is_app_limited: true, interval: 32.875848ms, delivered: 385, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 641340459 }), send_elapsed: 0ns, ack_elapsed: 32.875848ms, rtt: 32.875848ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 513294, last_update: Instant { tv_sec: 514, tv_nsec: 674657838 }, next_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.676782406Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Handshake version=1 dcid=e1692333eed053bd scid=cff6ef48c2116283bd23f91ad82e64241d4634c4 len=45 pn=3 [2025-09-12T05:03:14.676785422Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=57 blocks=[0..0] ecn_counts=None [2025-09-12T05:03:14.676787987Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm CRYPTO off=0 len=36 [2025-09-12T05:03:14.676798236Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=98.571199ms latest_rtt=32.875848ms srtt=32.875848ms min_rtt=32.875848ms rttvar=16.437924ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=None Rate { delivered: 385, delivered_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { bandwidth: 93.68 Kbps, is_app_limited: true, interval: 32.875848ms, delivered: 385, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 641340459 }), send_elapsed: 0ns, ack_elapsed: 32.875848ms, rtt: 32.875848ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 513294, last_update: Instant { tv_sec: 514, tv_nsec: 674809972 }, next_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, max_datagram_size: 1350, last_packet_size: None, iv: 192.872µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.676808795Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 dropped epoch 0 state [2025-09-12T05:03:14.676821569Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=1104 pn=4 [2025-09-12T05:03:14.676824364Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=23 blocks=[0..0] ecn_counts=None [2025-09-12T05:03:14.676826919Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[89, 81, 92, ab, e2, f0, 95, 1a, c7, 80, 0a, 44, 77, be, 77, 50, 97, c6, fb, 55] reset_token=[11, a4, 37, ef, 35, 61, 81, 10, b8, cd, 16, 83, c8, d1, 55, 15] [2025-09-12T05:03:14.676832700Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[80, 1f, c8, 6c, 2c, 90, a4, b0, 81, df, 4c, 93, d0, 9a, 10, 91, 4b, a4, 3b, 0d] reset_token=[2a, 82, 98, 2c, bc, b0, df, de, 1b, a8, 10, b0, c1, 9d, b1, c7] [2025-09-12T05:03:14.676837809Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[3c, 06, 4a, 4c, 5d, 69, 1d, 56, af, 10, 1d, 11, 3c, b8, 40, 5a, 69, 26, a8, e5] reset_token=[9b, 29, b9, 47, 4a, f8, de, 7b, 1c, ea, be, 98, a7, d9, be, ee] [2025-09-12T05:03:14.676842809Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[97, 30, 6a, c2, 77, ce, 00, b9, 86, 73, d2, 76, fa, 77, 0f, ad, 6c, 73, 22, 68] reset_token=[df, 8f, e0, e0, ca, 10, 62, af, 48, 60, dd, c2, 2a, c6, 48, c2] [2025-09-12T05:03:14.676847848Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm STREAM id=0 off=0 len=17 fin=true [2025-09-12T05:03:14.676850443Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm PADDING len=917 [2025-09-12T05:03:14.676858097Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=98.511348ms latest_rtt=32.875848ms srtt=32.875848ms min_rtt=32.875848ms rttvar=16.437924ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1229 app_limited=true congestion_recovery_start_time=None Rate { delivered: 385, delivered_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 674657869 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { bandwidth: 93.68 Kbps, is_app_limited: true, interval: 32.875848ms, delivered: 385, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 641340459 }), send_elapsed: 0ns, ack_elapsed: 32.875848ms, rtt: 32.875848ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1130, rate: 513294, last_update: Instant { tv_sec: 514, tv_nsec: 674809972 }, next_time: Instant { tv_sec: 514, tv_nsec: 675002844 }, max_datagram_size: 1350, last_packet_size: Some(1130), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.676896478Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.676901698Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.708844649Z TRACE quiche_apps::client] got 406 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.708857302Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=385 pn=1 [2025-09-12T05:03:14.708863805Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 path ID 0 now see SCID with seq num 1 [2025-09-12T05:03:14.708867421Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm HANDSHAKE_DONE [2025-09-12T05:03:14.708871419Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 dropped epoch 1 state [2025-09-12T05:03:14.708874394Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm ACK delay=16 blocks=[4..4] ecn_counts=None [2025-09-12T05:03:14.708877991Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 packet newly acked 4 [2025-09-12T05:03:14.708882540Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm CRYPTO off=0 len=356 [2025-09-12T05:03:14.708908027Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-09-12T05:03:14.708919879Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 406 bytes [2025-09-12T05:03:14.708923786Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.708926281Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.708929006Z INFO quiche_apps::client] Retiring source CID cff6ef48c2116283bd23f91ad82e64241d4634c4 [2025-09-12T05:03:14.708967768Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=45 pn=5 [2025-09-12T05:03:14.708971746Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=13 blocks=[1..1] ecn_counts=None [2025-09-12T05:03:14.708974811Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=1 conn_id=[3e, d2, 6b, fd, 7f, f2, 6e, 8d, 7b, 1e, 78, 96, c3, 7b, df, 1b, 4d, 90, fa, f2] reset_token=[b2, a8, 5c, 41, 76, 76, 39, 1f, 28, e2, 8d, 88, af, ad, a2, 8c] [2025-09-12T05:03:14.709006099Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=107.98043ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 71, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 707029457 }, next_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.709047577Z TRACE quiche_apps::client] written 71 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.709052486Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.709930249Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.709957380Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=1329 pn=2 [2025-09-12T05:03:14.709965014Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=0 len=1310 fin=false [2025-09-12T05:03:14.709972979Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1350 bytes [2025-09-12T05:03:14.709976656Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.709979000Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.709983498Z TRACE quiche_apps::common] received 1310 bytes [2025-09-12T05:03:14.709986203Z TRACE quiche_apps::common] stream 0 has 1310 bytes (fin? false) [2025-09-12T05:03:14.709994088Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=6 [2025-09-12T05:03:14.709996743Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..2] ecn_counts=None [2025-09-12T05:03:14.710003375Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=106.983244ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, max_datagram_size: 1350, last_packet_size: None, iv: 137.82µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.710035145Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.710039422Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.711026880Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.711036939Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=1329 pn=3 [2025-09-12T05:03:14.711043842Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=1310 len=1308 fin=false [2025-09-12T05:03:14.711051246Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1350 bytes [2025-09-12T05:03:14.711054702Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.711057027Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.711061014Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T05:03:14.711063328Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T05:03:14.711070832Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=7 [2025-09-12T05:03:14.711073477Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..3] ecn_counts=None [2025-09-12T05:03:14.711084999Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=105.901631ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.711116347Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.711120695Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.712129262Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.712139100Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=1329 pn=4 [2025-09-12T05:03:14.712145883Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=2618 len=1308 fin=false [2025-09-12T05:03:14.712153327Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1350 bytes [2025-09-12T05:03:14.712156733Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.712159057Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.712163045Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T05:03:14.712165259Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T05:03:14.712172583Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=8 [2025-09-12T05:03:14.712175087Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..4] ecn_counts=None [2025-09-12T05:03:14.712181188Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=104.805491ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.712216554Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.712220732Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.713232676Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.713242604Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=1329 pn=5 [2025-09-12T05:03:14.713249307Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=3926 len=1308 fin=false [2025-09-12T05:03:14.713256630Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1350 bytes [2025-09-12T05:03:14.713259996Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.713262291Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.713266288Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T05:03:14.713268582Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T05:03:14.713275766Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=9 [2025-09-12T05:03:14.713278270Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..5] ecn_counts=None [2025-09-12T05:03:14.713284863Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=103.701828ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.713314568Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.713318395Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.714338434Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.714348021Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=1329 pn=6 [2025-09-12T05:03:14.714354403Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=5234 len=1308 fin=false [2025-09-12T05:03:14.714361597Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1350 bytes [2025-09-12T05:03:14.714364963Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.714367227Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.714371255Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T05:03:14.714373479Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T05:03:14.714380672Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=10 [2025-09-12T05:03:14.714383207Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..6] ecn_counts=None [2025-09-12T05:03:14.714394548Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=102.592092ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 10, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.714425255Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.714429283Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.715441607Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.715451515Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=1329 pn=7 [2025-09-12T05:03:14.715458147Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=6542 len=1308 fin=false [2025-09-12T05:03:14.715465351Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1350 bytes [2025-09-12T05:03:14.715468757Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.715471042Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.715474979Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T05:03:14.715477213Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T05:03:14.715484567Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=11 [2025-09-12T05:03:14.715487091Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..7] ecn_counts=None [2025-09-12T05:03:14.715493353Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=101.493327ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 11, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.715523128Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.715534249Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.715773274Z TRACE quiche_apps::client] got 386 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.715780778Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=365 pn=8 [2025-09-12T05:03:14.715786839Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=7850 len=342 fin=false [2025-09-12T05:03:14.715794113Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 386 bytes [2025-09-12T05:03:14.715797489Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.715799773Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.715803670Z TRACE quiche_apps::common] received 342 bytes [2025-09-12T05:03:14.715805875Z TRACE quiche_apps::common] stream 0 has 342 bytes (fin? false) [2025-09-12T05:03:14.715813198Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=12 [2025-09-12T05:03:14.715815803Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..8] ecn_counts=None [2025-09-12T05:03:14.715821864Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=101.164846ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 12, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.715850999Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.715854716Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.716875505Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.716882859Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=1329 pn=9 [2025-09-12T05:03:14.716889381Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=8192 len=1308 fin=false [2025-09-12T05:03:14.716896404Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 1350 bytes [2025-09-12T05:03:14.716899770Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.716902065Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.716906082Z TRACE quiche_apps::common] received 1308 bytes [2025-09-12T05:03:14.716908306Z TRACE quiche_apps::common] stream 0 has 1308 bytes (fin? false) [2025-09-12T05:03:14.716930327Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=13 [2025-09-12T05:03:14.716953661Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=5 blocks=[1..9] ecn_counts=None [2025-09-12T05:03:14.716965864Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=100.020696ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 13, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.717001420Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.717005658Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.717525665Z TRACE quiche_apps::client] got 784 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.717533500Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=763 pn=10 [2025-09-12T05:03:14.717539641Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=9500 len=740 fin=false [2025-09-12T05:03:14.717546875Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 784 bytes [2025-09-12T05:03:14.717550261Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.717552556Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.717556343Z TRACE quiche_apps::common] received 740 bytes [2025-09-12T05:03:14.717558577Z TRACE quiche_apps::common] stream 0 has 740 bytes (fin? false) [2025-09-12T05:03:14.717566010Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=5 pn=14 [2025-09-12T05:03:14.717568515Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm ACK delay=4 blocks=[1..10] ecn_counts=None [2025-09-12T05:03:14.717574657Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=99.412013ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 4, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 708057831 }, next_time: Instant { tv_sec: 514, tv_nsec: 709272575 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.717603941Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.717615683Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.739486347Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.739497467Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx pkt Short dcid=898192abe2f0951ac7800a4477be775097c6fb55 key_phase=false len=22 pn=11 [2025-09-12T05:03:14.739503529Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 rx frm STREAM id=0 off=10240 len=0 fin=true [2025-09-12T05:03:14.739511684Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 43 bytes [2025-09-12T05:03:14.739515221Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.739517575Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.739522674Z TRACE quiche_apps::common] received 0 bytes [2025-09-12T05:03:14.739524929Z TRACE quiche_apps::common] stream 0 has 0 bytes (fin? true) [2025-09-12T05:03:14.739527243Z DEBUG quiche_apps::common] 1/1 responses received [2025-09-12T05:03:14.739529577Z INFO quiche_apps::common] 1/1 response(s) received in 132.916857ms, closing... [2025-09-12T05:03:14.739536640Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx pkt Short dcid=e1692333eed053bd key_phase=false len=10 pn=15 [2025-09-12T05:03:14.739539195Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-09-12T05:03:14.739546028Z TRACE quiche::recovery::congestion::recovery] cff6ef48c2116283bd23f91ad82e64241d4634c4 timer=108.01267ms latest_rtt=31.920686ms srtt=32.756452ms min_rtt=31.920686ms rttvar=12.567233ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=107 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1515, delivered_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, first_sent_time: Instant { tv_sec: 514, tv_nsec: 707029457 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { bandwidth: 280.17 Kbps, is_app_limited: true, interval: 32.265661ms, delivered: 1130, prior_delivered: 385, prior_time: Some(Instant { tv_sec: 514, tv_nsec: 674657869 }), send_elapsed: 344.975µs, ack_elapsed: 32.265661ms, rtt: 31.920686ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 36, rate: 515165, last_update: Instant { tv_sec: 514, tv_nsec: 737601445 }, next_time: Instant { tv_sec: 514, tv_nsec: 737601445 }, max_datagram_size: 1350, last_packet_size: Some(36), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:03:14.739577847Z TRACE quiche_apps::client] written 36 bytes from 0.0.0.0:49984 to 193.167.100.100:443 [2025-09-12T05:03:14.739581303Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.766095980Z TRACE quiche_apps::client] got 44 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.766111920Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 44 bytes [2025-09-12T05:03:14.766116919Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.766120015Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.766124944Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.770053526Z TRACE quiche_apps::client] got 47 bytes from 193.167.100.100:443 to 0.0.0.0:49984 [2025-09-12T05:03:14.770067191Z TRACE quiche_apps::client] 0.0.0.0:49984: processed 47 bytes [2025-09-12T05:03:14.770072271Z TRACE quiche_apps::client] 0.0.0.0:49984: recv() would block [2025-09-12T05:03:14.770075326Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.770080145Z TRACE quiche_apps::client] 0.0.0.0:49984 -> 193.167.100.100:443: done writing [2025-09-12T05:03:14.989353171Z TRACE quiche_apps::client] timed out [2025-09-12T05:03:14.989381464Z TRACE quiche] cff6ef48c2116283bd23f91ad82e64241d4634c4 draining timeout expired [2025-09-12T05:03:14.989417501Z TRACE quiche_apps::client] done reading [2025-09-12T05:03:14.989423191Z INFO quiche_apps::client] connection closed, recv=14 sent=16 lost=0 retrans=0 sent_bytes=2454 recv_bytes=12503 lost_bytes=0 [local_addr=0.0.0.0:49984 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=14 sent=16 lost=0 retrans=0 rtt=32.756452ms min_rtt=Some(31.920686ms) rttvar=12.567233ms cwnd=13500 sent_bytes=2454 recv_bytes=12503 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=35021]