[2025-04-30T08:43:09.718030314Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T08:43:09.718334563Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:37653 with scid 613ae902814d4b2470ffa4b7b007d9e1ba0e62af [2025-04-30T08:43:09.718375710Z TRACE quiche::tls] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af write message lvl=Initial len=266 [2025-04-30T08:43:09.718392231Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Initial version=1 dcid=336882302362d77d18d76f7dea53308d scid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af len=270 pn=0 [2025-04-30T08:43:09.718395387Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm CRYPTO off=0 len=266 [2025-04-30T08:43:09.718409283Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=998.932394ms 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: 321, tv_nsec: 299910465 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 299910465 }, 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: 321, tv_nsec: 299910465 }, next_time: Instant { tv_sec: 321, tv_nsec: 299910465 }, 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-30T08:43:09.718499842Z TRACE quiche_apps::client] written 1200 [2025-04-30T08:43:09.755265078Z TRACE quiche_apps::client] got 153 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.755300554Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Retry version=1 dcid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af scid=caacee9d token=76efa5b65ef2146709c74bd9460a043f78fb2d3c37bc358033df7e165ea13ff64da5df8aa092da82dcf81abeb7d669354d9a8195df2257ec7b29ed25d785f395c89e6f628a7b33b7b1fbb508e39ee56d723eb84fb7db0d070ea124d17d3115418099385f30375bb46aba [2025-04-30T08:43:09.755336932Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af dropped epoch 0 state [2025-04-30T08:43:09.755350638Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 153 bytes [2025-04-30T08:43:09.755355747Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.755359364Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.755409538Z TRACE quiche::tls] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af write message lvl=Initial len=266 [2025-04-30T08:43:09.755431649Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Initial version=1 dcid=caacee9d scid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af token=76efa5b65ef2146709c74bd9460a043f78fb2d3c37bc358033df7e165ea13ff64da5df8aa092da82dcf81abeb7d669354d9a8195df2257ec7b29ed25d785f395c89e6f628a7b33b7b1fbb508e39ee56d723eb84fb7db0d070ea124d17d3115418099385f30375bb46aba len=270 pn=1 [2025-04-30T08:43:09.755466424Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm CRYPTO off=0 len=266 [2025-04-30T08:43:09.755483326Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=998.885415ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=428 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 321, tv_nsec: 336937700 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 336937700 }, 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: 321, tv_nsec: 336937700 }, next_time: Instant { tv_sec: 321, tv_nsec: 336937700 }, 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-30T08:43:09.755558857Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.755565850Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.789323083Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.789353910Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Initial version=1 dcid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af scid=81c13461 token= len=310 pn=0 [2025-04-30T08:43:09.789370842Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm ACK delay=0 blocks=[1..1] ecn_counts=None [2025-04-30T08:43:09.789377995Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af packet newly acked 1 [2025-04-30T08:43:09.789385540Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm PADDING len=193 [2025-04-30T08:43:09.789389838Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm CRYPTO off=0 len=90 [2025-04-30T08:43:09.789533145Z TRACE quiche::tls] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af set write secret lvl=Handshake [2025-04-30T08:43:09.789547973Z TRACE quiche::tls] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af set read secret lvl=Handshake [2025-04-30T08:43:09.789586425Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Handshake version=1 dcid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af scid=81c13461 len=744 pn=0 [2025-04-30T08:43:09.789593649Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm CRYPTO off=0 len=722 [2025-04-30T08:43:09.789831223Z TRACE quiche::tls] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af write message lvl=Handshake len=36 [2025-04-30T08:43:09.789836062Z TRACE quiche::tls] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af set write secret lvl=OneRTT [2025-04-30T08:43:09.789844177Z TRACE quiche::tls] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af set read secret lvl=OneRTT [2025-04-30T08:43:09.789863263Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af 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(336882302362d77d18d76f7dea53308d), max_idle_timeout: 30000, stateless_reset_token: Some(72997760461244203248818153464814190617), max_udp_payload_size: 1452, initial_max_data: 786432, initial_max_stream_data_bidi_local: 524288, initial_max_stream_data_bidi_remote: 524288, initial_max_stream_data_uni: 524288, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 3, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(81c13461), retry_source_connection_id: Some(caacee9d), max_datagram_frame_size: None, unknown_params: None } [2025-04-30T08:43:09.789889582Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af key_phase=false len=138 pn=0 [2025-04-30T08:43:09.789902957Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[2b, 63, 7a, 69] reset_token=[8b, 56, e6, f6, 67, 7e, a7, b6, 2f, a0, 55, af, 05, 5c, 95, 01] [2025-04-30T08:43:09.789910912Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[22, 3f, 1e, c3] reset_token=[57, 99, 55, 6e, 73, 56, 41, 0c, 51, e0, 52, b7, 08, 76, c7, 15] [2025-04-30T08:43:09.789922674Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[c0, 18, 2a, 9b] reset_token=[12, 5d, f0, bf, 8f, bf, 16, e5, 7e, 08, 4b, 46, 4e, 8d, 60, 93] [2025-04-30T08:43:09.789928314Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[5d, e0, 23, 3b] reset_token=[5b, d4, 08, 54, 0e, fb, 62, 71, 8e, 24, 78, 20, 0f, ff, 76, fe] [2025-04-30T08:43:09.789934426Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[59, ae, 57, 61] reset_token=[ed, 7f, 73, cc, d0, 4f, 70, e8, 0f, a2, f9, 50, 19, d5, 47, f0] [2025-04-30T08:43:09.789944044Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.789948893Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.789951768Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.789959983Z DEBUG quiche_apps::common] sending HTTP request "GET /ctsvnbbnlr\r\n" [2025-04-30T08:43:09.790030425Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Initial version=1 dcid=81c13461 scid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af token=76efa5b65ef2146709c74bd9460a043f78fb2d3c37bc358033df7e165ea13ff64da5df8aa092da82dcf81abeb7d669354d9a8195df2257ec7b29ed25d785f395c89e6f628a7b33b7b1fbb508e39ee56d723eb84fb7db0d070ea124d17d3115418099385f30375bb46aba len=6 pn=2 [2025-04-30T08:43:09.790034563Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=84 blocks=[0..0] ecn_counts=None [2025-04-30T08:43:09.790043800Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=101.239257ms latest_rtt=33.978517ms srtt=33.978517ms min_rtt=33.978517ms rttvar=16.989258ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 428, delivered_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12596, is_app_limited: true, interval: 33.978517ms, delivered: 428, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 336937700 }), send_elapsed: 0ns, ack_elapsed: 33.978517ms, rtt: 33.978517ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 496637, last_update: Instant { tv_sec: 321, tv_nsec: 371429076 }, next_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, 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-30T08:43:09.790065460Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Handshake version=1 dcid=81c13461 scid=613ae902814d4b2470ffa4b7b007d9e1ba0e62af len=45 pn=3 [2025-04-30T08:43:09.790068206Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=59 blocks=[0..0] ecn_counts=None [2025-04-30T08:43:09.790070841Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm CRYPTO off=0 len=36 [2025-04-30T08:43:09.790076772Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=101.876218ms latest_rtt=33.978517ms srtt=33.978517ms min_rtt=33.978517ms rttvar=16.989258ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=95 app_limited=true congestion_recovery_start_time=None Rate { delivered: 428, delivered_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12596, is_app_limited: true, interval: 33.978517ms, delivered: 428, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 336937700 }), send_elapsed: 0ns, ack_elapsed: 33.978517ms, rtt: 33.978517ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 496637, last_update: Instant { tv_sec: 321, tv_nsec: 371585819 }, next_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, max_datagram_size: 1350, last_packet_size: None, iv: 191.287µ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-30T08:43:09.790092962Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af dropped epoch 0 state [2025-04-30T08:43:09.790097400Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13405 out_len=1091 left=1064 [2025-04-30T08:43:09.790107539Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=1069 pn=4 [2025-04-30T08:43:09.790110254Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=25 blocks=[0..0] ecn_counts=None [2025-04-30T08:43:09.790112769Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[a3, 76, b3, 6f, d4, 78, 13, 0e, 91, 55, db, 1a, 61, a0, 11, fb, 2b, f8, 5a, fb] reset_token=[f0, e9, 8b, 67, ad, 9b, 0a, 00, 92, 41, 1d, df, f7, b1, 8f, 30] [2025-04-30T08:43:09.790118610Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[3d, 1d, b3, 33, 7f, 56, 6f, 61, 35, 53, f8, 23, 82, b8, 8e, a2, 5b, 30, 50, 76] reset_token=[93, 3c, 42, ba, 6e, 8e, 20, 51, 71, f4, cd, f3, 15, 52, b0, 27] [2025-04-30T08:43:09.790123840Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[a1, 78, 49, 51, 3e, 14, a5, 54, a9, 75, 1b, e8, cf, 0c, c5, 96, 52, 4c, 5b, 98] reset_token=[a9, 3c, ef, 04, d6, 94, 35, 79, 24, f4, 5d, 8b, f9, 66, 24, 39] [2025-04-30T08:43:09.790129099Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T08:43:09.790131764Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm PADDING len=922 [2025-04-30T08:43:09.790139008Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=101.814022ms latest_rtt=33.978517ms srtt=33.978517ms min_rtt=33.978517ms rttvar=16.989258ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1186 app_limited=true congestion_recovery_start_time=None Rate { delivered: 428, delivered_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 371429116 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12596, is_app_limited: true, interval: 33.978517ms, delivered: 428, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 336937700 }), send_elapsed: 0ns, ack_elapsed: 33.978517ms, rtt: 33.978517ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1091, rate: 496637, last_update: Instant { tv_sec: 321, tv_nsec: 371585819 }, next_time: Instant { tv_sec: 321, tv_nsec: 371777106 }, max_datagram_size: 1350, last_packet_size: Some(1091), 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-30T08:43:09.790190955Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.790196616Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.822564862Z TRACE quiche_apps::client] got 278 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.822597944Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=257 pn=1 [2025-04-30T08:43:09.822609435Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af path ID 0 now see SCID with seq num 1 [2025-04-30T08:43:09.822621518Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm ACK delay=54 blocks=[4..4] ecn_counts=None [2025-04-30T08:43:09.822630094Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af packet newly acked 4 [2025-04-30T08:43:09.822636646Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm HANDSHAKE_DONE [2025-04-30T08:43:09.822642968Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af dropped epoch 1 state [2025-04-30T08:43:09.822646945Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm CRYPTO off=0 len=138 [2025-04-30T08:43:09.822673215Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T08:43:09.822682592Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm NEW_TOKEN len=86 [2025-04-30T08:43:09.822704924Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 278 bytes [2025-04-30T08:43:09.822710184Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.822713550Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.822717658Z INFO quiche_apps::client] Retiring source CID 613ae902814d4b2470ffa4b7b007d9e1ba0e62af [2025-04-30T08:43:09.822732035Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1323 [2025-04-30T08:43:09.822738988Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=45 pn=5 [2025-04-30T08:43:09.822742424Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=17 blocks=[1..1] ecn_counts=None [2025-04-30T08:43:09.822746261Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=1 conn_id=[95, 9f, 5e, 3a, 98, a1, ec, 18, 95, d6, 4d, e5, 75, 2f, e8, 7b, 53, 42, aa, 7e] reset_token=[a7, 77, ce, fa, c7, 67, 60, 88, 71, 49, 17, 42, d0, 87, 17, 8b] [2025-04-30T08:43:09.822760448Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=112.306811ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 67, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 404294942 }, next_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, max_datagram_size: 1350, last_packet_size: Some(67), 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-30T08:43:09.822816633Z TRACE quiche_apps::client] written 67 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.822822644Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.823882606Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.823893326Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=2 [2025-04-30T08:43:09.823905779Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=0 len=1239 fin=false [2025-04-30T08:43:09.823932839Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.823936837Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.823939261Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.823944130Z TRACE quiche_apps::common] received 1239 bytes [2025-04-30T08:43:09.823946815Z TRACE quiche_apps::common] stream 0 has 1239 bytes (fin? false) [2025-04-30T08:43:09.823954029Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.823957405Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=6 [2025-04-30T08:43:09.823959890Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=7 blocks=[1..2] ecn_counts=None [2025-04-30T08:43:09.823966863Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=111.100686ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, max_datagram_size: 1350, last_packet_size: None, iv: 134.116µ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-30T08:43:09.824003161Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.824007118Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.824928461Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.824938960Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=3 [2025-04-30T08:43:09.824945873Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=1239 len=1237 fin=false [2025-04-30T08:43:09.824953467Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.824956984Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.824959378Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.824963616Z TRACE quiche_apps::common] received 1237 bytes [2025-04-30T08:43:09.824965920Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false) [2025-04-30T08:43:09.824972392Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.824975578Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=7 [2025-04-30T08:43:09.824978033Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=4 blocks=[1..3] ecn_counts=None [2025-04-30T08:43:09.824984525Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=110.083114ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, 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-30T08:43:09.825023779Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.825028077Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.825978253Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.825988552Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=4 [2025-04-30T08:43:09.825995224Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=2476 len=1237 fin=false [2025-04-30T08:43:09.826002578Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.826006145Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.826008540Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.826012637Z TRACE quiche_apps::common] received 1237 bytes [2025-04-30T08:43:09.826014881Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false) [2025-04-30T08:43:09.826021133Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.826024299Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=8 [2025-04-30T08:43:09.826026683Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=4 blocks=[1..4] ecn_counts=None [2025-04-30T08:43:09.826033025Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=109.034594ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, 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-30T08:43:09.826072599Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.826076897Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.827025570Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.827035960Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=5 [2025-04-30T08:43:09.827042893Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=3713 len=1237 fin=false [2025-04-30T08:43:09.827050197Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.827053763Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.827056128Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.827060175Z TRACE quiche_apps::common] received 1237 bytes [2025-04-30T08:43:09.827062410Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false) [2025-04-30T08:43:09.827068811Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.827072068Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=9 [2025-04-30T08:43:09.827074492Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=4 blocks=[1..5] ecn_counts=None [2025-04-30T08:43:09.827081515Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=107.986074ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, 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-30T08:43:09.827114757Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.827118635Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.828077547Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.828088087Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=6 [2025-04-30T08:43:09.828094619Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=4950 len=1237 fin=false [2025-04-30T08:43:09.828101822Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.828105299Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.828107643Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.828111791Z TRACE quiche_apps::common] received 1237 bytes [2025-04-30T08:43:09.828113995Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false) [2025-04-30T08:43:09.828120327Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.828128663Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=10 [2025-04-30T08:43:09.828131187Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=4 blocks=[1..6] ecn_counts=None [2025-04-30T08:43:09.828137619Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=106.93002ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 10, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, 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-30T08:43:09.828172885Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.828176883Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.829120156Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.829130545Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=7 [2025-04-30T08:43:09.829137338Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=6187 len=1237 fin=false [2025-04-30T08:43:09.829144592Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.829148088Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.829150503Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.829154450Z TRACE quiche_apps::common] received 1237 bytes [2025-04-30T08:43:09.829156704Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false) [2025-04-30T08:43:09.829163066Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.829166222Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=11 [2025-04-30T08:43:09.829168627Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=4 blocks=[1..7] ecn_counts=None [2025-04-30T08:43:09.829174778Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=105.892851ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 11, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, 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-30T08:43:09.829213460Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.829217588Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.830167484Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.830177623Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=8 [2025-04-30T08:43:09.830184666Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=7424 len=1237 fin=false [2025-04-30T08:43:09.830191779Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.830195276Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.830197660Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.830201638Z TRACE quiche_apps::common] received 1237 bytes [2025-04-30T08:43:09.830203842Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false) [2025-04-30T08:43:09.830226554Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.830230121Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=12 [2025-04-30T08:43:09.830232556Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=6 blocks=[1..8] ecn_counts=None [2025-04-30T08:43:09.830238977Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=104.828622ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 12, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, 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-30T08:43:09.830272720Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.830276558Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.831214822Z TRACE quiche_apps::client] got 1280 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.831224780Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=1259 pn=9 [2025-04-30T08:43:09.831231453Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=8661 len=1237 fin=false [2025-04-30T08:43:09.831238666Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 1280 bytes [2025-04-30T08:43:09.831247382Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.831249867Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.831253975Z TRACE quiche_apps::common] received 1237 bytes [2025-04-30T08:43:09.831256229Z TRACE quiche_apps::common] stream 0 has 1237 bytes (fin? false) [2025-04-30T08:43:09.831262581Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1323 [2025-04-30T08:43:09.831265737Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=5 pn=13 [2025-04-30T08:43:09.831268111Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm ACK delay=4 blocks=[1..9] ecn_counts=None [2025-04-30T08:43:09.831274834Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=103.792805ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=67 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 4, last_sent_packet: 13, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 405518960 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, 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-30T08:43:09.831308006Z TRACE quiche_apps::client] written 27 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.831311813Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:09.831546141Z TRACE quiche_apps::client] got 385 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.831558334Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=364 pn=10 [2025-04-30T08:43:09.831567952Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=9898 len=342 fin=false [2025-04-30T08:43:09.831576437Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 385 bytes [2025-04-30T08:43:09.831581437Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:37653 [2025-04-30T08:43:09.831584483Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx pkt Short dcid=a376b36fd478130e9155db1a61a011fb2bf85afb key_phase=false len=22 pn=11 [2025-04-30T08:43:09.831588380Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af rx frm STREAM id=0 off=10240 len=0 fin=true [2025-04-30T08:43:09.831593289Z TRACE quiche_apps::client] 0.0.0.0:37653: processed 43 bytes [2025-04-30T08:43:09.831596615Z TRACE quiche_apps::client] 0.0.0.0:37653: recv() would block [2025-04-30T08:43:09.831599030Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:09.831605221Z TRACE quiche_apps::common] received 342 bytes [2025-04-30T08:43:09.831607526Z TRACE quiche_apps::common] stream 0 has 342 bytes (fin? true) [2025-04-30T08:43:09.831609820Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T08:43:09.831612244Z INFO quiche_apps::common] 1/1 response(s) received in 113.102764ms, closing... [2025-04-30T08:43:09.831618837Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13433 out_len=1350 left=1328 [2025-04-30T08:43:09.831627854Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx pkt Short dcid=81c13461 key_phase=false len=10 pn=14 [2025-04-30T08:43:09.831630378Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T08:43:09.831637542Z TRACE quiche::recovery::congestion::recovery] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af timer=112.319575ms latest_rtt=32.384427ms srtt=33.779255ms min_rtt=32.384427ms rttvar=13.140465ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=99 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1519, delivered_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, first_sent_time: Instant { tv_sec: 321, tv_nsec: 404294942 }, end_of_app_limited: 13, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33330, is_app_limited: true, interval: 32.732417ms, delivered: 1091, prior_delivered: 428, prior_time: Some(Instant { tv_sec: 321, tv_nsec: 371429116 }), send_elapsed: 347.99µs, ack_elapsed: 32.732417ms, rtt: 32.384427ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 499566, last_update: Instant { tv_sec: 321, tv_nsec: 413184460 }, next_time: Instant { tv_sec: 321, tv_nsec: 406671751 }, max_datagram_size: 1350, last_packet_size: None, iv: 64.056µ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-30T08:43:09.831671626Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:37653 to 193.167.100.100:443 [2025-04-30T08:43:09.831675142Z TRACE quiche_apps::client] 0.0.0.0:37653 -> 193.167.100.100:443: done writing [2025-04-30T08:43:10.091011673Z TRACE quiche_apps::client] timed out [2025-04-30T08:43:10.091045807Z TRACE quiche] 613ae902814d4b2470ffa4b7b007d9e1ba0e62af draining timeout expired [2025-04-30T08:43:10.091094688Z TRACE quiche_apps::client] done reading [2025-04-30T08:43:10.091099538Z INFO quiche_apps::client] connection closed, recv=14 sent=15 lost=0 retrans=0 sent_bytes=2426 recv_bytes=12226 lost_bytes=0 [local_addr=0.0.0.0:37653 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=14 sent=15 lost=0 retrans=0 rtt=33.779255ms min_rtt=Some(32.384427ms) rttvar=13.140465ms cwnd=13500 sent_bytes=2426 recv_bytes=12226 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=33330]