[2025-04-30T13:23:52.665553932Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T13:23:52.665842402Z INFO  quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:34867 with scid 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d
[2025-04-30T13:23:52.665884891Z TRACE quiche::tls] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d write message lvl=Initial len=266
[2025-04-30T13:23:52.665904207Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Initial version=1 dcid=09791b30da89decf88bafd657c027004 scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=270 pn=0 
[2025-04-30T13:23:52.665907373Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm CRYPTO off=0 len=266
[2025-04-30T13:23:52.665921720Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=998.929328ms 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: 463, tv_nsec: 33892310 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 33892310 }, 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: 463, tv_nsec: 33892310 }, next_time: Instant { tv_sec: 463, tv_nsec: 33892310 }, 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-30T13:23:52.666001670Z TRACE quiche_apps::client] written 1200
[2025-04-30T13:23:52.704200741Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:52.704216600Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Initial version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf token= len=116 pn=0 
[2025-04-30T13:23:52.704228773Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T13:23:52.704234674Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d packet newly acked 0
[2025-04-30T13:23:52.704240756Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=0 len=90
[2025-04-30T13:23:52.704347245Z TRACE quiche::tls] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d set write secret lvl=Handshake
[2025-04-30T13:23:52.704357474Z TRACE quiche::tls] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d set read secret lvl=Handshake
[2025-04-30T13:23:52.704387009Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1009 pn=0 
[2025-04-30T13:23:52.704394633Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=0 len=988
[2025-04-30T13:23:52.704413248Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:52.704419250Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:52.704422816Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:52.704439247Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Initial version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=1 
[2025-04-30T13:23:52.704443816Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=28 blocks=[0..0] ecn_counts=None
[2025-04-30T13:23:52.704452522Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=114.845945ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 72447597 }, next_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, 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-30T13:23:52.704489751Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=2 
[2025-04-30T13:23:52.704493348Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=12 blocks=[0..0] ecn_counts=None
[2025-04-30T13:23:52.704499710Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=114.798827ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 72447597 }, next_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, 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-30T13:23:52.704515550Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d dropped epoch 0 state
[2025-04-30T13:23:52.704557028Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:52.704568118Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:52.705164064Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:52.705174193Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1163 pn=1 
[2025-04-30T13:23:52.705182438Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=988 len=1141
[2025-04-30T13:23:52.705196154Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:52.705200673Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:52.705203838Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:52.705214078Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=3 
[2025-04-30T13:23:52.705217414Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=5 blocks=[0..1] ecn_counts=None
[2025-04-30T13:23:52.705231270Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=114.284654ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 72447597 }, next_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, 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-30T13:23:52.705278899Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:52.705289288Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:52.706136204Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:52.706143718Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1163 pn=2 
[2025-04-30T13:23:52.706149829Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=2129 len=1141
[2025-04-30T13:23:52.706160349Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:52.706163956Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:52.706166430Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:52.706174626Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=4 
[2025-04-30T13:23:52.706177281Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=3 blocks=[0..2] ecn_counts=None
[2025-04-30T13:23:52.706183412Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=113.332672ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 72447597 }, next_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, 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-30T13:23:52.706220802Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:52.706228917Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:52.820402616Z TRACE quiche_apps::client] timed out
[2025-04-30T13:23:52.820416301Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d loss detection timeout expired
[2025-04-30T13:23:52.820421010Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=230.164925ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 72447597 }, next_time: Instant { tv_sec: 463, tv_nsec: 72447637 }, 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-30T13:23:52.820439695Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:52.820457919Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=7 pn=5 
[2025-04-30T13:23:52.820461967Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=14289 blocks=[0..2] ecn_counts=None
[2025-04-30T13:23:52.820466615Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm PING mtu_probe=None
[2025-04-30T13:23:52.820478057Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=230.138145ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=61 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 61, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 188486397 }, next_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, 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-30T13:23:52.820537668Z TRACE quiche_apps::client] written 61 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:52.820549260Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.051835200Z TRACE quiche_apps::client] timed out
[2025-04-30T13:23:53.051849187Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d loss detection timeout expired
[2025-04-30T13:23:53.051853906Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=228.932791ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=61 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 61, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 188486397 }, next_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, 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-30T13:23:53.051881277Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.051900052Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=9 pn=6 
[2025-04-30T13:23:53.051904140Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=43219 blocks=[0..2] ecn_counts=None
[2025-04-30T13:23:53.051908869Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm PING mtu_probe=None
[2025-04-30T13:23:53.051920981Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=460.30812ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=124 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 419928400 }, next_time: Instant { tv_sec: 463, tv_nsec: 419928400 }, 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-30T13:23:53.052007022Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.052026559Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=9 pn=7 
[2025-04-30T13:23:53.052030666Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=43235 blocks=[0..2] ecn_counts=None
[2025-04-30T13:23:53.052034965Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm PING mtu_probe=None
[2025-04-30T13:23:53.052043751Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=460.314472ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 419928400 }, next_time: Instant { tv_sec: 463, tv_nsec: 419928400 }, 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-30T13:23:53.052095388Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.052102501Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.513595930Z TRACE quiche_apps::client] timed out
[2025-04-30T13:23:53.513615717Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d loss detection timeout expired
[2025-04-30T13:23:53.513621939Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=459.076794ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 419928400 }, next_time: Instant { tv_sec: 463, tv_nsec: 419928400 }, 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-30T13:23:53.513647677Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.513681470Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=9 pn=8 
[2025-04-30T13:23:53.513686209Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=100941 blocks=[0..2] ecn_counts=None
[2025-04-30T13:23:53.513692210Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm PING mtu_probe=None
[2025-04-30T13:23:53.513711707Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=920.6276ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=250 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 881696974 }, next_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, 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-30T13:23:53.513787298Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.513802346Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=9 pn=9 
[2025-04-30T13:23:53.513806304Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=100957 blocks=[0..2] ecn_counts=None
[2025-04-30T13:23:53.513810181Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm PING mtu_probe=None
[2025-04-30T13:23:53.513818366Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=920.658598ms latest_rtt=38.361805ms srtt=38.361805ms min_rtt=38.361805ms rttvar=19.180902ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=313 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 188486397 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8680, is_app_limited: true, interval: 38.361805ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 33892310 }), send_elapsed: 0ns, ack_elapsed: 38.361805ms, rtt: 38.361805ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 439890, last_update: Instant { tv_sec: 463, tv_nsec: 881696974 }, next_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, 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-30T13:23:53.513857049Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.513863591Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.545432311Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.545448541Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1163 pn=3 
[2025-04-30T13:23:53.545459783Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm ACK delay=0 blocks=[8..8] ecn_counts=None
[2025-04-30T13:23:53.545465483Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d packet newly acked 8
[2025-04-30T13:23:53.545471665Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d packet 5 lost on epoch 1
[2025-04-30T13:23:53.545475141Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d packet 6 lost on epoch 1
[2025-04-30T13:23:53.545478848Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d packet 7 lost on epoch 1
[2025-04-30T13:23:53.545491852Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=3270 len=1136
[2025-04-30T13:23:53.545513994Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.545519354Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.545522640Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.545534462Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=10 
[2025-04-30T13:23:53.545537939Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=10 blocks=[3..3] ecn_counts=None
[2025-04-30T13:23:53.545547106Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=69.902328ms latest_rtt=31.788872ms srtt=37.540188ms min_rtt=31.788872ms rttvar=16.028909ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 913485846 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 463, tv_nsec: 913485846 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 724.999449ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 188486397 }), send_elapsed: 693.210577ms, ack_elapsed: 724.999449ms, rtt: 31.788872ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314662, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, max_datagram_size: 1350, last_packet_size: None, iv: 400.43µ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-30T13:23:53.545603381Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.545609663Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.546394993Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.546407727Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1163 pn=4 
[2025-04-30T13:23:53.546416554Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=4406 len=1141
[2025-04-30T13:23:53.546430780Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.546435529Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.546438695Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.546449265Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=11 
[2025-04-30T13:23:53.546452731Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=5 blocks=[3..4] ecn_counts=None
[2025-04-30T13:23:53.546485312Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=68.963991ms latest_rtt=31.788872ms srtt=37.540188ms min_rtt=31.788872ms rttvar=16.028909ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 913485846 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 463, tv_nsec: 913485846 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, end_of_app_limited: 9, last_sent_packet: 11, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 724.999449ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 188486397 }), send_elapsed: 693.210577ms, ack_elapsed: 724.999449ms, rtt: 31.788872ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314662, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.546531309Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.546545244Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.547366612Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.547376992Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1163 pn=5 
[2025-04-30T13:23:53.547384095Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=5547 len=1141
[2025-04-30T13:23:53.547396508Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.547400365Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.547402860Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.547411136Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=12 
[2025-04-30T13:23:53.547413830Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=4 blocks=[3..5] ecn_counts=None
[2025-04-30T13:23:53.547420563Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=68.029041ms latest_rtt=31.788872ms srtt=37.540188ms min_rtt=31.788872ms rttvar=16.028909ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 913485846 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 463, tv_nsec: 913485846 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, end_of_app_limited: 9, last_sent_packet: 12, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 724.999449ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 188486397 }), send_elapsed: 693.210577ms, ack_elapsed: 724.999449ms, rtt: 31.788872ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314662, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.547456220Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.547461460Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.548349382Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.548359511Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1163 pn=6 
[2025-04-30T13:23:53.548366364Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=6688 len=1141
[2025-04-30T13:23:53.548377585Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.548381342Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.548383806Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.548392062Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=13 
[2025-04-30T13:23:53.548394687Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=4 blocks=[3..6] ecn_counts=None
[2025-04-30T13:23:53.548401149Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=67.048445ms latest_rtt=31.788872ms srtt=37.540188ms min_rtt=31.788872ms rttvar=16.028909ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 913485846 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 463, tv_nsec: 913485846 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, end_of_app_limited: 9, last_sent_packet: 13, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 724.999449ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 188486397 }), send_elapsed: 693.210577ms, ack_elapsed: 724.999449ms, rtt: 31.788872ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314662, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.548442356Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.548447977Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.549333925Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.549344024Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=1163 pn=7 
[2025-04-30T13:23:53.549350757Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=7829 len=1141
[2025-04-30T13:23:53.549363110Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.549366847Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.549369261Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.549377286Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=5 pn=14 
[2025-04-30T13:23:53.549379881Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=4 blocks=[3..7] ecn_counts=None
[2025-04-30T13:23:53.549386474Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=66.06311ms latest_rtt=31.788872ms srtt=37.540188ms min_rtt=31.788872ms rttvar=16.028909ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 913485846 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 463, tv_nsec: 913485846 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 881696974 }, end_of_app_limited: 9, last_sent_packet: 14, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 724.999449ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 188486397 }), send_elapsed: 693.210577ms, ack_elapsed: 724.999449ms, rtt: 31.788872ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314662, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.549421289Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.549426589Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.550259017Z TRACE quiche_apps::client] got 1129 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.550271540Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=970 pn=8 
[2025-04-30T13:23:53.550288151Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm CRYPTO off=8970 len=948
[2025-04-30T13:23:53.550802184Z TRACE quiche::tls] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d write message lvl=Handshake len=36
[2025-04-30T13:23:53.550806913Z TRACE quiche::tls] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d set write secret lvl=OneRTT
[2025-04-30T13:23:53.550816260Z TRACE quiche::tls] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d set read secret lvl=OneRTT
[2025-04-30T13:23:53.550830116Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d 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(09791b30da89decf88bafd657c027004), max_idle_timeout: 0, stateless_reset_token: None, max_udp_payload_size: 1472, initial_max_data: 65536, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 100, initial_max_streams_uni: 0, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 2, initial_source_connection_id: Some(275b9760c1c48faf), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T13:23:53.550852638Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Short dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d key_phase=false len=101 pn=0 
[2025-04-30T13:23:53.550859381Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[21, 6b, 55, e3, 7d, b7, f0, c5] reset_token=[84, d0, 96, a7, c9, a1, e1, 35, cb, 4f, bc, ee, b2, 1b, 4e, a5]
[2025-04-30T13:23:53.550866444Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[67, 56, 67, 9c, 80, 4d, ea, 16] reset_token=[d9, d8, 4b, 06, b9, 8d, 93, 58, 56, 75, b5, d5, e9, 27, 98, 44]
[2025-04-30T13:23:53.550871674Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[bd, b0, d9, 55, 91, fc, c1, f6] reset_token=[c8, 26, b8, 7b, 87, 81, 4d, 05, 96, 2c, e8, ff, 3e, 48, bd, de]
[2025-04-30T13:23:53.550878917Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1129 bytes
[2025-04-30T13:23:53.550885239Z TRACE quiche_apps::client] got 59 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.550888956Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Handshake version=1 dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d scid=275b9760c1c48faf len=22 pn=9 
[2025-04-30T13:23:53.550893805Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm ACK delay=0 blocks=[8..9] ecn_counts=None
[2025-04-30T13:23:53.550897071Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d packet newly acked 9
[2025-04-30T13:23:53.550905567Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 59 bytes
[2025-04-30T13:23:53.550909104Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.550911619Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.550920285Z DEBUG quiche_apps::common] sending HTTP request "GET /cnbaqnwtah\r\n"
[2025-04-30T13:23:53.551004553Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Handshake version=1 dcid=275b9760c1c48faf scid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d len=45 pn=15 
[2025-04-30T13:23:53.551011305Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=14 blocks=[3..9] ecn_counts=None
[2025-04-30T13:23:53.551014591Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm CRYPTO off=0 len=36
[2025-04-30T13:23:53.551022526Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=85.870227ms latest_rtt=37.231801ms srtt=37.501639ms min_rtt=31.788872ms rttvar=12.098777ms cwnd=9450 ssthresh=9450 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 950688293 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 9, rate_sample: RateSample { delivery_rate: 173, is_app_limited: true, interval: 724.999449ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 188486397 }), send_elapsed: 693.210577ms, ack_elapsed: 724.999449ms, rtt: 31.788872ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314986, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.551044347Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d pmtud probe status false hs_con=false hs_sent=false cwnd_avail=10728 out_len=1251 left=1220
[2025-04-30T13:23:53.551050749Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Short dcid=275b9760c1c48faf key_phase=false len=67 pn=16 
[2025-04-30T13:23:53.551053464Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=23 blocks=[0..0] ecn_counts=None
[2025-04-30T13:23:53.551056169Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[7a, ee, dd, 36, 89, 33, 33, 2c, fa, 3b, 15, f3, eb, b8, b4, 63, 1d, 7f, 21, b0] reset_token=[f9, d7, da, 10, f7, dd, b3, 2b, fb, 3c, 69, a6, 2e, b7, f7, 62]
[2025-04-30T13:23:53.551062952Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T13:23:53.551069244Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=85.82377ms latest_rtt=37.231801ms srtt=37.501639ms min_rtt=31.788872ms rttvar=12.098777ms cwnd=9450 ssthresh=9450 bytes_in_flight=192 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 950688293 }) Rate { delivered: 459, delivered_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 9, rate_sample: RateSample { delivery_rate: 173, is_app_limited: true, interval: 724.999449ms, delivered: 126, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 188486397 }), send_elapsed: 693.210577ms, ack_elapsed: 724.999449ms, rtt: 31.788872ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314986, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.551106884Z TRACE quiche_apps::client] written 192 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.551111613Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.581793199Z TRACE quiche_apps::client] got 44 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.581807797Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Short dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d key_phase=false len=23 pn=1 
[2025-04-30T13:23:53.581816153Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm ACK delay=0 blocks=[16..16] ecn_counts=None
[2025-04-30T13:23:53.581828285Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d packet newly acked 16
[2025-04-30T13:23:53.581833194Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm HANDSHAKE_DONE
[2025-04-30T13:23:53.581839045Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d dropped epoch 1 state
[2025-04-30T13:23:53.581855777Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 44 bytes
[2025-04-30T13:23:53.581864052Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.581869192Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.581881645Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10893 out_len=1350 left=1319
[2025-04-30T13:23:53.581887095Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Short dcid=275b9760c1c48faf key_phase=false len=5 pn=17 
[2025-04-30T13:23:53.581890421Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=9 blocks=[1..1] ecn_counts=None
[2025-04-30T13:23:53.581898376Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=none latest_rtt=34.962791ms srtt=37.184282ms min_rtt=31.788872ms rttvar=9.708794ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 950688293 }) Rate { delivered: 552, delivered_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, end_of_app_limited: 16, last_sent_packet: 17, largest_acked: 16, rate_sample: RateSample { delivery_rate: 2659, is_app_limited: true, interval: 34.962791ms, delivered: 93, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 914883683 }), send_elapsed: 0ns, ack_elapsed: 34.962791ms, rtt: 34.962791ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 317674, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.581944964Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.581953329Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.582852773Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.582865267Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Short dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d key_phase=false len=1179 pn=2 
[2025-04-30T13:23:53.582876077Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm STREAM id=0 off=0 len=1158 fin=false
[2025-04-30T13:23:53.582884883Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.582888751Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.582891255Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.582895994Z TRACE quiche_apps::common] received 1158 bytes
[2025-04-30T13:23:53.582898509Z TRACE quiche_apps::common] stream 0 has 1158 bytes (fin? false)
[2025-04-30T13:23:53.582905051Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10893 out_len=1350 left=1319
[2025-04-30T13:23:53.582908307Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Short dcid=275b9760c1c48faf key_phase=false len=5 pn=18 
[2025-04-30T13:23:53.582910772Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=5 blocks=[1..2] ecn_counts=None
[2025-04-30T13:23:53.582916863Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=none latest_rtt=34.962791ms srtt=37.184282ms min_rtt=31.788872ms rttvar=9.708794ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 950688293 }) Rate { delivered: 552, delivered_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, end_of_app_limited: 16, last_sent_packet: 18, largest_acked: 16, rate_sample: RateSample { delivery_rate: 2659, is_app_limited: true, interval: 34.962791ms, delivered: 93, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 914883683 }), send_elapsed: 0ns, ack_elapsed: 34.962791ms, rtt: 34.962791ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 317674, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.582980422Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.582990982Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.583823992Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.583830995Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Short dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d key_phase=false len=1179 pn=3 
[2025-04-30T13:23:53.583837757Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm STREAM id=0 off=1158 len=1156 fin=false
[2025-04-30T13:23:53.583845221Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.583848898Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.583851353Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.583855561Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T13:23:53.583857865Z TRACE quiche_apps::common] stream 0 has 1156 bytes (fin? false)
[2025-04-30T13:23:53.583864277Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10893 out_len=1350 left=1319
[2025-04-30T13:23:53.583867683Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Short dcid=275b9760c1c48faf key_phase=false len=5 pn=19 
[2025-04-30T13:23:53.583870158Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=4 blocks=[1..3] ecn_counts=None
[2025-04-30T13:23:53.583876450Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=none latest_rtt=34.962791ms srtt=37.184282ms min_rtt=31.788872ms rttvar=9.708794ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 950688293 }) Rate { delivered: 552, delivered_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, end_of_app_limited: 16, last_sent_packet: 19, largest_acked: 16, rate_sample: RateSample { delivery_rate: 2659, is_app_limited: true, interval: 34.962791ms, delivered: 93, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 914883683 }), send_elapsed: 0ns, ack_elapsed: 34.962791ms, rtt: 34.962791ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 317674, last_update: Instant { tv_sec: 463, tv_nsec: 913567368 }, next_time: Instant { tv_sec: 463, tv_nsec: 914883683 }, 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-30T13:23:53.583917336Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.583921544Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.605195571Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.605209838Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Short dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d key_phase=false len=1179 pn=4 
[2025-04-30T13:23:53.605219255Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm STREAM id=0 off=2314 len=1156 fin=false
[2025-04-30T13:23:53.605230026Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.605234855Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.605238081Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.605260553Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T13:23:53.605263769Z TRACE quiche_apps::common] stream 0 has 1156 bytes (fin? false)
[2025-04-30T13:23:53.605273447Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10893 out_len=1350 left=1319
[2025-04-30T13:23:53.605277936Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Short dcid=275b9760c1c48faf key_phase=false len=5 pn=20 
[2025-04-30T13:23:53.605281242Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=8 blocks=[1..4] ecn_counts=None
[2025-04-30T13:23:53.605290228Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=none latest_rtt=34.962791ms srtt=37.184282ms min_rtt=31.788872ms rttvar=9.708794ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 950688293 }) Rate { delivered: 552, delivered_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, end_of_app_limited: 16, last_sent_packet: 20, largest_acked: 16, rate_sample: RateSample { delivery_rate: 2659, is_app_limited: true, interval: 34.962791ms, delivered: 93, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 914883683 }), send_elapsed: 0ns, ack_elapsed: 34.962791ms, rtt: 34.962791ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 317674, last_update: Instant { tv_sec: 463, tv_nsec: 973309309 }, next_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, 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-30T13:23:53.605337717Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.605343248Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.606180886Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.606191125Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Short dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d key_phase=false len=1179 pn=5 
[2025-04-30T13:23:53.606197747Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm STREAM id=0 off=3470 len=1156 fin=false
[2025-04-30T13:23:53.606205031Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 1200 bytes
[2025-04-30T13:23:53.606208688Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.606211132Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.606215331Z TRACE quiche_apps::common] received 1156 bytes
[2025-04-30T13:23:53.606222494Z TRACE quiche_apps::common] stream 0 has 1156 bytes (fin? false)
[2025-04-30T13:23:53.606229197Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10893 out_len=1350 left=1319
[2025-04-30T13:23:53.606232492Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Short dcid=275b9760c1c48faf key_phase=false len=5 pn=21 
[2025-04-30T13:23:53.606234967Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm ACK delay=4 blocks=[1..5] ecn_counts=None
[2025-04-30T13:23:53.606241690Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=none latest_rtt=34.962791ms srtt=37.184282ms min_rtt=31.788872ms rttvar=9.708794ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 463, tv_nsec: 950688293 }) Rate { delivered: 552, delivered_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, end_of_app_limited: 16, last_sent_packet: 21, largest_acked: 16, rate_sample: RateSample { delivery_rate: 2659, is_app_limited: true, interval: 34.962791ms, delivered: 93, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 914883683 }), send_elapsed: 0ns, ack_elapsed: 34.962791ms, rtt: 34.962791ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 317674, last_update: Instant { tv_sec: 463, tv_nsec: 973309309 }, next_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, 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-30T13:23:53.606276585Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.606280663Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.606612755Z TRACE quiche_apps::client] got 538 bytes from 193.167.100.100:443 to 0.0.0.0:34867
[2025-04-30T13:23:53.606620209Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx pkt Short dcid=43409ea3b1c686d7093887e99c8e4ada6d1a6b5d key_phase=false len=517 pn=6 
[2025-04-30T13:23:53.606626370Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d rx frm STREAM id=0 off=4626 len=494 fin=true
[2025-04-30T13:23:53.606633764Z TRACE quiche_apps::client] 0.0.0.0:34867: processed 538 bytes
[2025-04-30T13:23:53.606637491Z TRACE quiche_apps::client] 0.0.0.0:34867: recv() would block
[2025-04-30T13:23:53.606639895Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.606645205Z TRACE quiche_apps::common] received 494 bytes
[2025-04-30T13:23:53.606647489Z TRACE quiche_apps::common] stream 0 has 494 bytes (fin? true)
[2025-04-30T13:23:53.606649874Z DEBUG quiche_apps::common] 1/1 responses received
[2025-04-30T13:23:53.606652269Z INFO  quiche_apps::common] 1/1 response(s) received in 940.641601ms, closing...
[2025-04-30T13:23:53.606658721Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10893 out_len=1350 left=1324
[2025-04-30T13:23:53.606662337Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx pkt Short dcid=275b9760c1c48faf key_phase=false len=10 pn=22 
[2025-04-30T13:23:53.606664802Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T13:23:53.606671795Z TRACE quiche::recovery::congestion::recovery] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d timer=101.003758ms latest_rtt=34.962791ms srtt=37.184282ms min_rtt=31.788872ms rttvar=9.708794ms cwnd=9450 ssthresh=9450 bytes_in_flight=36 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 464, tv_nsec: 6348171 }) Rate { delivered: 552, delivered_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, first_sent_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, end_of_app_limited: 21, last_sent_packet: 22, largest_acked: 16, rate_sample: RateSample { delivery_rate: 2659, is_app_limited: true, interval: 34.962791ms, delivered: 93, prior_delivered: 459, prior_time: Some(Instant { tv_sec: 463, tv_nsec: 914883683 }), send_elapsed: 0ns, ack_elapsed: 34.962791ms, rtt: 34.962791ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 317674, last_update: Instant { tv_sec: 463, tv_nsec: 973309309 }, next_time: Instant { tv_sec: 463, tv_nsec: 973309309 }, 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-30T13:23:53.606712762Z TRACE quiche_apps::client] written 36 bytes from 0.0.0.0:34867 to 193.167.100.100:443
[2025-04-30T13:23:53.606716579Z TRACE quiche_apps::client] 0.0.0.0:34867 -> 193.167.100.100:443: done writing
[2025-04-30T13:23:53.834996755Z TRACE quiche_apps::client] timed out
[2025-04-30T13:23:53.835010691Z TRACE quiche] 43409ea3b1c686d7093887e99c8e4ada6d1a6b5d draining timeout expired
[2025-04-30T13:23:53.835038443Z TRACE quiche_apps::client] done reading
[2025-04-30T13:23:53.835042440Z INFO  quiche_apps::client] connection closed, recv=18 sent=23 lost=6 retrans=0 sent_bytes=1561 recv_bytes=16170 lost_bytes=187 [local_addr=0.0.0.0:34867 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=18 sent=23 lost=6 retrans=0 rtt=37.184282ms min_rtt=Some(31.788872ms) rttvar=9.708794ms cwnd=9450 sent_bytes=1561 recv_bytes=16170 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=2659]