[2025-09-12T05:41:15.143394490Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T05:41:15.143691984Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:41280 with scid 67085ef7c817b33524af69c48f24550ae1b7050f [2025-09-12T05:41:15.143744612Z TRACE quiche::tls] 67085ef7c817b33524af69c48f24550ae1b7050f write message lvl=Initial len=537 [2025-09-12T05:41:15.143762205Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Initial version=1 dcid=80e0786bb0b98e5206df9ef62808e692 scid=67085ef7c817b33524af69c48f24550ae1b7050f len=541 pn=0 [2025-09-12T05:41:15.143765401Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm CRYPTO off=0 len=537 [2025-09-12T05:41:15.143779998Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=998.921725ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=604 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 275, tv_nsec: 943593806 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 943593806 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 275, tv_nsec: 943593806 }, next_time: Instant { tv_sec: 275, tv_nsec: 943593806 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.143870707Z TRACE quiche_apps::client] written 1200 [2025-09-12T05:41:15.177192688Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.177222343Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Initial version=1 dcid=67085ef7c817b33524af69c48f24550ae1b7050f scid=e4ac80ac163a234cf30b47c0 token= len=1158 pn=0 [2025-09-12T05:41:15.177238784Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm CRYPTO off=0 len=96 [2025-09-12T05:41:15.177328391Z TRACE quiche::tls] 67085ef7c817b33524af69c48f24550ae1b7050f set write secret lvl=Handshake [2025-09-12T05:41:15.177339060Z TRACE quiche::tls] 67085ef7c817b33524af69c48f24550ae1b7050f set read secret lvl=Handshake [2025-09-12T05:41:15.177350832Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm PADDING len=1038 [2025-09-12T05:41:15.177371531Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1200 bytes [2025-09-12T05:41:15.177376821Z TRACE quiche_apps::client] got 211 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.177380327Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Handshake version=1 dcid=67085ef7c817b33524af69c48f24550ae1b7050f scid=e4ac80ac163a234cf30b47c0 len=170 pn=0 [2025-09-12T05:41:15.177385257Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm CRYPTO off=0 len=146 [2025-09-12T05:41:15.177402248Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 211 bytes [2025-09-12T05:41:15.177406466Z TRACE quiche_apps::client] got 101 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.177409431Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Handshake version=1 dcid=67085ef7c817b33524af69c48f24550ae1b7050f scid=e4ac80ac163a234cf30b47c0 len=60 pn=1 [2025-09-12T05:41:15.177413820Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm CRYPTO off=146 len=36 [2025-09-12T05:41:15.177435069Z TRACE quiche::tls] 67085ef7c817b33524af69c48f24550ae1b7050f write message lvl=Handshake len=36 [2025-09-12T05:41:15.177438305Z TRACE quiche::tls] 67085ef7c817b33524af69c48f24550ae1b7050f set write secret lvl=OneRTT [2025-09-12T05:41:15.177454686Z TRACE quiche::tls] 67085ef7c817b33524af69c48f24550ae1b7050f set read secret lvl=OneRTT [2025-09-12T05:41:15.177465997Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=true TransportParams { original_destination_connection_id: Some(80e0786bb0b98e5206df9ef62808e692), max_idle_timeout: 120000, stateless_reset_token: Some(128825129971334875003164804413778710732), max_udp_payload_size: 1500, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 16777216, initial_max_stream_data_bidi_remote: 16777216, initial_max_stream_data_uni: 16777216, initial_max_streams_bidi: 128, initial_max_streams_uni: 128, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(e4ac80ac163a234cf30b47c0), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-09-12T05:41:15.177486966Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 101 bytes [2025-09-12T05:41:15.177491244Z TRACE quiche_apps::client] got 68 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.177494480Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Initial version=1 dcid=67085ef7c817b33524af69c48f24550ae1b7050f scid=e4ac80ac163a234cf30b47c0 token= len=26 pn=1 [2025-09-12T05:41:15.177499980Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm ACK delay=104 blocks=[0..0] ecn_counts=None [2025-09-12T05:41:15.177504509Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f packet newly acked 0 [2025-09-12T05:41:15.177516381Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 68 bytes [2025-09-12T05:41:15.177519937Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.177522462Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.177530617Z DEBUG quiche_apps::common] sending HTTP request "GET /mhmctcwjia\r\n" [2025-09-12T05:41:15.177616177Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Initial version=1 dcid=e4ac80ac163a234cf30b47c0 scid=67085ef7c817b33524af69c48f24550ae1b7050f len=5 pn=1 [2025-09-12T05:41:15.177619934Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=14 blocks=[0..1] ecn_counts=None [2025-09-12T05:41:15.177630483Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=101.237367ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 275, tv_nsec: 977289262 }, next_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.177652765Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Handshake version=1 dcid=e4ac80ac163a234cf30b47c0 scid=67085ef7c817b33524af69c48f24550ae1b7050f len=45 pn=2 [2025-09-12T05:41:15.177655730Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=30 blocks=[0..1] ecn_counts=None [2025-09-12T05:41:15.177663445Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm CRYPTO off=0 len=36 [2025-09-12T05:41:15.177669596Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=101.311596ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=103 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 275, tv_nsec: 977498442 }, next_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, max_datagram_size: 1350, last_packet_size: None, iv: 206.253µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.177680937Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f dropped epoch 0 state [2025-09-12T05:41:15.177694994Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=1153 pn=3 [2025-09-12T05:41:15.177697729Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[30, db, 75, ca, df, 17, 5c, 3f, c1, 21, 66, 34, 4e, c2, d1, ea, f3, b1, 95, a5] reset_token=[47, dd, da, 74, 26, 8c, 6b, 99, 21, 8f, cb, 7c, 14, 38, 54, 91] [2025-09-12T05:41:15.177704291Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[f8, 1a, 65, 66, dc, d4, fc, 6c, 09, 17, bc, 48, 11, ed, c2, 13, 40, 13, 27, 56] reset_token=[58, 23, 26, 70, bb, a1, 54, 92, 0d, 4d, a1, f8, 44, 50, 95, 4e] [2025-09-12T05:41:15.177709911Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[0b, ad, fd, a3, 89, 33, ad, d0, bf, c5, 1c, 61, 9f, 01, 65, 56, 80, 0e, 3e, 5e] reset_token=[6d, eb, 06, 42, 78, 90, b2, 8a, 27, bd, 26, 01, f4, 05, af, 93] [2025-09-12T05:41:15.177715502Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[33, f0, 0c, 6a, 01, 0d, 1d, ce, ee, 4a, 83, b0, 3b, b1, c3, 17, 62, c4, 65, fc] reset_token=[9b, 25, 8e, 35, ad, 51, 19, f1, 7f, 32, 3e, 89, ec, 06, 8b, c9] [2025-09-12T05:41:15.177721062Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[01, 4b, c9, 9b, 48, 4f, 94, 75, 51, 8f, 66, af, a3, f4, 64, 88, f0, ef, 71, 4b] reset_token=[26, 0e, ab, 33, cb, 08, 06, 65, a6, 11, 49, 86, 6d, c3, 28, df] [2025-09-12T05:41:15.177726723Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[76, 4d, ab, 28, 3e, dc, f3, 38, 63, 22, 6e, 6e, 70, fe, f7, 2f, 9f, 98, ba, 10] reset_token=[c1, cf, 7a, c1, c7, 49, 4f, 2a, 54, 51, 07, 47, 95, f6, 28, 28] [2025-09-12T05:41:15.177732032Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[4a, 70, 55, 37, 91, 50, 9e, 76, 60, d7, d4, 22, cf, 70, 7f, fc, 54, 5b, e7, f5] reset_token=[22, 62, dd, be, db, 3d, 1b, fc, f6, cb, 78, 77, 13, ed, e9, 7e] [2025-09-12T05:41:15.177737182Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm STREAM id=0 off=0 len=17 fin=true [2025-09-12T05:41:15.177739777Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm PADDING len=851 [2025-09-12T05:41:15.177752401Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=101.228741ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1286 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1183, rate: 499386, last_update: Instant { tv_sec: 275, tv_nsec: 977498442 }, next_time: Instant { tv_sec: 275, tv_nsec: 977704695 }, max_datagram_size: 1350, last_packet_size: Some(1183), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.177809076Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.177817402Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.210946485Z TRACE quiche_apps::client] got 42 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.210980989Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=21 pn=0 [2025-09-12T05:41:15.210996237Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm HANDSHAKE_DONE [2025-09-12T05:41:15.211003741Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f dropped epoch 1 state [2025-09-12T05:41:15.211021114Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 42 bytes [2025-09-12T05:41:15.211026544Z TRACE quiche_apps::client] got 52 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.211030601Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=31 pn=1 [2025-09-12T05:41:15.211038185Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm NEW_TOKEN len=9 [2025-09-12T05:41:15.211044918Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 52 bytes [2025-09-12T05:41:15.211049526Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.211052663Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.211068221Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=5 pn=4 [2025-09-12T05:41:15.211072159Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=4 blocks=[0..1] ecn_counts=None [2025-09-12T05:41:15.211084391Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=92.89624ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.211193765Z TRACE quiche_apps::client] written 35 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.211207671Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.211261351Z TRACE quiche_apps::client] got 302 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.211267312Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=281 pn=2 [2025-09-12T05:41:15.211275387Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm CRYPTO off=0 len=257 [2025-09-12T05:41:15.211308669Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 302 bytes [2025-09-12T05:41:15.211314280Z TRACE quiche_apps::client] got 67 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.211318879Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f dropped invalid packet [2025-09-12T05:41:15.211322154Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 67 bytes [2025-09-12T05:41:15.211326062Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.211328967Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.211337563Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=5 pn=5 [2025-09-12T05:41:15.211340900Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=8 blocks=[0..2] ecn_counts=None [2025-09-12T05:41:15.211349255Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=92.631747ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.211392456Z TRACE quiche_apps::client] written 35 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.211400551Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.211442883Z TRACE quiche_apps::client] got 73 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.211449966Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=52 pn=3 [2025-09-12T05:41:15.211459414Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[21, 2b, d4, 73, 70, 20, 73, c4, d2, 1e, 42, 14] reset_token=[f7, 5b, a0, 18, c2, d5, f3, e1, 3d, 91, a4, a7, 09, 41, ae, 9e] [2025-09-12T05:41:15.211501392Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 73 bytes [2025-09-12T05:41:15.211510218Z TRACE quiche_apps::client] got 73 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.211514126Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=52 pn=5 [2025-09-12T05:41:15.211521058Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[49, 10, 43, 4f, 8c, 35, 1b, 16, 26, 6c, 23, 0b] reset_token=[e3, 79, a7, d0, 13, 6c, 05, 45, d9, af, 83, 4b, 2d, b9, 4a, e8] [2025-09-12T05:41:15.211529033Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 73 bytes [2025-09-12T05:41:15.211533121Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.211536057Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.211544442Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=6 [2025-09-12T05:41:15.211547598Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=3 blocks=[0..3, 5..5] ecn_counts=None [2025-09-12T05:41:15.211555593Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=92.425379ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.211600096Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.211608271Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.212526802Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.212534597Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=6 [2025-09-12T05:41:15.212541189Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=0 len=1171 fin=false [2025-09-12T05:41:15.212548753Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.212552200Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.212554554Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.212559884Z TRACE quiche_apps::common] received 1171 bytes [2025-09-12T05:41:15.212562519Z TRACE quiche_apps::common] stream 0 has 1171 bytes (fin? false) [2025-09-12T05:41:15.212569251Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=7 [2025-09-12T05:41:15.212571806Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=4 blocks=[0..3, 5..6] ecn_counts=None [2025-09-12T05:41:15.212578549Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=91.402573ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.212616800Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.212624685Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.213507960Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.213515454Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=7 [2025-09-12T05:41:15.213521796Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=1171 len=1169 fin=false [2025-09-12T05:41:15.213528469Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.213531805Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.213534149Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.213538086Z TRACE quiche_apps::common] received 1169 bytes [2025-09-12T05:41:15.213540320Z TRACE quiche_apps::common] stream 0 has 1169 bytes (fin? false) [2025-09-12T05:41:15.213547013Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=8 [2025-09-12T05:41:15.213549478Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=3 blocks=[0..3, 5..7] ecn_counts=None [2025-09-12T05:41:15.213555799Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=90.425343ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.213588881Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.213595834Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.214507983Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.214520537Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=8 [2025-09-12T05:41:15.214526678Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=2340 len=1169 fin=false [2025-09-12T05:41:15.214533180Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.214536527Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.214538881Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.214542588Z TRACE quiche_apps::common] received 1169 bytes [2025-09-12T05:41:15.214544822Z TRACE quiche_apps::common] stream 0 has 1169 bytes (fin? false) [2025-09-12T05:41:15.214551584Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=9 [2025-09-12T05:41:15.214554099Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=3 blocks=[0..3, 5..8] ecn_counts=None [2025-09-12T05:41:15.214559980Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=89.421162ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 9, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.214593062Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.214600025Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.215503047Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.215510451Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=9 [2025-09-12T05:41:15.215516653Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=3509 len=1169 fin=false [2025-09-12T05:41:15.215523074Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.215526451Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.215528785Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.215532963Z TRACE quiche_apps::common] received 1169 bytes [2025-09-12T05:41:15.215535127Z TRACE quiche_apps::common] stream 0 has 1169 bytes (fin? false) [2025-09-12T05:41:15.215541679Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=10 [2025-09-12T05:41:15.215544194Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=3 blocks=[0..3, 5..9] ecn_counts=None [2025-09-12T05:41:15.215550235Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=88.430817ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 10, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.215589017Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.215595740Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.216498823Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.216506206Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=10 [2025-09-12T05:41:15.216512838Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=4678 len=1169 fin=false [2025-09-12T05:41:15.216519571Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.216522917Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.216525262Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.216529039Z TRACE quiche_apps::common] received 1169 bytes [2025-09-12T05:41:15.216531263Z TRACE quiche_apps::common] stream 0 has 1169 bytes (fin? false) [2025-09-12T05:41:15.216538045Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=11 [2025-09-12T05:41:15.216540510Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=3 blocks=[0..3, 5..10] ecn_counts=None [2025-09-12T05:41:15.216547133Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=87.43406ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 11, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.216580174Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.216587457Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.217495509Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.217508413Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=11 [2025-09-12T05:41:15.217515617Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=5847 len=1169 fin=false [2025-09-12T05:41:15.217522349Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.217525725Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.217528060Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.217531757Z TRACE quiche_apps::common] received 1169 bytes [2025-09-12T05:41:15.217534001Z TRACE quiche_apps::common] stream 0 has 1169 bytes (fin? false) [2025-09-12T05:41:15.217540764Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=12 [2025-09-12T05:41:15.217543228Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=4 blocks=[0..3, 5..11] ecn_counts=None [2025-09-12T05:41:15.217549249Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=86.431853ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 12, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.217582822Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.217589815Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.218492266Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.218499680Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=12 [2025-09-12T05:41:15.218505691Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=7016 len=1169 fin=false [2025-09-12T05:41:15.218512053Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.218515359Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.218517714Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.218521431Z TRACE quiche_apps::common] received 1169 bytes [2025-09-12T05:41:15.218523615Z TRACE quiche_apps::common] stream 0 has 1169 bytes (fin? false) [2025-09-12T05:41:15.218530247Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=13 [2025-09-12T05:41:15.218532732Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=3 blocks=[0..3, 5..12] ecn_counts=None [2025-09-12T05:41:15.218538973Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=85.442169ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 13, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.218577295Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.218584458Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.219501527Z TRACE quiche_apps::client] got 1216 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.219510403Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=1195 pn=13 [2025-09-12T05:41:15.219516915Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=8185 len=1169 fin=false [2025-09-12T05:41:15.219524279Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 1216 bytes [2025-09-12T05:41:15.219527675Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.219530040Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.219533747Z TRACE quiche_apps::common] received 1169 bytes [2025-09-12T05:41:15.219535921Z TRACE quiche_apps::common] stream 0 has 1169 bytes (fin? false) [2025-09-12T05:41:15.219559765Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=7 pn=14 [2025-09-12T05:41:15.219562540Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm ACK delay=6 blocks=[0..3, 5..13] ecn_counts=None [2025-09-12T05:41:15.219568882Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=84.41225ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1183 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 2, last_sent_packet: 14, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 10950497 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.219603096Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.219610600Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.220260531Z TRACE quiche_apps::client] got 933 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.220274457Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx pkt Short dcid=67085ef7c817b33524af69c48f24550ae1b7050f key_phase=false len=912 pn=14 [2025-09-12T05:41:15.220281209Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f rx frm STREAM id=0 off=9354 len=886 fin=true [2025-09-12T05:41:15.220288202Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 933 bytes [2025-09-12T05:41:15.220291579Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.220293943Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.220297740Z TRACE quiche_apps::common] received 886 bytes [2025-09-12T05:41:15.220299974Z TRACE quiche_apps::common] stream 0 has 886 bytes (fin? true) [2025-09-12T05:41:15.220302309Z DEBUG quiche_apps::common] 1/1 responses received [2025-09-12T05:41:15.220304603Z INFO quiche_apps::common] 1/1 response(s) received in 76.428656ms, closing... [2025-09-12T05:41:15.220311526Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx pkt Short dcid=e4ac80ac163a234cf30b47c0 key_phase=false len=10 pn=15 [2025-09-12T05:41:15.220314060Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-09-12T05:41:15.220321164Z TRACE quiche::recovery::congestion::recovery] 67085ef7c817b33524af69c48f24550ae1b7050f timer=126.361499ms latest_rtt=33.791495ms srtt=33.791495ms min_rtt=33.791495ms rttvar=16.895747ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1223 app_limited=true congestion_recovery_start_time=None Rate { delivered: 604, delivered_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 977289292 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 0, rate_sample: RateSample { bandwidth: 142.99 Kbps, is_app_limited: true, interval: 33.791495ms, delivered: 604, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 943593806 }), send_elapsed: 0ns, ack_elapsed: 33.791495ms, rtt: 33.791495ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499386, last_update: Instant { tv_sec: 276, tv_nsec: 20199963 }, next_time: Instant { tv_sec: 276, tv_nsec: 10950497 }, max_datagram_size: 1350, last_packet_size: None, iv: 80.098µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-09-12T05:41:15.220355598Z TRACE quiche_apps::client] written 40 bytes from 0.0.0.0:41280 to 193.167.100.100:443 [2025-09-12T05:41:15.220361970Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.234615045Z TRACE quiche_apps::client] got 47 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.234630123Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 47 bytes [2025-09-12T05:41:15.234634621Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.234637677Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.234643368Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.250973704Z TRACE quiche_apps::client] got 45 bytes from 193.167.100.100:443 to 0.0.0.0:41280 [2025-09-12T05:41:15.251000474Z TRACE quiche_apps::client] 0.0.0.0:41280: processed 45 bytes [2025-09-12T05:41:15.251005403Z TRACE quiche_apps::client] 0.0.0.0:41280: recv() would block [2025-09-12T05:41:15.251008619Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.251015452Z TRACE quiche_apps::client] 0.0.0.0:41280 -> 193.167.100.100:443: done writing [2025-09-12T05:41:15.525346712Z TRACE quiche_apps::client] timed out [2025-09-12T05:41:15.525366549Z TRACE quiche] 67085ef7c817b33524af69c48f24550ae1b7050f draining timeout expired [2025-09-12T05:41:15.525410581Z TRACE quiche_apps::client] done reading [2025-09-12T05:41:15.525417273Z INFO quiche_apps::client] connection closed, recv=18 sent=16 lost=0 retrans=0 sent_bytes=2397 recv_bytes=12783 lost_bytes=0 [local_addr=0.0.0.0:41280 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=18 sent=16 lost=0 retrans=0 rtt=33.791495ms min_rtt=Some(33.791495ms) rttvar=16.895747ms cwnd=13500 sent_bytes=2397 recv_bytes=12783 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=17874]