[2025-04-30T19:45:10.100841452Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T19:45:10.101126088Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:58177 with scid e8f726c17b9180e143e5188370d5f67793650b5f [2025-04-30T19:45:10.101166795Z TRACE quiche::tls] e8f726c17b9180e143e5188370d5f67793650b5f write message lvl=Initial len=266 [2025-04-30T19:45:10.101183286Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx pkt Initial version=1 dcid=f86579cb66186a5b5277d658f1a90bbd scid=e8f726c17b9180e143e5188370d5f67793650b5f len=270 pn=0 [2025-04-30T19:45:10.101186322Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm CRYPTO off=0 len=266 [2025-04-30T19:45:10.101199827Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=998.932362ms 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: 165, tv_nsec: 733921288 }, first_sent_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, 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: 165, tv_nsec: 733921288 }, next_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, 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-30T19:45:10.101292211Z TRACE quiche_apps::client] written 1200 [2025-04-30T19:45:11.101352224Z TRACE quiche_apps::client] timed out [2025-04-30T19:45:11.101386289Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f loss detection timeout expired [2025-04-30T19:45:11.101394114Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=997.737565ms 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: 165, tv_nsec: 733921288 }, first_sent_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, 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: 165, tv_nsec: 733921288 }, next_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, 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-30T19:45:11.101416255Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:11.101456451Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx pkt Initial version=1 dcid=f86579cb66186a5b5277d658f1a90bbd scid=e8f726c17b9180e143e5188370d5f67793650b5f len=270 pn=1 [2025-04-30T19:45:11.101460759Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm CRYPTO off=0 len=266 [2025-04-30T19:45:11.101478542Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=1.997955136s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=666 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, first_sent_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, 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: 166, tv_nsec: 734222135 }, next_time: Instant { tv_sec: 166, tv_nsec: 734222135 }, 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-30T19:45:11.101585013Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:58177 to 193.167.100.100:443 [2025-04-30T19:45:11.101592838Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:11.612188214Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:58177 [2025-04-30T19:45:11.612259218Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx pkt Initial version=1 dcid=e8f726c17b9180e143e5188370d5f67793650b5f scid=9ea391ba4714b03ce600 token= len=116 pn=0 [2025-04-30T19:45:11.612278965Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm ACK delay=0 blocks=[0..0] ecn_counts=None [2025-04-30T19:45:11.612286519Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f packet newly acked 0 [2025-04-30T19:45:11.612294023Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm CRYPTO off=0 len=90 [2025-04-30T19:45:11.612420061Z TRACE quiche::tls] e8f726c17b9180e143e5188370d5f67793650b5f set write secret lvl=Handshake [2025-04-30T19:45:11.612433136Z TRACE quiche::tls] e8f726c17b9180e143e5188370d5f67793650b5f set read secret lvl=Handshake [2025-04-30T19:45:11.612472199Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx pkt Handshake version=1 dcid=e8f726c17b9180e143e5188370d5f67793650b5f scid=9ea391ba4714b03ce600 len=753 pn=0 [2025-04-30T19:45:11.612479212Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm CRYPTO off=0 len=732 [2025-04-30T19:45:11.612720597Z TRACE quiche::tls] e8f726c17b9180e143e5188370d5f67793650b5f write message lvl=Handshake len=36 [2025-04-30T19:45:11.612725476Z TRACE quiche::tls] e8f726c17b9180e143e5188370d5f67793650b5f set write secret lvl=OneRTT [2025-04-30T19:45:11.612733692Z TRACE quiche::tls] e8f726c17b9180e143e5188370d5f67793650b5f set read secret lvl=OneRTT [2025-04-30T19:45:11.612752267Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f 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(f86579cb66186a5b5277d658f1a90bbd), max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1048576, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 1048576, initial_max_streams_bidi: 16, initial_max_streams_uni: 16, ack_delay_exponent: 3, max_ack_delay: 20, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(9ea391ba4714b03ce600), retry_source_connection_id: None, max_datagram_frame_size: Some(0), unknown_params: None } [2025-04-30T19:45:11.612776653Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx pkt Short dcid=0000000000000000000000000000000000000000 key_phase=false len=263 pn=205 [2025-04-30T19:45:11.612782604Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f dropped invalid packet [2025-04-30T19:45:11.612785820Z TRACE quiche_apps::client] 0.0.0.0:58177: processed 1232 bytes [2025-04-30T19:45:11.612792242Z TRACE quiche_apps::client] 0.0.0.0:58177: recv() would block [2025-04-30T19:45:11.612801640Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:11.612809975Z DEBUG quiche_apps::common] sending HTTP request "GET /zclataklbx\r\n" [2025-04-30T19:45:11.612887311Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx pkt Initial version=1 dcid=9ea391ba4714b03ce600 scid=e8f726c17b9180e143e5188370d5f67793650b5f len=6 pn=2 [2025-04-30T19:45:11.612891199Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm ACK delay=78 blocks=[0..0] ecn_counts=None [2025-04-30T19:45:11.612899925Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=4.021894186s latest_rtt=1.511120185s srtt=1.511120185s min_rtt=1.511120185s rttvar=755.560092ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 167, tv_nsec: 245041473 }, first_sent_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.511120185s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 165, tv_nsec: 733921288 }), send_elapsed: 0ns, ack_elapsed: 1.511120185s, rtt: 1.511120185s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11167, last_update: Instant { tv_sec: 167, tv_nsec: 245538139 }, next_time: Instant { tv_sec: 167, tv_nsec: 245538179 }, 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-30T19:45:11.612921456Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx pkt Handshake version=1 dcid=9ea391ba4714b03ce600 scid=e8f726c17b9180e143e5188370d5f67793650b5f len=45 pn=3 [2025-04-30T19:45:11.612924231Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm ACK delay=56 blocks=[0..0] ecn_counts=None [2025-04-30T19:45:11.612926786Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm CRYPTO off=0 len=36 [2025-04-30T19:45:11.612932867Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=4.021861524s latest_rtt=1.511120185s srtt=1.511120185s min_rtt=1.511120185s rttvar=755.560092ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=434 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 167, tv_nsec: 245041473 }, first_sent_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.511120185s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 165, tv_nsec: 733921288 }), send_elapsed: 0ns, ack_elapsed: 1.511120185s, rtt: 1.511120185s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11167, last_update: Instant { tv_sec: 167, tv_nsec: 245666511 }, next_time: Instant { tv_sec: 167, tv_nsec: 245538179 }, max_datagram_size: 1350, last_packet_size: None, iv: 9.044506ms, 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-30T19:45:11.612943968Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f dropped epoch 0 state [2025-04-30T19:45:11.612948416Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13399 out_len=1186 left=1158 [2025-04-30T19:45:11.612959738Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx pkt Short dcid=9ea391ba4714b03ce600 key_phase=false len=1158 pn=4 [2025-04-30T19:45:11.612966510Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[05, 18, 55, 0d, b4, 95, 93, 48, 0b, b0, 36, 02, 8f, 6a, c2, 9e, 69, d5, 32, c5] reset_token=[b7, 3d, 1f, 62, b3, b2, 7e, 4f, e9, 80, 04, e0, 9b, 83, d0, 04] [2025-04-30T19:45:11.612973614Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[6d, 30, d6, e1, e1, 5b, 3b, d2, ab, f5, 2a, 52, 63, f0, 63, 10, 7d, b6, fd, 11] reset_token=[db, 1f, 51, ea, 4b, ae, e9, 68, fa, 0a, df, 73, f0, ca, ce, 11] [2025-04-30T19:45:11.612978934Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[38, e3, 02, bb, c8, 16, 4a, ba, 96, f8, aa, 4d, 77, 5b, 26, c3, c3, 20, 9e, 18] reset_token=[f9, fd, 5b, cd, 3a, a1, cf, e9, c8, c2, 85, 33, 2d, ad, 13, a9] [2025-04-30T19:45:11.612984063Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[c7, 2e, cf, 96, db, b3, 1f, 55, d2, 3b, fe, c7, 5c, 03, fd, 9c, 06, 53, 8e, eb] reset_token=[29, c8, 38, a8, 07, 15, 02, 3b, ba, dc, 23, d3, 1d, 93, ed, 81] [2025-04-30T19:45:11.612989173Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[76, 4a, 9d, 34, 3d, 30, 4e, fc, 09, 35, 4c, fe, 5c, 88, ec, 87, 10, 69, 78, 6e] reset_token=[c4, f3, 29, ae, de, 3c, 88, 54, 0e, e5, f5, 77, b5, 11, 07, e1] [2025-04-30T19:45:11.612994223Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[b1, df, 87, f2, 4d, ae, 3b, 39, bc, 32, d9, 5b, 4b, e5, 55, 7f, 0d, f3, f1, 2e] reset_token=[1c, 1f, d7, 2f, a7, b4, 4a, c5, 92, 70, ed, 14, c3, fa, 66, 8b] [2025-04-30T19:45:11.612999162Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[5d, 5d, 4a, ff, 3d, 55, e8, 3a, 5a, be, c4, ed, 5a, c6, 7e, 35, a3, 99, 91, 50] reset_token=[af, de, 2a, c2, 90, cd, 46, c0, 47, 6d, cb, c4, 3e, 13, 6d, f9] [2025-04-30T19:45:11.613004061Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T19:45:11.613006566Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm PADDING len=856 [2025-04-30T19:45:11.613015513Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=4.533223254s latest_rtt=1.511120185s srtt=1.511120185s min_rtt=1.511120185s rttvar=755.560092ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1287 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 167, tv_nsec: 245041473 }, first_sent_time: Instant { tv_sec: 165, tv_nsec: 733921288 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.511120185s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 165, tv_nsec: 733921288 }), send_elapsed: 0ns, ack_elapsed: 1.511120185s, rtt: 1.511120185s } } pacer=Pacer { enabled: true, capacity: 13500, used: 1186, rate: 11167, last_update: Instant { tv_sec: 167, tv_nsec: 245666511 }, next_time: Instant { tv_sec: 167, tv_nsec: 254711017 }, max_datagram_size: 1350, last_packet_size: Some(1186), 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-30T19:45:11.613070086Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:58177 to 193.167.100.100:443 [2025-04-30T19:45:11.613075045Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:11.909900686Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:58177 [2025-04-30T19:45:11.909944408Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f dropped invalid packet [2025-04-30T19:45:11.909949749Z TRACE quiche_apps::client] 0.0.0.0:58177: processed 1232 bytes [2025-04-30T19:45:11.909955179Z TRACE quiche_apps::client] 0.0.0.0:58177: recv() would block [2025-04-30T19:45:11.909958555Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:11.909967552Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:12.604431291Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:58177 [2025-04-30T19:45:12.604474442Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f dropped invalid packet [2025-04-30T19:45:12.604479843Z TRACE quiche_apps::client] 0.0.0.0:58177: processed 1232 bytes [2025-04-30T19:45:12.604485142Z TRACE quiche_apps::client] 0.0.0.0:58177: recv() would block [2025-04-30T19:45:12.604488519Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:12.604497967Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:13.116689672Z TRACE quiche_apps::client] got 1332 bytes from 193.167.100.100:443 to 0.0.0.0:58177 [2025-04-30T19:45:13.116727583Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx pkt Handshake version=1 dcid=e8f726c17b9180e143e5188370d5f67793650b5f scid=9ea391ba4714b03ce600 len=22 pn=3 [2025-04-30T19:45:13.116743032Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm ACK delay=0 blocks=[3..3] ecn_counts=None [2025-04-30T19:45:13.116750486Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f packet newly acked 3 [2025-04-30T19:45:13.116783038Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx pkt Short dcid=e8f726c17b9180e143e5188370d5f67793650b5f key_phase=false len=1250 pn=0 [2025-04-30T19:45:13.116790201Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm ACK delay=0 blocks=[4..4] ecn_counts=None [2025-04-30T19:45:13.116793888Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f packet newly acked 4 [2025-04-30T19:45:13.116798747Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm HANDSHAKE_DONE [2025-04-30T19:45:13.116803967Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f dropped epoch 1 state [2025-04-30T19:45:13.116809237Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[bc, fb, 3a, ff, c0, 8d, 75, 72, 16, 01] reset_token=[59, 1b, 93, 31, f7, fe, f8, 9b, 8c, 61, 8d, e8, ff, f4, a0, ff] [2025-04-30T19:45:13.116818014Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[b2, 56, 67, c6, 90, 5b, e5, 7f, f5, d0] reset_token=[16, 3e, 03, 7b, 1d, 84, a2, fc, 62, 7b, 0d, e5, a9, 89, a1, 2d] [2025-04-30T19:45:13.116824155Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[ac, e3, 4a, ec, 11, aa, 4e, cc, 2e, fc] reset_token=[51, 60, 6f, 63, 05, e2, b9, 64, 0c, 41, 23, 39, 67, 06, 83, 3d] [2025-04-30T19:45:13.116829686Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[4a, 51, ff, bf, 7e, 65, 89, 22, 92, 3d] reset_token=[5b, da, 22, 1e, 98, 6b, 31, e0, df, 49, 5c, c4, ca, a7, 36, a5] [2025-04-30T19:45:13.116835777Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[11, eb, 6e, 7b, 59, 30, 8c, 39, c3, b5] reset_token=[94, 14, 98, b3, 22, 5c, cf, 74, 03, bf, f0, 11, 5d, 07, 0a, 6e] [2025-04-30T19:45:13.116841368Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[ef, 7f, 2b, da, a3, e7, 47, 6d, 52, 89] reset_token=[bd, a9, 8c, e2, ee, b5, 66, 81, ee, be, 17, e9, e8, ea, 99, 24] [2025-04-30T19:45:13.116847108Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[03, d1, 3b, 71, ae, bb, 28, d3, 69, a0] reset_token=[99, 5e, d4, 1d, e4, 5b, 72, 6a, 2e, cf, df, 79, ad, 9b, 87, 58] [2025-04-30T19:45:13.116871414Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm PADDING len=1017 [2025-04-30T19:45:13.116911129Z TRACE quiche_apps::client] 0.0.0.0:58177: processed 1332 bytes [2025-04-30T19:45:13.116917180Z TRACE quiche_apps::client] 0.0.0.0:58177: recv() would block [2025-04-30T19:45:13.116920437Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:13.116931838Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T19:45:13.116937919Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx pkt Short dcid=9ea391ba4714b03ce600 key_phase=false len=5 pn=5 [2025-04-30T19:45:13.116941016Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm ACK delay=18 blocks=[0..0] ecn_counts=None [2025-04-30T19:45:13.116950153Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=none latest_rtt=1.494859265s srtt=1.508305662s min_rtt=1.494859265s rttvar=430.18479ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 168, tv_nsec: 749714354 }, first_sent_time: Instant { tv_sec: 168, tv_nsec: 749714354 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { delivery_rate: 851, is_app_limited: true, interval: 1.511616891s, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 167, tv_nsec: 245041473 }), send_elapsed: 1.511616891s, ack_elapsed: 1.504468035s, rtt: 1.503971329s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11188, last_update: Instant { tv_sec: 168, tv_nsec: 749714354 }, next_time: Instant { tv_sec: 168, tv_nsec: 749714354 }, 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-30T19:45:13.117016418Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:58177 to 193.167.100.100:443 [2025-04-30T19:45:13.117022349Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:13.118785050Z TRACE quiche_apps::client] got 1332 bytes from 193.167.100.100:443 to 0.0.0.0:58177 [2025-04-30T19:45:13.118800018Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx pkt Short dcid=e8f726c17b9180e143e5188370d5f67793650b5f key_phase=false len=1311 pn=1 [2025-04-30T19:45:13.118808805Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm PING mtu_probe=None [2025-04-30T19:45:13.118812912Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm STREAM id=0 off=0 len=1024 fin=true [2025-04-30T19:45:13.118818122Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f rx frm CRYPTO off=0 len=261 [2025-04-30T19:45:13.118832920Z TRACE quiche_apps::client] 0.0.0.0:58177: processed 1332 bytes [2025-04-30T19:45:13.118837979Z TRACE quiche_apps::client] 0.0.0.0:58177: recv() would block [2025-04-30T19:45:13.118841076Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:13.118848029Z TRACE quiche_apps::common] received 1024 bytes [2025-04-30T19:45:13.118851385Z TRACE quiche_apps::common] stream 0 has 1024 bytes (fin? true) [2025-04-30T19:45:13.118854641Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T19:45:13.118857817Z INFO quiche_apps::common] 1/1 response(s) received in 3.017561178s, closing... [2025-04-30T19:45:13.118866553Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1322 [2025-04-30T19:45:13.118871122Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx pkt Short dcid=9ea391ba4714b03ce600 key_phase=false len=10 pn=6 [2025-04-30T19:45:13.118881251Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T19:45:13.118890539Z TRACE quiche::recovery::congestion::recovery] e8f726c17b9180e143e5188370d5f67793650b5f timer=3.249017s latest_rtt=1.494859265s srtt=1.508305662s min_rtt=1.494859265s rttvar=430.18479ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=38 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1620, delivered_time: Instant { tv_sec: 168, tv_nsec: 749714354 }, first_sent_time: Instant { tv_sec: 168, tv_nsec: 749714354 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { delivery_rate: 851, is_app_limited: true, interval: 1.511616891s, delivered: 1287, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 167, tv_nsec: 245041473 }), send_elapsed: 1.511616891s, ack_elapsed: 1.504468035s, rtt: 1.503971329s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11188, last_update: Instant { tv_sec: 168, tv_nsec: 751651274 }, next_time: Instant { tv_sec: 168, tv_nsec: 749714354 }, max_datagram_size: 1350, last_packet_size: None, iv: 3.396496ms, 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-30T19:45:13.118939110Z TRACE quiche_apps::client] written 38 bytes from 0.0.0.0:58177 to 193.167.100.100:443 [2025-04-30T19:45:13.118944019Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:13.194415551Z TRACE quiche_apps::client] got 147 bytes from 193.167.100.100:443 to 0.0.0.0:58177 [2025-04-30T19:45:13.194446730Z TRACE quiche_apps::client] 0.0.0.0:58177: processed 147 bytes [2025-04-30T19:45:13.194452691Z TRACE quiche_apps::client] 0.0.0.0:58177: recv() would block [2025-04-30T19:45:13.194456187Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:13.194463621Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:14.619607727Z TRACE quiche_apps::client] got 47 bytes from 193.167.100.100:443 to 0.0.0.0:58177 [2025-04-30T19:45:14.619636320Z TRACE quiche_apps::client] 0.0.0.0:58177: processed 47 bytes [2025-04-30T19:45:14.619644125Z TRACE quiche_apps::client] 0.0.0.0:58177: recv() would block [2025-04-30T19:45:14.619649014Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:14.619658222Z TRACE quiche_apps::client] 0.0.0.0:58177 -> 193.167.100.100:443: done writing [2025-04-30T19:45:22.812236358Z TRACE quiche_apps::client] timed out [2025-04-30T19:45:22.812280060Z TRACE quiche] e8f726c17b9180e143e5188370d5f67793650b5f draining timeout expired [2025-04-30T19:45:22.812331437Z TRACE quiche_apps::client] done reading [2025-04-30T19:45:22.812337718Z INFO quiche_apps::client] connection closed, recv=5 sent=7 lost=0 retrans=1 sent_bytes=2087 recv_bytes=3612 lost_bytes=0 [local_addr=0.0.0.0:58177 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=5 sent=7 lost=0 retrans=1 rtt=1.508305662s min_rtt=Some(1.494859265s) rttvar=430.18479ms cwnd=13500 sent_bytes=2087 recv_bytes=3612 lost_bytes=0 stream_retrans_bytes=266 pmtu=1350 delivery_rate=851]