[2025-04-30T21:41:26.803564761Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T21:41:26.803857815Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:51727 with scid dbe86a0cced34a59865c6e97611b38c289adcd8e [2025-04-30T21:41:26.803898070Z TRACE quiche::tls] dbe86a0cced34a59865c6e97611b38c289adcd8e write message lvl=Initial len=266 [2025-04-30T21:41:26.803914610Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx pkt Initial version=1 dcid=b5e339fd5ff797b789cd24849e6c0628 scid=dbe86a0cced34a59865c6e97611b38c289adcd8e len=270 pn=0 [2025-04-30T21:41:26.803917867Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm CRYPTO off=0 len=266 [2025-04-30T21:41:26.803931542Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=998.933126ms 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: 217, tv_nsec: 843548057 }, first_sent_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, 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: 217, tv_nsec: 843548057 }, next_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, 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:41:26.804011040Z TRACE quiche_apps::client] written 1200 [2025-04-30T21:41:27.803370248Z TRACE quiche_apps::client] timed out [2025-04-30T21:41:27.803402669Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e loss detection timeout expired [2025-04-30T21:41:27.803409431Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=998.454765ms 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: 217, tv_nsec: 843548057 }, first_sent_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, 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: 217, tv_nsec: 843548057 }, next_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, 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:41:27.803429318Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:27.803466387Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx pkt Initial version=1 dcid=b5e339fd5ff797b789cd24849e6c0628 scid=dbe86a0cced34a59865c6e97611b38c289adcd8e len=270 pn=1 [2025-04-30T21:41:27.803470054Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm CRYPTO off=0 len=266 [2025-04-30T21:41:27.803485573Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=1.997960056s 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: 217, tv_nsec: 843548057 }, first_sent_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, 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: 218, tv_nsec: 843128627 }, next_time: Instant { tv_sec: 218, tv_nsec: 843128627 }, 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:41:27.803576321Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:51727 to 193.167.100.100:443 [2025-04-30T21:41:27.803583194Z TRACE quiche_apps::client] 0.0.0.0:51727 -> 193.167.100.100:443: done writing [2025-04-30T21:41:28.314057072Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:28.314094361Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx pkt Initial version=1 dcid=dbe86a0cced34a59865c6e97611b38c289adcd8e scid=7265276839ec1bb54d38bf7d6c9e6737 token= len=117 pn=0 [2025-04-30T21:41:28.314110762Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm ACK delay=1617 blocks=[0..0] ecn_counts=None [2025-04-30T21:41:28.314118476Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e packet newly acked 0 [2025-04-30T21:41:28.314125359Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm CRYPTO off=0 len=90 [2025-04-30T21:41:28.314248447Z TRACE quiche::tls] dbe86a0cced34a59865c6e97611b38c289adcd8e set write secret lvl=Handshake [2025-04-30T21:41:28.314260640Z TRACE quiche::tls] dbe86a0cced34a59865c6e97611b38c289adcd8e set read secret lvl=Handshake [2025-04-30T21:41:28.314300815Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx pkt Handshake version=1 dcid=dbe86a0cced34a59865c6e97611b38c289adcd8e scid=7265276839ec1bb54d38bf7d6c9e6737 len=1024 pn=0 [2025-04-30T21:41:28.314307637Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm CRYPTO off=0 len=691 [2025-04-30T21:41:28.314578691Z TRACE quiche::tls] dbe86a0cced34a59865c6e97611b38c289adcd8e write message lvl=Handshake len=36 [2025-04-30T21:41:28.314584051Z TRACE quiche::tls] dbe86a0cced34a59865c6e97611b38c289adcd8e set write secret lvl=OneRTT [2025-04-30T21:41:28.314592787Z TRACE quiche::tls] dbe86a0cced34a59865c6e97611b38c289adcd8e set read secret lvl=OneRTT [2025-04-30T21:41:28.314611662Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e 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(b5e339fd5ff797b789cd24849e6c0628), 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(7265276839ec1bb54d38bf7d6c9e6737), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T21:41:28.314625237Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm PADDING len=312 [2025-04-30T21:41:28.314641768Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 1232 bytes [2025-04-30T21:41:28.314647709Z TRACE quiche_apps::client] 0.0.0.0:51727: recv() would block [2025-04-30T21:41:28.314650995Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:28.314667806Z DEBUG quiche_apps::common] sending HTTP request "GET /kfeiqxwqsu\r\n" [2025-04-30T21:41:28.314747565Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx pkt Initial version=1 dcid=7265276839ec1bb54d38bf7d6c9e6737 scid=dbe86a0cced34a59865c6e97611b38c289adcd8e len=6 pn=2 [2025-04-30T21:41:28.314752283Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm ACK delay=82 blocks=[0..0] ecn_counts=None [2025-04-30T21:41:28.314763504Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=4.019351219s latest_rtt=1.510223162s srtt=1.510223162s min_rtt=1.510223162s rttvar=755.111581ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 219, tv_nsec: 353771219 }, first_sent_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510223162s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 217, tv_nsec: 843548057 }), send_elapsed: 0ns, ack_elapsed: 1.510223162s, rtt: 1.510223162s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11173, last_update: Instant { tv_sec: 219, tv_nsec: 354291896 }, next_time: Instant { tv_sec: 219, tv_nsec: 354291926 }, 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:41:28.314788390Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx pkt Handshake version=1 dcid=7265276839ec1bb54d38bf7d6c9e6737 scid=dbe86a0cced34a59865c6e97611b38c289adcd8e len=45 pn=3 [2025-04-30T21:41:28.314791797Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm ACK delay=60 blocks=[0..0] ecn_counts=None [2025-04-30T21:41:28.314794993Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm CRYPTO off=0 len=36 [2025-04-30T21:41:28.314802226Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=4.019312828s latest_rtt=1.510223162s srtt=1.510223162s min_rtt=1.510223162s rttvar=755.111581ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=440 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 219, tv_nsec: 353771219 }, first_sent_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510223162s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 217, tv_nsec: 843548057 }), send_elapsed: 0ns, ack_elapsed: 1.510223162s, rtt: 1.510223162s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11173, last_update: Instant { tv_sec: 219, tv_nsec: 354420444 }, next_time: Instant { tv_sec: 219, tv_nsec: 354291926 }, max_datagram_size: 1350, last_packet_size: None, iv: 9.576658ms, 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:41:28.314815521Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e dropped epoch 0 state [2025-04-30T21:41:28.314821071Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13393 out_len=1174 left=1140 [2025-04-30T21:41:28.314834286Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx pkt Short dcid=7265276839ec1bb54d38bf7d6c9e6737 key_phase=false len=1140 pn=4 [2025-04-30T21:41:28.314837441Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[d9, a7, 53, 35, 6e, d5, 63, cb, 18, 2c, 93, d5, cd, 9e, 5f, 8f, 73, 63, da, f6] reset_token=[ce, 95, de, 4e, b8, a5, 9b, 29, 27, 55, b6, 45, 75, ce, 86, bc] [2025-04-30T21:41:28.314850225Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[5b, 6c, e4, 13, cc, 42, 6c, d6, 92, c3, 30, ac, 0f, a4, f9, 91, 90, ec, 0e, bf] reset_token=[ca, 3b, f5, 9a, cb, 13, 73, 8d, 57, 2f, 27, 6d, 5e, f4, 72, 22] [2025-04-30T21:41:28.314856497Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T21:41:28.314859693Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm PADDING len=1038 [2025-04-30T21:41:28.314868309Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=4.530538572s latest_rtt=1.510223162s srtt=1.510223162s min_rtt=1.510223162s rttvar=755.111581ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1281 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 219, tv_nsec: 353771219 }, first_sent_time: Instant { tv_sec: 217, tv_nsec: 843548057 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510223162s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 217, tv_nsec: 843548057 }), send_elapsed: 0ns, ack_elapsed: 1.510223162s, rtt: 1.510223162s } } pacer=Pacer { enabled: true, capacity: 13500, used: 1174, rate: 11173, last_update: Instant { tv_sec: 219, tv_nsec: 354420444 }, next_time: Instant { tv_sec: 219, tv_nsec: 363997102 }, max_datagram_size: 1350, last_packet_size: Some(1174), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } [2025-04-30T21:41:28.314929623Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:51727 to 193.167.100.100:443 [2025-04-30T21:41:28.314934792Z TRACE quiche_apps::client] 0.0.0.0:51727 -> 193.167.100.100:443: done writing [2025-04-30T21:41:29.307209746Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:29.307246204Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e dropped invalid packet [2025-04-30T21:41:29.307250862Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 1232 bytes [2025-04-30T21:41:29.307256092Z TRACE quiche_apps::client] 0.0.0.0:51727: recv() would block [2025-04-30T21:41:29.307259338Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:29.307268535Z TRACE quiche_apps::client] 0.0.0.0:51727 -> 193.167.100.100:443: done writing [2025-04-30T21:41:29.314251544Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:29.314267734Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e dropped invalid packet [2025-04-30T21:41:29.314272193Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 1200 bytes [2025-04-30T21:41:29.314277172Z TRACE quiche_apps::client] 0.0.0.0:51727: recv() would block [2025-04-30T21:41:29.314280428Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:29.314286749Z TRACE quiche_apps::client] 0.0.0.0:51727 -> 193.167.100.100:443: done writing [2025-04-30T21:41:29.315201208Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:29.315213701Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e dropped invalid packet [2025-04-30T21:41:29.315217007Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 1200 bytes [2025-04-30T21:41:29.315220744Z TRACE quiche_apps::client] 0.0.0.0:51727: recv() would block [2025-04-30T21:41:29.315223299Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:29.315227978Z TRACE quiche_apps::client] 0.0.0.0:51727 -> 193.167.100.100:443: done writing [2025-04-30T21:41:29.820197517Z TRACE quiche_apps::client] got 1452 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:29.820236950Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx pkt Short dcid=d9a753356ed563cb182c93d5cd9e5f8f7363daf6 key_phase=false len=1431 pn=0 [2025-04-30T21:41:29.820249683Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e path ID 0 now see SCID with seq num 1 [2025-04-30T21:41:29.820256606Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm PING mtu_probe=None [2025-04-30T21:41:29.820266976Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm PADDING len=1413 [2025-04-30T21:41:29.820282495Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 1452 bytes [2025-04-30T21:41:29.820288786Z TRACE quiche_apps::client] got 155 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:29.820292653Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx pkt Short dcid=d9a753356ed563cb182c93d5cd9e5f8f7363daf6 key_phase=false len=134 pn=1 [2025-04-30T21:41:29.820298173Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm ACK delay=187 blocks=[4..4] ecn_counts=None [2025-04-30T21:41:29.820304145Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e packet newly acked 4 [2025-04-30T21:41:29.820310336Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm HANDSHAKE_DONE [2025-04-30T21:41:29.820317008Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e dropped epoch 1 state [2025-04-30T21:41:29.820354588Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=1 conn_id=[29, 85, 90, 5b, 07, 12, 86, 5a, db, c0, 91, c0, d9, 74, 1c, f0] reset_token=[e3, 98, 7d, b3, 17, e3, 58, 49, 9c, ed, e9, b7, d7, fe, 12, 8f] [2025-04-30T21:41:29.820364156Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e path ID 0 changed DCID: old seq num 0 new seq num 1 [2025-04-30T21:41:29.820368875Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=1 conn_id=[32, 14, 46, e3, 73, ff, 90, fb, fc, 76, 28, 6f, 0f, 32, 07, 81] reset_token=[65, ad, eb, 4c, 84, 45, 17, d6, 5c, 82, 99, fb, af, 0c, 1d, 3a] [2025-04-30T21:41:29.820376519Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[54, 4b, 63, 33, aa, d0, 70, 4e, 34, ee, 1c, 6b, bb, a1, 5f, e4] reset_token=[86, da, f9, 5f, 2f, 53, dd, 4f, 14, af, 02, 36, d4, c4, a2, 87] [2025-04-30T21:41:29.820381378Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T21:41:29.820398750Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 155 bytes [2025-04-30T21:41:29.820404110Z TRACE quiche_apps::client] 0.0.0.0:51727: recv() would block [2025-04-30T21:41:29.820407376Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:29.820411594Z INFO quiche_apps::client] Retiring source CID dbe86a0cced34a59865c6e97611b38c289adcd8e [2025-04-30T21:41:29.820427434Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1311 [2025-04-30T21:41:29.820435629Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx pkt Short dcid=2985905b0712865adbc091c0d9741cf0 key_phase=false len=47 pn=5 [2025-04-30T21:41:29.820439366Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm ACK delay=16 blocks=[0..1] ecn_counts=None [2025-04-30T21:41:29.820443474Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=1 conn_id=[2a, 84, 27, d1, 8c, ae, 58, c4, 7a, cb, a1, 64, 04, 6f, 89, 89, 74, 2d, 63, d8] reset_token=[a3, 2f, de, 53, 3c, d9, f9, 67, 8a, 6f, 20, cb, 42, 38, b0, f4] [2025-04-30T21:41:29.820450256Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm RETIRE_CONNECTION_ID seq_num=0 [2025-04-30T21:41:29.820460295Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=3.812982675s latest_rtt=1.495977769s srtt=1.508442487s min_rtt=1.495977769s rttvar=569.895033ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=81 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 220, tv_nsec: 860103710 }, first_sent_time: Instant { tv_sec: 220, tv_nsec: 860103710 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { delivery_rate: 772, is_app_limited: true, interval: 1.520449045s, delivered: 1174, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 219, tv_nsec: 353771219 }), send_elapsed: 1.520449045s, ack_elapsed: 1.506203652s, rtt: 1.495977769s } } pacer=Pacer { enabled: true, capacity: 13500, used: 81, rate: 11187, last_update: Instant { tv_sec: 220, tv_nsec: 860103710 }, next_time: Instant { tv_sec: 220, tv_nsec: 860103710 }, max_datagram_size: 1350, last_packet_size: Some(81), 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:41:29.820540443Z TRACE quiche_apps::client] written 81 bytes from 0.0.0.0:51727 to 193.167.100.100:443 [2025-04-30T21:41:29.820546705Z TRACE quiche_apps::client] 0.0.0.0:51727 -> 193.167.100.100:443: done writing [2025-04-30T21:41:29.821101255Z TRACE quiche_apps::client] got 1067 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:29.821112506Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx pkt Short dcid=d9a753356ed563cb182c93d5cd9e5f8f7363daf6 key_phase=false len=1046 pn=2 [2025-04-30T21:41:29.821121954Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm HANDSHAKE_DONE [2025-04-30T21:41:29.821127233Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm STREAM id=0 off=0 len=1024 fin=false [2025-04-30T21:41:29.821137332Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 1067 bytes [2025-04-30T21:41:29.821142652Z TRACE quiche_apps::client] got 57 bytes from 193.167.100.100:443 to 0.0.0.0:51727 [2025-04-30T21:41:29.821145888Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx pkt Short dcid=d9a753356ed563cb182c93d5cd9e5f8f7363daf6 key_phase=false len=36 pn=3 [2025-04-30T21:41:29.821149595Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm HANDSHAKE_DONE [2025-04-30T21:41:29.821152210Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm STREAM id=0 off=1024 len=0 fin=true [2025-04-30T21:41:29.821155906Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e rx frm PADDING len=13 [2025-04-30T21:41:29.821160485Z TRACE quiche_apps::client] 0.0.0.0:51727: processed 57 bytes [2025-04-30T21:41:29.821163972Z TRACE quiche_apps::client] 0.0.0.0:51727: recv() would block [2025-04-30T21:41:29.821166346Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:29.821173069Z TRACE quiche_apps::common] received 1024 bytes [2025-04-30T21:41:29.821175814Z TRACE quiche_apps::common] stream 0 has 1024 bytes (fin? true) [2025-04-30T21:41:29.821178488Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T21:41:29.821181053Z INFO quiche_apps::common] 1/1 response(s) received in 3.017166076s, closing... [2025-04-30T21:41:29.821188307Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13419 out_len=1350 left=1316 [2025-04-30T21:41:29.821192094Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx pkt Short dcid=2985905b0712865adbc091c0d9741cf0 key_phase=false len=10 pn=6 [2025-04-30T21:41:29.821194629Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T21:41:29.821226918Z TRACE quiche::recovery::congestion::recovery] dbe86a0cced34a59865c6e97611b38c289adcd8e timer=3.812980671s latest_rtt=1.495977769s srtt=1.508442487s min_rtt=1.495977769s rttvar=569.895033ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=125 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1507, delivered_time: Instant { tv_sec: 220, tv_nsec: 860103710 }, first_sent_time: Instant { tv_sec: 220, tv_nsec: 860103710 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { delivery_rate: 772, is_app_limited: true, interval: 1.520449045s, delivered: 1174, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 219, tv_nsec: 353771219 }), send_elapsed: 1.520449045s, ack_elapsed: 1.506203652s, rtt: 1.495977769s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11187, last_update: Instant { tv_sec: 220, tv_nsec: 860868180 }, next_time: Instant { tv_sec: 220, tv_nsec: 860103710 }, max_datagram_size: 1350, last_packet_size: None, iv: 11.173684ms, 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:41:29.821269167Z TRACE quiche_apps::client] written 44 bytes from 0.0.0.0:51727 to 193.167.100.100:443 [2025-04-30T21:41:29.821273295Z TRACE quiche_apps::client] 0.0.0.0:51727 -> 193.167.100.100:443: done writing [2025-04-30T21:41:41.190382081Z TRACE quiche_apps::client] timed out [2025-04-30T21:41:41.190426644Z TRACE quiche] dbe86a0cced34a59865c6e97611b38c289adcd8e draining timeout expired [2025-04-30T21:41:41.190485172Z TRACE quiche_apps::client] done reading [2025-04-30T21:41:41.190497435Z INFO quiche_apps::client] connection closed, recv=6 sent=7 lost=0 retrans=1 sent_bytes=2141 recv_bytes=3963 lost_bytes=0 [local_addr=0.0.0.0:51727 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=6 sent=7 lost=0 retrans=1 rtt=1.508442487s min_rtt=Some(1.495977769s) rttvar=569.895033ms cwnd=13500 sent_bytes=2141 recv_bytes=3963 lost_bytes=0 stream_retrans_bytes=266 pmtu=1350 delivery_rate=772]