[2025-04-30T11:48:37.645785560Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T11:48:37.646089821Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:47766 with scid 0a87e09a395c70570110f898d77cf49cc15fcf93 [2025-04-30T11:48:37.646132661Z TRACE quiche::tls] 0a87e09a395c70570110f898d77cf49cc15fcf93 write message lvl=Initial len=266 [2025-04-30T11:48:37.646151476Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx pkt Initial version=1 dcid=d4bc4da75fa368b89b918a79df0aac58 scid=0a87e09a395c70570110f898d77cf49cc15fcf93 len=270 pn=0 [2025-04-30T11:48:37.646154562Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm CRYPTO off=0 len=266 [2025-04-30T11:48:37.646168648Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 timer=998.927725ms 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: 177, tv_nsec: 414751778 }, first_sent_time: Instant { tv_sec: 177, tv_nsec: 414751778 }, 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: 177, tv_nsec: 414751778 }, next_time: Instant { tv_sec: 177, tv_nsec: 414751778 }, 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-30T11:48:37.646233801Z TRACE quiche_apps::client] written 1200 [2025-04-30T11:48:37.686379501Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:47766 [2025-04-30T11:48:37.686408265Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx pkt Initial version=1 dcid=0a87e09a395c70570110f898d77cf49cc15fcf93 scid=fbd6cf42fcea3518 token= len=117 pn=0 [2025-04-30T11:48:37.686431869Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm ACK delay=125 blocks=[0..0] ecn_counts=None [2025-04-30T11:48:37.686439063Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 packet newly acked 0 [2025-04-30T11:48:37.686445214Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm CRYPTO off=0 len=90 [2025-04-30T11:48:37.686543568Z TRACE quiche::tls] 0a87e09a395c70570110f898d77cf49cc15fcf93 set write secret lvl=Handshake [2025-04-30T11:48:37.686555791Z TRACE quiche::tls] 0a87e09a395c70570110f898d77cf49cc15fcf93 set read secret lvl=Handshake [2025-04-30T11:48:37.686589084Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx pkt Handshake version=1 dcid=0a87e09a395c70570110f898d77cf49cc15fcf93 scid=fbd6cf42fcea3518 len=1008 pn=0 [2025-04-30T11:48:37.686595025Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm CRYPTO off=0 len=737 [2025-04-30T11:48:37.686810880Z TRACE quiche::tls] 0a87e09a395c70570110f898d77cf49cc15fcf93 write message lvl=Handshake len=52 [2025-04-30T11:48:37.686814677Z TRACE quiche::tls] 0a87e09a395c70570110f898d77cf49cc15fcf93 set write secret lvl=OneRTT [2025-04-30T11:48:37.686822542Z TRACE quiche::tls] 0a87e09a395c70570110f898d77cf49cc15fcf93 set read secret lvl=OneRTT [2025-04-30T11:48:37.686840205Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 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(d4bc4da75fa368b89b918a79df0aac58), max_idle_timeout: 30000, stateless_reset_token: Some(239333533060150243348478278764794140961), max_udp_payload_size: 2048, initial_max_data: 1638000, initial_max_stream_data_bidi_local: 16380, initial_max_stream_data_bidi_remote: 1474200, initial_max_stream_data_uni: 16380, initial_max_streams_bidi: 100, initial_max_streams_uni: 3, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 8, initial_source_connection_id: Some(fbd6cf42fcea3518), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T11:48:37.686859110Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm PADDING len=250 [2025-04-30T11:48:37.686872665Z TRACE quiche_apps::client] 0.0.0.0:47766: processed 1200 bytes [2025-04-30T11:48:37.686877334Z TRACE quiche_apps::client] 0.0.0.0:47766: recv() would block [2025-04-30T11:48:37.686879969Z TRACE quiche_apps::client] done reading [2025-04-30T11:48:37.686888706Z DEBUG quiche_apps::common] sending HTTP request "GET /myxjppjrbf\r\n" [2025-04-30T11:48:37.686960801Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx pkt Initial version=1 dcid=fbd6cf42fcea3518 scid=0a87e09a395c70570110f898d77cf49cc15fcf93 len=6 pn=1 [2025-04-30T11:48:37.686964668Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm ACK delay=70 blocks=[0..0] ecn_counts=None [2025-04-30T11:48:37.686973875Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 timer=120.326821ms latest_rtt=40.300991ms srtt=40.300991ms min_rtt=40.300991ms rttvar=20.150495ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, first_sent_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8262, is_app_limited: true, interval: 40.300991ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 177, tv_nsec: 414751778 }), send_elapsed: 0ns, ack_elapsed: 40.300991ms, rtt: 40.300991ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418724, last_update: Instant { tv_sec: 177, tv_nsec: 455492794 }, next_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, 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-30T11:48:37.686994624Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx pkt Handshake version=1 dcid=fbd6cf42fcea3518 scid=0a87e09a395c70570110f898d77cf49cc15fcf93 len=61 pn=2 [2025-04-30T11:48:37.686997490Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm ACK delay=50 blocks=[0..0] ecn_counts=None [2025-04-30T11:48:37.687000115Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm CRYPTO off=0 len=52 [2025-04-30T11:48:37.687006406Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 timer=120.848238ms latest_rtt=40.300991ms srtt=40.300991ms min_rtt=40.300991ms rttvar=20.150495ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=115 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, first_sent_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8262, is_app_limited: true, interval: 40.300991ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 177, tv_nsec: 414751778 }), send_elapsed: 0ns, ack_elapsed: 40.300991ms, rtt: 40.300991ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 418724, last_update: Instant { tv_sec: 177, tv_nsec: 455606517 }, next_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, max_datagram_size: 1350, last_packet_size: None, iv: 274.644µ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-30T11:48:37.687021625Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 dropped epoch 0 state [2025-04-30T11:48:37.687026274Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13385 out_len=1174 left=1148 [2025-04-30T11:48:37.687038146Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx pkt Short dcid=fbd6cf42fcea3518 key_phase=false len=1148 pn=3 [2025-04-30T11:48:37.687040771Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[78, 0d, 0e, 37, 6c, b8, 91, 23, 6f, 90, bc, 9d, 23, 41, 92, 4a, 33, 4b, be, 1d] reset_token=[4c, 4b, fa, df, c6, d1, 8a, dc, 37, 0b, f2, 4a, 91, 4b, 89, b7] [2025-04-30T11:48:37.687047634Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[02, 77, 66, 3f, 74, bf, 7e, 84, 30, e6, 8c, a9, da, ef, f1, e9, af, 4d, 96, 64] reset_token=[25, 61, d2, 8a, 9b, a7, e9, 31, 83, df, 4e, 37, 38, 63, 4c, 04] [2025-04-30T11:48:37.687052883Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[d4, d0, 98, 55, 1a, 37, 6c, 58, 65, 49, 80, 5f, f5, 86, bf, 54, 64, fb, 8a, d7] reset_token=[3d, 44, 8f, eb, 56, 6b, a9, 49, 43, 58, 2c, 70, 84, e2, 6f, c2] [2025-04-30T11:48:37.687057803Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[ac, 57, 07, 32, 05, 78, 50, 00, 85, 17, 8b, fd, 21, 04, 94, 1d, 39, b9, eb, 6d] reset_token=[63, 22, 6c, 88, a1, 4c, b7, 22, 9f, 66, 05, a7, 99, 19, 2b, 0e] [2025-04-30T11:48:37.687063013Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[85, da, da, 75, 9a, 2c, 76, 79, 1c, dc, 4d, bd, 07, 35, 46, ad, 23, c1, 03, 2c] reset_token=[8f, 45, 56, 2c, f7, 14, ed, 97, 35, 06, bc, 7f, 81, e9, 1d, 0d] [2025-04-30T11:48:37.687068002Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[9c, a5, db, f0, 21, c5, 10, 90, 28, ae, 7a, 49, b6, 0a, 64, 65, 28, de, 2f, 4c] reset_token=[aa, 75, 99, 01, cc, 81, 20, f7, d2, 7b, 95, 5c, 3e, 84, 0d, ce] [2025-04-30T11:48:37.687072971Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[8e, 2e, d4, 54, 5f, 33, 6f, 43, 12, f5, 7e, 9d, 91, 8b, 2e, 60, 39, 0a, cc, 5c] reset_token=[95, ed, 7b, 37, 4f, 1f, d2, 04, 04, cd, fb, ff, 7b, c2, 46, f8] [2025-04-30T11:48:37.687077860Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T11:48:37.687080355Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm PADDING len=846 [2025-04-30T11:48:37.687089111Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 timer=120.765443ms latest_rtt=40.300991ms srtt=40.300991ms min_rtt=40.300991ms rttvar=20.150495ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, first_sent_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8262, is_app_limited: true, interval: 40.300991ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 177, tv_nsec: 414751778 }), send_elapsed: 0ns, ack_elapsed: 40.300991ms, rtt: 40.300991ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1174, rate: 418724, last_update: Instant { tv_sec: 177, tv_nsec: 455606517 }, next_time: Instant { tv_sec: 177, tv_nsec: 455881161 }, max_datagram_size: 1350, last_packet_size: Some(1174), 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-30T11:48:37.687139095Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:47766 to 193.167.100.100:443 [2025-04-30T11:48:37.687146940Z TRACE quiche_apps::client] 0.0.0.0:47766 -> 193.167.100.100:443: done writing [2025-04-30T11:48:37.720859036Z TRACE quiche_apps::client] got 646 bytes from 193.167.100.100:443 to 0.0.0.0:47766 [2025-04-30T11:48:37.720874365Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx pkt Handshake version=1 dcid=0a87e09a395c70570110f898d77cf49cc15fcf93 scid=fbd6cf42fcea3518 len=22 pn=1 [2025-04-30T11:48:37.720883482Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm ACK delay=0 blocks=[2..2] ecn_counts=None [2025-04-30T11:48:37.720888452Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 packet newly acked 2 [2025-04-30T11:48:37.720905323Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx pkt Short dcid=0a87e09a395c70570110f898d77cf49cc15fcf93 key_phase=false len=567 pn=0 [2025-04-30T11:48:37.720912597Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm CRYPTO off=0 len=546 [2025-04-30T11:48:37.720943345Z TRACE quiche_apps::client] 0.0.0.0:47766: processed 646 bytes [2025-04-30T11:48:37.720948534Z TRACE quiche_apps::client] 0.0.0.0:47766: recv() would block [2025-04-30T11:48:37.720951770Z TRACE quiche_apps::client] done reading [2025-04-30T11:48:37.720960817Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12326 out_len=1350 left=1319 [2025-04-30T11:48:37.720965426Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx pkt Short dcid=fbd6cf42fcea3518 key_phase=false len=5 pn=4 [2025-04-30T11:48:37.720968582Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm ACK delay=6 blocks=[0..0] ecn_counts=None [2025-04-30T11:48:37.720976557Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 timer=97.211483ms latest_rtt=34.033409ms srtt=39.517543ms min_rtt=34.033409ms rttvar=16.679766ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1174 app_limited=true congestion_recovery_start_time=None Rate { delivered: 448, delivered_time: Instant { tv_sec: 177, tv_nsec: 489526233 }, first_sent_time: Instant { tv_sec: 177, tv_nsec: 455492824 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 2, rate_sample: RateSample { delivery_rate: 3379, is_app_limited: true, interval: 34.033409ms, delivered: 115, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 177, tv_nsec: 455492824 }), send_elapsed: 0ns, ack_elapsed: 34.033409ms, rtt: 34.033409ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 427025, last_update: Instant { tv_sec: 177, tv_nsec: 489611133 }, next_time: Instant { tv_sec: 177, tv_nsec: 489611133 }, 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-30T11:48:37.721026501Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:47766 to 193.167.100.100:443 [2025-04-30T11:48:37.721032181Z TRACE quiche_apps::client] 0.0.0.0:47766 -> 193.167.100.100:443: done writing [2025-04-30T11:48:37.721823756Z TRACE quiche_apps::client] got 168 bytes from 193.167.100.100:443 to 0.0.0.0:47766 [2025-04-30T11:48:37.721831070Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx pkt Short dcid=0a87e09a395c70570110f898d77cf49cc15fcf93 key_phase=false len=147 pn=1 [2025-04-30T11:48:37.721836820Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm ACK delay=250 blocks=[3..3] ecn_counts=None [2025-04-30T11:48:37.721846999Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 packet newly acked 3 [2025-04-30T11:48:37.721851207Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm HANDSHAKE_DONE [2025-04-30T11:48:37.721854644Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 dropped epoch 1 state [2025-04-30T11:48:37.721859192Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm NEW_TOKEN len=37 [2025-04-30T11:48:37.721862859Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[7e, 89, 4b, e6, 3c, 14, 5a, 99] reset_token=[1b, 47, 14, 75, e4, b7, c8, c0, 9f, d4, 71, 1f, d9, 37, 15, 4e] [2025-04-30T11:48:37.721868950Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[8e, 62, 7b, 77, 54, da, fa, 01] reset_token=[72, 54, 19, c6, 2f, eb, 5e, 6c, 74, 04, 94, 04, d2, a3, 36, b0] [2025-04-30T11:48:37.721873689Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[91, 0f, 45, b3, ca, 67, c5, 62] reset_token=[9a, d5, 1b, b2, 76, 2c, 68, 4b, 36, 87, d8, 01, cb, 5a, 49, da] [2025-04-30T11:48:37.721903295Z TRACE quiche_apps::client] 0.0.0.0:47766: processed 168 bytes [2025-04-30T11:48:37.721907443Z TRACE quiche_apps::client] 0.0.0.0:47766: recv() would block [2025-04-30T11:48:37.721909797Z TRACE quiche_apps::client] done reading [2025-04-30T11:48:37.721916139Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T11:48:37.721919475Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx pkt Short dcid=fbd6cf42fcea3518 key_phase=false len=5 pn=5 [2025-04-30T11:48:37.721921950Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm ACK delay=10 blocks=[0..1] ecn_counts=None [2025-04-30T11:48:37.721928031Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 timer=none latest_rtt=34.60335ms srtt=38.903268ms min_rtt=34.033409ms rttvar=13.738372ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1622, delivered_time: Instant { tv_sec: 177, tv_nsec: 489611133 }, first_sent_time: Instant { tv_sec: 177, tv_nsec: 489611133 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 3, rate_sample: RateSample { delivery_rate: 37874, is_app_limited: true, interval: 34.033409ms, delivered: 1289, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 177, tv_nsec: 455492824 }), send_elapsed: 0ns, ack_elapsed: 34.033409ms, rtt: 34.033409ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 433768, last_update: Instant { tv_sec: 177, tv_nsec: 489611133 }, next_time: Instant { tv_sec: 177, tv_nsec: 489611133 }, 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-30T11:48:37.721961895Z TRACE quiche_apps::client] written 31 bytes from 0.0.0.0:47766 to 193.167.100.100:443 [2025-04-30T11:48:37.721965862Z TRACE quiche_apps::client] 0.0.0.0:47766 -> 193.167.100.100:443: done writing [2025-04-30T11:48:37.723849855Z TRACE quiche_apps::client] got 1066 bytes from 193.167.100.100:443 to 0.0.0.0:47766 [2025-04-30T11:48:37.723856838Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx pkt Short dcid=0a87e09a395c70570110f898d77cf49cc15fcf93 key_phase=false len=1045 pn=2 [2025-04-30T11:48:37.723862760Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 rx frm STREAM id=0 off=0 len=1024 fin=true [2025-04-30T11:48:37.723869402Z TRACE quiche_apps::client] 0.0.0.0:47766: processed 1066 bytes [2025-04-30T11:48:37.723877387Z TRACE quiche_apps::client] 0.0.0.0:47766: recv() would block [2025-04-30T11:48:37.723879781Z TRACE quiche_apps::client] done reading [2025-04-30T11:48:37.723885332Z TRACE quiche_apps::common] received 1024 bytes [2025-04-30T11:48:37.723888157Z TRACE quiche_apps::common] stream 0 has 1024 bytes (fin? true) [2025-04-30T11:48:37.723890662Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T11:48:37.723892996Z INFO quiche_apps::common] 1/1 response(s) received in 77.654567ms, closing... [2025-04-30T11:48:37.723899037Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1324 [2025-04-30T11:48:37.723902344Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx pkt Short dcid=fbd6cf42fcea3518 key_phase=false len=10 pn=6 [2025-04-30T11:48:37.723904808Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T11:48:37.723911801Z TRACE quiche::recovery::congestion::recovery] 0a87e09a395c70570110f898d77cf49cc15fcf93 timer=118.841828ms latest_rtt=34.60335ms srtt=38.903268ms min_rtt=34.033409ms rttvar=13.738372ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=36 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1622, delivered_time: Instant { tv_sec: 177, tv_nsec: 489611133 }, first_sent_time: Instant { tv_sec: 177, tv_nsec: 489611133 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 3, rate_sample: RateSample { delivery_rate: 37874, is_app_limited: true, interval: 34.033409ms, delivered: 1289, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 177, tv_nsec: 455492824 }), send_elapsed: 0ns, ack_elapsed: 34.033409ms, rtt: 34.033409ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 433768, last_update: Instant { tv_sec: 177, tv_nsec: 492551757 }, next_time: Instant { tv_sec: 177, tv_nsec: 489611133 }, max_datagram_size: 1350, last_packet_size: None, iv: 82.994µ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-30T11:48:37.723943791Z TRACE quiche_apps::client] written 36 bytes from 0.0.0.0:47766 to 193.167.100.100:443 [2025-04-30T11:48:37.723947378Z TRACE quiche_apps::client] 0.0.0.0:47766 -> 193.167.100.100:443: done writing [2025-04-30T11:48:37.754728243Z TRACE quiche_apps::client] got 42 bytes from 193.167.100.100:443 to 0.0.0.0:47766 [2025-04-30T11:48:37.754740916Z TRACE quiche_apps::client] 0.0.0.0:47766: processed 42 bytes [2025-04-30T11:48:37.754745475Z TRACE quiche_apps::client] 0.0.0.0:47766: recv() would block [2025-04-30T11:48:37.754748551Z TRACE quiche_apps::client] done reading [2025-04-30T11:48:37.754753520Z TRACE quiche_apps::client] 0.0.0.0:47766 -> 193.167.100.100:443: done writing [2025-04-30T11:48:38.006033531Z TRACE quiche_apps::client] timed out [2025-04-30T11:48:38.006051816Z TRACE quiche] 0a87e09a395c70570110f898d77cf49cc15fcf93 draining timeout expired [2025-04-30T11:48:38.006084767Z TRACE quiche_apps::client] done reading [2025-04-30T11:48:38.006088695Z INFO quiche_apps::client] connection closed, recv=6 sent=7 lost=0 retrans=0 sent_bytes=1781 recv_bytes=3080 lost_bytes=0 [local_addr=0.0.0.0:47766 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=6 sent=7 lost=0 retrans=0 rtt=38.903268ms min_rtt=Some(34.033409ms) rttvar=13.738372ms cwnd=13500 sent_bytes=1781 recv_bytes=3080 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=37874]