[2025-09-12T06:28:57.631589066Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T06:28:57.631931576Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:57117 with scid 93becbe94eb569c13ee4c763fe69019873a43bfd [2025-09-12T06:28:57.631974597Z TRACE quiche::tls] 93becbe94eb569c13ee4c763fe69019873a43bfd write message lvl=Initial len=266 [2025-09-12T06:28:57.631994594Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Initial version=1 dcid=ec318a2e3522523f425cbf20cf9e87e2 scid=93becbe94eb569c13ee4c763fe69019873a43bfd len=270 pn=0 [2025-09-12T06:28:57.631997810Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm CRYPTO off=0 len=266 [2025-09-12T06:28:57.632014882Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=998.923758ms 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: 656, tv_nsec: 421667709 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, 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: 656, tv_nsec: 421667709 }, next_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, 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-12T06:28:57.632069584Z TRACE quiche_apps::client] written 1200 [2025-09-12T06:28:58.631922908Z TRACE quiche_apps::client] timed out [2025-09-12T06:28:58.631946141Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd loss detection timeout expired [2025-09-12T06:28:58.631953905Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=997.983642ms 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: 656, tv_nsec: 421667709 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, 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: 656, tv_nsec: 421667709 }, next_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, 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-12T06:28:58.631979504Z TRACE quiche_apps::client] done reading [2025-09-12T06:28:58.632017645Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Initial version=1 dcid=ec318a2e3522523f425cbf20cf9e87e2 scid=93becbe94eb569c13ee4c763fe69019873a43bfd len=270 pn=1 [2025-09-12T06:28:58.632021913Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm CRYPTO off=0 len=266 [2025-09-12T06:28:58.632041700Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=1.997951659s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=666 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, 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: 657, tv_nsec: 421722178 }, next_time: Instant { tv_sec: 657, tv_nsec: 421722178 }, 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-12T06:28:58.632111570Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:57117 to 193.167.100.100:443 [2025-09-12T06:28:58.632123673Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:28:59.140938182Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:28:59.140969530Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx pkt Initial version=1 dcid=93becbe94eb569c13ee4c763fe69019873a43bfd scid=180945cbd5598fba token= len=117 pn=0 [2025-09-12T06:28:59.140988806Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm ACK delay=132 blocks=[0..0] ecn_counts=None [2025-09-12T06:28:59.140996651Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd packet newly acked 0 [2025-09-12T06:28:59.141004054Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm CRYPTO off=0 len=90 [2025-09-12T06:28:59.141139949Z TRACE quiche::tls] 93becbe94eb569c13ee4c763fe69019873a43bfd set write secret lvl=Handshake [2025-09-12T06:28:59.141154576Z TRACE quiche::tls] 93becbe94eb569c13ee4c763fe69019873a43bfd set read secret lvl=Handshake [2025-09-12T06:28:59.141196224Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx pkt Handshake version=1 dcid=93becbe94eb569c13ee4c763fe69019873a43bfd scid=180945cbd5598fba len=1060 pn=1 [2025-09-12T06:28:59.141203848Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm CRYPTO off=0 len=710 [2025-09-12T06:28:59.141519328Z TRACE quiche::tls] 93becbe94eb569c13ee4c763fe69019873a43bfd write message lvl=Handshake len=36 [2025-09-12T06:28:59.141527123Z TRACE quiche::tls] 93becbe94eb569c13ee4c763fe69019873a43bfd set write secret lvl=OneRTT [2025-09-12T06:28:59.141536380Z TRACE quiche::tls] 93becbe94eb569c13ee4c763fe69019873a43bfd set read secret lvl=OneRTT [2025-09-12T06:28:59.141558251Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd connection established: proto=Ok("h3") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(ec318a2e3522523f425cbf20cf9e87e2), max_idle_timeout: 30000, stateless_reset_token: Some(265821192573148956362654764756749045745), max_udp_payload_size: 65527, initial_max_data: 1572864, initial_max_stream_data_bidi_local: 0, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 12288, initial_max_streams_bidi: 100, initial_max_streams_uni: 3, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(180945cbd5598fba), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-09-12T06:28:59.141575122Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm PADDING len=329 [2025-09-12T06:28:59.141594108Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 1252 bytes [2025-09-12T06:28:59.141600239Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:28:59.141603726Z TRACE quiche_apps::client] done reading [2025-09-12T06:28:59.141623042Z TRACE quiche::h3] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm SETTINGS stream=2 len=18 [2025-09-12T06:28:59.141650283Z TRACE quiche::h3] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm GREASE stream=0 len=0 [2025-09-12T06:28:59.141658027Z TRACE quiche::h3] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm GREASE stream=0 len=18 [2025-09-12T06:28:59.141667735Z TRACE quiche::h3] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm HEADERS stream=0 len=29 fin=true [2025-09-12T06:28:59.141675630Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server4", ":path: /rrnysauadu", "user-agent: quiche"] [2025-09-12T06:28:59.141774004Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Initial version=1 dcid=180945cbd5598fba scid=93becbe94eb569c13ee4c763fe69019873a43bfd len=6 pn=2 [2025-09-12T06:28:59.141779083Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm ACK delay=101 blocks=[0..0] ecn_counts=None [2025-09-12T06:28:59.141791707Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=4.017270539s latest_rtt=1.509023036s srtt=1.509023036s min_rtt=1.509023036s rttvar=754.511518ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 657, tv_nsec: 930690745 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.509023036s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 421667709 }), send_elapsed: 0ns, ack_elapsed: 1.509023036s, rtt: 1.509023036s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11182, last_update: Instant { tv_sec: 657, tv_nsec: 931283773 }, next_time: Instant { tv_sec: 657, tv_nsec: 931283824 }, 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-12T06:28:59.141820401Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Handshake version=1 dcid=180945cbd5598fba scid=93becbe94eb569c13ee4c763fe69019873a43bfd len=46 pn=3 [2025-09-12T06:28:59.141824328Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm ACK delay=77 blocks=[1..1] ecn_counts=None [2025-09-12T06:28:59.141827825Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm CRYPTO off=0 len=36 [2025-09-12T06:28:59.141835760Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=4.017226708s latest_rtt=1.509023036s srtt=1.509023036s min_rtt=1.509023036s rttvar=754.511518ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=433 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 657, tv_nsec: 930690745 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.509023036s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 421667709 }), send_elapsed: 0ns, ack_elapsed: 1.509023036s, rtt: 1.509023036s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11182, last_update: Instant { tv_sec: 657, tv_nsec: 931491001 }, next_time: Instant { tv_sec: 657, tv_nsec: 931283824 }, max_datagram_size: 1350, last_packet_size: None, iv: 8.942944ms, 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-12T06:28:59.141857821Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd dropped epoch 0 state [2025-09-12T06:28:59.141875504Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Short dcid=180945cbd5598fba key_phase=false len=1163 pn=4 [2025-09-12T06:28:59.141879021Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[db, 1d, c8, 8f, 60, 36, 8d, 0a, 62, 7c, 9f, 33, 08, 17, 5a, 76, 6f, c2, 9d, ff] reset_token=[29, 65, 4a, 93, 10, 1e, 87, be, 7a, 2f, 39, a6, 36, 0c, 57, 56] [2025-09-12T06:28:59.141888458Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[35, 1c, f4, f8, a9, 9d, bd, e9, 72, d4, 35, aa, 8a, 4c, 81, 3b, 6d, 22, dc, 7d] reset_token=[2c, 1a, da, 7e, 60, 13, 0c, 6b, 64, eb, 5d, 68, b9, bb, 5b, 06] [2025-09-12T06:28:59.141896423Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[75, 53, 22, ad, f8, b1, eb, 2b, 33, 6b, b0, f1, 78, 4e, 76, d3, 11, c0, 09, c8] reset_token=[d4, 48, b6, 19, f4, cb, 43, c3, 03, 72, 29, d2, b3, 7a, f2, e8] [2025-09-12T06:28:59.141903997Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[d7, 71, a3, 28, 33, b4, 33, 49, 3e, f2, 3a, d9, e4, 8e, fb, 45, d7, 53, 96, ec] reset_token=[38, 37, 2d, 7a, 83, 05, 03, ac, 73, b5, bb, c4, 53, 38, e5, b0] [2025-09-12T06:28:59.141911471Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[98, ee, 3d, 10, d9, 61, c6, f7, 87, c6, 02, 8f, 1f, fd, 9e, ee, 8e, 75, 45, f1] reset_token=[00, c0, eb, 0f, 0a, c5, b5, ef, d2, 8b, 18, 3d, 92, 17, 00, 11] [2025-09-12T06:28:59.141919225Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[ec, 50, d6, eb, 19, 45, 24, 6a, 64, 29, 7b, 13, b3, e5, e7, f9, 12, 2f, 0e, 3d] reset_token=[55, 8b, e0, c4, 36, 2b, 05, 2f, 37, 07, 10, 0c, c2, 43, 13, ad] [2025-09-12T06:28:59.141926770Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[82, 37, 38, c1, 15, ec, 75, 12, f0, 0d, 1c, a5, 11, 03, 09, 71, 85, 97, a6, af] reset_token=[14, c0, 2a, d6, f7, 7f, c8, 19, f8, c0, 93, 08, 0a, ed, d9, 85] [2025-09-12T06:28:59.141934374Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm STREAM id=2 off=0 len=19 fin=false [2025-09-12T06:28:59.141937820Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm PADDING len=859 [2025-09-12T06:28:59.141969910Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=4.526861209s latest_rtt=1.509023036s srtt=1.509023036s min_rtt=1.509023036s rttvar=754.511518ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 657, tv_nsec: 930690745 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.509023036s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 421667709 }), send_elapsed: 0ns, ack_elapsed: 1.509023036s, rtt: 1.509023036s } } pacer=Pacer { enabled: true, capacity: 13500, used: 1189, rate: 11182, last_update: Instant { tv_sec: 657, tv_nsec: 931491001 }, next_time: Instant { tv_sec: 657, tv_nsec: 940433945 }, max_datagram_size: 1350, last_packet_size: Some(1189), 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-12T06:28:59.142040442Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:57117 to 193.167.100.100:443 [2025-09-12T06:28:59.142065669Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Short dcid=180945cbd5598fba key_phase=false len=6 pn=5 [2025-09-12T06:28:59.142071891Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm STREAM id=6 off=0 len=1 fin=false [2025-09-12T06:28:59.142081850Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=4.526748759s latest_rtt=1.509023036s srtt=1.509023036s min_rtt=1.509023036s rttvar=754.511518ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 657, tv_nsec: 930690745 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.509023036s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 421667709 }), send_elapsed: 0ns, ack_elapsed: 1.509023036s, rtt: 1.509023036s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11182, last_update: Instant { tv_sec: 657, tv_nsec: 931785612 }, next_time: Instant { tv_sec: 657, tv_nsec: 940433945 }, max_datagram_size: 1350, last_packet_size: None, iv: 109.193346ms, 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-12T06:28:59.142119190Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:57117 to 193.167.100.100:443 [2025-09-12T06:28:59.142130731Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Short dcid=180945cbd5598fba key_phase=false len=6 pn=6 [2025-09-12T06:28:59.142134699Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm STREAM id=10 off=0 len=1 fin=false [2025-09-12T06:28:59.142143946Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=4.526687014s latest_rtt=1.509023036s srtt=1.509023036s min_rtt=1.509023036s rttvar=754.511518ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1353 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 657, tv_nsec: 930690745 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.509023036s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 421667709 }), send_elapsed: 0ns, ack_elapsed: 1.509023036s, rtt: 1.509023036s } } pacer=Pacer { enabled: true, capacity: 13500, used: 32, rate: 11182, last_update: Instant { tv_sec: 657, tv_nsec: 931785612 }, next_time: Instant { tv_sec: 658, tv_nsec: 49627291 }, max_datagram_size: 1350, last_packet_size: Some(32), 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-12T06:28:59.142177539Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:57117 to 193.167.100.100:443 [2025-09-12T06:28:59.142187918Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Short dcid=180945cbd5598fba key_phase=false len=72 pn=7 [2025-09-12T06:28:59.142192066Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm STREAM id=0 off=0 len=67 fin=true [2025-09-12T06:28:59.142201423Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=4.526629476s latest_rtt=1.509023036s srtt=1.509023036s min_rtt=1.509023036s rttvar=754.511518ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1451 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 657, tv_nsec: 930690745 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.509023036s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 421667709 }), send_elapsed: 0ns, ack_elapsed: 1.509023036s, rtt: 1.509023036s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11182, last_update: Instant { tv_sec: 657, tv_nsec: 931911567 }, next_time: Instant { tv_sec: 658, tv_nsec: 49627291 }, max_datagram_size: 1350, last_packet_size: None, iv: 11.625827ms, 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-12T06:28:59.142240186Z TRACE quiche_apps::client] written 98 bytes from 0.0.0.0:57117 to 193.167.100.100:443 [2025-09-12T06:28:59.142247459Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:28:59.441390189Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:28:59.441407842Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd dropped invalid packet [2025-09-12T06:28:59.441412601Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 1252 bytes [2025-09-12T06:28:59.441417490Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:28:59.441420716Z TRACE quiche_apps::client] done reading [2025-09-12T06:28:59.441427639Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:00.134835173Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:00.134866321Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd dropped invalid packet [2025-09-12T06:29:00.134872182Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 1252 bytes [2025-09-12T06:29:00.134877652Z TRACE quiche_apps::client] got 61 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:00.134881519Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd dropped invalid packet [2025-09-12T06:29:00.134884415Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 61 bytes [2025-09-12T06:29:00.134888743Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:00.134891878Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:00.134902799Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:00.645548216Z TRACE quiche_apps::client] got 583 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:00.645570949Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx pkt Short dcid=93becbe94eb569c13ee4c763fe69019873a43bfd key_phase=false len=562 pn=7 [2025-09-12T06:29:00.645594373Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm CRYPTO off=0 len=540 [2025-09-12T06:29:00.645634448Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm HANDSHAKE_DONE [2025-09-12T06:29:00.645641661Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd dropped epoch 1 state [2025-09-12T06:29:00.645658613Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 583 bytes [2025-09-12T06:29:00.645663562Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:00.645666778Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:00.645682407Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Short dcid=180945cbd5598fba key_phase=false len=5 pn=8 [2025-09-12T06:29:00.645686455Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm ACK delay=13 blocks=[7..7] ecn_counts=None [2025-09-12T06:29:00.645699699Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=3.048551736s latest_rtt=1.509023036s srtt=1.509023036s min_rtt=1.509023036s rttvar=754.511518ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1351 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 657, tv_nsec: 930690745 }, first_sent_time: Instant { tv_sec: 656, tv_nsec: 421667709 }, end_of_app_limited: 6, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.509023036s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 656, tv_nsec: 421667709 }), send_elapsed: 0ns, ack_elapsed: 1.509023036s, rtt: 1.509023036s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11182, last_update: Instant { tv_sec: 659, tv_nsec: 435401268 }, next_time: Instant { tv_sec: 659, tv_nsec: 447027095 }, 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-12T06:29:00.645767286Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:57117 to 193.167.100.100:443 [2025-09-12T06:29:00.645777214Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:00.645789848Z TRACE quiche_apps::client] got 309 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:00.645796420Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd dropped invalid packet [2025-09-12T06:29:00.645801529Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 309 bytes [2025-09-12T06:29:00.645810356Z TRACE quiche_apps::client] got 48 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:00.645815806Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx pkt Short dcid=93becbe94eb569c13ee4c763fe69019873a43bfd key_phase=false len=27 pn=10 [2025-09-12T06:29:00.645822278Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm ACK delay=23 blocks=[4..7] ecn_counts=None [2025-09-12T06:29:00.645827107Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd packet newly acked 4 [2025-09-12T06:29:00.645831045Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd packet newly acked 5 [2025-09-12T06:29:00.645834321Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd packet newly acked 6 [2025-09-12T06:29:00.645837136Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd packet newly acked 7 [2025-09-12T06:29:00.645842045Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd rx frm STREAM id=0 off=0 len=0 fin=true [2025-09-12T06:29:00.645861481Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 48 bytes [2025-09-12T06:29:00.645865800Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:00.645868735Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:00.645871831Z TRACE quiche::h3] 93becbe94eb569c13ee4c763fe69019873a43bfd stream id 0 is readable [2025-09-12T06:29:00.645879625Z TRACE quiche::h3::stream] 93becbe94eb569c13ee4c763fe69019873a43bfd read 0 bytes on stream 0 [2025-09-12T06:29:00.645883723Z DEBUG quiche_apps::common] 1/1 responses received [2025-09-12T06:29:00.645886949Z INFO quiche_apps::common] 1/1 response(s) received in 3.013813809s, closing... [2025-09-12T06:29:00.645896938Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx pkt Short dcid=180945cbd5598fba key_phase=false len=11 pn=9 [2025-09-12T06:29:00.645900214Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-09-12T06:29:00.645908259Z TRACE quiche::recovery::congestion::recovery] 93becbe94eb569c13ee4c763fe69019873a43bfd timer=3.905259916s latest_rtt=1.385915902s srtt=1.493634643s min_rtt=1.385915902s rttvar=596.660421ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1684, delivered_time: Instant { tv_sec: 659, tv_nsec: 447027095 }, first_sent_time: Instant { tv_sec: 659, tv_nsec: 447027095 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 7, rate_sample: RateSample { bandwidth: 6.63 Kbps, is_app_limited: true, interval: 1.627959582s, delivered: 1351, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 657, tv_nsec: 930690745 }), send_elapsed: 1.627959582s, ack_elapsed: 1.504852448s, rtt: 1.385915902s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11297, last_update: Instant { tv_sec: 659, tv_nsec: 435620587 }, next_time: Instant { tv_sec: 659, tv_nsec: 447027095 }, max_datagram_size: 1350, last_packet_size: None, iv: 3.275206ms, 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-12T06:29:00.645947622Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:57117 to 193.167.100.100:443 [2025-09-12T06:29:00.645954525Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:00.802603887Z TRACE quiche_apps::client] got 1097 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:00.802627852Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 1097 bytes [2025-09-12T06:29:00.802633523Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:00.802637139Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:00.802645154Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:01.312703947Z TRACE quiche_apps::client] got 46 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.312728202Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 46 bytes [2025-09-12T06:29:01.312734584Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.312738591Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 43 bytes [2025-09-12T06:29:01.312743100Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:01.312746406Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:01.312754581Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:01.470120581Z TRACE quiche_apps::client] got 1159 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.470138274Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 1159 bytes [2025-09-12T06:29:01.470143824Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:01.470147250Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:01.470153322Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:01.814091296Z TRACE quiche_apps::client] got 50 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.814114550Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 50 bytes [2025-09-12T06:29:01.814122064Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:01.814127063Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:01.814135148Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:01.814564961Z TRACE quiche_apps::client] got 583 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.814581762Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 583 bytes [2025-09-12T06:29:01.814588906Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:01.814593875Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:01.814600798Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:01.814739737Z TRACE quiche_apps::client] got 250 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.814753242Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 250 bytes [2025-09-12T06:29:01.814775474Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.814779732Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 43 bytes [2025-09-12T06:29:01.814783930Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:01.814786985Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:01.814791935Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:01.970498903Z TRACE quiche_apps::client] got 1159 bytes from 193.167.100.100:443 to 0.0.0.0:57117 [2025-09-12T06:29:01.970514482Z TRACE quiche_apps::client] 0.0.0.0:57117: processed 1159 bytes [2025-09-12T06:29:01.970520063Z TRACE quiche_apps::client] 0.0.0.0:57117: recv() would block [2025-09-12T06:29:01.970523449Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:01.970528909Z TRACE quiche_apps::client] 0.0.0.0:57117 -> 193.167.100.100:443: done writing [2025-09-12T06:29:12.297909360Z TRACE quiche_apps::client] timed out [2025-09-12T06:29:12.297946059Z TRACE quiche] 93becbe94eb569c13ee4c763fe69019873a43bfd draining timeout expired [2025-09-12T06:29:12.297995091Z TRACE quiche_apps::client] done reading [2025-09-12T06:29:12.298004278Z INFO quiche_apps::client] connection closed, recv=4 sent=10 lost=0 retrans=1 sent_bytes=2246 recv_bytes=1883 lost_bytes=0 [local_addr=0.0.0.0:57117 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=4 sent=10 lost=0 retrans=1 rtt=1.493634643s min_rtt=Some(1.385915902s) rttvar=596.660421ms cwnd=13500 sent_bytes=2246 recv_bytes=1883 lost_bytes=0 stream_retrans_bytes=266 pmtu=1350 delivery_rate=829]