[2025-04-30T10:57:42.605204255Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T10:57:42.605489298Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:42127 with scid ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 [2025-04-30T10:57:42.605529483Z TRACE quiche::tls] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 write message lvl=Initial len=266 [2025-04-30T10:57:42.605548889Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Initial version=1 dcid=eb81f30cd8ae27e1c84093f16e5e82b5 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=270 pn=0 [2025-04-30T10:57:42.605552015Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm CRYPTO off=0 len=266 [2025-04-30T10:57:42.605565540Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=998.93053ms 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: 391, tv_nsec: 506512173 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 506512173 }, 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: 391, tv_nsec: 506512173 }, next_time: Instant { tv_sec: 391, tv_nsec: 506512173 }, 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-30T10:57:42.605625382Z TRACE quiche_apps::client] written 1200 [2025-04-30T10:57:42.643899159Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:42.643926179Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Initial version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 token= len=120 pn=67181 [2025-04-30T10:57:42.643941488Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=91 blocks=[0..0] ecn_counts=None [2025-04-30T10:57:42.643948020Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 0 [2025-04-30T10:57:42.643953991Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=0 len=90 [2025-04-30T10:57:42.644073064Z TRACE quiche::tls] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 set write secret lvl=Handshake [2025-04-30T10:57:42.644085416Z TRACE quiche::tls] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 set read secret lvl=Handshake [2025-04-30T10:57:42.644116735Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1057 pn=0 [2025-04-30T10:57:42.644123358Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=0 len=1033 [2025-04-30T10:57:42.644140660Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:42.644145529Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:42.644148504Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:42.644170946Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Initial version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=8 pn=1 [2025-04-30T10:57:42.644173962Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=30 blocks=[67181..67181] ecn_counts=None [2025-04-30T10:57:42.644181817Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=115.011626ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 545151602 }, next_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, 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-30T10:57:42.644208526Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=2 [2025-04-30T10:57:42.644211422Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=11 blocks=[0..0] ecn_counts=None [2025-04-30T10:57:42.644216692Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=114.977011ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 545151602 }, next_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, 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-30T10:57:42.644227342Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 dropped epoch 0 state [2025-04-30T10:57:42.644267737Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:42.644276383Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:42.644876444Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:42.644881153Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1215 pn=1 [2025-04-30T10:57:42.644887575Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=1033 len=1190 [2025-04-30T10:57:42.644898125Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:42.644901762Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:42.644904166Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:42.644911951Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=3 [2025-04-30T10:57:42.644914496Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=3 blocks=[0..1] ecn_counts=None [2025-04-30T10:57:42.644925566Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=114.510009ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 545151602 }, next_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, 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-30T10:57:42.644961744Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:42.644969849Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:42.760113730Z TRACE quiche_apps::client] timed out [2025-04-30T10:57:42.760139188Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 loss detection timeout expired [2025-04-30T10:57:42.760143937Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=230.539246ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 545151602 }, next_time: Instant { tv_sec: 391, tv_nsec: 545151633 }, 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-30T10:57:42.760163373Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:42.760190965Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=7 pn=4 [2025-04-30T10:57:42.760194602Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=14413 blocks=[0..1] ecn_counts=None [2025-04-30T10:57:42.760199341Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm PING mtu_probe=None [2025-04-30T10:57:42.760214569Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=230.502336ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=61 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 61, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 661186729 }, next_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, 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-30T10:57:42.760292003Z TRACE quiche_apps::client] written 61 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:42.760302323Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:42.991588943Z TRACE quiche_apps::client] timed out [2025-04-30T10:57:42.991617115Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 loss detection timeout expired [2025-04-30T10:57:42.991623006Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=229.638524ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=61 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 61, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 661186729 }, next_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, 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-30T10:57:42.991645959Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:42.991678310Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=9 pn=5 [2025-04-30T10:57:42.991682547Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=43349 blocks=[0..1] ecn_counts=None [2025-04-30T10:57:42.991688368Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm PING mtu_probe=None [2025-04-30T10:57:42.991705650Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=461.041261ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=124 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 892670878 }, next_time: Instant { tv_sec: 391, tv_nsec: 892670878 }, 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-30T10:57:42.991796110Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:42.991815375Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=9 pn=6 [2025-04-30T10:57:42.991820335Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=43366 blocks=[0..1] ecn_counts=None [2025-04-30T10:57:42.991826707Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm PING mtu_probe=None [2025-04-30T10:57:42.991840673Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=461.055367ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 892670878 }, next_time: Instant { tv_sec: 391, tv_nsec: 892670878 }, 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-30T10:57:42.991887089Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:42.991897179Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.453413918Z TRACE quiche_apps::client] timed out [2025-04-30T10:57:43.453441790Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 loss detection timeout expired [2025-04-30T10:57:43.453447771Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=460.539704ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=187 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 439174, last_update: Instant { tv_sec: 391, tv_nsec: 892670878 }, next_time: Instant { tv_sec: 391, tv_nsec: 892670878 }, 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-30T10:57:43.453470774Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.453502333Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=9 pn=7 [2025-04-30T10:57:43.453521168Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=101077 blocks=[0..1] ecn_counts=None [2025-04-30T10:57:43.453527029Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm PING mtu_probe=None [2025-04-30T10:57:43.453543510Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=922.120433ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=250 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 63, rate: 439174, last_update: Instant { tv_sec: 392, tv_nsec: 354495963 }, next_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, 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-30T10:57:43.453627417Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.453647604Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=9 pn=8 [2025-04-30T10:57:43.453653906Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=101095 blocks=[0..1] ecn_counts=None [2025-04-30T10:57:43.453660078Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm PING mtu_probe=None [2025-04-30T10:57:43.453672491Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=922.147243ms latest_rtt=38.424328ms srtt=38.424328ms min_rtt=38.424328ms rttvar=19.212164ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=313 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, first_sent_time: Instant { tv_sec: 391, tv_nsec: 661186729 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8666, is_app_limited: true, interval: 38.424328ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 506512173 }), send_elapsed: 0ns, ack_elapsed: 38.424328ms, rtt: 38.424328ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 126, rate: 439174, last_update: Instant { tv_sec: 392, tv_nsec: 354495963 }, next_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, 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-30T10:57:43.453715261Z TRACE quiche_apps::client] written 63 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.453725280Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.485310546Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.485330383Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1215 pn=2 [2025-04-30T10:57:43.485352143Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=15 blocks=[8..8] ecn_counts=None [2025-04-30T10:57:43.485358826Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 8 [2025-04-30T10:57:43.485363996Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet 4 lost on epoch 1 [2025-04-30T10:57:43.485368734Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet 5 lost on epoch 1 [2025-04-30T10:57:43.485371730Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet 6 lost on epoch 1 [2025-04-30T10:57:43.485378082Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=2223 len=1185 [2025-04-30T10:57:43.485402497Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:43.485407898Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.485411204Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.485424188Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=9 [2025-04-30T10:57:43.485427865Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=11 blocks=[2..2] ecn_counts=None [2025-04-30T10:57:43.485436351Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=70.016293ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, max_datagram_size: 1350, last_packet_size: None, iv: 401.089µ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-30T10:57:43.485493087Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.485503787Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.486303190Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.486313129Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1215 pn=3 [2025-04-30T10:57:43.486320783Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=15 blocks=[8..8] ecn_counts=None [2025-04-30T10:57:43.486326223Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=3408 len=1185 [2025-04-30T10:57:43.486340079Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:43.486344437Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.486347423Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.486356831Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=10 [2025-04-30T10:57:43.486366228Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=5 blocks=[2..3] ecn_counts=None [2025-04-30T10:57:43.486374153Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=69.078561ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.486420880Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.486430508Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.487315010Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.487322585Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1215 pn=4 [2025-04-30T10:57:43.487328716Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=15 blocks=[8..8] ecn_counts=None [2025-04-30T10:57:43.487332944Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=4593 len=1185 [2025-04-30T10:57:43.487365355Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:43.487369322Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.487371767Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.487379731Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=11 [2025-04-30T10:57:43.487382416Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=7 blocks=[2..4] ecn_counts=None [2025-04-30T10:57:43.487388578Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=68.064296ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 10, last_sent_packet: 11, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.487428262Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.487436608Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.488339114Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.488347099Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1215 pn=5 [2025-04-30T10:57:43.488353000Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=15 blocks=[8..8] ecn_counts=None [2025-04-30T10:57:43.488357228Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=5778 len=1185 [2025-04-30T10:57:43.488367537Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:43.488371003Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.488373368Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.488380581Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=12 [2025-04-30T10:57:43.488383156Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=4 blocks=[2..5] ecn_counts=None [2025-04-30T10:57:43.488388586Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=67.064298ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 11, last_sent_packet: 12, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.488424954Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.488432879Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.489363728Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.489371012Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1215 pn=6 [2025-04-30T10:57:43.489376943Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=15 blocks=[8..8] ecn_counts=None [2025-04-30T10:57:43.489380970Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=6963 len=1185 [2025-04-30T10:57:43.489391901Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:43.489396099Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.489398493Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.489411067Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=13 [2025-04-30T10:57:43.489413731Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=5 blocks=[2..6] ecn_counts=None [2025-04-30T10:57:43.489419162Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=66.033722ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 12, last_sent_packet: 13, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.489455139Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.489463184Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.490389965Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.490398211Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=1215 pn=7 [2025-04-30T10:57:43.490404212Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=15 blocks=[8..8] ecn_counts=None [2025-04-30T10:57:43.490408310Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=8148 len=1185 [2025-04-30T10:57:43.490418388Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1252 bytes [2025-04-30T10:57:43.490421805Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.490424189Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.490431483Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=5 pn=14 [2025-04-30T10:57:43.490434048Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=4 blocks=[2..7] ecn_counts=None [2025-04-30T10:57:43.490439307Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=65.013616ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=63 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 13, last_sent_packet: 14, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.490479262Z TRACE quiche_apps::client] written 59 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.490487477Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.491310896Z TRACE quiche_apps::client] got 1121 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.491318440Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Handshake version=1 dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 scid=5ae2aa60acb3e3a2 len=645 pn=8 [2025-04-30T10:57:43.491324261Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=15 blocks=[8..8] ecn_counts=None [2025-04-30T10:57:43.491327968Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=9333 len=615 [2025-04-30T10:57:43.491813745Z TRACE quiche::tls] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 write message lvl=Handshake len=36 [2025-04-30T10:57:43.491818604Z TRACE quiche::tls] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 set write secret lvl=OneRTT [2025-04-30T10:57:43.491827251Z TRACE quiche::tls] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 set read secret lvl=OneRTT [2025-04-30T10:57:43.491841076Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 connection established: proto=Ok("h3") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(eb81f30cd8ae27e1c84093f16e5e82b5), max_idle_timeout: 180000, stateless_reset_token: Some(304089678463546041313617651950185461593), max_udp_payload_size: 1440, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 2097152, initial_max_stream_data_bidi_remote: 65635, initial_max_stream_data_uni: 65535, initial_max_streams_bidi: 512, initial_max_streams_uni: 512, ack_delay_exponent: 3, max_ack_delay: 10, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(5ae2aa60acb3e3a2), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T10:57:43.491862887Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Short dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 key_phase=false len=418 pn=0 [2025-04-30T10:57:43.491868457Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm CRYPTO off=0 len=125 [2025-04-30T10:57:43.491883846Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_TOKEN len=50 [2025-04-30T10:57:43.491887724Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[20, fe, b6, 9b, 3d, 38, b2, dc] reset_token=[e0, b8, ea, ae, 85, 53, e5, f9, c9, 2c, 0c, 9c, eb, 34, 54, 43] [2025-04-30T10:57:43.491894296Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[f1, 4f, 9e, 98, 2d, 65, 03, 87] reset_token=[77, c7, 45, 49, 96, 55, 13, 38, 60, 89, 34, 18, 16, 98, 86, c7] [2025-04-30T10:57:43.491899275Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[88, 0d, 26, 57, 06, f3, 60, bc] reset_token=[ba, 5d, 76, 88, d6, 43, ce, 03, 28, 22, 19, 7c, b7, e0, b6, bf] [2025-04-30T10:57:43.491903723Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[b7, 9d, 91, f5, ac, 4f, b4, ac] reset_token=[8c, 16, 21, 97, d9, 9f, 27, 7a, 3a, 48, ba, fb, a9, e2, 2d, 73] [2025-04-30T10:57:43.491908502Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[19, ae, a0, 75, e1, 64, a7, 51] reset_token=[f5, dc, 10, 21, 9a, 48, c1, 8c, c6, cd, d6, 0b, 4d, b9, 55, 34] [2025-04-30T10:57:43.491917910Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[cb, 87, a1, 74, 4e, 34, aa, 46] reset_token=[62, b4, 44, 21, 57, 36, 85, e7, 70, 0c, 72, c3, b8, 88, 3f, 85] [2025-04-30T10:57:43.491922649Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[fa, 1b, 28, 51, ea, e4, 59, 13] reset_token=[65, 29, 24, 3c, 35, 95, 77, 95, e5, 91, aa, d2, a9, ae, d8, d8] [2025-04-30T10:57:43.491926466Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=3 off=0 len=9 fin=false [2025-04-30T10:57:43.491930423Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=7 off=0 len=1 fin=false [2025-04-30T10:57:43.491933299Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=11 off=0 len=1 fin=false [2025-04-30T10:57:43.491936154Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm PADDING len=4 [2025-04-30T10:57:43.491946062Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1121 bytes [2025-04-30T10:57:43.491950310Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.491952735Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.491967342Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm SETTINGS stream=2 len=18 [2025-04-30T10:57:43.491979014Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 open GREASE stream 14 [2025-04-30T10:57:43.492010282Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm GREASE stream=0 len=0 [2025-04-30T10:57:43.492029919Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm GREASE stream=0 len=18 [2025-04-30T10:57:43.492037734Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm HEADERS stream=0 len=30 fin=true [2025-04-30T10:57:43.492044076Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server4", ":path: /lnjfjkidew", "user-agent: quiche"] [2025-04-30T10:57:43.492091745Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 3 is readable [2025-04-30T10:57:43.492097596Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 3 [2025-04-30T10:57:43.492101543Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 open peer's control stream 3 [2025-04-30T10:57:43.492104869Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 3 [2025-04-30T10:57:43.492107965Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 3 [2025-04-30T10:57:43.492111502Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 6 bytes on stream 3 [2025-04-30T10:57:43.492114427Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm SETTINGS max_field_section=None, qpack_max_table=Some(0), qpack_blocked=Some(0) raw=Some([(1, 0), (7, 0), (8, 1)]), additional_settings=None stream=3 payload_len=6 [2025-04-30T10:57:43.492121320Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 7 is readable [2025-04-30T10:57:43.492124676Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 7 [2025-04-30T10:57:43.492128073Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 11 is readable [2025-04-30T10:57:43.492131569Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 11 [2025-04-30T10:57:43.492143862Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Handshake version=1 dcid=5ae2aa60acb3e3a2 scid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 len=46 pn=15 [2025-04-30T10:57:43.492146687Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=103 blocks=[2..8] ecn_counts=None [2025-04-30T10:57:43.492149803Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm CRYPTO off=0 len=36 [2025-04-30T10:57:43.492157077Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=101.796373ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=163 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.492175281Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=10600 out_len=1250 left=1219 [2025-04-30T10:57:43.492182204Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=309 pn=16 [2025-04-30T10:57:43.492184819Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=39 blocks=[0..0] ecn_counts=None [2025-04-30T10:57:43.492187544Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[3d, 8a, 62, 3d, d7, 14, 08, f0, 79, 36, eb, 1e, 20, 25, 3c, 6a, 73, 12, 13, ad] reset_token=[d1, c3, 33, 6b, 23, fd, c3, b3, 88, 3d, c1, f6, dc, c9, a9, fd] [2025-04-30T10:57:43.492193264Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[db, eb, 9c, c8, 6f, ae, 6f, cd, e3, cc, 80, e6, 24, b6, ab, 2f, c8, 1b, 5f, 65] reset_token=[81, 74, 9e, 1e, a4, 39, 09, 53, 10, ab, 5e, ce, 3f, f1, d9, c6] [2025-04-30T10:57:43.492198374Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[8a, 5c, cd, 69, 9b, 68, d9, f1, 65, 8e, f7, e6, 11, 7e, 78, bb, b3, de, 56, f4] reset_token=[a2, 2a, 03, 19, 8d, 0b, 08, 48, 6d, 2a, 9d, 16, 31, cc, f2, 90] [2025-04-30T10:57:43.492203433Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[03, 4d, 09, 88, 34, 52, 0c, e1, 04, 30, 16, 11, 6f, 40, b7, f3, ac, bc, cd, ce] reset_token=[c0, d4, b7, ed, 0a, 71, 1a, 9b, ce, 4a, 68, 18, 7e, 8a, 9e, e0] [2025-04-30T10:57:43.492208733Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[01, 5f, 0e, 34, ea, 91, aa, b0, 23, af, d6, 73, f4, 50, 4d, f4, 5e, 22, 13, 4c] reset_token=[4e, ad, 96, 17, 9a, b3, 8b, ae, 06, c0, 5b, 97, 51, bd, 1a, 2b] [2025-04-30T10:57:43.492213823Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[87, 5e, ac, f3, 5c, aa, da, a1, b3, cf, 99, 8a, d7, 54, a2, 7e, 64, 74, 2a, f4] reset_token=[e2, c8, c0, 30, cd, d2, 68, 19, fc, c5, 57, 00, 01, 81, 3a, b0] [2025-04-30T10:57:43.492218852Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[52, dc, 73, c4, 09, 57, 7a, b9, 65, 36, 76, a0, 3f, 29, 10, 33, 7f, a2, 66, 2c] reset_token=[1a, f2, f8, 5b, da, 51, 1c, 80, 0b, 3e, 22, 20, 7f, 17, 05, a4] [2025-04-30T10:57:43.492224002Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm STREAM id=2 off=0 len=19 fin=false [2025-04-30T10:57:43.492232909Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=101.720652ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=498 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.492274967Z TRACE quiche_apps::client] written 435 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.492285216Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=9930 out_len=1350 left=1324 [2025-04-30T10:57:43.492291298Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=6 pn=17 [2025-04-30T10:57:43.492295666Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm STREAM id=6 off=0 len=1 fin=false [2025-04-30T10:57:43.492304833Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=101.648266ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=530 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 16, last_sent_packet: 17, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.492342423Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.492352382Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=9866 out_len=1350 left=1324 [2025-04-30T10:57:43.492358353Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=6 pn=18 [2025-04-30T10:57:43.492362020Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm STREAM id=10 off=0 len=1 fin=false [2025-04-30T10:57:43.492371257Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=101.582073ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=562 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 17, last_sent_packet: 18, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.492409819Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.492418756Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=9802 out_len=1350 left=1324 [2025-04-30T10:57:43.492425027Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=73 pn=19 [2025-04-30T10:57:43.492429095Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm STREAM id=0 off=0 len=68 fin=true [2025-04-30T10:57:43.492438442Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=101.514877ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=661 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 18, last_sent_packet: 19, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.492470813Z TRACE quiche_apps::client] written 99 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.492479760Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=9604 out_len=1350 left=1324 [2025-04-30T10:57:43.492485821Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=31 pn=20 [2025-04-30T10:57:43.492489758Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm STREAM id=14 off=0 len=26 fin=true [2025-04-30T10:57:43.492499096Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=101.454214ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=718 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 19, last_sent_packet: 20, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.492536456Z TRACE quiche_apps::client] written 57 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.492543519Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.492554259Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.492559859Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Short dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 key_phase=false len=1329 pn=1 [2025-04-30T10:57:43.492568916Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm PING mtu_probe=None [2025-04-30T10:57:43.492576120Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm PADDING len=1311 [2025-04-30T10:57:43.492582191Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1350 bytes [2025-04-30T10:57:43.492585637Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.492587992Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.492594264Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=9490 out_len=1350 left=1319 [2025-04-30T10:57:43.492597289Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=5 pn=21 [2025-04-30T10:57:43.492599634Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=4 blocks=[0..1] ecn_counts=None [2025-04-30T10:57:43.492605545Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=101.347976ms latest_rtt=31.845934ms srtt=37.602028ms min_rtt=31.845934ms rttvar=16.053721ms cwnd=9450 ssthresh=9450 bytes_in_flight=718 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 396, delivered_time: Instant { tv_sec: 392, tv_nsec: 386341897 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 354495963 }, end_of_app_limited: 19, last_sent_packet: 21, largest_acked: 8, rate_sample: RateSample { delivery_rate: 86, is_app_limited: true, interval: 725.155168ms, delivered: 63, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 391, tv_nsec: 661186729 }), send_elapsed: 693.309234ms, ack_elapsed: 725.155168ms, rtt: 31.845934ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 314145, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.492639017Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.492646060Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.523214329Z TRACE quiche_apps::client] got 55 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.523230188Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Short dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 key_phase=false len=34 pn=2 [2025-04-30T10:57:43.523240197Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=2 blocks=[16..18] ecn_counts=None [2025-04-30T10:57:43.523245186Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 16 [2025-04-30T10:57:43.523249204Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 17 [2025-04-30T10:57:43.523251939Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 18 [2025-04-30T10:57:43.523256437Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm HANDSHAKE_DONE [2025-04-30T10:57:43.523262499Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 dropped epoch 1 state [2025-04-30T10:57:43.523265284Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm PADDING len=11 [2025-04-30T10:57:43.523281765Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 55 bytes [2025-04-30T10:57:43.523285742Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.523288297Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.523297374Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10052 out_len=1350 left=1319 [2025-04-30T10:57:43.523301461Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=5 pn=22 [2025-04-30T10:57:43.523303986Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=8 blocks=[1..2] ecn_counts=None [2025-04-30T10:57:43.523310408Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=65.929094ms latest_rtt=36.474994ms srtt=37.459148ms min_rtt=31.845934ms rttvar=12.326048ms cwnd=9450 ssthresh=9450 bytes_in_flight=156 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 795, delivered_time: Instant { tv_sec: 392, tv_nsec: 424243025 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, end_of_app_limited: 21, last_sent_packet: 22, largest_acked: 18, rate_sample: RateSample { delivery_rate: 10527, is_app_limited: true, interval: 37.901128ms, delivered: 399, prior_delivered: 396, prior_time: Some(Instant { tv_sec: 392, tv_nsec: 386341897 }), send_elapsed: 33.272068ms, ack_elapsed: 37.901128ms, rtt: 36.474994ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 315343, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.523355783Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.523363918Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.524473561Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.524487247Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Short dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 key_phase=false len=1329 pn=3 [2025-04-30T10:57:43.524494631Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm ACK delay=3 blocks=[16..21] ecn_counts=None [2025-04-30T10:57:43.524498167Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 19 [2025-04-30T10:57:43.524508096Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 20 [2025-04-30T10:57:43.524510400Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 packet newly acked 21 [2025-04-30T10:57:43.524513846Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=0 off=0 len=23 fin=false [2025-04-30T10:57:43.524518615Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=0 off=23 len=1278 fin=false [2025-04-30T10:57:43.524543081Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1350 bytes [2025-04-30T10:57:43.524546968Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.524549383Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.524552118Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 0 is readable [2025-04-30T10:57:43.524556997Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 0 [2025-04-30T10:57:43.524560744Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 0 [2025-04-30T10:57:43.524563720Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 0 [2025-04-30T10:57:43.524567096Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 17 bytes on stream 0 [2025-04-30T10:57:43.524569871Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm HEADERS stream=0 payload_len=17 [2025-04-30T10:57:43.524573498Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0 [2025-04-30T10:57:43.524576053Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true [2025-04-30T10:57:43.524578768Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[72, 51, 90, 101, 114, 111, 47, 49, 46, 48] [2025-04-30T10:57:43.524582044Z TRACE quiche::h3::qpack::decoder] Indexed index=53 static=true [2025-04-30T10:57:43.524589017Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "H3Zero/1.0"), ("content-type", "text/plain")] on stream id 0 [2025-04-30T10:57:43.524593566Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 0 is readable [2025-04-30T10:57:43.524596571Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 0 [2025-04-30T10:57:43.524599617Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 0 [2025-04-30T10:57:43.524603023Z TRACE quiche::h3::stream] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 read 1 bytes on stream 0 [2025-04-30T10:57:43.524605408Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm DATA stream=0 wire_payload_len=5120 [2025-04-30T10:57:43.524610527Z DEBUG quiche_apps::common] got 1278 bytes of response data on stream 0 [2025-04-30T10:57:43.524618242Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10208 out_len=1350 left=1319 [2025-04-30T10:57:43.524621648Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=5 pn=23 [2025-04-30T10:57:43.524624083Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=16 blocks=[2..3] ecn_counts=None [2025-04-30T10:57:43.524630244Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=none latest_rtt=37.732924ms srtt=37.490369ms min_rtt=31.845934ms rttvar=9.30698ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 951, delivered_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, end_of_app_limited: 22, last_sent_packet: 23, largest_acked: 21, rate_sample: RateSample { delivery_rate: 14643, is_app_limited: true, interval: 37.901128ms, delivered: 555, prior_delivered: 396, prior_time: Some(Instant { tv_sec: 392, tv_nsec: 386341897 }), send_elapsed: 33.272068ms, ack_elapsed: 37.901128ms, rtt: 36.474994ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 315080, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.524674898Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.524682031Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.525554270Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.525562776Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Short dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 key_phase=false len=1329 pn=4 [2025-04-30T10:57:43.525569779Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=0 off=1301 len=1308 fin=false [2025-04-30T10:57:43.525576983Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1350 bytes [2025-04-30T10:57:43.525580429Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.525583134Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.525586681Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 0 is readable [2025-04-30T10:57:43.525591740Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 0 [2025-04-30T10:57:43.525598323Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10208 out_len=1350 left=1319 [2025-04-30T10:57:43.525601559Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=5 pn=24 [2025-04-30T10:57:43.525603973Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=4 blocks=[2..4] ecn_counts=None [2025-04-30T10:57:43.525609894Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=none latest_rtt=37.732924ms srtt=37.490369ms min_rtt=31.845934ms rttvar=9.30698ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 951, delivered_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, end_of_app_limited: 22, last_sent_packet: 24, largest_acked: 21, rate_sample: RateSample { delivery_rate: 14643, is_app_limited: true, interval: 37.901128ms, delivered: 555, prior_delivered: 396, prior_time: Some(Instant { tv_sec: 392, tv_nsec: 386341897 }), send_elapsed: 33.272068ms, ack_elapsed: 37.901128ms, rtt: 36.474994ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 315080, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.525646563Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.525653455Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.526657591Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.526665667Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Short dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 key_phase=false len=1329 pn=5 [2025-04-30T10:57:43.526677499Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=0 off=2609 len=1308 fin=false [2025-04-30T10:57:43.526684682Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1350 bytes [2025-04-30T10:57:43.526688179Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.526690513Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.526693028Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 0 is readable [2025-04-30T10:57:43.526697476Z DEBUG quiche_apps::common] got 1308 bytes of response data on stream 0 [2025-04-30T10:57:43.526703978Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10208 out_len=1350 left=1319 [2025-04-30T10:57:43.526707124Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=5 pn=25 [2025-04-30T10:57:43.526709508Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm ACK delay=4 blocks=[2..5] ecn_counts=None [2025-04-30T10:57:43.526715480Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=none latest_rtt=37.732924ms srtt=37.490369ms min_rtt=31.845934ms rttvar=9.30698ms cwnd=9450 ssthresh=9450 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 386341897 }) Rate { delivered: 951, delivered_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, end_of_app_limited: 22, last_sent_packet: 25, largest_acked: 21, rate_sample: RateSample { delivery_rate: 14643, is_app_limited: true, interval: 37.901128ms, delivered: 555, prior_delivered: 396, prior_time: Some(Instant { tv_sec: 392, tv_nsec: 386341897 }), send_elapsed: 33.272068ms, ack_elapsed: 37.901128ms, rtt: 36.474994ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 315080, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.526751477Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.526758931Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.527746606Z TRACE quiche_apps::client] got 1335 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.527755112Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx pkt Short dcid=ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 key_phase=false len=1314 pn=6 [2025-04-30T10:57:43.527761444Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm STREAM id=0 off=3917 len=1226 fin=true [2025-04-30T10:57:43.527765051Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 rx frm PADDING len=65 [2025-04-30T10:57:43.527771653Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1335 bytes [2025-04-30T10:57:43.527775009Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.527777414Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.527779908Z TRACE quiche::h3] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 stream id 0 is readable [2025-04-30T10:57:43.527785629Z DEBUG quiche_apps::common] got 1226 bytes of response data on stream 0 [2025-04-30T10:57:43.527788434Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T10:57:43.527791049Z INFO quiche_apps::common] 1/1 response(s) received in 922.161229ms, closing... [2025-04-30T10:57:43.527796930Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=10208 out_len=1350 left=1324 [2025-04-30T10:57:43.527805506Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx pkt Short dcid=5ae2aa60acb3e3a2 key_phase=false len=11 pn=26 [2025-04-30T10:57:43.527808001Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T10:57:43.527814974Z TRACE quiche::recovery::congestion::recovery] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 timer=84.698021ms latest_rtt=37.732924ms srtt=37.490369ms min_rtt=31.845934ms rttvar=9.30698ms cwnd=9450 ssthresh=9450 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=Some(Instant { tv_sec: 392, tv_nsec: 421660230 }) Rate { delivered: 951, delivered_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, first_sent_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, end_of_app_limited: 25, last_sent_packet: 26, largest_acked: 21, rate_sample: RateSample { delivery_rate: 14643, is_app_limited: true, interval: 37.901128ms, delivered: 555, prior_delivered: 396, prior_time: Some(Instant { tv_sec: 392, tv_nsec: 386341897 }), send_elapsed: 33.272068ms, ack_elapsed: 37.901128ms, rtt: 36.474994ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 315080, last_update: Instant { tv_sec: 392, tv_nsec: 386431584 }, next_time: Instant { tv_sec: 392, tv_nsec: 387768031 }, 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-30T10:57:43.527852935Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:42127 to 193.167.100.100:443 [2025-04-30T10:57:43.527859407Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.555478996Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.555494004Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1350 bytes [2025-04-30T10:57:43.555498632Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.555501558Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.555507459Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.556562230Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.556567499Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1350 bytes [2025-04-30T10:57:43.556570595Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.556572829Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.556575985Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.557655322Z TRACE quiche_apps::client] got 1350 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.557660562Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1350 bytes [2025-04-30T10:57:43.557663617Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.557665841Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.557668757Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.558746711Z TRACE quiche_apps::client] got 1335 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.558751520Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 1335 bytes [2025-04-30T10:57:43.558755607Z TRACE quiche_apps::client] got 42 bytes from 193.167.100.100:443 to 0.0.0.0:42127 [2025-04-30T10:57:43.558758282Z TRACE quiche_apps::client] 0.0.0.0:42127: processed 42 bytes [2025-04-30T10:57:43.558761238Z TRACE quiche_apps::client] 0.0.0.0:42127: recv() would block [2025-04-30T10:57:43.558763452Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.558766388Z TRACE quiche_apps::client] 0.0.0.0:42127 -> 193.167.100.100:443: done writing [2025-04-30T10:57:43.753033833Z TRACE quiche_apps::client] timed out [2025-04-30T10:57:43.753065533Z TRACE quiche] ea80d63660a1c4c14b2b840e5d7972f2f0ec4097 draining timeout expired [2025-04-30T10:57:43.753107521Z TRACE quiche_apps::client] done reading [2025-04-30T10:57:43.753112070Z INFO quiche_apps::client] connection closed, recv=17 sent=27 lost=5 retrans=0 sent_bytes=2028 recv_bytes=17927 lost_bytes=187 [local_addr=0.0.0.0:42127 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=17 sent=27 lost=5 retrans=0 rtt=37.490369ms min_rtt=Some(31.845934ms) rttvar=9.30698ms cwnd=9450 sent_bytes=2028 recv_bytes=17927 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=14643]