[2025-04-30T18:33:15.134632580Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T18:33:15.134930137Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:44459 with scid aadb6979291d720fec068764bfb0f113f16df223 [2025-04-30T18:33:15.134974340Z TRACE quiche::tls] aadb6979291d720fec068764bfb0f113f16df223 write message lvl=Initial len=266 [2025-04-30T18:33:15.134994618Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Initial version=1 dcid=2b33eb9b7b4c2263b7cac0cee9cf2a5e scid=aadb6979291d720fec068764bfb0f113f16df223 len=270 pn=0 [2025-04-30T18:33:15.134997634Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm CRYPTO off=0 len=266 [2025-04-30T18:33:15.135012712Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=998.924318ms 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: 256, tv_nsec: 604370523 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, 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: 256, tv_nsec: 604370523 }, next_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, 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-30T18:33:15.135079827Z TRACE quiche_apps::client] written 1200 [2025-04-30T18:33:16.135161336Z TRACE quiche_apps::client] timed out [2025-04-30T18:33:16.135199307Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 loss detection timeout expired [2025-04-30T18:33:16.135207642Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=997.728617ms 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: 256, tv_nsec: 604370523 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, 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: 256, tv_nsec: 604370523 }, next_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, 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-30T18:33:16.135231848Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:16.135278485Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Initial version=1 dcid=2b33eb9b7b4c2263b7cac0cee9cf2a5e scid=aadb6979291d720fec068764bfb0f113f16df223 len=270 pn=1 [2025-04-30T18:33:16.135282813Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm CRYPTO off=0 len=266 [2025-04-30T18:33:16.135302420Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=1.997948623s 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: 256, tv_nsec: 604370523 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, 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: 257, tv_nsec: 604684245 }, next_time: Instant { tv_sec: 257, tv_nsec: 604684245 }, 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-30T18:33:16.135429728Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:44459 to 193.167.100.100:443 [2025-04-30T18:33:16.135437793Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:16.643986390Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:16.644030703Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx pkt Initial version=1 dcid=aadb6979291d720fec068764bfb0f113f16df223 scid=eb5606fc11fbcdc357 token= len=119 pn=0 [2025-04-30T18:33:16.644048757Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm ACK delay=3 blocks=[0..0] ecn_counts=None [2025-04-30T18:33:16.644056882Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 packet newly acked 0 [2025-04-30T18:33:16.644064917Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm CRYPTO off=0 len=90 [2025-04-30T18:33:16.644210019Z TRACE quiche::tls] aadb6979291d720fec068764bfb0f113f16df223 set write secret lvl=Handshake [2025-04-30T18:33:16.644224706Z TRACE quiche::tls] aadb6979291d720fec068764bfb0f113f16df223 set read secret lvl=Handshake [2025-04-30T18:33:16.644269500Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx pkt Handshake version=1 dcid=aadb6979291d720fec068764bfb0f113f16df223 scid=eb5606fc11fbcdc357 len=1024 pn=1 [2025-04-30T18:33:16.644277144Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm CRYPTO off=0 len=740 [2025-04-30T18:33:16.644533685Z TRACE quiche::tls] aadb6979291d720fec068764bfb0f113f16df223 write message lvl=Handshake len=52 [2025-04-30T18:33:16.644538854Z TRACE quiche::tls] aadb6979291d720fec068764bfb0f113f16df223 set write secret lvl=OneRTT [2025-04-30T18:33:16.644548503Z TRACE quiche::tls] aadb6979291d720fec068764bfb0f113f16df223 set read secret lvl=OneRTT [2025-04-30T18:33:16.644599127Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 connection established: proto=Ok("hq-interop") cipher=Some(AES256_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(2b33eb9b7b4c2263b7cac0cee9cf2a5e), max_idle_timeout: 30000, stateless_reset_token: Some(178852241365078527301315062854366626009), max_udp_payload_size: 1472, initial_max_data: 16777216, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 8, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(eb5606fc11fbcdc357), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T18:33:16.644615317Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm PADDING len=260 [2025-04-30T18:33:16.644632429Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1220 bytes [2025-04-30T18:33:16.644638240Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:16.644641637Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:16.644658679Z DEBUG quiche_apps::common] sending HTTP request "GET /qwnddvwfzu\r\n" [2025-04-30T18:33:16.644752885Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Initial version=1 dcid=eb5606fc11fbcdc357 scid=aadb6979291d720fec068764bfb0f113f16df223 len=6 pn=2 [2025-04-30T18:33:16.644757374Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm ACK delay=90 blocks=[0..0] ecn_counts=None [2025-04-30T18:33:16.644768675Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=4.017741583s latest_rtt=1.509086489s srtt=1.509086489s min_rtt=1.509086489s rttvar=754.543244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 258, tv_nsec: 113457012 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.509086489s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 256, tv_nsec: 604370523 }), send_elapsed: 0ns, ack_elapsed: 1.509086489s, rtt: 1.509086489s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11182, last_update: Instant { tv_sec: 258, tv_nsec: 114029304 }, next_time: Instant { tv_sec: 258, tv_nsec: 114029344 }, 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-30T18:33:16.644794152Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Handshake version=1 dcid=eb5606fc11fbcdc357 scid=aadb6979291d720fec068764bfb0f113f16df223 len=62 pn=3 [2025-04-30T18:33:16.644797719Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm ACK delay=65 blocks=[1..1] ecn_counts=None [2025-04-30T18:33:16.644800955Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm CRYPTO off=0 len=52 [2025-04-30T18:33:16.644808299Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=4.017702269s latest_rtt=1.509086489s srtt=1.509086489s min_rtt=1.509086489s rttvar=754.543244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 258, tv_nsec: 113457012 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.509086489s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 256, tv_nsec: 604370523 }), send_elapsed: 0ns, ack_elapsed: 1.509086489s, rtt: 1.509086489s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11182, last_update: Instant { tv_sec: 258, tv_nsec: 114174696 }, next_time: Instant { tv_sec: 258, tv_nsec: 114029344 }, max_datagram_size: 1350, last_packet_size: None, iv: 10.463245ms, 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-30T18:33:16.644821964Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 dropped epoch 0 state [2025-04-30T18:33:16.644827445Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13383 out_len=1171 left=1144 [2025-04-30T18:33:16.644841381Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Short dcid=eb5606fc11fbcdc357 key_phase=false len=1144 pn=4 [2025-04-30T18:33:16.644844597Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[9f, 9a, af, 95, 58, 0e, aa, 0c, a6, 1f, fc, 99, 88, 37, c0, 16, 86, e4, b5, 72] reset_token=[bf, db, c6, c2, ae, 47, 53, 91, 51, be, b7, 7c, 87, 2a, 0e, f1] [2025-04-30T18:33:16.644858453Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[b4, 4c, 9e, 41, cb, 5a, 9f, 84, 06, b4, a1, 3e, b8, 4e, 6f, 6f, 8a, 6f, 27, 00] reset_token=[e7, d9, ef, 6a, 6a, b8, 56, b0, ca, 04, 66, d5, 7c, bc, 89, 47] [2025-04-30T18:33:16.644865486Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[79, 3f, 72, 2d, 24, 48, db, 92, 20, fc, c7, 1b, 2d, 7a, 8d, 66, 29, 23, 58, 5f] reset_token=[52, 2d, f3, a9, 01, 6a, b0, d1, 7b, dd, 40, 12, d0, d0, 17, 62] [2025-04-30T18:33:16.644872229Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T18:33:16.644875515Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm PADDING len=1002 [2025-04-30T18:33:16.644884832Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=4.527115766s latest_rtt=1.509086489s srtt=1.509086489s min_rtt=1.509086489s rttvar=754.543244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1288 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 258, tv_nsec: 113457012 }, first_sent_time: Instant { tv_sec: 256, tv_nsec: 604370523 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.509086489s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 256, tv_nsec: 604370523 }), send_elapsed: 0ns, ack_elapsed: 1.509086489s, rtt: 1.509086489s } } pacer=Pacer { enabled: true, capacity: 13500, used: 1171, rate: 11182, last_update: Instant { tv_sec: 258, tv_nsec: 114174696 }, next_time: Instant { tv_sec: 258, tv_nsec: 124637941 }, max_datagram_size: 1350, last_packet_size: Some(1171), 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-30T18:33:16.644950645Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:44459 to 193.167.100.100:443 [2025-04-30T18:33:16.644958760Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:16.794401017Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:16.794444739Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 dropped invalid packet [2025-04-30T18:33:16.794450540Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1220 bytes [2025-04-30T18:33:16.794456091Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:16.794459447Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:16.794469315Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:17.094969275Z TRACE quiche_apps::client] got 1132 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:17.095009130Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 dropped invalid packet [2025-04-30T18:33:17.095014580Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1132 bytes [2025-04-30T18:33:17.095020060Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:17.095023496Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:17.095033184Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:17.663712894Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:17.663754773Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 dropped invalid packet [2025-04-30T18:33:17.663760062Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1220 bytes [2025-04-30T18:33:17.663783236Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:17.663786933Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:17.663796320Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:17.695999153Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:17.696036453Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 dropped invalid packet [2025-04-30T18:33:17.696041312Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1220 bytes [2025-04-30T18:33:17.696046101Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:17.696048856Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:17.696057352Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:18.148104190Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:18.148144305Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx pkt Short dcid=aadb6979291d720fec068764bfb0f113f16df223 key_phase=false len=1199 pn=9 [2025-04-30T18:33:18.148162309Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm ACK delay=0 blocks=[4..4] ecn_counts=None [2025-04-30T18:33:18.148170574Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 packet newly acked 4 [2025-04-30T18:33:18.148178229Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm HANDSHAKE_DONE [2025-04-30T18:33:18.148186043Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 dropped epoch 1 state [2025-04-30T18:33:18.148193948Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[eb, 56, c8, e0, ca, 42, d9, 5c, 55] reset_token=[fe, af, 5f, 51, 6b, 26, 9e, f0, 96, 32, a5, 2a, ae, 60, bf, c1] [2025-04-30T18:33:18.148205139Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[eb, 56, 7f, 0e, b4, 49, dd, 25, 29] reset_token=[30, 71, 22, d6, de, a4, 80, ba, d7, 84, 24, 8e, 75, 99, ff, 34] [2025-04-30T18:33:18.148212994Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[eb, 56, 3f, 9a, 17, fd, 06, 1d, bb] reset_token=[11, c6, cf, d4, ca, de, e3, 54, e8, 03, 64, 0d, 47, bb, b9, 92] [2025-04-30T18:33:18.148223413Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm PADDING len=1086 [2025-04-30T18:33:18.148257557Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1220 bytes [2025-04-30T18:33:18.148263368Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:18.148266614Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:18.148279268Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318 [2025-04-30T18:33:18.148286461Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Short dcid=eb5606fc11fbcdc357 key_phase=false len=5 pn=5 [2025-04-30T18:33:18.148289848Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm ACK delay=17 blocks=[9..9] ecn_counts=None [2025-04-30T18:33:18.148299185Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=none latest_rtt=1.492932964s srtt=1.507067297s min_rtt=1.492932964s rttvar=569.945814ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1504, delivered_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, first_sent_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { delivery_rate: 770, is_app_limited: true, interval: 1.520267418s, delivered: 1171, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 258, tv_nsec: 113457012 }), send_elapsed: 1.520267418s, ack_elapsed: 1.504113893s, rtt: 1.492932964s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11197, last_update: Instant { tv_sec: 259, tv_nsec: 617705717 }, next_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, 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-30T18:33:18.148395856Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:44459 to 193.167.100.100:443 [2025-04-30T18:33:18.148406266Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:18.148967386Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:18.148980210Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx pkt Short dcid=aadb6979291d720fec068764bfb0f113f16df223 key_phase=false len=1231 pn=10 [2025-04-30T18:33:18.148988004Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm PING mtu_probe=None [2025-04-30T18:33:18.148995048Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm PADDING len=1210 [2025-04-30T18:33:18.149002281Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1252 bytes [2025-04-30T18:33:18.149006128Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:18.149008573Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:18.149015576Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318 [2025-04-30T18:33:18.149019193Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Short dcid=eb5606fc11fbcdc357 key_phase=false len=5 pn=6 [2025-04-30T18:33:18.149021717Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm ACK delay=4 blocks=[9..10] ecn_counts=None [2025-04-30T18:33:18.149028670Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=none latest_rtt=1.492932964s srtt=1.507067297s min_rtt=1.492932964s rttvar=569.945814ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1504, delivered_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, first_sent_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { delivery_rate: 770, is_app_limited: true, interval: 1.520267418s, delivered: 1171, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 258, tv_nsec: 113457012 }), send_elapsed: 1.520267418s, ack_elapsed: 1.504113893s, rtt: 1.492932964s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11197, last_update: Instant { tv_sec: 259, tv_nsec: 617705717 }, next_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, 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-30T18:33:18.149074827Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:44459 to 193.167.100.100:443 [2025-04-30T18:33:18.149083052Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:18.149165687Z TRACE quiche_apps::client] got 366 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:18.149171177Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx pkt Short dcid=aadb6979291d720fec068764bfb0f113f16df223 key_phase=false len=345 pn=11 [2025-04-30T18:33:18.149177499Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm CRYPTO off=0 len=321 [2025-04-30T18:33:18.149209669Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 366 bytes [2025-04-30T18:33:18.149219668Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:18.149222373Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:18.149229005Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318 [2025-04-30T18:33:18.149236369Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Short dcid=eb5606fc11fbcdc357 key_phase=false len=5 pn=7 [2025-04-30T18:33:18.149240006Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm ACK delay=7 blocks=[9..11] ecn_counts=None [2025-04-30T18:33:18.149249043Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=none latest_rtt=1.492932964s srtt=1.507067297s min_rtt=1.492932964s rttvar=569.945814ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1504, delivered_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, first_sent_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { delivery_rate: 770, is_app_limited: true, interval: 1.520267418s, delivered: 1171, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 258, tv_nsec: 113457012 }), send_elapsed: 1.520267418s, ack_elapsed: 1.504113893s, rtt: 1.492932964s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11197, last_update: Instant { tv_sec: 259, tv_nsec: 617705717 }, next_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, 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-30T18:33:18.149288266Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:44459 to 193.167.100.100:443 [2025-04-30T18:33:18.149295880Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:18.150162392Z TRACE quiche_apps::client] got 1069 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:18.150175086Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx pkt Short dcid=aadb6979291d720fec068764bfb0f113f16df223 key_phase=false len=1048 pn=12 [2025-04-30T18:33:18.150183291Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 rx frm STREAM id=0 off=0 len=1024 fin=true [2025-04-30T18:33:18.150227414Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1069 bytes [2025-04-30T18:33:18.150231772Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:18.150234317Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:18.150241149Z TRACE quiche_apps::common] received 1024 bytes [2025-04-30T18:33:18.150243945Z TRACE quiche_apps::common] stream 0 has 1024 bytes (fin? true) [2025-04-30T18:33:18.150246840Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T18:33:18.150249405Z INFO quiche_apps::common] 1/1 response(s) received in 3.01516552s, closing... [2025-04-30T18:33:18.150257069Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1323 [2025-04-30T18:33:18.150260686Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx pkt Short dcid=eb5606fc11fbcdc357 key_phase=false len=10 pn=8 [2025-04-30T18:33:18.150263201Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T18:33:18.150270965Z TRACE quiche::recovery::congestion::recovery] aadb6979291d720fec068764bfb0f113f16df223 timer=3.812833411s latest_rtt=1.492932964s srtt=1.507067297s min_rtt=1.492932964s rttvar=569.945814ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1504, delivered_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, first_sent_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { delivery_rate: 770, is_app_limited: true, interval: 1.520267418s, delivered: 1171, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 258, tv_nsec: 113457012 }), send_elapsed: 1.520267418s, ack_elapsed: 1.504113893s, rtt: 1.492932964s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11197, last_update: Instant { tv_sec: 259, tv_nsec: 619686975 }, next_time: Instant { tv_sec: 259, tv_nsec: 617705717 }, max_datagram_size: 1350, last_packet_size: None, iv: 3.304457ms, 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-30T18:33:18.150319977Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:44459 to 193.167.100.100:443 [2025-04-30T18:33:18.150327772Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:19.650862173Z TRACE quiche_apps::client] got 1332 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:19.650907177Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 1332 bytes [2025-04-30T18:33:19.650915763Z TRACE quiche_apps::client] got 57 bytes from 193.167.100.100:443 to 0.0.0.0:44459 [2025-04-30T18:33:19.650921173Z TRACE quiche_apps::client] 0.0.0.0:44459: processed 57 bytes [2025-04-30T18:33:19.650927555Z TRACE quiche_apps::client] 0.0.0.0:44459: recv() would block [2025-04-30T18:33:19.650932304Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:19.650941572Z TRACE quiche_apps::client] 0.0.0.0:44459 -> 193.167.100.100:443: done writing [2025-04-30T18:33:29.513642646Z TRACE quiche_apps::client] timed out [2025-04-30T18:33:29.513686498Z TRACE quiche] aadb6979291d720fec068764bfb0f113f16df223 draining timeout expired [2025-04-30T18:33:29.513739898Z TRACE quiche_apps::client] done reading [2025-04-30T18:33:29.513746540Z INFO quiche_apps::client] connection closed, recv=6 sent=9 lost=0 retrans=1 sent_bytes=2149 recv_bytes=5127 lost_bytes=0 [local_addr=0.0.0.0:44459 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=6 sent=9 lost=0 retrans=1 rtt=1.507067297s min_rtt=Some(1.492932964s) rttvar=569.945814ms cwnd=13500 sent_bytes=2149 recv_bytes=5127 lost_bytes=0 stream_retrans_bytes=266 pmtu=1350 delivery_rate=770]