[2025-04-30T21:44:04.960762096Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T21:44:04.961058596Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:43560 with scid e7ef31ecc042080670c045be1e01f242d2a4bc8e [2025-04-30T21:44:04.961098591Z TRACE quiche::tls] e7ef31ecc042080670c045be1e01f242d2a4bc8e write message lvl=Initial len=266 [2025-04-30T21:44:04.961117526Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Initial version=1 dcid=99565820911dfe398571fdf05542cdcb scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=270 pn=0 [2025-04-30T21:44:04.961120822Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm CRYPTO off=0 len=266 [2025-04-30T21:44:04.961134297Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=998.931222ms 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: 376, tv_nsec: 748859 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 748859 }, 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: 376, tv_nsec: 748859 }, next_time: Instant { tv_sec: 376, tv_nsec: 748859 }, 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-30T21:44:04.961194248Z TRACE quiche_apps::client] written 1200 [2025-04-30T21:44:05.001229028Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.001247001Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Initial version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 token= len=117 pn=0 [2025-04-30T21:44:05.001260386Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm ACK delay=1713 blocks=[0..0] ecn_counts=None [2025-04-30T21:44:05.001266668Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e packet newly acked 0 [2025-04-30T21:44:05.001272849Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=0 len=90 [2025-04-30T21:44:05.001404564Z TRACE quiche::tls] e7ef31ecc042080670c045be1e01f242d2a4bc8e set write secret lvl=Handshake [2025-04-30T21:44:05.001417718Z TRACE quiche::tls] e7ef31ecc042080670c045be1e01f242d2a4bc8e set read secret lvl=Handshake [2025-04-30T21:44:05.001448876Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1024 pn=0 [2025-04-30T21:44:05.001456861Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=0 len=1003 [2025-04-30T21:44:05.001479242Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.001486376Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.001489662Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.001506824Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Initial version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=1 [2025-04-30T21:44:05.001510380Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=32 blocks=[0..0] ecn_counts=None [2025-04-30T21:44:05.001518786Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=120.255264ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 41154487 }, next_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, 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-30T21:44:05.001546117Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=2 [2025-04-30T21:44:05.001549613Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=12 blocks=[0..0] ecn_counts=None [2025-04-30T21:44:05.001556045Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=120.218115ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 41154487 }, next_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, 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-30T21:44:05.001568669Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e dropped epoch 0 state [2025-04-30T21:44:05.001605267Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.001611849Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.002213957Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.002219938Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1187 pn=1 [2025-04-30T21:44:05.002227773Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=1003 len=1165 [2025-04-30T21:44:05.002240927Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.002245526Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.002248501Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.002258189Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=3 [2025-04-30T21:44:05.002261385Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=4 blocks=[0..1] ecn_counts=None [2025-04-30T21:44:05.002274650Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=119.755506ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 41154487 }, next_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, 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-30T21:44:05.002314153Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.002336254Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.003209105Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.003213994Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1187 pn=2 [2025-04-30T21:44:05.003220566Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=2168 len=1165 [2025-04-30T21:44:05.003231166Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.003234843Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.003237197Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.003245322Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=4 [2025-04-30T21:44:05.003247877Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=3 blocks=[0..2] ecn_counts=None [2025-04-30T21:44:05.003254018Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=118.776288ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 41154487 }, next_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, 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-30T21:44:05.003285757Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.003294994Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.122475789Z TRACE quiche_apps::client] timed out [2025-04-30T21:44:05.122506496Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e loss detection timeout expired [2025-04-30T21:44:05.122512127Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=241.054619ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, end_of_app_limited: 1, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 41154487 }, next_time: Instant { tv_sec: 376, tv_nsec: 41154537 }, 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-30T21:44:05.122534959Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.122568912Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=7 pn=5 [2025-04-30T21:44:05.122573270Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=14919 blocks=[0..2] ecn_counts=None [2025-04-30T21:44:05.122579081Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm PING mtu_probe=None [2025-04-30T21:44:05.122596533Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=241.010718ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=69 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 69, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 162227726 }, next_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, max_datagram_size: 1350, last_packet_size: Some(69), 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-30T21:44:05.122689977Z TRACE quiche_apps::client] written 69 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.122698413Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.364000840Z TRACE quiche_apps::client] timed out [2025-04-30T21:44:05.364029253Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e loss detection timeout expired [2025-04-30T21:44:05.364035374Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=240.633579ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=69 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 69, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 162227726 }, next_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, max_datagram_size: 1350, last_packet_size: Some(69), 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-30T21:44:05.364075399Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.364111426Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=9 pn=6 [2025-04-30T21:44:05.364116114Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=45111 blocks=[0..2] ecn_counts=None [2025-04-30T21:44:05.364122025Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm PING mtu_probe=None [2025-04-30T21:44:05.364141722Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=482.069594ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=140 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 71, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 403769137 }, next_time: Instant { tv_sec: 376, tv_nsec: 403769137 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T21:44:05.364228833Z TRACE quiche_apps::client] written 71 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.364243340Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=9 pn=7 [2025-04-30T21:44:05.364247098Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=45128 blocks=[0..2] ecn_counts=None [2025-04-30T21:44:05.364250925Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm PING mtu_probe=None [2025-04-30T21:44:05.364258448Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=482.101825ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=211 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 142, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 403769137 }, next_time: Instant { tv_sec: 376, tv_nsec: 403769137 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T21:44:05.364303623Z TRACE quiche_apps::client] written 71 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.364310115Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.847825194Z TRACE quiche_apps::client] timed out [2025-04-30T21:44:05.847843207Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e loss detection timeout expired [2025-04-30T21:44:05.847848287Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=480.636583ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=211 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 142, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 403769137 }, next_time: Instant { tv_sec: 376, tv_nsec: 403769137 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T21:44:05.847868615Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.847897959Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=9 pn=8 [2025-04-30T21:44:05.847902127Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=105585 blocks=[0..2] ecn_counts=None [2025-04-30T21:44:05.847906856Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm PING mtu_probe=None [2025-04-30T21:44:05.847922545Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=964.20448ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=282 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 71, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 887559348 }, next_time: Instant { tv_sec: 376, tv_nsec: 887559348 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T21:44:05.848004337Z TRACE quiche_apps::client] written 71 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.848020897Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=9 pn=9 [2025-04-30T21:44:05.848025486Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=105600 blocks=[0..2] ecn_counts=None [2025-04-30T21:44:05.848030876Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm PING mtu_probe=None [2025-04-30T21:44:05.848038320Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=964.223375ms latest_rtt=40.177113ms srtt=40.177113ms min_rtt=40.177113ms rttvar=20.088556ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=353 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 162227726 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8288, is_app_limited: true, interval: 40.177113ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 748859 }), send_elapsed: 0ns, ack_elapsed: 40.177113ms, rtt: 40.177113ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 142, rate: 420015, last_update: Instant { tv_sec: 376, tv_nsec: 887559348 }, next_time: Instant { tv_sec: 376, tv_nsec: 887559348 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T21:44:05.848074236Z TRACE quiche_apps::client] written 71 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.848081891Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.881489813Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.881509310Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1187 pn=3 [2025-04-30T21:44:05.881521111Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm ACK delay=944 blocks=[8..9] ecn_counts=None [2025-04-30T21:44:05.881526812Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e packet newly acked 8 [2025-04-30T21:44:05.881529718Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e packet newly acked 9 [2025-04-30T21:44:05.881534657Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e packet 5 lost on epoch 1 [2025-04-30T21:44:05.881537232Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e packet 6 lost on epoch 1 [2025-04-30T21:44:05.881540087Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e packet 7 lost on epoch 1 [2025-04-30T21:44:05.881545557Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=3333 len=1159 [2025-04-30T21:44:05.881569732Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.881574240Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.881576965Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.881588477Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=10 [2025-04-30T21:44:05.881597904Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=10 blocks=[3..3] ecn_counts=None [2025-04-30T21:44:05.881605939Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=none latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 921187409 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 887559348 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 887559348 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 887559348 }, max_datagram_size: 1350, last_packet_size: None, iv: 473.136µ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-30T21:44:05.881648809Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.881653988Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.882476145Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.882486685Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1187 pn=4 [2025-04-30T21:44:05.882494018Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=4492 len=1165 [2025-04-30T21:44:05.882529063Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.882533111Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.882535555Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.882544743Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=11 [2025-04-30T21:44:05.882547548Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=7 blocks=[3..4] ecn_counts=None [2025-04-30T21:44:05.882554751Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=none latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 921187409 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 9, last_sent_packet: 11, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.882593924Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.882598873Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.883483676Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.883494296Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1187 pn=5 [2025-04-30T21:44:05.883501519Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=5657 len=1165 [2025-04-30T21:44:05.883513391Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.883517158Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.883519563Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.883527958Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=12 [2025-04-30T21:44:05.883530674Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=4 blocks=[3..5] ecn_counts=None [2025-04-30T21:44:05.883537546Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=none latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 921187409 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 9, last_sent_packet: 12, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.883571690Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.883575998Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.884492289Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.884502558Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1187 pn=6 [2025-04-30T21:44:05.884509551Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=6822 len=1165 [2025-04-30T21:44:05.884521984Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.884525681Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.884528106Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.884536281Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=13 [2025-04-30T21:44:05.884538886Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=4 blocks=[3..6] ecn_counts=None [2025-04-30T21:44:05.884550868Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=none latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 921187409 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 9, last_sent_packet: 13, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.884585262Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.884589750Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.885502456Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.885513305Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=1187 pn=7 [2025-04-30T21:44:05.885520148Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=7987 len=1165 [2025-04-30T21:44:05.885531419Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.885535056Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.885537461Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.885545616Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=5 pn=14 [2025-04-30T21:44:05.885548241Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=4 blocks=[3..7] ecn_counts=None [2025-04-30T21:44:05.885554793Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=none latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 921187409 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 9, last_sent_packet: 14, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.885594116Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.885599085Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.886205451Z TRACE quiche_apps::client] got 852 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.886213135Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Handshake version=1 dcid=e7ef31ecc042080670c045be1e01f242d2a4bc8e scid=11434ddac47c5ea004b3f4ed3270d0d4 len=807 pn=8 [2025-04-30T21:44:05.886219757Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm CRYPTO off=9152 len=785 [2025-04-30T21:44:05.886726939Z TRACE quiche::tls] e7ef31ecc042080670c045be1e01f242d2a4bc8e write message lvl=Handshake len=36 [2025-04-30T21:44:05.886733401Z TRACE quiche::tls] e7ef31ecc042080670c045be1e01f242d2a4bc8e set write secret lvl=OneRTT [2025-04-30T21:44:05.886742228Z TRACE quiche::tls] e7ef31ecc042080670c045be1e01f242d2a4bc8e set read secret lvl=OneRTT [2025-04-30T21:44:05.886755663Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e 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(99565820911dfe398571fdf05542cdcb), max_idle_timeout: 300000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 3750000, initial_max_stream_data_bidi_local: 3750000, initial_max_stream_data_bidi_remote: 3750000, initial_max_stream_data_uni: 3750000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 3, initial_source_connection_id: Some(11434ddac47c5ea004b3f4ed3270d0d4), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T21:44:05.886775930Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 852 bytes [2025-04-30T21:44:05.886780138Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.886782543Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.886790588Z DEBUG quiche_apps::common] sending HTTP request "GET /ttoyrpjzso\r\n" [2025-04-30T21:44:05.886851751Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Handshake version=1 dcid=11434ddac47c5ea004b3f4ed3270d0d4 scid=e7ef31ecc042080670c045be1e01f242d2a4bc8e len=46 pn=15 [2025-04-30T21:44:05.886855669Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=79 blocks=[3..8] ecn_counts=None [2025-04-30T21:44:05.886858995Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm CRYPTO off=0 len=36 [2025-04-30T21:44:05.886866779Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=106.150067ms latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=108 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 960019986 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.886886175Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=false hs_sent=false cwnd_avail=10726 out_len=1242 left=1208 [2025-04-30T21:44:05.886892807Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=11434ddac47c5ea004b3f4ed3270d0d4 key_phase=false len=102 pn=16 [2025-04-30T21:44:05.886895342Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[33, 74, ba, d6, 35, 23, af, bb, 5f, c2, b4, 0e, f5, 5c, 28, 6e, e0, 62, b0, 48] reset_token=[b9, 19, e9, c3, 58, 2d, a7, 19, e4, 82, 50, b6, 86, 39, bd, a7] [2025-04-30T21:44:05.886901734Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[9d, 3d, d8, b6, 21, 74, 7a, 8c, 27, 1b, e7, 06, 01, 27, f5, 40, 07, ae, b0, 20] reset_token=[56, cc, af, 6b, c4, 33, 7e, 1e, 9e, 09, fc, 94, 26, 8d, 6d, 20] [2025-04-30T21:44:05.886907214Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T21:44:05.886914047Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=106.102919ms latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=244 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 960019986 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.886951747Z TRACE quiche_apps::client] written 244 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.886956946Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.920035517Z TRACE quiche_apps::client] got 1452 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.920052449Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Short dcid=3374bad63523afbb5fc2b40ef55c286ee062b048 key_phase=false len=1431 pn=0 [2025-04-30T21:44:05.920061556Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e path ID 0 now see SCID with seq num 1 [2025-04-30T21:44:05.920066766Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm PING mtu_probe=None [2025-04-30T21:44:05.920076834Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm PADDING len=1413 [2025-04-30T21:44:05.920087955Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1452 bytes [2025-04-30T21:44:05.920095990Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.920101860Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.920116518Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=false hs_sent=false cwnd_avail=10454 out_len=1350 left=1311 [2025-04-30T21:44:05.920124543Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=11434ddac47c5ea004b3f4ed3270d0d4 key_phase=false len=5 pn=17 [2025-04-30T21:44:05.920130073Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=8 blocks=[0..0] ecn_counts=None [2025-04-30T21:44:05.920155560Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=72.860224ms latest_rtt=33.628061ms srtt=39.35848ms min_rtt=33.628061ms rttvar=16.70368ms cwnd=9450 ssthresh=9450 bytes_in_flight=244 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 960019986 }) Rate { delivered: 475, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 15, last_sent_packet: 17, largest_acked: 9, rate_sample: RateSample { delivery_rate: 187, is_app_limited: true, interval: 758.959683ms, delivered: 142, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 162227726 }), send_elapsed: 725.331622ms, ack_elapsed: 758.959683ms, rtt: 33.628061ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 300125, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.920216674Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.920222996Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.920237873Z TRACE quiche_apps::client] got 155 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.920246008Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Short dcid=3374bad63523afbb5fc2b40ef55c286ee062b048 key_phase=false len=134 pn=1 [2025-04-30T21:44:05.920257680Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm ACK delay=100 blocks=[16..16] ecn_counts=None [2025-04-30T21:44:05.920265254Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e packet newly acked 16 [2025-04-30T21:44:05.920273950Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm HANDSHAKE_DONE [2025-04-30T21:44:05.920283668Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e dropped epoch 1 state [2025-04-30T21:44:05.920292986Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=1 conn_id=[0e, ae, e1, 5a, b1, 6d, c6, 10, 71, 21, 3b, bc, ad, 3c, aa, e5] reset_token=[70, 66, ac, 09, 57, 14, fd, 35, a3, a7, b5, 67, b0, 3d, c5, 99] [2025-04-30T21:44:05.920305178Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e path ID 0 changed DCID: old seq num 0 new seq num 1 [2025-04-30T21:44:05.920310648Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=1 conn_id=[cf, 06, 6b, a5, ea, 9d, 49, 47, cb, d9, 1d, 3e, 97, 06, 63, 6b] reset_token=[ae, 84, c9, cc, a3, 01, c8, df, cf, 08, d4, ca, aa, 04, 2c, ec] [2025-04-30T21:44:05.920340294Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[3a, ea, 5e, c1, 11, 45, b6, 14, b4, 5f, 90, bb, 76, 26, 44, 3a] reset_token=[bb, c0, 45, fa, 8e, a6, b5, 15, e5, e2, b5, ef, ab, d3, 97, fd] [2025-04-30T21:44:05.920349831Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T21:44:05.920367143Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 155 bytes [2025-04-30T21:44:05.920372724Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.920375909Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.920379436Z INFO quiche_apps::client] Retiring source CID e7ef31ecc042080670c045be1e01f242d2a4bc8e [2025-04-30T21:44:05.920392791Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10936 out_len=1350 left=1311 [2025-04-30T21:44:05.920406065Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=0eaee15ab16dc61071213bbcad3caae5 key_phase=false len=47 pn=18 [2025-04-30T21:44:05.920409702Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=18 blocks=[0..1] ecn_counts=None [2025-04-30T21:44:05.920413830Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[d5, b4, 3e, 49, 4d, b3, eb, fe, 80, af, e1, a2, f6, f3, 3f, 1e, 91, 88, 42, 96] reset_token=[f7, da, 65, 1d, 83, aa, 6d, ba, ec, d4, 5e, 81, 55, f1, f1, 4c] [2025-04-30T21:44:05.920420773Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T21:44:05.920430160Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=116.98778ms latest_rtt=37.232238ms srtt=38.992699ms min_rtt=33.628061ms rttvar=13.25932ms cwnd=9450 ssthresh=9450 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 993564502 }) Rate { delivered: 611, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 17, last_sent_packet: 18, largest_acked: 16, rate_sample: RateSample { delivery_rate: 3652, is_app_limited: true, interval: 37.232238ms, delivered: 136, prior_delivered: 475, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 922694916 }), send_elapsed: 0ns, ack_elapsed: 37.232238ms, rtt: 37.232238ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 302941, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.920482958Z TRACE quiche_apps::client] written 81 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.920488819Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.921358053Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.921369274Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Short dcid=3374bad63523afbb5fc2b40ef55c286ee062b048 key_phase=false len=1211 pn=2 [2025-04-30T21:44:05.921375506Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm HANDSHAKE_DONE [2025-04-30T21:44:05.921379283Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm STREAM id=0 off=0 len=1191 fin=false [2025-04-30T21:44:05.921387458Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.921391115Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.921393499Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.921398388Z TRACE quiche_apps::common] received 1191 bytes [2025-04-30T21:44:05.921401104Z TRACE quiche_apps::common] stream 0 has 1191 bytes (fin? false) [2025-04-30T21:44:05.921408126Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10774 out_len=1350 left=1311 [2025-04-30T21:44:05.921411453Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=0eaee15ab16dc61071213bbcad3caae5 key_phase=false len=5 pn=19 [2025-04-30T21:44:05.921413907Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=4 blocks=[0..2] ecn_counts=None [2025-04-30T21:44:05.921420269Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=115.997872ms latest_rtt=37.232238ms srtt=38.992699ms min_rtt=33.628061ms rttvar=13.25932ms cwnd=9450 ssthresh=9450 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 993564502 }) Rate { delivered: 611, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 17, last_sent_packet: 19, largest_acked: 16, rate_sample: RateSample { delivery_rate: 3652, is_app_limited: true, interval: 37.232238ms, delivered: 136, prior_delivered: 475, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 922694916 }), send_elapsed: 0ns, ack_elapsed: 37.232238ms, rtt: 37.232238ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 302941, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.921460814Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.921465152Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.922367548Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.922377918Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Short dcid=3374bad63523afbb5fc2b40ef55c286ee062b048 key_phase=false len=1211 pn=3 [2025-04-30T21:44:05.922383929Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm HANDSHAKE_DONE [2025-04-30T21:44:05.922387455Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm STREAM id=0 off=1191 len=1189 fin=false [2025-04-30T21:44:05.922406972Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.922410708Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.922413043Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.922417471Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:44:05.922419745Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:44:05.922426718Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10774 out_len=1350 left=1311 [2025-04-30T21:44:05.922429914Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=0eaee15ab16dc61071213bbcad3caae5 key_phase=false len=5 pn=20 [2025-04-30T21:44:05.922432308Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=6 blocks=[0..3] ecn_counts=None [2025-04-30T21:44:05.922438771Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=114.979441ms latest_rtt=37.232238ms srtt=38.992699ms min_rtt=33.628061ms rttvar=13.25932ms cwnd=9450 ssthresh=9450 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 993564502 }) Rate { delivered: 611, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 17, last_sent_packet: 20, largest_acked: 16, rate_sample: RateSample { delivery_rate: 3652, is_app_limited: true, interval: 37.232238ms, delivered: 136, prior_delivered: 475, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 922694916 }), send_elapsed: 0ns, ack_elapsed: 37.232238ms, rtt: 37.232238ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 302941, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.922476481Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.922480758Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.923375700Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.923386561Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Short dcid=3374bad63523afbb5fc2b40ef55c286ee062b048 key_phase=false len=1211 pn=4 [2025-04-30T21:44:05.923397882Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm HANDSHAKE_DONE [2025-04-30T21:44:05.923404855Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm STREAM id=0 off=2380 len=1189 fin=false [2025-04-30T21:44:05.923412429Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1232 bytes [2025-04-30T21:44:05.923416035Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.923418390Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.923422698Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:44:05.923424912Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:44:05.923431644Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10774 out_len=1350 left=1311 [2025-04-30T21:44:05.923434780Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=0eaee15ab16dc61071213bbcad3caae5 key_phase=false len=5 pn=21 [2025-04-30T21:44:05.923437175Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=5 blocks=[0..4] ecn_counts=None [2025-04-30T21:44:05.923443737Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=113.974464ms latest_rtt=37.232238ms srtt=38.992699ms min_rtt=33.628061ms rttvar=13.25932ms cwnd=9450 ssthresh=9450 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 993564502 }) Rate { delivered: 611, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 17, last_sent_packet: 21, largest_acked: 16, rate_sample: RateSample { delivery_rate: 3652, is_app_limited: true, interval: 37.232238ms, delivered: 136, prior_delivered: 475, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 922694916 }), send_elapsed: 0ns, ack_elapsed: 37.232238ms, rtt: 37.232238ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 302941, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.923477660Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.923481657Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.923843900Z TRACE quiche_apps::client] got 572 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.923851194Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Short dcid=3374bad63523afbb5fc2b40ef55c286ee062b048 key_phase=false len=551 pn=5 [2025-04-30T21:44:05.923856834Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm HANDSHAKE_DONE [2025-04-30T21:44:05.923859639Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm STREAM id=0 off=3569 len=527 fin=false [2025-04-30T21:44:05.923866863Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 572 bytes [2025-04-30T21:44:05.923870459Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.923878104Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.923882241Z TRACE quiche_apps::common] received 527 bytes [2025-04-30T21:44:05.923884485Z TRACE quiche_apps::common] stream 0 has 527 bytes (fin? false) [2025-04-30T21:44:05.923891128Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10774 out_len=1350 left=1311 [2025-04-30T21:44:05.923894234Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=0eaee15ab16dc61071213bbcad3caae5 key_phase=false len=5 pn=22 [2025-04-30T21:44:05.923896578Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm ACK delay=5 blocks=[0..5] ecn_counts=None [2025-04-30T21:44:05.923902769Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=113.515482ms latest_rtt=37.232238ms srtt=38.992699ms min_rtt=33.628061ms rttvar=13.25932ms cwnd=9450 ssthresh=9450 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 993564502 }) Rate { delivered: 611, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 17, last_sent_packet: 22, largest_acked: 16, rate_sample: RateSample { delivery_rate: 3652, is_app_limited: true, interval: 37.232238ms, delivered: 136, prior_delivered: 475, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 922694916 }), send_elapsed: 0ns, ack_elapsed: 37.232238ms, rtt: 37.232238ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 302941, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.923936241Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.923940159Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:05.925959489Z TRACE quiche_apps::client] got 1069 bytes from 193.167.100.100:443 to 0.0.0.0:43560 [2025-04-30T21:44:05.925970038Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx pkt Short dcid=3374bad63523afbb5fc2b40ef55c286ee062b048 key_phase=false len=1048 pn=6 [2025-04-30T21:44:05.925975949Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm HANDSHAKE_DONE [2025-04-30T21:44:05.925978905Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e rx frm STREAM id=0 off=4096 len=1024 fin=true [2025-04-30T21:44:05.925986319Z TRACE quiche_apps::client] 0.0.0.0:43560: processed 1069 bytes [2025-04-30T21:44:05.925989915Z TRACE quiche_apps::client] 0.0.0.0:43560: recv() would block [2025-04-30T21:44:05.925992320Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:05.925997660Z TRACE quiche_apps::common] received 1024 bytes [2025-04-30T21:44:05.925999914Z TRACE quiche_apps::common] stream 0 has 1024 bytes (fin? true) [2025-04-30T21:44:05.926002278Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T21:44:05.926004623Z INFO quiche_apps::common] 1/1 response(s) received in 964.806637ms, closing... [2025-04-30T21:44:05.926011095Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10774 out_len=1350 left=1316 [2025-04-30T21:44:05.926014361Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx pkt Short dcid=0eaee15ab16dc61071213bbcad3caae5 key_phase=false len=10 pn=23 [2025-04-30T21:44:05.926016755Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T21:44:05.926023938Z TRACE quiche::recovery::congestion::recovery] e7ef31ecc042080670c045be1e01f242d2a4bc8e timer=117.01435ms latest_rtt=37.232238ms srtt=38.992699ms min_rtt=33.628061ms rttvar=13.25932ms cwnd=9450 ssthresh=9450 bytes_in_flight=125 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 376, tv_nsec: 993564502 }) Rate { delivered: 611, delivered_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, first_sent_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, end_of_app_limited: 22, last_sent_packet: 23, largest_acked: 16, rate_sample: RateSample { delivery_rate: 3652, is_app_limited: true, interval: 37.232238ms, delivered: 136, prior_delivered: 475, prior_time: Some(Instant { tv_sec: 376, tv_nsec: 922694916 }), send_elapsed: 0ns, ack_elapsed: 37.232238ms, rtt: 37.232238ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 302941, last_update: Instant { tv_sec: 376, tv_nsec: 921263601 }, next_time: Instant { tv_sec: 376, tv_nsec: 922694916 }, 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-30T21:44:05.926064424Z TRACE quiche_apps::client] written 44 bytes from 0.0.0.0:43560 to 193.167.100.100:443 [2025-04-30T21:44:05.926068221Z TRACE quiche_apps::client] 0.0.0.0:43560 -> 193.167.100.100:443: done writing [2025-04-30T21:44:06.203406794Z TRACE quiche_apps::client] timed out [2025-04-30T21:44:06.203437631Z TRACE quiche] e7ef31ecc042080670c045be1e01f242d2a4bc8e draining timeout expired [2025-04-30T21:44:06.203481482Z TRACE quiche_apps::client] done reading [2025-04-30T21:44:06.203486532Z INFO quiche_apps::client] connection closed, recv=17 sent=24 lost=6 retrans=0 sent_bytes=1854 recv_bytes=17652 lost_bytes=211 [local_addr=0.0.0.0:43560 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=17 sent=24 lost=6 retrans=0 rtt=38.992699ms min_rtt=Some(33.628061ms) rttvar=13.25932ms cwnd=9450 sent_bytes=1854 recv_bytes=17652 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=3652]