[2025-04-30T08:44:51.741036653Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T08:44:51.741312689Z INFO  quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:49762 with scid 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437
[2025-04-30T08:44:51.741352884Z TRACE quiche::tls] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 write message lvl=Initial len=266
[2025-04-30T08:44:51.741372140Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Initial version=1 dcid=5034795fb02fe88b43f2f506acd9465f scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=270 pn=0 
[2025-04-30T08:44:51.741375216Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm CRYPTO off=0 len=266
[2025-04-30T08:44:51.741389182Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=998.93ms 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: 423, tv_nsec: 322887920 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 322887920 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, 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: 423, tv_nsec: 322887920 }, next_time: Instant { tv_sec: 423, tv_nsec: 322887920 }, 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-04-30T08:44:51.741467668Z TRACE quiche_apps::client] written 1200
[2025-04-30T08:44:51.780080043Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:51.780094721Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Initial version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 token= len=117 pn=0 
[2025-04-30T08:44:51.780103958Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T08:44:51.780109088Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 packet newly acked 0
[2025-04-30T08:44:51.780114318Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=0 len=90
[2025-04-30T08:44:51.780197323Z TRACE quiche::tls] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 set write secret lvl=Handshake
[2025-04-30T08:44:51.780205668Z TRACE quiche::tls] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 set read secret lvl=Handshake
[2025-04-30T08:44:51.780231507Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1096 pn=0 
[2025-04-30T08:44:51.780236917Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=0 len=1074
[2025-04-30T08:44:51.780251614Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:51.780255992Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:51.780258457Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:51.780272734Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Initial version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=1 
[2025-04-30T08:44:51.780275849Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=22 blocks=[0..0] ecn_counts=None
[2025-04-30T08:44:51.780282793Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=116.12435ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 361815684 }, next_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, 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-04-30T08:44:51.780305505Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=2 
[2025-04-30T08:44:51.780308300Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=9 blocks=[0..0] ecn_counts=None
[2025-04-30T08:44:51.780313480Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=116.093762ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 361815684 }, next_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, 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-04-30T08:44:51.780323348Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 dropped epoch 0 state
[2025-04-30T08:44:51.780356110Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:51.780361229Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:51.781105447Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:51.781112540Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1247 pn=1 
[2025-04-30T08:44:51.781118962Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=1074 len=1224
[2025-04-30T08:44:51.781130644Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:51.781134311Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:51.781136716Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:51.781144049Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=3 
[2025-04-30T08:44:51.781146634Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=4 blocks=[0..1] ecn_counts=None
[2025-04-30T08:44:51.781152896Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=115.429844ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 361815684 }, next_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, 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-04-30T08:44:51.781193371Z TRACE quiche_apps::client] written 55 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:51.781198280Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:51.782148797Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:51.782156352Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1247 pn=2 
[2025-04-30T08:44:51.782162293Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=2298 len=1224
[2025-04-30T08:44:51.782172422Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:51.782176008Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:51.782178353Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:51.782185596Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=4 
[2025-04-30T08:44:51.782188161Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=3 blocks=[0..2] ecn_counts=None
[2025-04-30T08:44:51.782194062Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=114.388788ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 361815684 }, next_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, 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-04-30T08:44:51.782225150Z TRACE quiche_apps::client] written 55 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:51.782229418Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:51.897406843Z TRACE quiche_apps::client] timed out
[2025-04-30T08:44:51.897459521Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 loss detection timeout expired
[2025-04-30T08:44:51.897467897Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=232.620884ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 361815684 }, next_time: Instant { tv_sec: 423, tv_nsec: 361815714 }, 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-04-30T08:44:51.897490970Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:51.897530554Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=7 pn=5 
[2025-04-30T08:44:51.897534802Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=14421 blocks=[0..2] ecn_counts=None
[2025-04-30T08:44:51.897540803Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm PING mtu_probe=None
[2025-04-30T08:44:51.897558666Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=232.577273ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=57 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 57, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 479072873 }, next_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, max_datagram_size: 1350, last_packet_size: Some(57), 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-04-30T08:44:51.897641722Z TRACE quiche_apps::client] written 57 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:51.897648845Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.130940784Z TRACE quiche_apps::client] timed out
[2025-04-30T08:44:52.130970921Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 loss detection timeout expired
[2025-04-30T08:44:52.130976752Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=231.789529ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=57 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 57, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 479072873 }, next_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, max_datagram_size: 1350, last_packet_size: Some(57), 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-04-30T08:44:52.131024862Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.131057903Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=9 pn=6 
[2025-04-30T08:44:52.131062292Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=43612 blocks=[0..2] ecn_counts=None
[2025-04-30T08:44:52.131068133Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm PING mtu_probe=None
[2025-04-30T08:44:52.131087298Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=465.210429ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=116 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 59, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 712603108 }, next_time: Instant { tv_sec: 423, tv_nsec: 712603108 }, max_datagram_size: 1350, last_packet_size: Some(59), 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-04-30T08:44:52.131183328Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.131195130Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=9 pn=7 
[2025-04-30T08:44:52.131198617Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=43629 blocks=[0..2] ecn_counts=None
[2025-04-30T08:44:52.131202163Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm PING mtu_probe=None
[2025-04-30T08:44:52.131209367Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=465.242279ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=175 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 118, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 712603108 }, next_time: Instant { tv_sec: 423, tv_nsec: 712603108 }, max_datagram_size: 1350, last_packet_size: Some(59), 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-04-30T08:44:52.131244973Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.131250203Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.597778507Z TRACE quiche_apps::client] timed out
[2025-04-30T08:44:52.597803044Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 loss detection timeout expired
[2025-04-30T08:44:52.597809305Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=463.904577ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=175 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 118, rate: 435237, last_update: Instant { tv_sec: 423, tv_nsec: 712603108 }, next_time: Instant { tv_sec: 423, tv_nsec: 712603108 }, max_datagram_size: 1350, last_packet_size: Some(59), 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-04-30T08:44:52.597833651Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.597866792Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=9 pn=8 
[2025-04-30T08:44:52.597871381Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=101963 blocks=[0..2] ecn_counts=None
[2025-04-30T08:44:52.597877312Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm PING mtu_probe=None
[2025-04-30T08:44:52.597895626Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=930.47445ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=234 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 59, rate: 435237, last_update: Instant { tv_sec: 424, tv_nsec: 179412258 }, next_time: Instant { tv_sec: 424, tv_nsec: 179412258 }, max_datagram_size: 1350, last_packet_size: Some(59), 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-04-30T08:44:52.598002076Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.598020951Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=9 pn=9 
[2025-04-30T08:44:52.598026130Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=101983 blocks=[0..2] ecn_counts=None
[2025-04-30T08:44:52.598031240Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm PING mtu_probe=None
[2025-04-30T08:44:52.598042100Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=930.493875ms latest_rtt=38.771933ms srtt=38.771933ms min_rtt=38.771933ms rttvar=19.385966ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=293 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, first_sent_time: Instant { tv_sec: 423, tv_nsec: 479072873 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8588, is_app_limited: true, interval: 38.771933ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 322887920 }), send_elapsed: 0ns, ack_elapsed: 38.771933ms, rtt: 38.771933ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 118, rate: 435237, last_update: Instant { tv_sec: 424, tv_nsec: 179412258 }, next_time: Instant { tv_sec: 424, tv_nsec: 179412258 }, max_datagram_size: 1350, last_packet_size: Some(59), 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-04-30T08:44:52.598094879Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.598105318Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.629812490Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.629835332Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1247 pn=3 
[2025-04-30T08:44:52.629847896Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm ACK delay=0 blocks=[8..8] ecn_counts=None
[2025-04-30T08:44:52.629854218Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 packet newly acked 8
[2025-04-30T08:44:52.629861100Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 packet 5 lost on epoch 1
[2025-04-30T08:44:52.629864317Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 packet 6 lost on epoch 1
[2025-04-30T08:44:52.629868114Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 packet 7 lost on epoch 1
[2025-04-30T08:44:52.629874325Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=3522 len=1219
[2025-04-30T08:44:52.629901686Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.629907117Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.629910853Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.629923167Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=10 
[2025-04-30T08:44:52.629926683Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=11 blocks=[3..3] ecn_counts=None
[2025-04-30T08:44:52.629936732Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=70.939894ms latest_rtt=31.987204ms srtt=37.923841ms min_rtt=31.987204ms rttvar=16.235656ms cwnd=9450 ssthresh=9450 bytes_in_flight=59 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 211399462 }) Rate { delivered: 392, delivered_time: Instant { tv_sec: 424, tv_nsec: 211399462 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 179412258 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 8, rate_sample: RateSample { delivery_rate: 80, is_app_limited: true, interval: 732.326589ms, delivered: 59, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 479072873 }), send_elapsed: 700.339385ms, ack_elapsed: 732.326589ms, rtt: 31.987204ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 311479, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 179412258 }, max_datagram_size: 1350, last_packet_size: None, iv: 378.838µ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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.630003086Z TRACE quiche_apps::client] written 55 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.630014126Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.630851592Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.630860148Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1247 pn=4 
[2025-04-30T08:44:52.630866460Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm ACK delay=0 blocks=[8..9] ecn_counts=None
[2025-04-30T08:44:52.630870037Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 packet newly acked 9
[2025-04-30T08:44:52.630874024Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=4741 len=1219
[2025-04-30T08:44:52.630922515Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.630926592Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.630928997Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.630937212Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=11 
[2025-04-30T08:44:52.630939947Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=9 blocks=[3..4] ecn_counts=None
[2025-04-30T08:44:52.630946460Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=none latest_rtt=33.014555ms srtt=37.310179ms min_rtt=31.987204ms rttvar=13.404063ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 211399462 }) Rate { delivered: 451, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 10, last_sent_packet: 11, largest_acked: 9, rate_sample: RateSample { delivery_rate: 161, is_app_limited: true, interval: 732.326589ms, delivered: 118, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 479072873 }), send_elapsed: 700.339385ms, ack_elapsed: 732.326589ms, rtt: 31.987204ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 316602, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.630988799Z TRACE quiche_apps::client] written 55 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.630997124Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.631885335Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.631893490Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1247 pn=5 
[2025-04-30T08:44:52.631899702Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=5960 len=1224
[2025-04-30T08:44:52.631909690Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.631913227Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.631915561Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.631922665Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=12 
[2025-04-30T08:44:52.631925229Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=3 blocks=[3..5] ecn_counts=None
[2025-04-30T08:44:52.631931581Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=none latest_rtt=33.014555ms srtt=37.310179ms min_rtt=31.987204ms rttvar=13.404063ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 211399462 }) Rate { delivered: 451, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 10, last_sent_packet: 12, largest_acked: 9, rate_sample: RateSample { delivery_rate: 161, is_app_limited: true, interval: 732.326589ms, delivered: 118, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 479072873 }), send_elapsed: 700.339385ms, ack_elapsed: 732.326589ms, rtt: 31.987204ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 316602, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.631966917Z TRACE quiche_apps::client] written 55 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.631974652Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.632933574Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.632942381Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1247 pn=6 
[2025-04-30T08:44:52.632948823Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=7184 len=1224
[2025-04-30T08:44:52.632959182Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.632962709Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.632965023Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.632972096Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=13 
[2025-04-30T08:44:52.632974591Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=3 blocks=[3..6] ecn_counts=None
[2025-04-30T08:44:52.632986583Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=none latest_rtt=33.014555ms srtt=37.310179ms min_rtt=31.987204ms rttvar=13.404063ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 211399462 }) Rate { delivered: 451, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 10, last_sent_packet: 13, largest_acked: 9, rate_sample: RateSample { delivery_rate: 161, is_app_limited: true, interval: 732.326589ms, delivered: 118, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 479072873 }), send_elapsed: 700.339385ms, ack_elapsed: 732.326589ms, rtt: 31.987204ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 316602, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.633029844Z TRACE quiche_apps::client] written 55 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.633038360Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.633984569Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.633992574Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=1247 pn=7 
[2025-04-30T08:44:52.633998646Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=8408 len=1224
[2025-04-30T08:44:52.634008244Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.634011690Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.634014004Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.634021108Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=5 pn=14 
[2025-04-30T08:44:52.634023592Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=3 blocks=[3..7] ecn_counts=None
[2025-04-30T08:44:52.634029713Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=none latest_rtt=33.014555ms srtt=37.310179ms min_rtt=31.987204ms rttvar=13.404063ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 211399462 }) Rate { delivered: 451, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 10, last_sent_packet: 14, largest_acked: 9, rate_sample: RateSample { delivery_rate: 161, is_app_limited: true, interval: 732.326589ms, delivered: 118, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 479072873 }), send_elapsed: 700.339385ms, ack_elapsed: 732.326589ms, rtt: 31.987204ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 316602, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.634064208Z TRACE quiche_apps::client] written 55 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.634072073Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.634392291Z TRACE quiche_apps::client] got 534 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.634401969Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Handshake version=1 dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 scid=54398ce0 len=342 pn=8 
[2025-04-30T08:44:52.634407249Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=9632 len=319
[2025-04-30T08:44:52.634919036Z TRACE quiche::tls] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 write message lvl=Handshake len=36
[2025-04-30T08:44:52.634924076Z TRACE quiche::tls] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 set write secret lvl=OneRTT
[2025-04-30T08:44:52.634932872Z TRACE quiche::tls] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 set read secret lvl=OneRTT
[2025-04-30T08:44:52.634946207Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 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(5034795fb02fe88b43f2f506acd9465f), max_idle_timeout: 30000, stateless_reset_token: Some(292157159093541039086566497163599518007), max_udp_payload_size: 1452, initial_max_data: 786432, initial_max_stream_data_bidi_local: 524288, initial_max_stream_data_bidi_remote: 524288, initial_max_stream_data_uni: 524288, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(54398ce0), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T08:44:52.634968729Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 key_phase=false len=138 pn=0 
[2025-04-30T08:44:52.634975071Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[63, e9, ca, 87] reset_token=[c9, 63, e1, b1, a9, cb, 74, de, 12, b5, d1, 70, 3e, ca, dc, bf]
[2025-04-30T08:44:52.634981463Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[49, 8a, 8f, 27] reset_token=[c3, d8, 10, 46, 1c, 48, fc, 8d, 00, 6d, ae, 50, 95, 2b, cc, 73]
[2025-04-30T08:44:52.634985841Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[42, ff, 82, 17] reset_token=[5f, 98, d0, 43, a1, 68, d5, d0, ff, 31, 96, 25, 92, 93, 4d, 25]
[2025-04-30T08:44:52.634990009Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[01, 2b, 60, 43] reset_token=[f5, 89, 4f, d9, bf, 58, 73, f0, b9, a9, 24, d9, f1, 97, 3f, 0f]
[2025-04-30T08:44:52.634994607Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[14, 66, 63, 5e] reset_token=[4b, cc, c9, 4a, 30, f0, 31, 27, 21, 43, 6f, 1b, ca, 78, 57, 9f]
[2025-04-30T08:44:52.635002041Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 534 bytes
[2025-04-30T08:44:52.635006249Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.635008724Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.635016408Z DEBUG quiche_apps::common] sending HTTP request "GET /ptcbsoosin\r\n"
[2025-04-30T08:44:52.635081339Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Handshake version=1 dcid=54398ce0 scid=0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 len=46 pn=15 
[2025-04-30T08:44:52.635085046Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=84 blocks=[3..8] ecn_counts=None
[2025-04-30T08:44:52.635088312Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm CRYPTO off=0 len=36
[2025-04-30T08:44:52.635095757Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=90.904089ms latest_rtt=33.014555ms srtt=37.310179ms min_rtt=31.987204ms rttvar=13.404063ms cwnd=9450 ssthresh=9450 bytes_in_flight=96 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 248462606 }) Rate { delivered: 451, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 9, rate_sample: RateSample { delivery_rate: 161, is_app_limited: true, interval: 732.326589ms, delivered: 118, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 479072873 }), send_elapsed: 700.339385ms, ack_elapsed: 732.326589ms, rtt: 31.987204ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 316602, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.635114993Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=10726 out_len=1254 left=1227
[2025-04-30T08:44:52.635121725Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=147 pn=16 
[2025-04-30T08:44:52.635124380Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=18 blocks=[0..0] ecn_counts=None
[2025-04-30T08:44:52.635127005Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[27, f6, 68, 7e, ac, 1d, 96, ca, 52, 20, 66, a2, bd, e9, 77, f3, 9d, 71, 53, 4e] reset_token=[9d, 1f, 02, 3e, 14, c4, 24, 55, 35, 2e, 3f, 3a, 06, e6, a5, bd]
[2025-04-30T08:44:52.635132646Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[e7, da, 49, 4c, db, 14, ac, b4, 76, b1, 00, c4, 0b, 7e, 3d, 2b, 4f, 66, 97, 4b] reset_token=[3e, 7c, 9a, d6, 89, fc, 9a, 5d, c4, 85, 84, 54, 28, d5, a1, 54]
[2025-04-30T08:44:52.635137815Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[6c, 0f, 71, 53, 0a, 5d, 4f, f7, ed, b1, f1, 1a, 63, 2e, b8, 48, 8f, 40, c5, d6] reset_token=[62, 3f, 64, 66, e8, 66, d0, 9d, 04, 82, 32, ce, d0, 0a, c8, d2]
[2025-04-30T08:44:52.635143025Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T08:44:52.635150178Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=90.849778ms latest_rtt=33.014555ms srtt=37.310179ms min_rtt=31.987204ms rttvar=13.404063ms cwnd=9450 ssthresh=9450 bytes_in_flight=265 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 248462606 }) Rate { delivered: 451, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 9, rate_sample: RateSample { delivery_rate: 161, is_app_limited: true, interval: 732.326589ms, delivered: 118, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 423, tv_nsec: 479072873 }), send_elapsed: 700.339385ms, ack_elapsed: 732.326589ms, rtt: 31.987204ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 316602, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.635190434Z TRACE quiche_apps::client] written 265 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.635205141Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.666351226Z TRACE quiche_apps::client] got 278 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.666370211Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=27f6687eac1d96ca522066a2bde977f39d71534e key_phase=false len=257 pn=1 
[2025-04-30T08:44:52.666379228Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 path ID 0 now see SCID with seq num 1
[2025-04-30T08:44:52.666385430Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm ACK delay=31 blocks=[16..16] ecn_counts=None
[2025-04-30T08:44:52.666390720Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 packet newly acked 16
[2025-04-30T08:44:52.666401269Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm NEW_TOKEN len=86
[2025-04-30T08:44:52.666404956Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm CRYPTO off=0 len=138
[2025-04-30T08:44:52.666430384Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm HANDSHAKE_DONE
[2025-04-30T08:44:52.666464327Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 dropped epoch 1 state
[2025-04-30T08:44:52.666469357Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm RETIRE_CONNECTION_ID seq_num=0
[2025-04-30T08:44:52.666489204Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 278 bytes
[2025-04-30T08:44:52.666494484Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.666497569Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.666500916Z INFO  quiche_apps::client] Retiring source CID 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437
[2025-04-30T08:44:52.666514782Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10969 out_len=1350 left=1323
[2025-04-30T08:44:52.666520612Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=45 pn=17 
[2025-04-30T08:44:52.666523909Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=18 blocks=[1..1] ecn_counts=None
[2025-04-30T08:44:52.666527676Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=1 conn_id=[a1, 19, 56, 64, f4, 86, 38, f1, 49, f9, 28, 66, 6b, 1c, a3, d1, aa, ce, 1b, 6e] reset_token=[df, f7, e5, b2, 17, 5a, df, 30, 91, d7, db, a2, a7, d5, 55, 9f]
[2025-04-30T08:44:52.666541061Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=105.680385ms latest_rtt=35.056064ms srtt=36.997414ms min_rtt=31.987204ms rttvar=10.678575ms cwnd=9450 ssthresh=9450 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 279899063 }) Rate { delivered: 620, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 16, last_sent_packet: 17, largest_acked: 16, rate_sample: RateSample { delivery_rate: 4820, is_app_limited: true, interval: 35.056064ms, delivered: 169, prior_delivered: 451, prior_time: Some(Instant { tv_sec: 424, tv_nsec: 212879329 }), send_elapsed: 0ns, ack_elapsed: 35.056064ms, rtt: 35.056064ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 319279, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.666597316Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.666606373Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.667456452Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.667465639Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=27f6687eac1d96ca522066a2bde977f39d71534e key_phase=false len=1259 pn=2 
[2025-04-30T08:44:52.667472712Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm STREAM id=0 off=0 len=1239 fin=false
[2025-04-30T08:44:52.667480026Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.667483623Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.667486007Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.667490586Z TRACE quiche_apps::common] received 1239 bytes
[2025-04-30T08:44:52.667493201Z TRACE quiche_apps::common] stream 0 has 1239 bytes (fin? false)
[2025-04-30T08:44:52.667499643Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10835 out_len=1350 left=1323
[2025-04-30T08:44:52.667502999Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=5 pn=18 
[2025-04-30T08:44:52.667505433Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=4 blocks=[1..2] ecn_counts=None
[2025-04-30T08:44:52.667523487Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=104.698009ms latest_rtt=35.056064ms srtt=36.997414ms min_rtt=31.987204ms rttvar=10.678575ms cwnd=9450 ssthresh=9450 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 279899063 }) Rate { delivered: 620, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 16, last_sent_packet: 18, largest_acked: 16, rate_sample: RateSample { delivery_rate: 4820, is_app_limited: true, interval: 35.056064ms, delivered: 169, prior_delivered: 451, prior_time: Some(Instant { tv_sec: 424, tv_nsec: 212879329 }), send_elapsed: 0ns, ack_elapsed: 35.056064ms, rtt: 35.056064ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 319279, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.667561408Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.667568692Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.668485916Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.668493280Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=27f6687eac1d96ca522066a2bde977f39d71534e key_phase=false len=1259 pn=3 
[2025-04-30T08:44:52.668499362Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm STREAM id=0 off=1239 len=1237 fin=false
[2025-04-30T08:44:52.668506194Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.668509651Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.668511985Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.668516013Z TRACE quiche_apps::common] received 1237 bytes
[2025-04-30T08:44:52.668518267Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false)
[2025-04-30T08:44:52.668524218Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10835 out_len=1350 left=1323
[2025-04-30T08:44:52.668527304Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=5 pn=19 
[2025-04-30T08:44:52.668541570Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=3 blocks=[1..3] ecn_counts=None
[2025-04-30T08:44:52.668547622Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=103.674054ms latest_rtt=35.056064ms srtt=36.997414ms min_rtt=31.987204ms rttvar=10.678575ms cwnd=9450 ssthresh=9450 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 279899063 }) Rate { delivered: 620, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 16, last_sent_packet: 19, largest_acked: 16, rate_sample: RateSample { delivery_rate: 4820, is_app_limited: true, interval: 35.056064ms, delivered: 169, prior_delivered: 451, prior_time: Some(Instant { tv_sec: 424, tv_nsec: 212879329 }), send_elapsed: 0ns, ack_elapsed: 35.056064ms, rtt: 35.056064ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 319279, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.668582878Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.668589279Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.669532032Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.669539446Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=27f6687eac1d96ca522066a2bde977f39d71534e key_phase=false len=1259 pn=4 
[2025-04-30T08:44:52.669545407Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm STREAM id=0 off=2476 len=1237 fin=false
[2025-04-30T08:44:52.669551969Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.669555416Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.669557780Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.669561547Z TRACE quiche_apps::common] received 1237 bytes
[2025-04-30T08:44:52.669563751Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false)
[2025-04-30T08:44:52.669569582Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10835 out_len=1350 left=1323
[2025-04-30T08:44:52.669572648Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=5 pn=20 
[2025-04-30T08:44:52.669574982Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=3 blocks=[1..4] ecn_counts=None
[2025-04-30T08:44:52.669580823Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=102.640863ms latest_rtt=35.056064ms srtt=36.997414ms min_rtt=31.987204ms rttvar=10.678575ms cwnd=9450 ssthresh=9450 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 279899063 }) Rate { delivered: 620, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 16, last_sent_packet: 20, largest_acked: 16, rate_sample: RateSample { delivery_rate: 4820, is_app_limited: true, interval: 35.056064ms, delivered: 169, prior_delivered: 451, prior_time: Some(Instant { tv_sec: 424, tv_nsec: 212879329 }), send_elapsed: 0ns, ack_elapsed: 35.056064ms, rtt: 35.056064ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 319279, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.669620417Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.669626979Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.670581814Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.670589178Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=27f6687eac1d96ca522066a2bde977f39d71534e key_phase=false len=1259 pn=5 
[2025-04-30T08:44:52.670595580Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm STREAM id=0 off=3713 len=1237 fin=false
[2025-04-30T08:44:52.670602503Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 1280 bytes
[2025-04-30T08:44:52.670605949Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.670608284Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.670612301Z TRACE quiche_apps::common] received 1237 bytes
[2025-04-30T08:44:52.670614505Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false)
[2025-04-30T08:44:52.670620096Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10835 out_len=1350 left=1323
[2025-04-30T08:44:52.670623121Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=5 pn=21 
[2025-04-30T08:44:52.670625436Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=3 blocks=[1..5] ecn_counts=None
[2025-04-30T08:44:52.670631267Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=101.59041ms latest_rtt=35.056064ms srtt=36.997414ms min_rtt=31.987204ms rttvar=10.678575ms cwnd=9450 ssthresh=9450 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 279899063 }) Rate { delivered: 620, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 16, last_sent_packet: 21, largest_acked: 16, rate_sample: RateSample { delivery_rate: 4820, is_app_limited: true, interval: 35.056064ms, delivered: 169, prior_delivered: 451, prior_time: Some(Instant { tv_sec: 424, tv_nsec: 212879329 }), send_elapsed: 0ns, ack_elapsed: 35.056064ms, rtt: 35.056064ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 319279, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.670667204Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.670674047Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.670729070Z TRACE quiche_apps::client] got 213 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.670734449Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=27f6687eac1d96ca522066a2bde977f39d71534e key_phase=false len=192 pn=6 
[2025-04-30T08:44:52.670740010Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm STREAM id=0 off=4950 len=170 fin=false
[2025-04-30T08:44:52.670746362Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 213 bytes
[2025-04-30T08:44:52.670754717Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.670757092Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.670760839Z TRACE quiche_apps::common] received 170 bytes
[2025-04-30T08:44:52.670763023Z TRACE quiche_apps::common] stream 0 has 170 bytes (fin? false)
[2025-04-30T08:44:52.670768944Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10835 out_len=1350 left=1323
[2025-04-30T08:44:52.670771970Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=5 pn=22 
[2025-04-30T08:44:52.670774324Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm ACK delay=4 blocks=[1..6] ecn_counts=None
[2025-04-30T08:44:52.670779925Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=101.441752ms latest_rtt=35.056064ms srtt=36.997414ms min_rtt=31.987204ms rttvar=10.678575ms cwnd=9450 ssthresh=9450 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 279899063 }) Rate { delivered: 620, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 16, last_sent_packet: 22, largest_acked: 16, rate_sample: RateSample { delivery_rate: 4820, is_app_limited: true, interval: 35.056064ms, delivered: 169, prior_delivered: 451, prior_time: Some(Instant { tv_sec: 424, tv_nsec: 212879329 }), send_elapsed: 0ns, ack_elapsed: 35.056064ms, rtt: 35.056064ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 319279, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.670814890Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.670821362Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.670832292Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:49762
[2025-04-30T08:44:52.670837472Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx pkt Short dcid=27f6687eac1d96ca522066a2bde977f39d71534e key_phase=false len=22 pn=7 
[2025-04-30T08:44:52.670845216Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 rx frm STREAM id=0 off=5120 len=0 fin=true
[2025-04-30T08:44:52.670852751Z TRACE quiche_apps::client] 0.0.0.0:49762: processed 43 bytes
[2025-04-30T08:44:52.670856237Z TRACE quiche_apps::client] 0.0.0.0:49762: recv() would block
[2025-04-30T08:44:52.670858622Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.670863801Z TRACE quiche_apps::common] received 0 bytes
[2025-04-30T08:44:52.670866026Z TRACE quiche_apps::common] stream 0 has 0 bytes (fin? true)
[2025-04-30T08:44:52.670868230Z DEBUG quiche_apps::common] 1/1 responses received
[2025-04-30T08:44:52.670870714Z INFO  quiche_apps::common] 1/1 response(s) received in 929.39473ms, closing...
[2025-04-30T08:44:52.670876305Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10835 out_len=1350 left=1328
[2025-04-30T08:44:52.670879571Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx pkt Short dcid=54398ce0 key_phase=false len=10 pn=23 
[2025-04-30T08:44:52.670881945Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T08:44:52.670888488Z TRACE quiche::recovery::congestion::recovery] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 timer=105.697408ms latest_rtt=35.056064ms srtt=36.997414ms min_rtt=31.987204ms rttvar=10.678575ms cwnd=9450 ssthresh=9450 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 424, tv_nsec: 279899063 }) Rate { delivered: 620, delivered_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, first_sent_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, end_of_app_limited: 22, last_sent_packet: 23, largest_acked: 16, rate_sample: RateSample { delivery_rate: 4820, is_app_limited: true, interval: 35.056064ms, delivered: 169, prior_delivered: 451, prior_time: Some(Instant { tv_sec: 424, tv_nsec: 212879329 }), send_elapsed: 0ns, ack_elapsed: 35.056064ms, rtt: 35.056064ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 319279, last_update: Instant { tv_sec: 424, tv_nsec: 211483419 }, next_time: Instant { tv_sec: 424, tv_nsec: 212879329 }, 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=1.9574338205844317 w_max=13500 } 
[2025-04-30T08:44:52.670928102Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:49762 to 193.167.100.100:443
[2025-04-30T08:44:52.670934163Z TRACE quiche_apps::client] 0.0.0.0:49762 -> 193.167.100.100:443: done writing
[2025-04-30T08:44:52.911228759Z TRACE quiche_apps::client] timed out
[2025-04-30T08:44:52.911257633Z TRACE quiche] 0c18e0f7a2c399e24a73eeca8bc7f7de317e2437 draining timeout expired
[2025-04-30T08:44:52.911300393Z TRACE quiche_apps::client] done reading
[2025-04-30T08:44:52.911305122Z INFO  quiche_apps::client] connection closed, recv=18 sent=24 lost=6 retrans=0 sent_bytes=1621 recv_bytes=16428 lost_bytes=175 [local_addr=0.0.0.0:49762 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=18 sent=24 lost=6 retrans=0 rtt=36.997414ms min_rtt=Some(31.987204ms) rttvar=10.678575ms cwnd=9450 sent_bytes=1621 recv_bytes=16428 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=4820]