[2025-04-30T21:42:24.754052659Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T21:42:24.754362133Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:51154 with scid 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef [2025-04-30T21:42:24.754404322Z TRACE quiche::tls] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef write message lvl=Initial len=266 [2025-04-30T21:42:24.754424139Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Initial version=1 dcid=75f6b6267e27f98cef01e4aa988c7329 scid=6a5f44d94e0c2b40b08a087e86c32c2d9f170aef len=270 pn=0 [2025-04-30T21:42:24.754427204Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm CRYPTO off=0 len=266 [2025-04-30T21:42:24.754440790Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=998.92999ms 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: 275, tv_nsec: 794054159 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 794054159 }, 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: 275, tv_nsec: 794054159 }, next_time: Instant { tv_sec: 275, tv_nsec: 794054159 }, 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-30T21:42:24.754504067Z TRACE quiche_apps::client] written 1200 [2025-04-30T21:42:24.791659069Z TRACE quiche_apps::client] got 145 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.791678114Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Retry version=1 dcid=6a5f44d94e0c2b40b08a087e86c32c2d9f170aef scid=7cd7dd19222980bd59c42b52ac0dfb97 token=601075f6b6267e27f98cef01e4aa988c7329000000007adc164e7e47905c54778dc6b227499386acf8c37b2d8c7353d92814b89c76f63a1f0d37fa9d81676cf80c020e09f6c2e5d68e0e5a5d2381b4f94447cc460df0 [2025-04-30T21:42:24.791701928Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef dropped epoch 0 state [2025-04-30T21:42:24.791710184Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 145 bytes [2025-04-30T21:42:24.791714151Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.791716766Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.791751831Z TRACE quiche::tls] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef write message lvl=Initial len=266 [2025-04-30T21:42:24.791766298Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Initial version=1 dcid=7cd7dd19222980bd59c42b52ac0dfb97 scid=6a5f44d94e0c2b40b08a087e86c32c2d9f170aef token=601075f6b6267e27f98cef01e4aa988c7329000000007adc164e7e47905c54778dc6b227499386acf8c37b2d8c7353d92814b89c76f63a1f0d37fa9d81676cf80c020e09f6c2e5d68e0e5a5d2381b4f94447cc460df0 len=270 pn=1 [2025-04-30T21:42:24.791769564Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm CRYPTO off=0 len=266 [2025-04-30T21:42:24.791779593Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=998.943525ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=420 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 275, tv_nsec: 831406397 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 831406397 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 0, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 275, tv_nsec: 831406397 }, next_time: Instant { tv_sec: 275, tv_nsec: 831406397 }, 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-30T21:42:24.791831599Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.791837500Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.833906990Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.833931977Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Initial version=1 dcid=6a5f44d94e0c2b40b08a087e86c32c2d9f170aef scid=7cd7dd19222980bd59c42b52ac0dfb97 token= len=117 pn=0 [2025-04-30T21:42:24.833948988Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm ACK delay=8984 blocks=[1..1] ecn_counts=None [2025-04-30T21:42:24.833956141Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef packet newly acked 1 [2025-04-30T21:42:24.833963415Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm CRYPTO off=0 len=90 [2025-04-30T21:42:24.834082396Z TRACE quiche::tls] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef set write secret lvl=Handshake [2025-04-30T21:42:24.834094448Z TRACE quiche::tls] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef set read secret lvl=Handshake [2025-04-30T21:42:24.834130626Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Handshake version=1 dcid=6a5f44d94e0c2b40b08a087e86c32c2d9f170aef scid=7cd7dd19222980bd59c42b52ac0dfb97 len=1024 pn=0 [2025-04-30T21:42:24.834138650Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm CRYPTO off=0 len=711 [2025-04-30T21:42:24.834425954Z TRACE quiche::tls] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef write message lvl=Handshake len=36 [2025-04-30T21:42:24.834433688Z TRACE quiche::tls] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef set write secret lvl=OneRTT [2025-04-30T21:42:24.834442835Z TRACE quiche::tls] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef set read secret lvl=OneRTT [2025-04-30T21:42:24.834463804Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(75f6b6267e27f98cef01e4aa988c7329), max_idle_timeout: 300000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 3750000, initial_max_stream_data_bidi_local: 3750000, initial_max_stream_data_bidi_remote: 3750000, initial_max_stream_data_uni: 3750000, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 3, initial_source_connection_id: Some(7cd7dd19222980bd59c42b52ac0dfb97), retry_source_connection_id: Some(7cd7dd19222980bd59c42b52ac0dfb97), max_datagram_frame_size: None, unknown_params: None } [2025-04-30T21:42:24.834477149Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm PADDING len=292 [2025-04-30T21:42:24.834490414Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.834495212Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.834497837Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.834506193Z DEBUG quiche_apps::common] sending HTTP request "GET /schixkewef\r\n" [2025-04-30T21:42:24.834575922Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Initial version=1 dcid=7cd7dd19222980bd59c42b52ac0dfb97 scid=6a5f44d94e0c2b40b08a087e86c32c2d9f170aef token=601075f6b6267e27f98cef01e4aa988c7329000000007adc164e7e47905c54778dc6b227499386acf8c37b2d8c7353d92814b89c76f63a1f0d37fa9d81676cf80c020e09f6c2e5d68e0e5a5d2381b4f94447cc460df0 len=6 pn=2 [2025-04-30T21:42:24.834584929Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=80 blocks=[0..0] ecn_counts=None [2025-04-30T21:42:24.834593525Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=125.940239ms latest_rtt=42.202637ms srtt=42.202637ms min_rtt=42.202637ms rttvar=21.101318ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 420, delivered_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 9951, is_app_limited: true, interval: 42.202637ms, delivered: 420, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 831406397 }), send_elapsed: 0ns, ack_elapsed: 42.202637ms, rtt: 42.202637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 399856, last_update: Instant { tv_sec: 275, tv_nsec: 874143857 }, next_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, 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-30T21:42:24.834613312Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Handshake version=1 dcid=7cd7dd19222980bd59c42b52ac0dfb97 scid=6a5f44d94e0c2b40b08a087e86c32c2d9f170aef len=45 pn=3 [2025-04-30T21:42:24.834616067Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=60 blocks=[0..0] ecn_counts=None [2025-04-30T21:42:24.834618612Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm CRYPTO off=0 len=36 [2025-04-30T21:42:24.834624252Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=126.548468ms latest_rtt=42.202637ms srtt=42.202637ms min_rtt=42.202637ms rttvar=21.101318ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=107 app_limited=true congestion_recovery_start_time=None Rate { delivered: 420, delivered_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 9951, is_app_limited: true, interval: 42.202637ms, delivered: 420, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 831406397 }), send_elapsed: 0ns, ack_elapsed: 42.202637ms, rtt: 42.202637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 399856, last_update: Instant { tv_sec: 275, tv_nsec: 874247750 }, next_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, max_datagram_size: 1350, last_packet_size: None, iv: 267.596µ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-30T21:42:24.834635163Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef dropped epoch 0 state [2025-04-30T21:42:24.834639831Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13393 out_len=1087 left=1053 [2025-04-30T21:42:24.834649509Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=7cd7dd19222980bd59c42b52ac0dfb97 key_phase=false len=1053 pn=4 [2025-04-30T21:42:24.834651954Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[b8, a4, ab, c7, e7, 48, 69, 11, d7, 58, 1e, 81, 73, 7a, bb, c1, f4, 5b, 0b, 0d] reset_token=[b1, af, 04, dd, d4, 5a, 85, 33, 12, fc, 7b, e2, 68, 3b, 7e, b9] [2025-04-30T21:42:24.834661692Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[2e, a6, 1b, f7, bc, 80, be, 87, 6a, ab, c9, eb, cc, 7b, 4b, a1, 26, bb, 02, e5] reset_token=[b1, 42, 1a, f1, b2, 80, 07, b5, 8f, fe, 02, 06, 59, 51, 1f, 1f] [2025-04-30T21:42:24.834667012Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T21:42:24.834669536Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm PADDING len=951 [2025-04-30T21:42:24.834676229Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=126.496462ms latest_rtt=42.202637ms srtt=42.202637ms min_rtt=42.202637ms rttvar=21.101318ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1194 app_limited=true congestion_recovery_start_time=None Rate { delivered: 420, delivered_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 9951, is_app_limited: true, interval: 42.202637ms, delivered: 420, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 831406397 }), send_elapsed: 0ns, ack_elapsed: 42.202637ms, rtt: 42.202637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1087, rate: 399856, last_update: Instant { tv_sec: 275, tv_nsec: 874247750 }, next_time: Instant { tv_sec: 275, tv_nsec: 874515346 }, max_datagram_size: 1350, last_packet_size: Some(1087), 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-30T21:42:24.834717055Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.834721864Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.869283411Z TRACE quiche_apps::client] got 1452 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.869298298Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1431 pn=0 [2025-04-30T21:42:24.869306483Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef path ID 0 now see SCID with seq num 1 [2025-04-30T21:42:24.869311363Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm PING mtu_probe=None [2025-04-30T21:42:24.869346288Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm PADDING len=1413 [2025-04-30T21:42:24.869362397Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1452 bytes [2025-04-30T21:42:24.869368649Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.869372737Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.869385911Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12306 out_len=1350 left=1311 [2025-04-30T21:42:24.869391471Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=7cd7dd19222980bd59c42b52ac0dfb97 key_phase=false len=5 pn=5 [2025-04-30T21:42:24.869393986Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=11 blocks=[0..0] ecn_counts=None [2025-04-30T21:42:24.869403113Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=91.769377ms latest_rtt=42.202637ms srtt=42.202637ms min_rtt=42.202637ms rttvar=21.101318ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1194 app_limited=true congestion_recovery_start_time=None Rate { delivered: 420, delivered_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 874143898 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { delivery_rate: 9951, is_app_limited: true, interval: 42.202637ms, delivered: 420, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 831406397 }), send_elapsed: 0ns, ack_elapsed: 42.202637ms, rtt: 42.202637ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 399856, last_update: Instant { tv_sec: 275, tv_nsec: 909061566 }, next_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, 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-30T21:42:24.869450681Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.869455811Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.869464657Z TRACE quiche_apps::client] got 155 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.869469897Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=134 pn=1 [2025-04-30T21:42:24.869478663Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm ACK delay=164 blocks=[4..4] ecn_counts=None [2025-04-30T21:42:24.869484104Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef packet newly acked 4 [2025-04-30T21:42:24.869490435Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.869496416Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef dropped epoch 1 state [2025-04-30T21:42:24.869503289Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=1 conn_id=[ae, 1b, 67, de, b2, 67, d2, cd, 95, 22, 6a, 85, 55, 19, ad, 91] reset_token=[e2, df, 77, 13, 63, c2, 15, 30, 81, 05, 76, f1, 47, ae, c2, 01] [2025-04-30T21:42:24.869512917Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef path ID 0 changed DCID: old seq num 0 new seq num 1 [2025-04-30T21:42:24.869519178Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=1 conn_id=[a8, ab, 08, cb, 82, ca, 6a, 71, ad, 62, e4, 95, 76, c5, 61, 04] reset_token=[4d, 58, e4, ce, f3, 4e, ed, d8, ed, 40, fb, cf, f2, 41, f4, a0] [2025-04-30T21:42:24.869526572Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[c0, f8, 89, 49, ef, 5e, 4a, ff, e7, 83, 6b, 0a, d0, d0, 49, 97] reset_token=[18, 34, 65, 25, ed, fd, 04, a2, 8a, d9, 2f, 40, a5, 17, aa, df] [2025-04-30T21:42:24.869530580Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T21:42:24.869542853Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 155 bytes [2025-04-30T21:42:24.869546890Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.869549325Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.869551909Z INFO quiche_apps::client] Retiring source CID 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef [2025-04-30T21:42:24.869561167Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1311 [2025-04-30T21:42:24.869565695Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=47 pn=6 [2025-04-30T21:42:24.869569021Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=11 blocks=[0..1] ecn_counts=None [2025-04-30T21:42:24.869573660Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[d6, ba, ae, bb, c1, 31, 4f, c3, ed, eb, 40, 0b, 8b, aa, 71, 70, 07, 8a, d5, 4e] reset_token=[3d, e8, e4, 26, 67, e1, 9b, c7, f2, 82, 38, 9d, 4f, a2, 36, 29] [2025-04-30T21:42:24.869589419Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T21:42:24.869599808Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=137.085044ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, max_datagram_size: 1350, last_packet_size: None, iv: 198.033µ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-30T21:42:24.869637328Z TRACE quiche_apps::client] written 81 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.869641957Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.870664926Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.870676037Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1211 pn=2 [2025-04-30T21:42:24.870682469Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.870685976Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=0 len=1191 fin=false [2025-04-30T21:42:24.870694181Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.870697847Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.870700252Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.870704780Z TRACE quiche_apps::common] received 1191 bytes [2025-04-30T21:42:24.870707345Z TRACE quiche_apps::common] stream 0 has 1191 bytes (fin? false) [2025-04-30T21:42:24.870714288Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.870717654Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=7 [2025-04-30T21:42:24.870720059Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=4 blocks=[0..2] ecn_counts=None [2025-04-30T21:42:24.870746688Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=135.938445ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.870785821Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.870790169Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.871668330Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.871679220Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1211 pn=3 [2025-04-30T21:42:24.871685301Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.871688547Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=1191 len=1189 fin=false [2025-04-30T21:42:24.871696362Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.871699989Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.871702363Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.871706441Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:42:24.871708655Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:42:24.871715277Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.871718493Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=8 [2025-04-30T21:42:24.871720907Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=4 blocks=[0..3] ecn_counts=None [2025-04-30T21:42:24.871727129Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=134.958104ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.871760581Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.871764548Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.872677123Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.872687052Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1211 pn=4 [2025-04-30T21:42:24.872693013Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.872701048Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=2380 len=1189 fin=false [2025-04-30T21:42:24.872708271Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.872711808Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.872714162Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.872718159Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:42:24.872720354Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:42:24.872726846Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.872729941Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=9 [2025-04-30T21:42:24.872732296Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=5 blocks=[0..4] ecn_counts=None [2025-04-30T21:42:24.872739048Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=133.946225ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.872772841Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.872776728Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.873156524Z TRACE quiche_apps::client] got 572 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.873164158Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=551 pn=5 [2025-04-30T21:42:24.873169748Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.873172664Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=3569 len=527 fin=false [2025-04-30T21:42:24.873179757Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 572 bytes [2025-04-30T21:42:24.873183314Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.873185658Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.873189545Z TRACE quiche_apps::common] received 527 bytes [2025-04-30T21:42:24.873191739Z TRACE quiche_apps::common] stream 0 has 527 bytes (fin? false) [2025-04-30T21:42:24.873198141Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.873201297Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=10 [2025-04-30T21:42:24.873203741Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=4 blocks=[0..5] ecn_counts=None [2025-04-30T21:42:24.873209833Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=133.47541ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 10, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.873247373Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.873251520Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.874166910Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.874176699Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1211 pn=6 [2025-04-30T21:42:24.874182639Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.874185986Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=4096 len=1189 fin=false [2025-04-30T21:42:24.874193069Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.874196676Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.874199030Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.874202947Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:42:24.874205101Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:42:24.874211573Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.874214719Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=11 [2025-04-30T21:42:24.874217114Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=4 blocks=[0..6] ecn_counts=None [2025-04-30T21:42:24.874223235Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=132.462048ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 11, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.874261837Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.874266034Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.875176285Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.875186173Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1211 pn=7 [2025-04-30T21:42:24.875192034Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.875195030Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=5285 len=1189 fin=false [2025-04-30T21:42:24.875202203Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.875205779Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.875208144Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.875212101Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:42:24.875214295Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:42:24.875220827Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.875223963Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=12 [2025-04-30T21:42:24.875226368Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=4 blocks=[0..7] ecn_counts=None [2025-04-30T21:42:24.875232459Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=131.452794ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 12, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.875265130Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.875269047Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.876186251Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.876196129Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1211 pn=8 [2025-04-30T21:42:24.876202090Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.876205095Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=6474 len=1189 fin=false [2025-04-30T21:42:24.876212148Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.876220955Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.876223389Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.876227387Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:42:24.876229561Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:42:24.876236033Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.876239139Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=13 [2025-04-30T21:42:24.876241553Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=5 blocks=[0..8] ecn_counts=None [2025-04-30T21:42:24.876248256Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=130.436998ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 13, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.876281147Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.876285114Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.876669999Z TRACE quiche_apps::client] got 574 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.876680228Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=553 pn=9 [2025-04-30T21:42:24.876685968Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.876688844Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=7663 len=529 fin=false [2025-04-30T21:42:24.876696448Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 574 bytes [2025-04-30T21:42:24.876699945Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.876702299Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.876706186Z TRACE quiche_apps::common] received 529 bytes [2025-04-30T21:42:24.876708400Z TRACE quiche_apps::common] stream 0 has 529 bytes (fin? false) [2025-04-30T21:42:24.876715223Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.876718369Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=14 [2025-04-30T21:42:24.876720723Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=4 blocks=[0..9] ecn_counts=None [2025-04-30T21:42:24.876726764Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=129.958489ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.876765176Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.876769504Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.877679534Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.877689462Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=1211 pn=10 [2025-04-30T21:42:24.877695293Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.877698469Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=8192 len=1189 fin=false [2025-04-30T21:42:24.877705472Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 1232 bytes [2025-04-30T21:42:24.877709039Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.877711383Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.877715240Z TRACE quiche_apps::common] received 1189 bytes [2025-04-30T21:42:24.877717434Z TRACE quiche_apps::common] stream 0 has 1189 bytes (fin? false) [2025-04-30T21:42:24.877738062Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1311 [2025-04-30T21:42:24.877741489Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=5 pn=15 [2025-04-30T21:42:24.877743893Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm ACK delay=6 blocks=[0..10] ecn_counts=None [2025-04-30T21:42:24.877750275Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=128.934978ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 5, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 909241070 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, 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-30T21:42:24.877787063Z TRACE quiche_apps::client] written 39 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.877791301Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:24.878425058Z TRACE quiche_apps::client] got 904 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.878436950Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=883 pn=11 [2025-04-30T21:42:24.878445316Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.878450275Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=9381 len=859 fin=false [2025-04-30T21:42:24.878458170Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 904 bytes [2025-04-30T21:42:24.878463139Z TRACE quiche_apps::client] got 57 bytes from 193.167.100.100:443 to 0.0.0.0:51154 [2025-04-30T21:42:24.878466165Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx pkt Short dcid=b8a4abc7e7486911d7581e81737abbc1f45b0b0d key_phase=false len=36 pn=12 [2025-04-30T21:42:24.878469972Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm HANDSHAKE_DONE [2025-04-30T21:42:24.878472496Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm STREAM id=0 off=10240 len=0 fin=true [2025-04-30T21:42:24.878475632Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef rx frm PADDING len=13 [2025-04-30T21:42:24.878479940Z TRACE quiche_apps::client] 0.0.0.0:51154: processed 57 bytes [2025-04-30T21:42:24.878483246Z TRACE quiche_apps::client] 0.0.0.0:51154: recv() would block [2025-04-30T21:42:24.878485530Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:24.878490820Z TRACE quiche_apps::common] received 859 bytes [2025-04-30T21:42:24.878493044Z TRACE quiche_apps::common] stream 0 has 859 bytes (fin? true) [2025-04-30T21:42:24.878495419Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T21:42:24.878497683Z INFO quiche_apps::common] 1/1 response(s) received in 123.989749ms, closing... [2025-04-30T21:42:24.878504165Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1316 [2025-04-30T21:42:24.878507401Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx pkt Short dcid=ae1b67deb267d2cd95226a855519ad91 key_phase=false len=10 pn=16 [2025-04-30T21:42:24.878509846Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T21:42:24.878516508Z TRACE quiche::recovery::congestion::recovery] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef timer=137.112234ms latest_rtt=34.636207ms srtt=41.256832ms min_rtt=34.636207ms rttvar=17.717595ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=125 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, first_sent_time: Instant { tv_sec: 275, tv_nsec: 909061566 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 4, rate_sample: RateSample { delivery_rate: 31050, is_app_limited: true, interval: 35.007655ms, delivered: 1087, prior_delivered: 420, prior_time: Some(Instant { tv_sec: 275, tv_nsec: 874143898 }), send_elapsed: 371.448µs, ack_elapsed: 35.007655ms, rtt: 34.636207ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 409023, last_update: Instant { tv_sec: 275, tv_nsec: 918184539 }, next_time: Instant { tv_sec: 275, tv_nsec: 910591823 }, max_datagram_size: 1350, last_packet_size: None, iv: 107.573µ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-30T21:42:24.878550221Z TRACE quiche_apps::client] written 44 bytes from 0.0.0.0:51154 to 193.167.100.100:443 [2025-04-30T21:42:24.878561201Z TRACE quiche_apps::client] 0.0.0.0:51154 -> 193.167.100.100:443: done writing [2025-04-30T21:42:25.215964516Z TRACE quiche_apps::client] timed out [2025-04-30T21:42:25.215995674Z TRACE quiche] 6a5f44d94e0c2b40b08a087e86c32c2d9f170aef draining timeout expired [2025-04-30T21:42:25.216042742Z TRACE quiche_apps::client] done reading [2025-04-30T21:42:25.216047330Z INFO quiche_apps::client] connection closed, recv=15 sent=17 lost=0 retrans=0 sent_bytes=2618 recv_bytes=13570 lost_bytes=0 [local_addr=0.0.0.0:51154 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=15 sent=17 lost=0 retrans=0 rtt=41.256832ms min_rtt=Some(34.636207ms) rttvar=17.717595ms cwnd=13500 sent_bytes=2618 recv_bytes=13570 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=31050]