[2025-09-12T13:23:16.323683963Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T13:23:16.323988033Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:58120 with scid 835b1a7f5896c06dd24722677d72d4d4861df623 [2025-09-12T13:23:16.324033388Z TRACE quiche::tls] 835b1a7f5896c06dd24722677d72d4d4861df623 write message lvl=Initial len=266 [2025-09-12T13:23:16.324049728Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Initial version=1 dcid=93a792c613cb3ec5efa9fa744ba4a83f scid=835b1a7f5896c06dd24722677d72d4d4861df623 len=270 pn=0 [2025-09-12T13:23:16.324052854Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm CRYPTO off=0 len=266 [2025-09-12T13:23:16.324067231Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=998.926903ms 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: 539, tv_nsec: 525262455 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 525262455 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 539, tv_nsec: 525262455 }, next_time: Instant { tv_sec: 539, tv_nsec: 525262455 }, 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-09-12T13:23:16.324122385Z TRACE quiche_apps::client] written 1200 [2025-09-12T13:23:16.362974295Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:58120 [2025-09-12T13:23:16.362994232Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx pkt Initial version=1 dcid=835b1a7f5896c06dd24722677d72d4d4861df623 scid=ab79adc3de31f6f8 token= len=117 pn=0 [2025-09-12T13:23:16.363019109Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm ACK delay=149 blocks=[0..0] ecn_counts=None [2025-09-12T13:23:16.363028356Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 packet newly acked 0 [2025-09-12T13:23:16.363036732Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm CRYPTO off=0 len=90 [2025-09-12T13:23:16.363175191Z TRACE quiche::tls] 835b1a7f5896c06dd24722677d72d4d4861df623 set write secret lvl=Handshake [2025-09-12T13:23:16.363186683Z TRACE quiche::tls] 835b1a7f5896c06dd24722677d72d4d4861df623 set read secret lvl=Handshake [2025-09-12T13:23:16.363216319Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx pkt Handshake version=1 dcid=835b1a7f5896c06dd24722677d72d4d4861df623 scid=ab79adc3de31f6f8 len=1060 pn=1 [2025-09-12T13:23:16.363223963Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm CRYPTO off=0 len=711 [2025-09-12T13:23:16.363430590Z TRACE quiche::tls] 835b1a7f5896c06dd24722677d72d4d4861df623 write message lvl=Handshake len=36 [2025-09-12T13:23:16.363434347Z TRACE quiche::tls] 835b1a7f5896c06dd24722677d72d4d4861df623 set write secret lvl=OneRTT [2025-09-12T13:23:16.363440779Z TRACE quiche::tls] 835b1a7f5896c06dd24722677d72d4d4861df623 set read secret lvl=OneRTT [2025-09-12T13:23:16.363455717Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 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(93a792c613cb3ec5efa9fa744ba4a83f), max_idle_timeout: 30000, stateless_reset_token: Some(306605429186670145493991015125849588690), max_udp_payload_size: 65527, initial_max_data: 1572864, initial_max_stream_data_bidi_local: 0, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 12288, initial_max_streams_bidi: 100, initial_max_streams_uni: 3, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(ab79adc3de31f6f8), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-09-12T13:23:16.363473931Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm PADDING len=328 [2025-09-12T13:23:16.363487697Z TRACE quiche_apps::client] 0.0.0.0:58120: processed 1252 bytes [2025-09-12T13:23:16.363492466Z TRACE quiche_apps::client] 0.0.0.0:58120: recv() would block [2025-09-12T13:23:16.363494981Z TRACE quiche_apps::client] done reading [2025-09-12T13:23:16.363508536Z TRACE quiche::h3] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm SETTINGS stream=2 len=18 [2025-09-12T13:23:16.363524115Z TRACE quiche::h3] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm GREASE stream=0 len=0 [2025-09-12T13:23:16.363530007Z TRACE quiche::h3] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm GREASE stream=0 len=18 [2025-09-12T13:23:16.363537450Z TRACE quiche::h3] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm HEADERS stream=0 len=29 fin=true [2025-09-12T13:23:16.363543341Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server4", ":path: /idnftfqgsf", "user-agent: quiche"] [2025-09-12T13:23:16.363602552Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Initial version=1 dcid=ab79adc3de31f6f8 scid=835b1a7f5896c06dd24722677d72d4d4861df623 len=6 pn=1 [2025-09-12T13:23:16.363606440Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm ACK delay=76 blocks=[0..0] ecn_counts=None [2025-09-12T13:23:16.363615156Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=116.354002ms latest_rtt=38.993045ms srtt=38.993045ms min_rtt=38.993045ms rttvar=19.496522ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 68.31 Kbps, is_app_limited: true, interval: 38.993045ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 525262455 }), send_elapsed: 0ns, ack_elapsed: 38.993045ms, rtt: 38.993045ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432769, last_update: Instant { tv_sec: 539, tv_nsec: 564718948 }, next_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, 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-09-12T13:23:16.363633510Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Handshake version=1 dcid=ab79adc3de31f6f8 scid=835b1a7f5896c06dd24722677d72d4d4861df623 len=45 pn=2 [2025-09-12T13:23:16.363636446Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm ACK delay=52 blocks=[1..1] ecn_counts=None [2025-09-12T13:23:16.363639061Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm CRYPTO off=0 len=36 [2025-09-12T13:23:16.363644571Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=116.929911ms latest_rtt=38.993045ms srtt=38.993045ms min_rtt=38.993045ms rttvar=19.496522ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 68.31 Kbps, is_app_limited: true, interval: 38.993045ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 525262455 }), send_elapsed: 0ns, ack_elapsed: 38.993045ms, rtt: 38.993045ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432769, last_update: Instant { tv_sec: 539, tv_nsec: 564860584 }, next_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, max_datagram_size: 1350, last_packet_size: None, iv: 228.759µ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=0 w_max=0 } [2025-09-12T13:23:16.363659710Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 dropped epoch 0 state [2025-09-12T13:23:16.363672884Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Short dcid=ab79adc3de31f6f8 key_phase=false len=1164 pn=3 [2025-09-12T13:23:16.363675479Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[c3, 9d, 04, ee, df, 49, 9a, 19, 90, bc, 1c, c3, 57, 05, 6c, 32, 80, 7b, 6e, 9c] reset_token=[7c, 69, 26, 42, 2c, fd, b3, 50, 6f, b1, 7e, 5e, 16, 58, ba, 5d] [2025-09-12T13:23:16.363681821Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[e1, e8, 31, 09, 00, cc, 80, 17, 50, 60, a1, ee, d6, 4f, 7f, 99, 56, 9f, e1, 08] reset_token=[ef, 0b, 6d, 83, 39, 87, 05, f6, 72, 90, 5c, b8, 5c, 52, dc, 0c] [2025-09-12T13:23:16.363687231Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[df, cc, a0, 17, a7, 57, ef, 08, bb, dc, 22, b1, 2f, 84, 4f, b3, 43, fc, 33, e9] reset_token=[bb, 5a, ea, 9a, 28, ac, 2b, f4, 49, c5, 7f, ab, ce, b1, bc, 72] [2025-09-12T13:23:16.363692120Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[52, e0, 75, 1f, 4e, 41, cd, 6e, ae, 2b, 7f, 8e, 8e, eb, 16, 8b, 0b, 2b, 80, f0] reset_token=[66, 47, 24, 48, b5, 45, 32, 45, 91, b1, 0f, bf, 3c, 7a, 30, 7d] [2025-09-12T13:23:16.363696919Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[2e, 79, 8c, c6, 40, af, b7, 1a, 65, 7b, 6a, 8e, e5, b8, 87, 20, 73, fc, 07, 01] reset_token=[86, e8, dd, 1b, 39, cf, b5, 87, b8, 09, f1, 79, 7d, 1b, 72, ca] [2025-09-12T13:23:16.363701758Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[21, 2a, e2, 71, 12, fa, 83, 5d, fd, 5f, 88, 5b, e1, e1, 48, e6, 23, 38, d4, 08] reset_token=[5f, 6e, a2, 93, d2, fa, 21, cb, f2, 0c, 69, de, bb, d5, bc, 0e] [2025-09-12T13:23:16.363706577Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[b9, f0, d5, 85, 5b, 8f, 82, cd, 69, dc, 42, 6d, ce, be, 79, 97, cd, be, 10, 99] reset_token=[7b, 78, 0d, 90, 78, f4, af, e8, 57, 81, e0, c7, ec, f0, 69, a2] [2025-09-12T13:23:16.363711276Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm STREAM id=2 off=0 len=19 fin=false [2025-09-12T13:23:16.363713821Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm PADDING len=860 [2025-09-12T13:23:16.363767461Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=116.80637ms latest_rtt=38.993045ms srtt=38.993045ms min_rtt=38.993045ms rttvar=19.496522ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 68.31 Kbps, is_app_limited: true, interval: 38.993045ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 525262455 }), send_elapsed: 0ns, ack_elapsed: 38.993045ms, rtt: 38.993045ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1190, rate: 432769, last_update: Instant { tv_sec: 539, tv_nsec: 564860584 }, next_time: Instant { tv_sec: 539, tv_nsec: 565089343 }, max_datagram_size: 1350, last_packet_size: Some(1190), 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-09-12T13:23:16.363807467Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:58120 to 193.167.100.100:443 [2025-09-12T13:23:16.363816503Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Short dcid=ab79adc3de31f6f8 key_phase=false len=6 pn=4 [2025-09-12T13:23:16.363821573Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm STREAM id=6 off=0 len=1 fin=false [2025-09-12T13:23:16.363831231Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=116.74273ms latest_rtt=38.993045ms srtt=38.993045ms min_rtt=38.993045ms rttvar=19.496522ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1321 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 68.31 Kbps, is_app_limited: true, interval: 38.993045ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 525262455 }), send_elapsed: 0ns, ack_elapsed: 38.993045ms, rtt: 38.993045ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432769, last_update: Instant { tv_sec: 539, tv_nsec: 565076639 }, next_time: Instant { tv_sec: 539, tv_nsec: 565089343 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.823677ms, 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-09-12T13:23:16.363877548Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:58120 to 193.167.100.100:443 [2025-09-12T13:23:16.363890011Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Short dcid=ab79adc3de31f6f8 key_phase=false len=6 pn=5 [2025-09-12T13:23:16.363894139Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm STREAM id=10 off=0 len=1 fin=false [2025-09-12T13:23:16.363903556Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=116.670365ms latest_rtt=38.993045ms srtt=38.993045ms min_rtt=38.993045ms rttvar=19.496522ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1353 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { bandwidth: 68.31 Kbps, is_app_limited: true, interval: 38.993045ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 525262455 }), send_elapsed: 0ns, ack_elapsed: 38.993045ms, rtt: 38.993045ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 32, rate: 432769, last_update: Instant { tv_sec: 539, tv_nsec: 565076639 }, next_time: Instant { tv_sec: 539, tv_nsec: 567973132 }, 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-09-12T13:23:16.363944593Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:58120 to 193.167.100.100:443 [2025-09-12T13:23:16.363953951Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Short dcid=ab79adc3de31f6f8 key_phase=false len=72 pn=6 [2025-09-12T13:23:16.363958439Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm STREAM id=0 off=0 len=67 fin=true [2025-09-12T13:23:16.363967857Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=116.606134ms latest_rtt=38.993045ms srtt=38.993045ms min_rtt=38.993045ms rttvar=19.496522ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1451 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { bandwidth: 68.31 Kbps, is_app_limited: true, interval: 38.993045ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 525262455 }), send_elapsed: 0ns, ack_elapsed: 38.993045ms, rtt: 38.993045ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432769, last_update: Instant { tv_sec: 539, tv_nsec: 565213325 }, next_time: Instant { tv_sec: 539, tv_nsec: 567973132 }, max_datagram_size: 1350, last_packet_size: None, iv: 300.391µ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=0 w_max=0 } [2025-09-12T13:23:16.364006039Z TRACE quiche_apps::client] written 98 bytes from 0.0.0.0:58120 to 193.167.100.100:443 [2025-09-12T13:23:16.364011208Z TRACE quiche_apps::client] 0.0.0.0:58120 -> 193.167.100.100:443: done writing [2025-09-12T13:23:16.396862220Z TRACE quiche_apps::client] got 583 bytes from 193.167.100.100:443 to 0.0.0.0:58120 [2025-09-12T13:23:16.396880164Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx pkt Short dcid=835b1a7f5896c06dd24722677d72d4d4861df623 key_phase=false len=562 pn=2 [2025-09-12T13:23:16.396892838Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm CRYPTO off=0 len=540 [2025-09-12T13:23:16.396928975Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm HANDSHAKE_DONE [2025-09-12T13:23:16.396937872Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 dropped epoch 1 state [2025-09-12T13:23:16.396951327Z TRACE quiche_apps::client] 0.0.0.0:58120: processed 583 bytes [2025-09-12T13:23:16.396958631Z TRACE quiche_apps::client] 0.0.0.0:58120: recv() would block [2025-09-12T13:23:16.396962989Z TRACE quiche_apps::client] done reading [2025-09-12T13:23:16.396977496Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Short dcid=ab79adc3de31f6f8 key_phase=false len=5 pn=7 [2025-09-12T13:23:16.396982606Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm ACK delay=12 blocks=[2..2] ecn_counts=None [2025-09-12T13:23:16.396995871Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=108.930641ms latest_rtt=38.993045ms srtt=38.993045ms min_rtt=38.993045ms rttvar=19.496522ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1352 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 564718978 }, end_of_app_limited: 5, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { bandwidth: 68.31 Kbps, is_app_limited: true, interval: 38.993045ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 525262455 }), send_elapsed: 0ns, ack_elapsed: 38.993045ms, rtt: 38.993045ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 432769, last_update: Instant { tv_sec: 539, tv_nsec: 598234866 }, next_time: Instant { tv_sec: 539, tv_nsec: 598535257 }, 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-09-12T13:23:16.397064690Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:58120 to 193.167.100.100:443 [2025-09-12T13:23:16.397075200Z TRACE quiche_apps::client] 0.0.0.0:58120 -> 193.167.100.100:443: done writing [2025-09-12T13:23:16.397088685Z TRACE quiche_apps::client] got 314 bytes from 193.167.100.100:443 to 0.0.0.0:58120 [2025-09-12T13:23:16.397095668Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 dropped invalid packet [2025-09-12T13:23:16.397100978Z TRACE quiche_apps::client] 0.0.0.0:58120: processed 314 bytes [2025-09-12T13:23:16.397107770Z TRACE quiche_apps::client] 0.0.0.0:58120: recv() would block [2025-09-12T13:23:16.397112319Z TRACE quiche_apps::client] done reading [2025-09-12T13:23:16.397120064Z TRACE quiche_apps::client] 0.0.0.0:58120 -> 193.167.100.100:443: done writing [2025-09-12T13:23:16.397131094Z TRACE quiche_apps::client] got 48 bytes from 193.167.100.100:443 to 0.0.0.0:58120 [2025-09-12T13:23:16.397138187Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx pkt Short dcid=835b1a7f5896c06dd24722677d72d4d4861df623 key_phase=false len=27 pn=5 [2025-09-12T13:23:16.397148106Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm ACK delay=15 blocks=[3..6] ecn_counts=None [2025-09-12T13:23:16.397154478Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 packet newly acked 3 [2025-09-12T13:23:16.397159718Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 packet newly acked 4 [2025-09-12T13:23:16.397164036Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 packet newly acked 5 [2025-09-12T13:23:16.397167923Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 packet newly acked 6 [2025-09-12T13:23:16.397174135Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 rx frm STREAM id=0 off=0 len=0 fin=true [2025-09-12T13:23:16.397198751Z TRACE quiche_apps::client] 0.0.0.0:58120: processed 48 bytes [2025-09-12T13:23:16.397206676Z TRACE quiche_apps::client] 0.0.0.0:58120: recv() would block [2025-09-12T13:23:16.397211315Z TRACE quiche_apps::client] done reading [2025-09-12T13:23:16.397216514Z TRACE quiche::h3] 835b1a7f5896c06dd24722677d72d4d4861df623 stream id 0 is readable [2025-09-12T13:23:16.397226192Z TRACE quiche::h3::stream] 835b1a7f5896c06dd24722677d72d4d4861df623 read 0 bytes on stream 0 [2025-09-12T13:23:16.397231923Z DEBUG quiche_apps::common] 1/1 responses received [2025-09-12T13:23:16.397236722Z INFO quiche_apps::common] 1/1 response(s) received in 73.1105ms, closing... [2025-09-12T13:23:16.397249025Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx pkt Short dcid=ab79adc3de31f6f8 key_phase=false len=11 pn=8 [2025-09-12T13:23:16.397254906Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-09-12T13:23:16.397268101Z TRACE quiche::recovery::congestion::recovery] 835b1a7f5896c06dd24722677d72d4d4861df623 timer=129.951691ms latest_rtt=30.428507ms srtt=37.922477ms min_rtt=30.428507ms rttvar=16.763525ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1685, delivered_time: Instant { tv_sec: 539, tv_nsec: 598535257 }, first_sent_time: Instant { tv_sec: 539, tv_nsec: 598535257 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 6, rate_sample: RateSample { bandwidth: 321.11 Kbps, is_app_limited: true, interval: 33.682661ms, delivered: 1352, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 539, tv_nsec: 564718978 }), send_elapsed: 3.254154ms, ack_elapsed: 33.682661ms, rtt: 30.428507ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 444986, last_update: Instant { tv_sec: 539, tv_nsec: 598509141 }, next_time: Instant { tv_sec: 539, tv_nsec: 598535257 }, max_datagram_size: 1350, last_packet_size: None, iv: 83.149µ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=0 w_max=0 } [2025-09-12T13:23:16.397329185Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:58120 to 193.167.100.100:443 [2025-09-12T13:23:16.397334856Z TRACE quiche_apps::client] 0.0.0.0:58120 -> 193.167.100.100:443: done writing [2025-09-12T13:23:16.712706645Z TRACE quiche_apps::client] timed out [2025-09-12T13:23:16.712725490Z TRACE quiche] 835b1a7f5896c06dd24722677d72d4d4861df623 draining timeout expired [2025-09-12T13:23:16.712792205Z TRACE quiche_apps::client] done reading [2025-09-12T13:23:16.712799679Z INFO quiche_apps::client] connection closed, recv=4 sent=9 lost=0 retrans=0 sent_bytes=1913 recv_bytes=1883 lost_bytes=0 [local_addr=0.0.0.0:58120 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=4 sent=9 lost=0 retrans=0 rtt=37.922477ms min_rtt=Some(30.428507ms) rttvar=16.763525ms cwnd=13500 sent_bytes=1913 recv_bytes=1883 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=40139]