[2025-04-30T11:52:06.574682383Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T11:52:06.574977907Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:48955 with scid 72d217079e13434dd4ea253de7655934df251de6 [2025-04-30T11:52:06.575021659Z TRACE quiche::tls] 72d217079e13434dd4ea253de7655934df251de6 write message lvl=Initial len=266 [2025-04-30T11:52:06.575041156Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Initial version=1 dcid=a8b9323db01006404137b93daff9695b scid=72d217079e13434dd4ea253de7655934df251de6 len=270 pn=0 [2025-04-30T11:52:06.575044302Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm CRYPTO off=0 len=266 [2025-04-30T11:52:06.575058027Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=998.930369ms 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: 386, tv_nsec: 343643681 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 343643681 }, 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: 386, tv_nsec: 343643681 }, next_time: Instant { tv_sec: 386, tv_nsec: 343643681 }, 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-30T11:52:06.575139791Z TRACE quiche_apps::client] written 1200 [2025-04-30T11:52:06.615447316Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:06.615471321Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Initial version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 token= len=117 pn=0 [2025-04-30T11:52:06.615487031Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm ACK delay=125 blocks=[0..0] ecn_counts=None [2025-04-30T11:52:06.615493944Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 0 [2025-04-30T11:52:06.615500957Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=0 len=90 [2025-04-30T11:52:06.615623126Z TRACE quiche::tls] 72d217079e13434dd4ea253de7655934df251de6 set write secret lvl=Handshake [2025-04-30T11:52:06.615637112Z TRACE quiche::tls] 72d217079e13434dd4ea253de7655934df251de6 set read secret lvl=Handshake [2025-04-30T11:52:06.615673621Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1060 pn=0 [2025-04-30T11:52:06.615681065Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=0 len=1039 [2025-04-30T11:52:06.615700151Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:06.615705550Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:06.615708817Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:06.615735306Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Initial version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=1 [2025-04-30T11:52:06.615738913Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=33 blocks=[0..0] ecn_counts=None [2025-04-30T11:52:06.615748982Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=121.146944ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 384349324 }, next_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, 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-30T11:52:06.615779740Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=2 [2025-04-30T11:52:06.615783216Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=13 blocks=[0..0] ecn_counts=None [2025-04-30T11:52:06.615789508Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=121.106639ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 384349324 }, next_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, 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-30T11:52:06.615801921Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 dropped epoch 0 state [2025-04-30T11:52:06.615843940Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:06.615854430Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:06.616437213Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:06.616446841Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1215 pn=1 [2025-04-30T11:52:06.616454796Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=1039 len=1193 [2025-04-30T11:52:06.616468231Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:06.616472750Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:06.616475725Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:06.616485033Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=3 [2025-04-30T11:52:06.616488189Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=4 blocks=[0..1] ecn_counts=None [2025-04-30T11:52:06.616501714Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=120.655443ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 384349324 }, next_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, 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-30T11:52:06.616545276Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:06.616555335Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:06.617327172Z TRACE quiche_apps::client] got 1096 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:06.617332132Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1059 pn=2 [2025-04-30T11:52:06.617337932Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=2232 len=1037 [2025-04-30T11:52:06.617363751Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1096 bytes [2025-04-30T11:52:06.617370484Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:06.617372878Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:06.617381274Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=4 [2025-04-30T11:52:06.617383889Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=6 blocks=[0..2] ecn_counts=None [2025-04-30T11:52:06.617390501Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=119.766826ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 384349324 }, next_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, 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-30T11:52:06.617425066Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:06.617432620Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:06.737595462Z TRACE quiche_apps::client] timed out [2025-04-30T11:52:06.737617032Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 loss detection timeout expired [2025-04-30T11:52:06.737622753Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=242.853499ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 384349324 }, next_time: Instant { tv_sec: 386, tv_nsec: 384349364 }, 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-30T11:52:06.737644483Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:06.737674871Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=7 pn=5 [2025-04-30T11:52:06.737678988Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=15042 blocks=[0..2] ecn_counts=None [2025-04-30T11:52:06.737684328Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm PING mtu_probe=None [2025-04-30T11:52:06.737701481Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=242.812784ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=61 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 61, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 506308124 }, next_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, max_datagram_size: 1350, last_packet_size: Some(61), 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-30T11:52:06.737785017Z TRACE quiche_apps::client] written 61 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:06.737796278Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:06.981070251Z TRACE quiche_apps::client] timed out [2025-04-30T11:52:06.981096610Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 loss detection timeout expired [2025-04-30T11:52:06.981102211Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=242.272386ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=61 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 61, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 506308124 }, next_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, max_datagram_size: 1350, last_packet_size: Some(61), 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-30T11:52:06.981134401Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:06.981164327Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=9 pn=6 [2025-04-30T11:52:06.981167854Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=45478 blocks=[0..2] ecn_counts=None [2025-04-30T11:52:06.981172833Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm PING mtu_probe=None [2025-04-30T11:52:06.981190245Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=485.675391ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=124 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 749798232 }, next_time: Instant { tv_sec: 386, tv_nsec: 749798232 }, max_datagram_size: 1350, last_packet_size: Some(63), 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-30T11:52:06.981269935Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:06.981284633Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=9 pn=7 [2025-04-30T11:52:06.981289562Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=45494 blocks=[0..2] ecn_counts=None [2025-04-30T11:52:06.981293810Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm PING mtu_probe=None [2025-04-30T11:52:06.981303879Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=485.694365ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 749798232 }, next_time: Instant { tv_sec: 386, tv_nsec: 749798232 }, max_datagram_size: 1350, last_packet_size: Some(63), 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-30T11:52:06.981367859Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:06.981377747Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.467916700Z TRACE quiche_apps::client] timed out [2025-04-30T11:52:07.467947678Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 loss detection timeout expired [2025-04-30T11:52:07.467954019Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=484.766062ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 416904, last_update: Instant { tv_sec: 386, tv_nsec: 749798232 }, next_time: Instant { tv_sec: 386, tv_nsec: 749798232 }, max_datagram_size: 1350, last_packet_size: Some(63), 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-30T11:52:07.467977303Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.468012239Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=9 pn=8 [2025-04-30T11:52:07.468017098Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=106334 blocks=[0..2] ecn_counts=None [2025-04-30T11:52:07.468022648Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm PING mtu_probe=None [2025-04-30T11:52:07.468039931Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=971.392658ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=250 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 416904, last_update: Instant { tv_sec: 387, tv_nsec: 236642917 }, next_time: Instant { tv_sec: 387, tv_nsec: 236642917 }, max_datagram_size: 1350, last_packet_size: Some(63), 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-30T11:52:07.468143345Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.468156740Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=9 pn=9 [2025-04-30T11:52:07.468160377Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=106353 blocks=[0..2] ecn_counts=None [2025-04-30T11:52:07.468163973Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm PING mtu_probe=None [2025-04-30T11:52:07.468171427Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=971.422154ms latest_rtt=40.476863ms srtt=40.476863ms min_rtt=40.476863ms rttvar=20.238431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=313 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, first_sent_time: Instant { tv_sec: 386, tv_nsec: 506308124 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8226, is_app_limited: true, interval: 40.476863ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 343643681 }), send_elapsed: 0ns, ack_elapsed: 40.476863ms, rtt: 40.476863ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 416904, last_update: Instant { tv_sec: 387, tv_nsec: 236642917 }, next_time: Instant { tv_sec: 387, tv_nsec: 236642917 }, max_datagram_size: 1350, last_packet_size: Some(63), 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-30T11:52:07.468216592Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.468225859Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.501536651Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.501561898Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1215 pn=3 [2025-04-30T11:52:07.501576786Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm ACK delay=0 blocks=[8..9] ecn_counts=None [2025-04-30T11:52:07.501583499Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 8 [2025-04-30T11:52:07.501587546Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 9 [2025-04-30T11:52:07.501593778Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet 5 lost on epoch 1 [2025-04-30T11:52:07.501596994Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet 6 lost on epoch 1 [2025-04-30T11:52:07.501600731Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet 7 lost on epoch 1 [2025-04-30T11:52:07.501619717Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=3269 len=1188 [2025-04-30T11:52:07.501649753Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.501655514Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.501658870Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.501672556Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=10 [2025-04-30T11:52:07.501691572Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=14 blocks=[3..3] ecn_counts=None [2025-04-30T11:52:07.501702312Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=33.568265ms srtt=39.613288ms min_rtt=33.568265ms rttvar=16.905972ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 270211182 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 387, tv_nsec: 236642917 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 236642917 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 9, rate_sample: RateSample { delivery_rate: 164, is_app_limited: true, interval: 763.903058ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 506308124 }), send_elapsed: 730.334793ms, ack_elapsed: 763.903058ms, rtt: 33.568265ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 298195, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 236642917 }, max_datagram_size: 1350, last_packet_size: None, iv: 422.542µ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-30T11:52:07.501762324Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.501768897Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.502539031Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.502551785Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1215 pn=4 [2025-04-30T11:52:07.502559760Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=4457 len=1193 [2025-04-30T11:52:07.502573906Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.502578264Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.502580769Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.502589165Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=11 [2025-04-30T11:52:07.502592050Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=4 blocks=[3..4] ecn_counts=None [2025-04-30T11:52:07.502623489Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=33.568265ms srtt=39.613288ms min_rtt=33.568265ms rttvar=16.905972ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 270211182 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 9, last_sent_packet: 11, largest_acked: 9, rate_sample: RateSample { delivery_rate: 164, is_app_limited: true, interval: 763.903058ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 506308124 }), send_elapsed: 730.334793ms, ack_elapsed: 763.903058ms, rtt: 33.568265ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 298195, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.502667131Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.502672882Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.503524599Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.503535210Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1215 pn=5 [2025-04-30T11:52:07.503542112Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=5650 len=1193 [2025-04-30T11:52:07.503553504Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.503557261Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.503559675Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.503567680Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=12 [2025-04-30T11:52:07.503570485Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=4 blocks=[3..5] ecn_counts=None [2025-04-30T11:52:07.503577158Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=33.568265ms srtt=39.613288ms min_rtt=33.568265ms rttvar=16.905972ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 270211182 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 9, last_sent_packet: 12, largest_acked: 9, rate_sample: RateSample { delivery_rate: 164, is_app_limited: true, interval: 763.903058ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 506308124 }), send_elapsed: 730.334793ms, ack_elapsed: 763.903058ms, rtt: 33.568265ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 298195, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.503611703Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.503616392Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.504546006Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.504556505Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1215 pn=6 [2025-04-30T11:52:07.504562997Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=6843 len=1193 [2025-04-30T11:52:07.504575150Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.504578777Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.504581181Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.504588926Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=13 [2025-04-30T11:52:07.504591581Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=4 blocks=[3..6] ecn_counts=None [2025-04-30T11:52:07.504598023Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=33.568265ms srtt=39.613288ms min_rtt=33.568265ms rttvar=16.905972ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 270211182 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 9, last_sent_packet: 13, largest_acked: 9, rate_sample: RateSample { delivery_rate: 164, is_app_limited: true, interval: 763.903058ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 506308124 }), send_elapsed: 730.334793ms, ack_elapsed: 763.903058ms, rtt: 33.568265ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 298195, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.504649269Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.504656102Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.505571148Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.505582049Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=1215 pn=7 [2025-04-30T11:52:07.505588962Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=8036 len=1193 [2025-04-30T11:52:07.505599952Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.505603589Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.505605983Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.505613838Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=5 pn=14 [2025-04-30T11:52:07.505616614Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=4 blocks=[3..7] ecn_counts=None [2025-04-30T11:52:07.505623076Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=33.568265ms srtt=39.613288ms min_rtt=33.568265ms rttvar=16.905972ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 270211182 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 9, last_sent_packet: 14, largest_acked: 9, rate_sample: RateSample { delivery_rate: 164, is_app_limited: true, interval: 763.903058ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 506308124 }), send_elapsed: 730.334793ms, ack_elapsed: 763.903058ms, rtt: 33.568265ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 298195, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.505656338Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.505660726Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.506241706Z TRACE quiche_apps::client] got 810 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.506249561Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=773 pn=8 [2025-04-30T11:52:07.506256143Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=9229 len=751 [2025-04-30T11:52:07.506765618Z TRACE quiche::tls] 72d217079e13434dd4ea253de7655934df251de6 write message lvl=Handshake len=52 [2025-04-30T11:52:07.506770508Z TRACE quiche::tls] 72d217079e13434dd4ea253de7655934df251de6 set write secret lvl=OneRTT [2025-04-30T11:52:07.506780506Z TRACE quiche::tls] 72d217079e13434dd4ea253de7655934df251de6 set read secret lvl=OneRTT [2025-04-30T11:52:07.506795645Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 connection established: proto=Ok("hq-interop") cipher=Some(AES256_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(a8b9323db01006404137b93daff9695b), max_idle_timeout: 30000, stateless_reset_token: Some(75133789814393491662508906753963257424), max_udp_payload_size: 2048, initial_max_data: 1638000, initial_max_stream_data_bidi_local: 16380, initial_max_stream_data_bidi_remote: 1474200, initial_max_stream_data_uni: 16380, initial_max_streams_bidi: 100, initial_max_streams_uni: 3, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 8, initial_source_connection_id: Some(b23ebf6421ad4e13), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T11:52:07.506817315Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 810 bytes [2025-04-30T11:52:07.506821443Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.506823848Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.506832073Z DEBUG quiche_apps::common] sending HTTP request "GET /yawbsqcbwr\r\n" [2025-04-30T11:52:07.506892537Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Handshake version=1 dcid=b23ebf6421ad4e13 scid=72d217079e13434dd4ea253de7655934df251de6 len=62 pn=15 [2025-04-30T11:52:07.506896374Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=80 blocks=[3..8] ecn_counts=None [2025-04-30T11:52:07.506899680Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm CRYPTO off=0 len=52 [2025-04-30T11:52:07.506907224Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=107.215095ms latest_rtt=33.568265ms srtt=39.613288ms min_rtt=33.568265ms rttvar=16.905972ms cwnd=9450 ssthresh=9450 bytes_in_flight=116 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 9, rate_sample: RateSample { delivery_rate: 164, is_app_limited: true, interval: 763.903058ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 506308124 }), send_elapsed: 730.334793ms, ack_elapsed: 763.903058ms, rtt: 33.568265ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 298195, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.506920830Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=10694 out_len=1234 left=1208 [2025-04-30T11:52:07.506928243Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=302 pn=16 [2025-04-30T11:52:07.506935697Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[15, f4, 15, c7, e5, be, c5, 23, 1d, bd, 14, c8, d9, a1, 7f, 99, ce, 7a, ae, d8] reset_token=[c4, 00, a1, 5e, e3, 03, f8, 09, 32, b3, 87, 47, 02, e4, 7f, c1] [2025-04-30T11:52:07.506942590Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[ba, bc, cc, ee, cd, 7f, 71, b6, d0, fb, ba, fb, 52, b9, 3a, bd, 62, 02, 55, 3e] reset_token=[f9, b5, 89, 1f, e7, de, 11, ec, 9f, 6c, 8b, eb, cf, 80, 45, 32] [2025-04-30T11:52:07.506947570Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[da, 56, 0b, b5, 97, 18, 5a, b5, f0, 6a, be, 1b, 64, 03, a9, f9, f6, 00, 93, d2] reset_token=[f9, 37, 77, 23, 7f, 6d, f5, e5, 55, d3, 11, 45, b2, dc, 62, 68] [2025-04-30T11:52:07.506952589Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[5d, 6d, 7f, 98, 1a, 23, 01, 2c, d5, d7, f3, 10, 6e, 7b, 0b, 5f, 8a, 7d, f1, 41] reset_token=[8e, 52, 96, 78, 8a, d2, 79, a1, c8, dd, e0, 95, f1, 2f, 6d, 3d] [2025-04-30T11:52:07.506957489Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[7f, e3, e2, 27, 17, 56, 5a, ec, 8a, 03, 5d, b1, 2d, 42, 86, 22, 6d, ab, b2, 85] reset_token=[15, 08, 9b, 1b, 93, 1f, b6, 8b, 55, c2, 3a, ae, 1e, bb, e0, 03] [2025-04-30T11:52:07.506962388Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[15, e1, c6, 3b, 00, 3a, d1, 6a, d8, 8d, 5a, a5, 29, 79, d7, ec, df, c8, 26, 72] reset_token=[31, 83, 6b, b0, a5, 82, e4, 00, 1d, cf, 95, 9c, 3f, 0e, a9, 05] [2025-04-30T11:52:07.506967367Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[02, af, c2, 5d, d3, 67, ab, 4d, 06, 61, 46, b1, 6a, 75, 97, c0, 68, df, cd, d8] reset_token=[73, a1, 98, fc, 8c, 7a, 7d, 39, 04, dc, 1e, bc, ca, 06, ec, ba] [2025-04-30T11:52:07.506972386Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T11:52:07.506981043Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=107.141377ms latest_rtt=33.568265ms srtt=39.613288ms min_rtt=33.568265ms rttvar=16.905972ms cwnd=9450 ssthresh=9450 bytes_in_flight=444 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 9, rate_sample: RateSample { delivery_rate: 164, is_app_limited: true, interval: 763.903058ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 386, tv_nsec: 506308124 }), send_elapsed: 730.334793ms, ack_elapsed: 763.903058ms, rtt: 33.568265ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 298195, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.507018743Z TRACE quiche_apps::client] written 444 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.507024464Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.539540983Z TRACE quiche_apps::client] got 646 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.539575368Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Handshake version=1 dcid=72d217079e13434dd4ea253de7655934df251de6 scid=b23ebf6421ad4e13 len=22 pn=9 [2025-04-30T11:52:07.539589203Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm ACK delay=0 blocks=[8..15] ecn_counts=None [2025-04-30T11:52:07.539596437Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 10 [2025-04-30T11:52:07.539600415Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 11 [2025-04-30T11:52:07.539603190Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 12 [2025-04-30T11:52:07.539605885Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 13 [2025-04-30T11:52:07.539609101Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 14 [2025-04-30T11:52:07.539612257Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 15 [2025-04-30T11:52:07.539637404Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Short dcid=72d217079e13434dd4ea253de7655934df251de6 key_phase=false len=567 pn=0 [2025-04-30T11:52:07.539644948Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm CRYPTO off=0 len=546 [2025-04-30T11:52:07.539688319Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 646 bytes [2025-04-30T11:52:07.539694311Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.539697647Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.539709259Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=10588 out_len=1350 left=1319 [2025-04-30T11:52:07.539715711Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=5 pn=17 [2025-04-30T11:52:07.539719217Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=8 blocks=[0..0] ecn_counts=None [2025-04-30T11:52:07.539728154Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=85.157239ms latest_rtt=36.562729ms srtt=39.231968ms min_rtt=33.568265ms rttvar=13.442118ms cwnd=9450 ssthresh=9450 bytes_in_flight=328 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 575, delivered_time: Instant { tv_sec: 387, tv_nsec: 308224060 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 236642917 }, end_of_app_limited: 16, last_sent_packet: 17, largest_acked: 15, rate_sample: RateSample { delivery_rate: 1620, is_app_limited: true, interval: 71.581143ms, delivered: 116, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 387, tv_nsec: 236642917 }), send_elapsed: 0ns, ack_elapsed: 71.581143ms, rtt: 71.581143ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 301093, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.539792655Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.539800991Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.540463634Z TRACE quiche_apps::client] got 168 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.540473442Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Short dcid=72d217079e13434dd4ea253de7655934df251de6 key_phase=false len=147 pn=1 [2025-04-30T11:52:07.540487588Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm ACK delay=125 blocks=[16..16] ecn_counts=None [2025-04-30T11:52:07.540492187Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 packet newly acked 16 [2025-04-30T11:52:07.540496996Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm HANDSHAKE_DONE [2025-04-30T11:52:07.540502697Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 dropped epoch 1 state [2025-04-30T11:52:07.540509389Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm NEW_TOKEN len=37 [2025-04-30T11:52:07.540514349Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[59, 15, f4, 7a, db, 3a, 9b, 3e] reset_token=[a2, 54, 02, ea, c6, 7d, cb, 9d, 1c, e9, 8c, 70, 29, 67, 9f, ce] [2025-04-30T11:52:07.540522724Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[e3, 98, cc, 04, 07, 8c, a7, 69] reset_token=[76, b7, 80, f5, 9c, 4d, 63, 82, ae, 42, 45, 48, 01, 73, a9, 69] [2025-04-30T11:52:07.540527654Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[48, a3, 40, 9e, 7b, 31, 05, 31] reset_token=[15, ae, e6, e4, bc, 53, 3d, 7d, 65, fc, 23, ef, ea, 0c, b6, 73] [2025-04-30T11:52:07.540554774Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 168 bytes [2025-04-30T11:52:07.540558682Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.540561076Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.540567689Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=11128 out_len=1350 left=1319 [2025-04-30T11:52:07.540571045Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=5 pn=18 [2025-04-30T11:52:07.540573580Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=11 blocks=[0..1] ecn_counts=None [2025-04-30T11:52:07.540579952Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=37.464911ms srtt=38.886085ms min_rtt=33.568265ms rttvar=10.773352ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 903, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 17, last_sent_packet: 18, largest_acked: 16, rate_sample: RateSample { delivery_rate: 6202, is_app_limited: true, interval: 71.581143ms, delivered: 444, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 387, tv_nsec: 236642917 }), send_elapsed: 0ns, ack_elapsed: 71.581143ms, rtt: 71.581143ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 303771, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.540617182Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.540622381Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.542721438Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.542734282Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Short dcid=72d217079e13434dd4ea253de7655934df251de6 key_phase=false len=1231 pn=2 [2025-04-30T11:52:07.542743379Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm STREAM id=0 off=0 len=1210 fin=false [2025-04-30T11:52:07.542758327Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.542762856Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.542765771Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.542771612Z TRACE quiche_apps::common] received 1210 bytes [2025-04-30T11:52:07.542774918Z TRACE quiche_apps::common] stream 0 has 1210 bytes (fin? false) [2025-04-30T11:52:07.542783424Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=11128 out_len=1350 left=1319 [2025-04-30T11:52:07.542787682Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=5 pn=19 [2025-04-30T11:52:07.542790778Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=6 blocks=[0..2] ecn_counts=None [2025-04-30T11:52:07.542798643Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=37.464911ms srtt=38.886085ms min_rtt=33.568265ms rttvar=10.773352ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 903, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 17, last_sent_packet: 19, largest_acked: 16, rate_sample: RateSample { delivery_rate: 6202, is_app_limited: true, interval: 71.581143ms, delivered: 444, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 387, tv_nsec: 236642917 }), send_elapsed: 0ns, ack_elapsed: 71.581143ms, rtt: 71.581143ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 303771, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.542840722Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.542845822Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.543722847Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.543732655Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Short dcid=72d217079e13434dd4ea253de7655934df251de6 key_phase=false len=1231 pn=3 [2025-04-30T11:52:07.543739358Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm STREAM id=0 off=1210 len=1208 fin=false [2025-04-30T11:52:07.543746812Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.543750278Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.543752662Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.543756840Z TRACE quiche_apps::common] received 1208 bytes [2025-04-30T11:52:07.543759235Z TRACE quiche_apps::common] stream 0 has 1208 bytes (fin? false) [2025-04-30T11:52:07.543765597Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=11128 out_len=1350 left=1319 [2025-04-30T11:52:07.543768793Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=5 pn=20 [2025-04-30T11:52:07.543771177Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=4 blocks=[0..3] ecn_counts=None [2025-04-30T11:52:07.543777329Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=37.464911ms srtt=38.886085ms min_rtt=33.568265ms rttvar=10.773352ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 903, delivered_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, end_of_app_limited: 17, last_sent_packet: 20, largest_acked: 16, rate_sample: RateSample { delivery_rate: 6202, is_app_limited: true, interval: 71.581143ms, delivered: 444, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 387, tv_nsec: 236642917 }), send_elapsed: 0ns, ack_elapsed: 71.581143ms, rtt: 71.581143ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 303771, last_update: Instant { tv_sec: 387, tv_nsec: 270318513 }, next_time: Instant { tv_sec: 387, tv_nsec: 271661331 }, 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-30T11:52:07.543815270Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.543819438Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.572362916Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.572386150Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Short dcid=72d217079e13434dd4ea253de7655934df251de6 key_phase=false len=1231 pn=4 [2025-04-30T11:52:07.572400778Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm STREAM id=0 off=2418 len=1208 fin=false [2025-04-30T11:52:07.572418130Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.572422999Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.572426295Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.572433439Z TRACE quiche_apps::common] received 1208 bytes [2025-04-30T11:52:07.572436615Z TRACE quiche_apps::common] stream 0 has 1208 bytes (fin? false) [2025-04-30T11:52:07.572448036Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=11128 out_len=1350 left=1319 [2025-04-30T11:52:07.572453997Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=5 pn=21 [2025-04-30T11:52:07.572457173Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=8 blocks=[0..4] ecn_counts=None [2025-04-30T11:52:07.572468945Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=37.464911ms srtt=38.886085ms min_rtt=33.568265ms rttvar=10.773352ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 903, delivered_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, end_of_app_limited: 17, last_sent_packet: 21, largest_acked: 16, rate_sample: RateSample { delivery_rate: 6202, is_app_limited: true, interval: 71.581143ms, delivered: 444, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 387, tv_nsec: 236642917 }), send_elapsed: 0ns, ack_elapsed: 71.581143ms, rtt: 71.581143ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 303771, last_update: Instant { tv_sec: 387, tv_nsec: 341096658 }, next_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, 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-30T11:52:07.572528357Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.572533977Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.573363764Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.573376367Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Short dcid=72d217079e13434dd4ea253de7655934df251de6 key_phase=false len=1231 pn=5 [2025-04-30T11:52:07.573384563Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm STREAM id=0 off=3626 len=1208 fin=false [2025-04-30T11:52:07.573393560Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 1252 bytes [2025-04-30T11:52:07.573398048Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.573401003Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.573406053Z TRACE quiche_apps::common] received 1208 bytes [2025-04-30T11:52:07.573408898Z TRACE quiche_apps::common] stream 0 has 1208 bytes (fin? false) [2025-04-30T11:52:07.573416853Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=11128 out_len=1350 left=1319 [2025-04-30T11:52:07.573420811Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=5 pn=22 [2025-04-30T11:52:07.573423776Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm ACK delay=5 blocks=[0..5] ecn_counts=None [2025-04-30T11:52:07.573431360Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=none latest_rtt=37.464911ms srtt=38.886085ms min_rtt=33.568265ms rttvar=10.773352ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 308947400 }) Rate { delivered: 903, delivered_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, end_of_app_limited: 17, last_sent_packet: 22, largest_acked: 16, rate_sample: RateSample { delivery_rate: 6202, is_app_limited: true, interval: 71.581143ms, delivered: 444, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 387, tv_nsec: 236642917 }), send_elapsed: 0ns, ack_elapsed: 71.581143ms, rtt: 71.581143ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 303771, last_update: Instant { tv_sec: 387, tv_nsec: 341096658 }, next_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, 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-30T11:52:07.573470584Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.573475533Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.600296280Z TRACE quiche_apps::client] got 330 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.600318422Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx pkt Short dcid=72d217079e13434dd4ea253de7655934df251de6 key_phase=false len=309 pn=6 [2025-04-30T11:52:07.600331376Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 rx frm STREAM id=0 off=4834 len=286 fin=true [2025-04-30T11:52:07.600368044Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 330 bytes [2025-04-30T11:52:07.600373415Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.600376671Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.600386249Z TRACE quiche_apps::common] received 286 bytes [2025-04-30T11:52:07.600389214Z TRACE quiche_apps::common] stream 0 has 286 bytes (fin? true) [2025-04-30T11:52:07.600392591Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T11:52:07.600405575Z INFO quiche_apps::common] 1/1 response(s) received in 1.025259783s, closing... [2025-04-30T11:52:07.600416315Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=11128 out_len=1350 left=1324 [2025-04-30T11:52:07.600421906Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx pkt Short dcid=b23ebf6421ad4e13 key_phase=false len=10 pn=23 [2025-04-30T11:52:07.600425002Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T11:52:07.600436353Z TRACE quiche::recovery::congestion::recovery] 72d217079e13434dd4ea253de7655934df251de6 timer=106.954116ms latest_rtt=37.464911ms srtt=38.886085ms min_rtt=33.568265ms rttvar=10.773352ms cwnd=9450 ssthresh=9450 bytes_in_flight=36 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 387, tv_nsec: 402473593 }) Rate { delivered: 903, delivered_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, first_sent_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, end_of_app_limited: 22, last_sent_packet: 23, largest_acked: 16, rate_sample: RateSample { delivery_rate: 6202, is_app_limited: true, interval: 71.581143ms, delivered: 444, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 387, tv_nsec: 236642917 }), send_elapsed: 0ns, ack_elapsed: 71.581143ms, rtt: 71.581143ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 303771, last_update: Instant { tv_sec: 387, tv_nsec: 341096658 }, next_time: Instant { tv_sec: 387, tv_nsec: 341096658 }, 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-30T11:52:07.600493360Z TRACE quiche_apps::client] written 36 bytes from 0.0.0.0:48955 to 193.167.100.100:443 [2025-04-30T11:52:07.600498108Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.631369364Z TRACE quiche_apps::client] got 42 bytes from 193.167.100.100:443 to 0.0.0.0:48955 [2025-04-30T11:52:07.631385604Z TRACE quiche_apps::client] 0.0.0.0:48955: processed 42 bytes [2025-04-30T11:52:07.631392287Z TRACE quiche_apps::client] 0.0.0.0:48955: recv() would block [2025-04-30T11:52:07.631394981Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.631400402Z TRACE quiche_apps::client] 0.0.0.0:48955 -> 193.167.100.100:443: done writing [2025-04-30T11:52:07.846666632Z TRACE quiche_apps::client] timed out [2025-04-30T11:52:07.846699203Z TRACE quiche] 72d217079e13434dd4ea253de7655934df251de6 draining timeout expired [2025-04-30T11:52:07.846747464Z TRACE quiche_apps::client] done reading [2025-04-30T11:52:07.846752273Z INFO quiche_apps::client] connection closed, recv=18 sent=24 lost=6 retrans=0 sent_bytes=1844 recv_bytes=16822 lost_bytes=187 [local_addr=0.0.0.0:48955 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=18 sent=24 lost=6 retrans=0 rtt=38.886085ms min_rtt=Some(33.568265ms) rttvar=10.773352ms cwnd=9450 sent_bytes=1844 recv_bytes=16822 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=6202]