[2025-04-30T09:13:22.016635575Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T09:13:22.016915540Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:34440 with scid 70cdd7931c069efd0c87839a471270562306d7fd [2025-04-30T09:13:22.016962788Z TRACE quiche::tls] 70cdd7931c069efd0c87839a471270562306d7fd write message lvl=Initial len=553 [2025-04-30T09:13:22.016981734Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Initial version=1 dcid=fe368702c68f801ce2c858b20917af93 scid=70cdd7931c069efd0c87839a471270562306d7fd len=557 pn=0 [2025-04-30T09:13:22.016985140Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm CRYPTO off=0 len=553 [2025-04-30T09:13:22.016998155Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=998.923597ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=620 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 358, tv_nsec: 676386221 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 676386221 }, 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: 358, tv_nsec: 676386221 }, next_time: Instant { tv_sec: 358, tv_nsec: 676386221 }, 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-30T09:13:22.017095377Z TRACE quiche_apps::client] written 1200 [2025-04-30T09:13:22.051209894Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.051231034Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Initial version=1 dcid=70cdd7931c069efd0c87839a471270562306d7fd scid=000000000000200233d88c6a533ca911b86b8881 token= len=122 pn=0 [2025-04-30T09:13:22.051243868Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm ACK delay=0 blocks=[0..0] ecn_counts=None [2025-04-30T09:13:22.051250490Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd packet newly acked 0 [2025-04-30T09:13:22.051256672Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm CRYPTO off=0 len=96 [2025-04-30T09:13:22.051352652Z TRACE quiche::tls] 70cdd7931c069efd0c87839a471270562306d7fd set write secret lvl=Handshake [2025-04-30T09:13:22.051363963Z TRACE quiche::tls] 70cdd7931c069efd0c87839a471270562306d7fd set read secret lvl=Handshake [2025-04-30T09:13:22.051390723Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Handshake version=1 dcid=70cdd7931c069efd0c87839a471270562306d7fd scid=000000000000200233d88c6a533ca911b86b8881 len=979 pn=0 [2025-04-30T09:13:22.051397316Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm CRYPTO off=0 len=165 [2025-04-30T09:13:22.051428634Z TRACE quiche::tls] 70cdd7931c069efd0c87839a471270562306d7fd write message lvl=Handshake len=36 [2025-04-30T09:13:22.051432121Z TRACE quiche::tls] 70cdd7931c069efd0c87839a471270562306d7fd set write secret lvl=OneRTT [2025-04-30T09:13:22.051439214Z TRACE quiche::tls] 70cdd7931c069efd0c87839a471270562306d7fd set read secret lvl=OneRTT [2025-04-30T09:13:22.051454783Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd connection established: proto=Ok("h3") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=true TransportParams { original_destination_connection_id: Some(fe368702c68f801ce2c858b20917af93), max_idle_timeout: 75000, stateless_reset_token: Some(27690946949365839635572378916153252947), max_udp_payload_size: 65527, initial_max_data: 8585216, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 128, initial_max_streams_uni: 3, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 2, initial_source_connection_id: Some(000000000000200233d88c6a533ca911b86b8881), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T09:13:22.051479520Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm PADDING len=793 [2025-04-30T09:13:22.051494358Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.051499808Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.051502914Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.051519735Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd tx frm SETTINGS stream=2 len=18 [2025-04-30T09:13:22.051562886Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd tx frm GREASE stream=0 len=0 [2025-04-30T09:13:22.051570901Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd tx frm GREASE stream=0 len=18 [2025-04-30T09:13:22.051579387Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd tx frm HEADERS stream=0 len=30 fin=true [2025-04-30T09:13:22.051585879Z DEBUG quiche_apps::common] Sent HTTP request [":method: GET", ":scheme: https", ":authority: server4", ":path: /qnozgcwwee", "user-agent: quiche"] [2025-04-30T09:13:22.051654979Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Initial version=1 dcid=000000000000200233d88c6a533ca911b86b8881 scid=70cdd7931c069efd0c87839a471270562306d7fd len=5 pn=1 [2025-04-30T09:13:22.051658676Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=53 blocks=[0..0] ecn_counts=None [2025-04-30T09:13:22.051666861Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=102.473607ms latest_rtt=34.304624ms srtt=34.304624ms min_rtt=34.304624ms rttvar=17.152312ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 620, delivered_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 18073, is_app_limited: true, interval: 34.304624ms, delivered: 620, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 676386221 }), send_elapsed: 0ns, ack_elapsed: 34.304624ms, rtt: 34.304624ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 491916, last_update: Instant { tv_sec: 358, tv_nsec: 710916728 }, next_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, 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-30T09:13:22.051686267Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Handshake version=1 dcid=000000000000200233d88c6a533ca911b86b8881 scid=70cdd7931c069efd0c87839a471270562306d7fd len=45 pn=2 [2025-04-30T09:13:22.051689113Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=36 blocks=[0..0] ecn_counts=None [2025-04-30T09:13:22.051691808Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm CRYPTO off=0 len=36 [2025-04-30T09:13:22.051697839Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=102.862716ms latest_rtt=34.304624ms srtt=34.304624ms min_rtt=34.304624ms rttvar=17.152312ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=111 app_limited=true congestion_recovery_start_time=None Rate { delivered: 620, delivered_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 18073, is_app_limited: true, interval: 34.304624ms, delivered: 620, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 676386221 }), send_elapsed: 0ns, ack_elapsed: 34.304624ms, rtt: 34.304624ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 491916, last_update: Instant { tv_sec: 358, tv_nsec: 711110802 }, next_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, max_datagram_size: 1350, last_packet_size: None, iv: 225.648µ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-04-30T09:13:22.051713999Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd dropped epoch 0 state [2025-04-30T09:13:22.051718899Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13389 out_len=1167 left=1129 [2025-04-30T09:13:22.051730069Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=1129 pn=3 [2025-04-30T09:13:22.051732564Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[11, 7f, 41, 97, a2, a8, 44, e9, db, 03, a2, 08, a7, be, 77, 48, 16, 37, 51, 81] reset_token=[7f, 80, 56, 30, dc, 93, 14, 70, 09, 6a, 7f, 37, 7b, eb, 0e, 0b] [2025-04-30T09:13:22.051739597Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm STREAM id=2 off=0 len=19 fin=false [2025-04-30T09:13:22.051742222Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm PADDING len=1065 [2025-04-30T09:13:22.051748514Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=102.812111ms latest_rtt=34.304624ms srtt=34.304624ms min_rtt=34.304624ms rttvar=17.152312ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1278 app_limited=true congestion_recovery_start_time=None Rate { delivered: 620, delivered_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 18073, is_app_limited: true, interval: 34.304624ms, delivered: 620, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 676386221 }), send_elapsed: 0ns, ack_elapsed: 34.304624ms, rtt: 34.304624ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1167, rate: 491916, last_update: Instant { tv_sec: 358, tv_nsec: 711110802 }, next_time: Instant { tv_sec: 358, tv_nsec: 711336450 }, max_datagram_size: 1350, last_packet_size: Some(1167), 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-30T09:13:22.051794831Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.051805221Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12222 out_len=1350 left=1312 [2025-04-30T09:13:22.051811112Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=6 pn=4 [2025-04-30T09:13:22.051815470Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm STREAM id=6 off=0 len=1 fin=false [2025-04-30T09:13:22.051824466Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=102.735598ms latest_rtt=34.304624ms srtt=34.304624ms min_rtt=34.304624ms rttvar=17.152312ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1322 app_limited=true congestion_recovery_start_time=None Rate { delivered: 620, delivered_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 18073, is_app_limited: true, interval: 34.304624ms, delivered: 620, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 676386221 }), send_elapsed: 0ns, ack_elapsed: 34.304624ms, rtt: 34.304624ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 491916, last_update: Instant { tv_sec: 358, tv_nsec: 711265011 }, next_time: Instant { tv_sec: 358, tv_nsec: 711336450 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.461802ms, 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-30T09:13:22.051870383Z TRACE quiche_apps::client] written 44 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.051880902Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12178 out_len=1350 left=1312 [2025-04-30T09:13:22.051886874Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=6 pn=5 [2025-04-30T09:13:22.051891162Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm STREAM id=10 off=0 len=1 fin=false [2025-04-30T09:13:22.051899808Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=102.660697ms latest_rtt=34.304624ms srtt=34.304624ms min_rtt=34.304624ms rttvar=17.152312ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1366 app_limited=true congestion_recovery_start_time=None Rate { delivered: 620, delivered_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 18073, is_app_limited: true, interval: 34.304624ms, delivered: 620, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 676386221 }), send_elapsed: 0ns, ack_elapsed: 34.304624ms, rtt: 34.304624ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 44, rate: 491916, last_update: Instant { tv_sec: 358, tv_nsec: 711265011 }, next_time: Instant { tv_sec: 358, tv_nsec: 713802315 }, max_datagram_size: 1350, last_packet_size: Some(44), 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-30T09:13:22.051932720Z TRACE quiche_apps::client] written 44 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.051942247Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12134 out_len=1350 left=1312 [2025-04-30T09:13:22.051948048Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=73 pn=6 [2025-04-30T09:13:22.051952306Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm STREAM id=0 off=0 len=68 fin=true [2025-04-30T09:13:22.051981892Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=102.578393ms latest_rtt=34.304624ms srtt=34.304624ms min_rtt=34.304624ms rttvar=17.152312ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1477 app_limited=true congestion_recovery_start_time=None Rate { delivered: 620, delivered_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 710916768 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 18073, is_app_limited: true, interval: 34.304624ms, delivered: 620, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 676386221 }), send_elapsed: 0ns, ack_elapsed: 34.304624ms, rtt: 34.304624ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 491916, last_update: Instant { tv_sec: 358, tv_nsec: 711402128 }, next_time: Instant { tv_sec: 358, tv_nsec: 713802315 }, max_datagram_size: 1350, last_packet_size: None, iv: 315.094µ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-04-30T09:13:22.052021446Z TRACE quiche_apps::client] written 111 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.052029120Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.085377351Z TRACE quiche_apps::client] got 890 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.085399021Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=869 pn=0 [2025-04-30T09:13:22.085410302Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm ACK delay=0 blocks=[3..3] ecn_counts=None [2025-04-30T09:13:22.085415963Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd packet newly acked 3 [2025-04-30T09:13:22.085422095Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm CRYPTO off=0 len=540 [2025-04-30T09:13:22.085448364Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm HANDSHAKE_DONE [2025-04-30T09:13:22.085453784Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd dropped epoch 1 state [2025-04-30T09:13:22.085459835Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 20, 02, bb, e0, 4b, db, 23, 07, 2d, 1f, 07, a7, 48, 91] reset_token=[e1, 9b, ac, 45, 5d, 11, a3, 01, f2, 99, ba, 4e, 8d, 55, 90, 21] [2025-04-30T09:13:22.085467961Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 20, 02, c7, 2a, eb, 05, 04, 30, 1f, b5, 46, 32, 54, fb] reset_token=[61, 9d, 81, 84, 7f, c1, 62, 7d, 52, db, 14, 8d, e6, 09, 0a, a0] [2025-04-30T09:13:22.085474262Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 20, 02, 48, 5d, 9a, e9, 2b, c2, a2, 0a, c2, df, 35, 08] reset_token=[4e, 98, a5, 00, 57, f5, cf, cc, 23, 38, 05, ce, d4, 7d, 4f, 37] [2025-04-30T09:13:22.085479873Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 20, 02, 9c, f2, a7, 6d, f3, b2, 61, 8f, 9f, 4b, 16, 54] reset_token=[e8, 5f, 60, 64, 1b, 4e, a2, c4, 39, 18, 9f, c1, 15, f8, 1b, 19] [2025-04-30T09:13:22.085485514Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 20, 02, 55, b2, a5, 73, 0b, 2a, 68, b8, 49, f7, 68, 3d] reset_token=[38, fa, 4c, a1, 94, da, b5, f9, df, 07, 1f, 1a, e4, 87, 93, e9] [2025-04-30T09:13:22.085491334Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 20, 02, b0, 41, 03, bd, d0, 1a, a2, bd, 0b, ff, 19, 82] reset_token=[66, f5, a5, 0a, 52, a2, 3d, a7, f0, f9, 39, c3, 3f, 0d, b4, 2a] [2025-04-30T09:13:22.085496945Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[00, 00, 00, 00, 00, 00, 20, 02, 73, cf, 38, c0, a3, c7, e9, 58, eb, f6, c4, 37] reset_token=[c5, c8, b3, a4, 54, 32, 11, 9b, c5, 46, 67, 6e, d0, ec, a1, 7b] [2025-04-30T09:13:22.085508166Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=3 off=0 len=1 fin=false [2025-04-30T09:13:22.085512254Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=3 off=1 len=8 fin=false [2025-04-30T09:13:22.085515179Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=7 off=0 len=1 fin=false [2025-04-30T09:13:22.085534636Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 890 bytes [2025-04-30T09:13:22.085564932Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.085571836Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=22 pn=1 [2025-04-30T09:13:22.085576915Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm ACK delay=0 blocks=[3..5] ecn_counts=None [2025-04-30T09:13:22.085580021Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd packet newly acked 4 [2025-04-30T09:13:22.085582476Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd packet newly acked 5 [2025-04-30T09:13:22.085590871Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 43 bytes [2025-04-30T09:13:22.085594618Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.085597183Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.085600379Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 3 is readable [2025-04-30T09:13:22.085606581Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 3 [2025-04-30T09:13:22.085611350Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd open peer's control stream 3 [2025-04-30T09:13:22.085614746Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 3 [2025-04-30T09:13:22.085617852Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 3 [2025-04-30T09:13:22.085621078Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 6 bytes on stream 3 [2025-04-30T09:13:22.085623873Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd rx frm SETTINGS max_field_section=None, qpack_max_table=Some(4096), qpack_blocked=Some(128) raw=Some([(1, 4096), (7, 128)]), additional_settings=None stream=3 payload_len=6 [2025-04-30T09:13:22.085632129Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 7 is readable [2025-04-30T09:13:22.085635465Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 7 [2025-04-30T09:13:22.085645483Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13389 out_len=1350 left=1307 [2025-04-30T09:13:22.085649832Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=7 [2025-04-30T09:13:22.085653178Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=9 blocks=[0..1] ecn_counts=None [2025-04-30T09:13:22.085659890Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=67.266888ms latest_rtt=31.232397ms srtt=33.835055ms min_rtt=31.232397ms rttvar=10.538431ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=111 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1875, delivered_time: Instant { tv_sec: 358, tv_nsec: 745034712 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 711336450 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 5, rate_sample: RateSample { delivery_rate: 36974, is_app_limited: true, interval: 33.942234ms, delivered: 1255, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 498743, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.085711988Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.085719843Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.087429499Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.087437744Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=2 [2025-04-30T09:13:22.087444196Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm ACK delay=0 blocks=[3..6] ecn_counts=None [2025-04-30T09:13:22.087447502Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd packet newly acked 6 [2025-04-30T09:13:22.087452021Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=0 len=1152 fin=false [2025-04-30T09:13:22.087462270Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.087465897Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.087468251Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.087470926Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.087474433Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 0 [2025-04-30T09:13:22.087477619Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 0 [2025-04-30T09:13:22.087480564Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 0 [2025-04-30T09:13:22.087484061Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 140 bytes on stream 0 [2025-04-30T09:13:22.087486626Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd rx frm HEADERS stream=0 payload_len=140 [2025-04-30T09:13:22.087489772Z TRACE quiche::h3::qpack::decoder] Header count=0 base=0 [2025-04-30T09:13:22.087492317Z TRACE quiche::h3::qpack::decoder] Indexed index=25 static=true [2025-04-30T09:13:22.087496605Z TRACE quiche::h3::qpack::decoder] Literal name_idx=92 static=true value=[110, 103, 105, 110, 120, 47, 49, 46, 50, 55, 46, 48] [2025-04-30T09:13:22.087502756Z 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, 48, 57, 58, 49, 51, 58, 50, 50, 32, 71, 77, 84] [2025-04-30T09:13:22.087507946Z TRACE quiche::h3::qpack::decoder] Literal name_idx=53 static=true value=[97, 112, 112, 108, 105, 99, 97, 116, 105, 111, 110, 47, 111, 99, 116, 101, 116, 45, 115, 116, 114, 101, 97, 109] [2025-04-30T09:13:22.087511813Z TRACE quiche::h3::qpack::decoder] Literal name_idx=4 static=true value=[49, 48, 50, 52, 48] [2025-04-30T09:13:22.087514899Z 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, 48, 57, 58, 49, 51, 58, 50, 48, 32, 71, 77, 84] [2025-04-30T09:13:22.087519778Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[101, 116, 97, 103] value=[34, 54, 56, 49, 49, 101, 57, 98, 48, 45, 50, 56, 48, 48, 34] [2025-04-30T09:13:22.087524457Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[97, 108, 116, 45, 115, 118, 99] value=[104, 113, 45, 50, 57, 61, 34, 58, 52, 52, 51, 34] [2025-04-30T09:13:22.087528144Z TRACE quiche::h3::qpack::decoder] Literal Without Name Reference name=[97, 99, 99, 101, 112, 116, 45, 114, 97, 110, 103, 101, 115] value=[98, 121, 116, 101, 115] [2025-04-30T09:13:22.087567237Z DEBUG quiche_apps::common] got response headers [(":status", "200"), ("server", "nginx/1.27.0"), ("date", "Wed, 30 Apr 2025 09:13:22 GMT"), ("content-type", "application/octet-stream"), ("content-length", "10240"), ("last-modified", "Wed, 30 Apr 2025 09:13:20 GMT"), ("etag", "\"6811e9b0-2800\""), ("alt-svc", "hq-29=\":443\""), ("accept-ranges", "bytes")] on stream id 0 [2025-04-30T09:13:22.087577697Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.087581344Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 0 [2025-04-30T09:13:22.087584439Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 0 [2025-04-30T09:13:22.087587375Z TRACE quiche::h3::stream] 70cdd7931c069efd0c87839a471270562306d7fd read 1 bytes on stream 0 [2025-04-30T09:13:22.087589639Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd rx frm DATA stream=0 wire_payload_len=10240 [2025-04-30T09:13:22.087594418Z DEBUG quiche_apps::common] got 1006 bytes of response data on stream 0 [2025-04-30T09:13:22.087602753Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.087606000Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=8 [2025-04-30T09:13:22.087608494Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=20 blocks=[0..2] ecn_counts=None [2025-04-30T09:13:22.087614826Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.087653168Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.087660372Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.088407733Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.088412903Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=3 [2025-04-30T09:13:22.088419465Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=1152 len=1156 fin=false [2025-04-30T09:13:22.088426458Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.088429975Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.088432429Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.088434954Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.088439192Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0 [2025-04-30T09:13:22.088451074Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.088454270Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=9 [2025-04-30T09:13:22.088456675Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=4 blocks=[0..3] ecn_counts=None [2025-04-30T09:13:22.088462606Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 9, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.088497431Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.088504475Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.089388682Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.089396256Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=4 [2025-04-30T09:13:22.089402208Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=2308 len=1156 fin=false [2025-04-30T09:13:22.089408770Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.089412257Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.089414621Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.089417116Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.089421404Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0 [2025-04-30T09:13:22.089427826Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.089430841Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=10 [2025-04-30T09:13:22.089433216Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=3 blocks=[0..4] ecn_counts=None [2025-04-30T09:13:22.089452722Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 10, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.089491735Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.089499160Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.090376465Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.090383608Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=5 [2025-04-30T09:13:22.090389649Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=3464 len=1156 fin=false [2025-04-30T09:13:22.090396352Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.090399778Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.090402163Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.090404687Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.090408915Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0 [2025-04-30T09:13:22.090415588Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.090418604Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=11 [2025-04-30T09:13:22.090420988Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=4 blocks=[0..5] ecn_counts=None [2025-04-30T09:13:22.090427320Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 11, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.090462165Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.090469118Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.091355931Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.091363004Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=6 [2025-04-30T09:13:22.091373824Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=4620 len=1156 fin=false [2025-04-30T09:13:22.091380477Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.091383963Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.091386318Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.091388803Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.091392991Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0 [2025-04-30T09:13:22.091399593Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.091402609Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=12 [2025-04-30T09:13:22.091404993Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=4 blocks=[0..6] ecn_counts=None [2025-04-30T09:13:22.091410834Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 12, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.091445449Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.091451891Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.092339816Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.092346999Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=7 [2025-04-30T09:13:22.092352891Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=5776 len=1156 fin=false [2025-04-30T09:13:22.092359563Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.092362919Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.092365294Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.092367738Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.092371856Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0 [2025-04-30T09:13:22.092378308Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.092381294Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=13 [2025-04-30T09:13:22.092383658Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=3 blocks=[0..7] ecn_counts=None [2025-04-30T09:13:22.092394198Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 13, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.092429434Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.092436608Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.093324021Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.093331195Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=8 [2025-04-30T09:13:22.093337176Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=6932 len=1156 fin=false [2025-04-30T09:13:22.093343708Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.093347115Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.093349439Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.093351894Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.093356072Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0 [2025-04-30T09:13:22.093362584Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.093365559Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=14 [2025-04-30T09:13:22.093367954Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=3 blocks=[0..8] ecn_counts=None [2025-04-30T09:13:22.093373654Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 14, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.093413389Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.093420553Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.094310852Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.094318045Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1179 pn=9 [2025-04-30T09:13:22.094323936Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=8088 len=1156 fin=false [2025-04-30T09:13:22.094330479Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1200 bytes [2025-04-30T09:13:22.094333845Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.094336179Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.094338654Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.094342782Z DEBUG quiche_apps::common] got 1156 bytes of response data on stream 0 [2025-04-30T09:13:22.094366516Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1307 [2025-04-30T09:13:22.094369822Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=5 pn=15 [2025-04-30T09:13:22.094372247Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm ACK delay=6 blocks=[0..9] ecn_counts=None [2025-04-30T09:13:22.094378699Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=none latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 7, last_sent_packet: 15, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 745104924 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, 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-30T09:13:22.094414506Z TRACE quiche_apps::client] written 43 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.094421549Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.095289527Z TRACE quiche_apps::client] got 1191 bytes from 193.167.100.100:443 to 0.0.0.0:34440 [2025-04-30T09:13:22.095297662Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx pkt Short dcid=70cdd7931c069efd0c87839a471270562306d7fd key_phase=false len=1170 pn=10 [2025-04-30T09:13:22.095303854Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=9244 len=1142 fin=false [2025-04-30T09:13:22.095307210Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd rx frm STREAM id=0 off=10386 len=0 fin=true [2025-04-30T09:13:22.095314273Z TRACE quiche_apps::client] 0.0.0.0:34440: processed 1191 bytes [2025-04-30T09:13:22.095317730Z TRACE quiche_apps::client] 0.0.0.0:34440: recv() would block [2025-04-30T09:13:22.095324733Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.095327338Z TRACE quiche::h3] 70cdd7931c069efd0c87839a471270562306d7fd stream id 0 is readable [2025-04-30T09:13:22.095333509Z DEBUG quiche_apps::common] got 1142 bytes of response data on stream 0 [2025-04-30T09:13:22.095336204Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T09:13:22.095338739Z INFO quiche_apps::common] 1/1 response(s) received in 78.237561ms, closing... [2025-04-30T09:13:22.095345131Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1312 [2025-04-30T09:13:22.095348427Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx pkt Short dcid=000000000000200233d88c6a533ca911b86b8881 key_phase=false len=11 pn=16 [2025-04-30T09:13:22.095350872Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd tx frm APPLICATION_CLOSE err=100 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T09:13:22.095357745Z TRACE quiche::recovery::congestion::recovery] 70cdd7931c069efd0c87839a471270562306d7fd timer=91.079957ms latest_rtt=33.098015ms srtt=33.742924ms min_rtt=31.232397ms rttvar=8.088083ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=49 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1986, delivered_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, first_sent_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 6, rate_sample: RateSample { delivery_rate: 40244, is_app_limited: true, interval: 33.942234ms, delivered: 1366, prior_delivered: 620, prior_time: Some(Instant { tv_sec: 358, tv_nsec: 710916768 }), send_elapsed: 419.682µs, ack_elapsed: 33.942234ms, rtt: 33.522552ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 500104, last_update: Instant { tv_sec: 358, tv_nsec: 754806495 }, next_time: Instant { tv_sec: 358, tv_nsec: 745420018 }, max_datagram_size: 1350, last_packet_size: None, iv: 97.98µ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-04-30T09:13:22.095394354Z TRACE quiche_apps::client] written 49 bytes from 0.0.0.0:34440 to 193.167.100.100:443 [2025-04-30T09:13:22.095400916Z TRACE quiche_apps::client] 0.0.0.0:34440 -> 193.167.100.100:443: done writing [2025-04-30T09:13:22.294659296Z TRACE quiche_apps::client] timed out [2025-04-30T09:13:22.294690745Z TRACE quiche] 70cdd7931c069efd0c87839a471270562306d7fd draining timeout expired [2025-04-30T09:13:22.294748063Z TRACE quiche_apps::client] done reading [2025-04-30T09:13:22.294753152Z INFO quiche_apps::client] connection closed, recv=13 sent=17 lost=0 retrans=0 sent_bytes=2605 recv_bytes=12924 lost_bytes=0 [local_addr=0.0.0.0:34440 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=13 sent=17 lost=0 retrans=0 rtt=33.742924ms min_rtt=Some(31.232397ms) rttvar=8.088083ms cwnd=13500 sent_bytes=2605 recv_bytes=12924 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=40244]