[2025-04-30T19:23:24.848462110Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T19:23:24.848786628Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:47651 with scid 2aa093e21c5629c85b007a2e00ae20059b1d5d5f [2025-04-30T19:23:24.848829718Z TRACE quiche::tls] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f write message lvl=Initial len=266 [2025-04-30T19:23:24.848849355Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Initial version=1 dcid=bbf2e0268a75091dcee2a73b940aa4be scid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f len=270 pn=0 [2025-04-30T19:23:24.848852431Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm CRYPTO off=0 len=266 [2025-04-30T19:23:24.848866297Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=998.929248ms 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: 197, tv_nsec: 851071479 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, 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: 197, tv_nsec: 851071479 }, next_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, 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-30T19:23:24.848933472Z TRACE quiche_apps::client] written 1200 [2025-04-30T19:23:25.848991689Z TRACE quiche_apps::client] timed out [2025-04-30T19:23:25.849014562Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f loss detection timeout expired [2025-04-30T19:23:25.849022046Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=997.772967ms 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: 197, tv_nsec: 851071479 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, 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: 197, tv_nsec: 851071479 }, next_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, 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-30T19:23:25.849045621Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:25.849085655Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Initial version=1 dcid=bbf2e0268a75091dcee2a73b940aa4be scid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f len=270 pn=1 [2025-04-30T19:23:25.849089903Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm CRYPTO off=0 len=266 [2025-04-30T19:23:25.849108659Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=1.99795238s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=666 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 1, last_sent_packet: 1, 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: 198, tv_nsec: 851336743 }, next_time: Instant { tv_sec: 198, tv_nsec: 851336743 }, 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-30T19:23:25.849203196Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:25.849211010Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:26.361016583Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:26.361056748Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx pkt Initial version=1 dcid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f scid=a48d6ba6567ed396 token= len=118 pn=0 [2025-04-30T19:23:26.361075042Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm ACK delay=463 blocks=[0..0] ecn_counts=None [2025-04-30T19:23:26.361082556Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f packet newly acked 0 [2025-04-30T19:23:26.361089600Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm CRYPTO off=0 len=90 [2025-04-30T19:23:26.361225183Z TRACE quiche::tls] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f set write secret lvl=Handshake [2025-04-30T19:23:26.361240612Z TRACE quiche::tls] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f set read secret lvl=Handshake [2025-04-30T19:23:26.361278613Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx pkt Handshake version=1 dcid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f scid=a48d6ba6567ed396 len=756 pn=1 [2025-04-30T19:23:26.361286108Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm CRYPTO off=0 len=734 [2025-04-30T19:23:26.361529473Z TRACE quiche::tls] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f write message lvl=Handshake len=52 [2025-04-30T19:23:26.361534843Z TRACE quiche::tls] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f set write secret lvl=OneRTT [2025-04-30T19:23:26.361544692Z TRACE quiche::tls] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f set read secret lvl=OneRTT [2025-04-30T19:23:26.361567154Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f connection established: proto=Ok("h3") cipher=Some(AES256_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(bbf2e0268a75091dcee2a73b940aa4be), max_idle_timeout: 60000, stateless_reset_token: Some(72055041331715502688841296741075924801), max_udp_payload_size: 65527, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 1048576, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 1048576, initial_max_streams_bidi: 128, initial_max_streams_uni: 128, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(a48d6ba6567ed396), retry_source_connection_id: None, max_datagram_frame_size: Some(65536), unknown_params: None } [2025-04-30T19:23:26.361592531Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx pkt Short dcid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f key_phase=false len=230 pn=2 [2025-04-30T19:23:26.361598041Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm CRYPTO off=0 len=89 [2025-04-30T19:23:26.361609954Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm STREAM id=3 off=0 len=19 fin=false [2025-04-30T19:23:26.361619842Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm STREAM id=7 off=0 len=1 fin=false [2025-04-30T19:23:26.361622998Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm STREAM id=11 off=0 len=1 fin=false [2025-04-30T19:23:26.361626585Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm PADDING len=86 [2025-04-30T19:23:26.361632686Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 1200 bytes [2025-04-30T19:23:26.361637305Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:26.361640130Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:26.361658795Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm SETTINGS stream=2 len=18 [2025-04-30T19:23:26.361671098Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f open GREASE stream 14 [2025-04-30T19:23:26.361680306Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm GREASE stream=0 len=0 [2025-04-30T19:23:26.361685996Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm GREASE stream=0 len=18 [2025-04-30T19:23:26.361693440Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm HEADERS stream=0 len=30 fin=true [2025-04-30T19:23:26.361699862Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server4", ":path: /vozjkbiadr", "user-agent: quiche"] [2025-04-30T19:23:26.361788067Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f stream id 3 is readable [2025-04-30T19:23:26.361797465Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 3 [2025-04-30T19:23:26.361801753Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f open peer's control stream 3 [2025-04-30T19:23:26.361805209Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 3 [2025-04-30T19:23:26.361808255Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 3 [2025-04-30T19:23:26.361811782Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 16 bytes on stream 3 [2025-04-30T19:23:26.361815379Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm SETTINGS max_field_section=None, qpack_max_table=Some(4096), qpack_blocked=Some(16) raw=Some([(1, 4096), (7, 16), (8, 1), (33, 1), (51, 1), (727725890, 1)]), additional_settings=Some([(33, 1), (727725890, 1)]) stream=3 payload_len=16 [2025-04-30T19:23:26.361824095Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f stream id 7 is readable [2025-04-30T19:23:26.361827511Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 7 [2025-04-30T19:23:26.361846216Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f stream id 11 is readable [2025-04-30T19:23:26.361850193Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 11 [2025-04-30T19:23:26.361873597Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Initial version=1 dcid=a48d6ba6567ed396 scid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f len=6 pn=2 [2025-04-30T19:23:26.361876342Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm ACK delay=102 blocks=[0..0] ecn_counts=None [2025-04-30T19:23:26.361885410Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=4.023937769s latest_rtt=1.51225416s srtt=1.51225416s min_rtt=1.51225416s rttvar=756.12708ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 199, tv_nsec: 363325639 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.51225416s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 197, tv_nsec: 851071479 }), send_elapsed: 0ns, ack_elapsed: 1.51225416s, rtt: 1.51225416s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11158, last_update: Instant { tv_sec: 199, tv_nsec: 363840093 }, next_time: Instant { tv_sec: 199, tv_nsec: 363840133 }, 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-30T19:23:26.361909484Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Handshake version=1 dcid=a48d6ba6567ed396 scid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f len=62 pn=3 [2025-04-30T19:23:26.361912320Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm ACK delay=78 blocks=[1..1] ecn_counts=None [2025-04-30T19:23:26.361914925Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm CRYPTO off=0 len=52 [2025-04-30T19:23:26.361921086Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=4.023902623s latest_rtt=1.51225416s srtt=1.51225416s min_rtt=1.51225416s rttvar=756.12708ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=449 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 199, tv_nsec: 363325639 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.51225416s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 197, tv_nsec: 851071479 }), send_elapsed: 0ns, ack_elapsed: 1.51225416s, rtt: 1.51225416s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11158, last_update: Instant { tv_sec: 199, tv_nsec: 364140725 }, next_time: Instant { tv_sec: 199, tv_nsec: 363840133 }, max_datagram_size: 1350, last_packet_size: None, iv: 10.396128ms, 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-30T19:23:26.361932418Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f dropped epoch 0 state [2025-04-30T19:23:26.361937176Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13384 out_len=1173 left=1142 [2025-04-30T19:23:26.361948628Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=1147 pn=4 [2025-04-30T19:23:26.361951253Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm ACK delay=43 blocks=[2..2] ecn_counts=None [2025-04-30T19:23:26.361953798Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[93, 29, 82, 30, 4b, f7, 70, d6, 78, 0e, ce, dd, 25, 81, 92, 9d, 96, 0a, fa, 49] reset_token=[c9, 3e, 35, 28, b1, 23, 6d, 2c, 45, 67, 7c, 01, 3f, ee, 44, ae] [2025-04-30T19:23:26.361960250Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[98, f7, 8d, 2d, c5, 00, 3b, 7c, 2b, a0, 85, 28, 87, 3f, 4d, cb, ba, 17, dd, 9c] reset_token=[86, 12, 85, 08, da, 6d, 1d, e3, 44, 60, 88, 15, ca, 9c, ff, ee] [2025-04-30T19:23:26.361965379Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[3b, 61, 46, 3d, f4, 3e, 46, cf, e2, 75, 3a, 8a, 16, 7e, 82, a8, ac, 31, f9, c0] reset_token=[20, 39, dc, de, c8, 35, d9, ae, 2d, f9, 5b, ce, 75, 4c, b7, 9d] [2025-04-30T19:23:26.361970118Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[16, f8, 69, d3, cd, e7, 58, b7, b9, 10, 18, 9b, b7, 08, 9f, e7, 72, 2c, 4f, 3b] reset_token=[52, ff, 15, 31, da, e8, a3, d4, 9e, c2, 1e, 7d, 6d, 7f, 6f, cf] [2025-04-30T19:23:26.361978544Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[f9, e1, 34, 8e, 65, 16, 50, 81, d7, e3, f5, 5b, d9, 01, 2f, 9e, 7e, d8, fa, f6] reset_token=[9a, df, 7a, c2, db, c9, d3, d1, 3c, 7a, c3, f8, 97, 20, de, ef] [2025-04-30T19:23:26.361983303Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[7d, 9a, 44, 36, d8, 42, f7, 5f, 58, 7a, f9, 59, 72, a5, 25, d3, 79, 1d, 1c, 6d] reset_token=[fd, 87, 96, 4d, 3b, ec, 5b, 08, 4e, db, 4b, 6a, cb, 8a, 73, d7] [2025-04-30T19:23:26.361988012Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[39, d3, 8a, 81, 08, 94, bc, 60, 6f, a2, 37, ff, 7c, 6d, 7a, f9, 85, b7, 4a, c6] reset_token=[a2, aa, 0f, d1, 08, 6c, fa, 5c, e7, c7, d9, 70, 4a, fc, 2a, 1c] [2025-04-30T19:23:26.361992871Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm STREAM id=2 off=0 len=19 fin=false [2025-04-30T19:23:26.361995355Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm PADDING len=838 [2025-04-30T19:23:26.362004603Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=4.536623088s latest_rtt=1.51225416s srtt=1.51225416s min_rtt=1.51225416s rttvar=756.12708ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 199, tv_nsec: 363325639 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.51225416s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 197, tv_nsec: 851071479 }), send_elapsed: 0ns, ack_elapsed: 1.51225416s, rtt: 1.51225416s } } pacer=Pacer { enabled: true, capacity: 13500, used: 1173, rate: 11158, last_update: Instant { tv_sec: 199, tv_nsec: 364140725 }, next_time: Instant { tv_sec: 199, tv_nsec: 374536853 }, max_datagram_size: 1350, last_packet_size: Some(1173), 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-30T19:23:26.362063353Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:26.362071207Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12211 out_len=1350 left=1324 [2025-04-30T19:23:26.362075115Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=6 pn=5 [2025-04-30T19:23:26.362077539Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm STREAM id=6 off=0 len=1 fin=false [2025-04-30T19:23:26.362083040Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=4.536544692s latest_rtt=1.51225416s srtt=1.51225416s min_rtt=1.51225416s rttvar=756.12708ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 199, tv_nsec: 363325639 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.51225416s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 197, tv_nsec: 851071479 }), send_elapsed: 0ns, ack_elapsed: 1.51225416s, rtt: 1.51225416s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11158, last_update: Instant { tv_sec: 199, tv_nsec: 364343696 }, next_time: Instant { tv_sec: 199, tv_nsec: 374536853 }, max_datagram_size: 1350, last_packet_size: None, iv: 107.994264ms, 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-30T19:23:26.362137251Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:26.362148522Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12179 out_len=1350 left=1324 [2025-04-30T19:23:26.362153321Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=6 pn=6 [2025-04-30T19:23:26.362156767Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm STREAM id=10 off=0 len=1 fin=false [2025-04-30T19:23:26.362165103Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=4.536462307s latest_rtt=1.51225416s srtt=1.51225416s min_rtt=1.51225416s rttvar=756.12708ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1353 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 199, tv_nsec: 363325639 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.51225416s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 197, tv_nsec: 851071479 }), send_elapsed: 0ns, ack_elapsed: 1.51225416s, rtt: 1.51225416s } } pacer=Pacer { enabled: true, capacity: 13500, used: 32, rate: 11158, last_update: Instant { tv_sec: 199, tv_nsec: 364343696 }, next_time: Instant { tv_sec: 199, tv_nsec: 482531117 }, max_datagram_size: 1350, last_packet_size: Some(32), 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-30T19:23:26.362210849Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:26.362219675Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12147 out_len=1350 left=1324 [2025-04-30T19:23:26.362223773Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=73 pn=7 [2025-04-30T19:23:26.362226899Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm STREAM id=0 off=0 len=68 fin=true [2025-04-30T19:23:26.362237298Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=4.536389732s latest_rtt=1.51225416s srtt=1.51225416s min_rtt=1.51225416s rttvar=756.12708ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1452 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 199, tv_nsec: 363325639 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.51225416s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 197, tv_nsec: 851071479 }), send_elapsed: 0ns, ack_elapsed: 1.51225416s, rtt: 1.51225416s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11158, last_update: Instant { tv_sec: 199, tv_nsec: 364490981 }, next_time: Instant { tv_sec: 199, tv_nsec: 482531117 }, max_datagram_size: 1350, last_packet_size: None, iv: 11.740455ms, 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-30T19:23:26.362288384Z TRACE quiche_apps::client] written 99 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:26.362297050Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12048 out_len=1350 left=1324 [2025-04-30T19:23:26.362301308Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=31 pn=8 [2025-04-30T19:23:26.362303793Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm STREAM id=14 off=0 len=26 fin=true [2025-04-30T19:23:26.362314433Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=4.536312787s latest_rtt=1.51225416s srtt=1.51225416s min_rtt=1.51225416s rttvar=756.12708ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1509 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 199, tv_nsec: 363325639 }, first_sent_time: Instant { tv_sec: 197, tv_nsec: 851071479 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.51225416s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 197, tv_nsec: 851071479 }), send_elapsed: 0ns, ack_elapsed: 1.51225416s, rtt: 1.51225416s } } pacer=Pacer { enabled: true, capacity: 13500, used: 57, rate: 11158, last_update: Instant { tv_sec: 199, tv_nsec: 364490981 }, next_time: Instant { tv_sec: 199, tv_nsec: 494271572 }, max_datagram_size: 1350, last_packet_size: Some(57), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T19:23:26.362362743Z TRACE quiche_apps::client] written 57 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:26.362369396Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:26.562173256Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:26.562209694Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f dropped invalid packet [2025-04-30T19:23:26.562215034Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 1200 bytes [2025-04-30T19:23:26.562220294Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:26.562223691Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:26.562234411Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:26.963550394Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:26.963587704Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f dropped invalid packet [2025-04-30T19:23:26.963593374Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 1200 bytes [2025-04-30T19:23:26.963598644Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:26.963602031Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:26.963613181Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:27.353221175Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:27.353248997Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f dropped invalid packet [2025-04-30T19:23:27.353254277Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 1200 bytes [2025-04-30T19:23:27.353259526Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:27.353262863Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:27.353273773Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:27.865474746Z TRACE quiche_apps::client] got 242 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:27.865525250Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx pkt Short dcid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f key_phase=false len=221 pn=12 [2025-04-30T19:23:27.865542683Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm ACK delay=139 blocks=[4..4] ecn_counts=None [2025-04-30T19:23:27.865550407Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f packet newly acked 4 [2025-04-30T19:23:27.865558312Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm HANDSHAKE_DONE [2025-04-30T19:23:27.865565516Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f dropped epoch 1 state [2025-04-30T19:23:27.865572238Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[79, f1, 33, 8c, 4b, 1c, f0, 3b] reset_token=[15, 67, a0, b0, 35, 33, 95, ec, a7, b9, f3, c2, c6, 58, 33, f8] [2025-04-30T19:23:27.865582788Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[32, 13, 83, 97, 29, e6, dc, 7e] reset_token=[96, 6c, 5a, 7d, 2d, 1d, 58, ed, bd, 05, 7d, a1, 3a, 20, ee, b9] [2025-04-30T19:23:27.865590372Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[18, 8a, b4, 89, d7, aa, 5a, 86] reset_token=[3d, b0, 40, 03, 4d, a5, 7a, f8, f6, d4, 8b, e3, d1, cc, 40, 2f] [2025-04-30T19:23:27.865596994Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[b1, 52, 04, 1a, 59, 76, 25, 43] reset_token=[e9, 5d, 51, 4c, b0, 0d, 29, d7, a2, cd, ff, ae, ae, 30, 5e, c7] [2025-04-30T19:23:27.865608756Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[8a, 40, 02, 8b, 84, ff, b7, df] reset_token=[85, 36, ec, c6, 3f, 4e, f4, d1, ef, 53, e7, eb, 97, 17, 75, 30] [2025-04-30T19:23:27.865615850Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[05, 5c, f0, b3, 95, 84, b4, 9e] reset_token=[fc, 73, 50, 5c, 39, 08, 5e, 00, b8, d4, 43, 49, 1b, 41, cc, 34] [2025-04-30T19:23:27.865623083Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[2a, 90, f0, 64, 2e, 12, 73, 76] reset_token=[b8, 13, 67, 6a, fe, e7, 59, 35, 6d, b8, f0, 05, ed, fd, a6, ed] [2025-04-30T19:23:27.865653560Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 242 bytes [2025-04-30T19:23:27.865659572Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:27.865662878Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:27.865677445Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13280 out_len=1350 left=1319 [2025-04-30T19:23:27.865683727Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=5 pn=9 [2025-04-30T19:23:27.865686933Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm ACK delay=19 blocks=[12..12] ecn_counts=None [2025-04-30T19:23:27.865696050Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=2.318853544s latest_rtt=1.4932581s srtt=1.509879652s min_rtt=1.4932581s rttvar=571.844325ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=220 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1506, delivered_time: Instant { tv_sec: 200, tv_nsec: 867794953 }, first_sent_time: Instant { tv_sec: 199, tv_nsec: 374536853 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { delivery_rate: 769, is_app_limited: true, interval: 1.523465374s, delivered: 1173, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 199, tv_nsec: 363325639 }), send_elapsed: 1.523465374s, ack_elapsed: 1.504469314s, rtt: 1.4932581s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11176, last_update: Instant { tv_sec: 200, tv_nsec: 867946457 }, next_time: Instant { tv_sec: 200, tv_nsec: 867946457 }, 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-30T19:23:27.865794164Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:27.865801287Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:27.869502357Z TRACE quiche_apps::client] got 44 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:27.869517756Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx pkt Short dcid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f key_phase=false len=23 pn=13 [2025-04-30T19:23:27.869526833Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm ACK delay=19 blocks=[4..8] ecn_counts=None [2025-04-30T19:23:27.869531541Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f packet newly acked 5 [2025-04-30T19:23:27.869534767Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f packet newly acked 6 [2025-04-30T19:23:27.869537733Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f packet newly acked 7 [2025-04-30T19:23:27.869540448Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f packet newly acked 8 [2025-04-30T19:23:27.869559825Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 44 bytes [2025-04-30T19:23:27.869564683Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:27.869567799Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:27.869573871Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:27.872024599Z TRACE quiche_apps::client] got 162 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:27.872039317Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx pkt Short dcid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f key_phase=false len=141 pn=14 [2025-04-30T19:23:27.872048905Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm STREAM id=0 off=0 len=119 fin=false [2025-04-30T19:23:27.872059565Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 162 bytes [2025-04-30T19:23:27.872064364Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:27.872067420Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:27.872070926Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f stream id 0 is readable [2025-04-30T19:23:27.872077689Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 0 [2025-04-30T19:23:27.872099109Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 0 [2025-04-30T19:23:27.872103247Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 0 [2025-04-30T19:23:27.872108557Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 116 bytes on stream 0 [2025-04-30T19:23:27.872112354Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm HEADERS stream=0 payload_len=116 [2025-04-30T19:23:27.872116822Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0 [2025-04-30T19:23:27.872119948Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true [2025-04-30T19:23:27.872125468Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[97, 105, 111, 113, 117, 105, 99, 47, 49, 46, 50, 46, 48] [2025-04-30T19:23:27.872132702Z TRACE quiche::h3::qpack::decoder] Literal name_idx=6 static=true value=[87, 101, 100, 44, 32, 51, 48, 32, 65, 112, 114, 32, 50, 48, 50, 53, 32, 49, 57, 58, 50, 51, 58, 50, 55, 32, 71, 77, 84] [2025-04-30T19:23:27.872138954Z TRACE quiche::h3::qpack::decoder] Literal name_idx=44 static=true value=[116, 101, 120, 116, 47, 112, 108, 97, 105, 110, 59, 32, 99, 104, 97, 114, 115, 101, 116, 61, 117, 116, 102, 45, 56] [2025-04-30T19:23:27.872146778Z TRACE quiche::h3::qpack::decoder] Literal name_idx=4 static=true value=[49, 48, 50, 52] [2025-04-30T19:23:27.872150535Z TRACE quiche::h3::qpack::decoder] Literal name_idx=10 static=true value=[87, 101, 100, 44, 32, 51, 48, 32, 65, 112, 114, 32, 50, 48, 50, 53, 32, 49, 57, 58, 50, 51, 58, 50, 51, 32, 71, 77, 84] [2025-04-30T19:23:27.872156516Z TRACE quiche::h3::qpack::decoder] Literal name_idx=7 static=true value=[34, 49, 48, 51, 101, 100, 100, 48, 55, 51, 57, 57, 97, 49, 99, 56, 57, 100, 52, 49, 48, 57, 100, 49, 57, 98, 97, 57, 99, 51, 55, 99, 52, 34] [2025-04-30T19:23:27.872169371Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "aioquic/1.2.0"), ("date", "Wed, 30 Apr 2025 19:23:27 GMT"), ("content-type", "text/plain; charset=utf-8"), ("content-length", "1024"), ("last-modified", "Wed, 30 Apr 2025 19:23:23 GMT"), ("etag", "\"103edd07399a1c89d4109d19ba9c37c4\"")] on stream id 0 [2025-04-30T19:23:27.872182816Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T19:23:27.872187174Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=5 pn=10 [2025-04-30T19:23:27.872190300Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm ACK delay=18 blocks=[12..14] ecn_counts=None [2025-04-30T19:23:27.872199056Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=none latest_rtt=1.377519393s srtt=1.493334619s min_rtt=1.377519393s rttvar=461.973307ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1726, delivered_time: Instant { tv_sec: 200, tv_nsec: 867946457 }, first_sent_time: Instant { tv_sec: 200, tv_nsec: 867946457 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 8, rate_sample: RateSample { delivery_rate: 914, is_app_limited: true, interval: 1.523465374s, delivered: 1393, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 199, tv_nsec: 363325639 }), send_elapsed: 1.523465374s, ack_elapsed: 1.504469314s, rtt: 1.4932581s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11300, last_update: Instant { tv_sec: 200, tv_nsec: 867946457 }, next_time: Instant { tv_sec: 200, tv_nsec: 867946457 }, 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-30T19:23:27.872248198Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:27.872253728Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:27.873299276Z TRACE quiche_apps::client] got 1072 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:27.873311749Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx pkt Short dcid=2aa093e21c5629c85b007a2e00ae20059b1d5d5f key_phase=false len=1051 pn=15 [2025-04-30T19:23:27.873319604Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm STREAM id=0 off=119 len=1027 fin=true [2025-04-30T19:23:27.873328350Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 1072 bytes [2025-04-30T19:23:27.873332258Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:27.873334722Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:27.873337477Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f stream id 0 is readable [2025-04-30T19:23:27.873341755Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 0 [2025-04-30T19:23:27.873345162Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 0 [2025-04-30T19:23:27.873353738Z TRACE quiche::h3::stream] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f read 1 bytes on stream 0 [2025-04-30T19:23:27.873356323Z TRACE quiche::h3] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f rx frm DATA stream=0 wire_payload_len=1024 [2025-04-30T19:23:27.873363566Z DEBUG quiche_apps::common] got 1024 bytes of response data on stream 0 [2025-04-30T19:23:27.873366862Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T19:23:27.873369648Z INFO quiche_apps::common] 1/1 response(s) received in 3.024430565s, closing... [2025-04-30T19:23:27.873376671Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1324 [2025-04-30T19:23:27.873380568Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx pkt Short dcid=a48d6ba6567ed396 key_phase=false len=11 pn=11 [2025-04-30T19:23:27.873383053Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T19:23:27.873390727Z TRACE quiche::recovery::congestion::recovery] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f timer=3.366210735s latest_rtt=1.377519393s srtt=1.493334619s min_rtt=1.377519393s rttvar=461.973307ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1726, delivered_time: Instant { tv_sec: 200, tv_nsec: 867946457 }, first_sent_time: Instant { tv_sec: 200, tv_nsec: 867946457 }, end_of_app_limited: 10, last_sent_packet: 11, largest_acked: 8, rate_sample: RateSample { delivery_rate: 914, is_app_limited: true, interval: 1.523465374s, delivered: 1393, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 199, tv_nsec: 363325639 }), send_elapsed: 1.523465374s, ack_elapsed: 1.504469314s, rtt: 1.4932581s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11300, last_update: Instant { tv_sec: 200, tv_nsec: 875649269 }, next_time: Instant { tv_sec: 200, tv_nsec: 867946457 }, max_datagram_size: 1350, last_packet_size: None, iv: 3.274336ms, 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-30T19:23:27.873430181Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:47651 to 193.167.100.100:443 [2025-04-30T19:23:27.873434199Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:28.073919767Z TRACE quiche_apps::client] got 166 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:28.073950695Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 166 bytes [2025-04-30T19:23:28.073956526Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:28.073959982Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:28.073968458Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:28.475081651Z TRACE quiche_apps::client] got 166 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:28.475113531Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 166 bytes [2025-04-30T19:23:28.475119502Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:28.475122898Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:28.475131184Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:29.276884493Z TRACE quiche_apps::client] got 166 bytes from 193.167.100.100:443 to 0.0.0.0:47651 [2025-04-30T19:23:29.276925140Z TRACE quiche_apps::client] 0.0.0.0:47651: processed 166 bytes [2025-04-30T19:23:29.276933244Z TRACE quiche_apps::client] 0.0.0.0:47651: recv() would block [2025-04-30T19:23:29.276938274Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:29.276948313Z TRACE quiche_apps::client] 0.0.0.0:47651 -> 193.167.100.100:443: done writing [2025-04-30T19:23:37.906648371Z TRACE quiche_apps::client] timed out [2025-04-30T19:23:37.906685300Z TRACE quiche] 2aa093e21c5629c85b007a2e00ae20059b1d5d5f draining timeout expired [2025-04-30T19:23:37.906753227Z TRACE quiche_apps::client] done reading [2025-04-30T19:23:37.906760891Z INFO quiche_apps::client] connection closed, recv=7 sent=12 lost=0 retrans=1 sent_bytes=2335 recv_bytes=2720 lost_bytes=0 [local_addr=0.0.0.0:47651 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=7 sent=12 lost=0 retrans=1 rtt=1.493334619s min_rtt=Some(1.377519393s) rttvar=461.973307ms cwnd=13500 sent_bytes=2335 recv_bytes=2720 lost_bytes=0 stream_retrans_bytes=266 pmtu=1350 delivery_rate=914]