[2025-09-11T19:18:46.050322236Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-09-11T19:18:46.050604664Z INFO  quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:38331 with scid c8b38a69830d591d595273557138094b4ab3eac6
[2025-09-11T19:18:46.050645229Z TRACE quiche::tls] c8b38a69830d591d595273557138094b4ab3eac6 write message lvl=Initial len=266
[2025-09-11T19:18:46.050662511Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Initial version=1 dcid=117fed50f4f0a608fad637e292a1ee4b scid=c8b38a69830d591d595273557138094b4ab3eac6 len=270 pn=0 
[2025-09-11T19:18:46.050665477Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm CRYPTO off=0 len=266
[2025-09-11T19:18:46.050679102Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=998.932273ms 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: 301, tv_nsec: 619881605 }, first_sent_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 301, tv_nsec: 619881605 }, next_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:46.050748402Z TRACE quiche_apps::client] written 1200
[2025-09-11T19:18:47.050808790Z TRACE quiche_apps::client] timed out
[2025-09-11T19:18:47.050838135Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 loss detection timeout expired
[2025-09-11T19:18:47.050845459Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=997.764925ms 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: 301, tv_nsec: 619881605 }, first_sent_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 301, tv_nsec: 619881605 }, next_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:47.050870305Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:47.050908266Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Initial version=1 dcid=117fed50f4f0a608fad637e292a1ee4b scid=c8b38a69830d591d595273557138094b4ab3eac6 len=270 pn=1 
[2025-09-11T19:18:47.050912554Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm CRYPTO off=0 len=266
[2025-09-11T19:18:47.050932050Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=1.997953152s 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: 301, tv_nsec: 619881605 }, first_sent_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, is_app_limited: false, interval: 0ns, delivered: 0, prior_delivered: 0, prior_time: None, send_elapsed: 0ns, ack_elapsed: 0ns, rtt: 0ns } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 302, tv_nsec: 620155302 }, next_time: Instant { tv_sec: 302, tv_nsec: 620155302 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:47.051008423Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:38331 to 193.167.100.100:443
[2025-09-11T19:18:47.051016158Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:47.558983608Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:47.559023743Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx pkt Initial version=1 dcid=c8b38a69830d591d595273557138094b4ab3eac6 scid=e5476cca76f71f24 token= len=116 pn=0 
[2025-09-11T19:18:47.559042027Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm ACK delay=59 blocks=[0..0] ecn_counts=None
[2025-09-11T19:18:47.559049150Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 packet newly acked 0
[2025-09-11T19:18:47.559056093Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm CRYPTO off=0 len=90
[2025-09-11T19:18:47.559179363Z TRACE quiche::tls] c8b38a69830d591d595273557138094b4ab3eac6 set write secret lvl=Handshake
[2025-09-11T19:18:47.559192267Z TRACE quiche::tls] c8b38a69830d591d595273557138094b4ab3eac6 set read secret lvl=Handshake
[2025-09-11T19:18:47.559232462Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx pkt Handshake version=1 dcid=c8b38a69830d591d595273557138094b4ab3eac6 scid=e5476cca76f71f24 len=1009 pn=0 
[2025-09-11T19:18:47.559239586Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm CRYPTO off=0 len=733
[2025-09-11T19:18:47.559482469Z TRACE quiche::tls] c8b38a69830d591d595273557138094b4ab3eac6 write message lvl=Handshake len=36
[2025-09-11T19:18:47.559487258Z TRACE quiche::tls] c8b38a69830d591d595273557138094b4ab3eac6 set write secret lvl=OneRTT
[2025-09-11T19:18:47.559495424Z TRACE quiche::tls] c8b38a69830d591d595273557138094b4ab3eac6 set read secret lvl=OneRTT
[2025-09-11T19:18:47.559514449Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 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(117fed50f4f0a608fad637e292a1ee4b), max_idle_timeout: 30000, stateless_reset_token: Some(82819326194062315139971587861479458301), max_udp_payload_size: 1472, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1250000, initial_max_stream_data_bidi_remote: 1250000, initial_max_stream_data_uni: 1250000, 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: 5, initial_source_connection_id: Some(e5476cca76f71f24), retry_source_connection_id: None, max_datagram_frame_size: Some(65535), unknown_params: None }
[2025-09-11T19:18:47.559528606Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm PADDING len=255
[2025-09-11T19:18:47.559544966Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 1200 bytes
[2025-09-11T19:18:47.559551719Z TRACE quiche_apps::client] got 234 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:47.559556107Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx pkt Short dcid=c8b38a69830d591d595273557138094b4ab3eac6 key_phase=false len=213 pn=0 
[2025-09-11T19:18:47.559569352Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[86, 3b, 09, 93, 3b, 09, 53, fc] reset_token=[66, 5e, 11, ae, f9, a5, cd, e7, b7, 80, c4, d8, 1c, 11, 5c, b6]
[2025-09-11T19:18:47.559577828Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[68, 43, 51, b1, 39, fc, 94, 64] reset_token=[89, 4b, 5f, 86, 7a, 12, ec, 86, 29, 60, 85, d3, 7d, 59, ff, 0c]
[2025-09-11T19:18:47.559583709Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[2a, 35, 93, d5, 4e, 17, 55, e9] reset_token=[56, 3e, 69, 13, 25, 55, 70, 28, 0c, 37, c3, 31, 90, bf, 08, 46]
[2025-09-11T19:18:47.559589159Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[f0, c2, e2, b1, bd, e7, 44, 6e] reset_token=[ff, 7a, f8, 41, 50, 35, 77, 91, 8d, b1, 4f, 4b, 44, 7a, 63, 09]
[2025-09-11T19:18:47.559595330Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[d0, 32, df, 13, c3, 4b, 90, 84] reset_token=[5d, 35, 71, ef, da, 0a, df, 35, f2, 44, a3, 77, f8, 10, b9, 3e]
[2025-09-11T19:18:47.559600911Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[18, 7b, 5d, b4, f5, bf, 96, 96] reset_token=[3d, f2, d9, 38, 4b, 8e, 40, 22, 3b, 27, e7, 19, 0d, 1f, be, 79]
[2025-09-11T19:18:47.559606421Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[5e, 81, a6, fe, c9, 31, 01, ef] reset_token=[b2, 83, 1a, a1, d3, 44, 32, de, 23, 1c, 7d, cf, e5, 2f, a9, a1]
[2025-09-11T19:18:47.559616500Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 234 bytes
[2025-09-11T19:18:47.559620948Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:47.559624044Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:47.559638281Z DEBUG quiche_apps::common] sending HTTP request "GET /nhphkohoha\r\n"
[2025-09-11T19:18:47.559718701Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Initial version=1 dcid=e5476cca76f71f24 scid=c8b38a69830d591d595273557138094b4ab3eac6 len=6 pn=2 
[2025-09-11T19:18:47.559723380Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm ACK delay=87 blocks=[0..0] ecn_counts=None
[2025-09-11T19:18:47.559771269Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=4.016330846s latest_rtt=1.508405785s srtt=1.508405785s min_rtt=1.508405785s rttvar=754.202892ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 303, tv_nsec: 128287390 }, first_sent_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.508405785s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 301, tv_nsec: 619881605 }), send_elapsed: 0ns, ack_elapsed: 1.508405785s, rtt: 1.508405785s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11187, last_update: Instant { tv_sec: 303, tv_nsec: 128782184 }, next_time: Instant { tv_sec: 303, tv_nsec: 128782224 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:47.559802407Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Handshake version=1 dcid=e5476cca76f71f24 scid=c8b38a69830d591d595273557138094b4ab3eac6 len=46 pn=3 
[2025-09-11T19:18:47.559811725Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm ACK delay=71 blocks=[0..0] ecn_counts=None
[2025-09-11T19:18:47.559815362Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm CRYPTO off=0 len=36
[2025-09-11T19:18:47.559823527Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=4.016279089s latest_rtt=1.508405785s srtt=1.508405785s min_rtt=1.508405785s rttvar=754.202892ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=433 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 303, tv_nsec: 128287390 }, first_sent_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.508405785s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 301, tv_nsec: 619881605 }), send_elapsed: 0ns, ack_elapsed: 1.508405785s, rtt: 1.508405785s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11187, last_update: Instant { tv_sec: 303, tv_nsec: 128977609 }, next_time: Instant { tv_sec: 303, tv_nsec: 128782224 }, max_datagram_size: 1350, last_packet_size: None, iv: 8.938947ms, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:47.559838385Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 dropped epoch 0 state
[2025-09-11T19:18:47.559854114Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Short dcid=e5476cca76f71f24 key_phase=false len=1163 pn=4 
[2025-09-11T19:18:47.559857540Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm ACK delay=35 blocks=[0..0] ecn_counts=None
[2025-09-11T19:18:47.559860796Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[a3, e6, b4, f1, bc, 28, ea, b8, 86, ff, 47, cc, 7a, 8e, d2, d4, aa, f8, 56, 1a] reset_token=[c7, da, 30, 9d, b0, 2f, b5, c8, 12, 67, dc, ec, fb, a5, 0e, 49]
[2025-09-11T19:18:47.559867910Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[5e, f0, 41, 6a, fe, 2f, e5, ea, e2, 95, b4, ac, da, da, 63, 82, fb, 66, f6, e0] reset_token=[59, 0c, b7, bf, be, 9c, c2, 88, 62, 5d, 1e, 4d, da, ae, 09, e4]
[2025-09-11T19:18:47.559874332Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[66, 87, f3, 28, 59, 85, 9e, 69, ee, d4, 3c, 21, af, 77, ad, e2, 92, ab, 29, fa] reset_token=[81, 28, 43, b0, 84, 28, 1b, 74, 2c, aa, f5, df, 82, 1e, dc, b8]
[2025-09-11T19:18:47.559880633Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[f0, 91, 55, c5, 3b, df, ab, 51, ef, 48, 54, 93, 45, a7, 78, e3, 7c, 4a, 70, bf] reset_token=[af, b4, 01, 3c, 72, 88, 5e, 2f, 45, dd, 3a, 1a, 70, c9, 6c, 9e]
[2025-09-11T19:18:47.559886895Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm STREAM id=0 off=0 len=17 fin=true
[2025-09-11T19:18:47.559890031Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm PADDING len=976
[2025-09-11T19:18:47.559899468Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=4.525025525s latest_rtt=1.508405785s srtt=1.508405785s min_rtt=1.508405785s rttvar=754.202892ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 303, tv_nsec: 128287390 }, first_sent_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.508405785s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 301, tv_nsec: 619881605 }), send_elapsed: 0ns, ack_elapsed: 1.508405785s, rtt: 1.508405785s } } pacer=Pacer { enabled: true, capacity: 13500, used: 1189, rate: 11187, last_update: Instant { tv_sec: 303, tv_nsec: 128977609 }, next_time: Instant { tv_sec: 303, tv_nsec: 137916556 }, max_datagram_size: 1350, last_packet_size: Some(1189), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:47.559959371Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:38331 to 193.167.100.100:443
[2025-09-11T19:18:47.559965732Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:47.860581676Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:47.860615409Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 dropped invalid packet
[2025-09-11T19:18:47.860621010Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 1200 bytes
[2025-09-11T19:18:47.860626209Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:47.860629445Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:47.860639304Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:47.861531480Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:47.861545887Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 dropped invalid packet
[2025-09-11T19:18:47.861550025Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 1200 bytes
[2025-09-11T19:18:47.861554574Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:47.861557589Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:47.861563450Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:48.553384667Z TRACE quiche_apps::client] got 851 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:48.553415745Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 dropped invalid packet
[2025-09-11T19:18:48.553421346Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 851 bytes
[2025-09-11T19:18:48.553426856Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:48.553430102Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:48.553439981Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:48.553945835Z TRACE quiche_apps::client] got 791 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:48.553958850Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx pkt Handshake version=1 dcid=c8b38a69830d591d595273557138094b4ab3eac6 scid=e5476cca76f71f24 len=754 pn=2 
[2025-09-11T19:18:48.553973457Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm CRYPTO off=0 len=733
[2025-09-11T19:18:48.553997662Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 791 bytes
[2025-09-11T19:18:48.554001399Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:48.554003804Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:48.554015305Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Handshake version=1 dcid=e5476cca76f71f24 scid=c8b38a69830d591d595273557138094b4ab3eac6 len=7 pn=5 
[2025-09-11T19:18:48.554019042Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm ACK delay=7 blocks=[0..0, 2..2] ecn_counts=None
[2025-09-11T19:18:48.554030874Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=3.530893438s latest_rtt=1.508405785s srtt=1.508405785s min_rtt=1.508405785s rttvar=754.202892ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1289 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 303, tv_nsec: 128287390 }, first_sent_time: Instant { tv_sec: 301, tv_nsec: 619881605 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { bandwidth: 1.76 Kbps, is_app_limited: true, interval: 1.508405785s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 301, tv_nsec: 619881605 }), send_elapsed: 0ns, ack_elapsed: 1.508405785s, rtt: 1.508405785s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11187, last_update: Instant { tv_sec: 304, tv_nsec: 123276999 }, next_time: Instant { tv_sec: 303, tv_nsec: 137916556 }, max_datagram_size: 1350, last_packet_size: None, iv: 106.28408ms, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:48.554103770Z TRACE quiche_apps::client] written 61 bytes from 0.0.0.0:38331 to 193.167.100.100:443
[2025-09-11T19:18:48.554111615Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:49.062477300Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:49.062515151Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 dropped invalid packet
[2025-09-11T19:18:49.062520752Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 1200 bytes
[2025-09-11T19:18:49.062525941Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:49.062529188Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:49.062538966Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:49.063365670Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:49.063377943Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 dropped invalid packet
[2025-09-11T19:18:49.063381309Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 1200 bytes
[2025-09-11T19:18:49.063384966Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:49.063387371Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:49.063392149Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:49.063713049Z TRACE quiche_apps::client] got 406 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:49.063723889Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx pkt Short dcid=a3e6b4f1bc28eab886ff47cc7a8ed2d4aaf8561a key_phase=false len=385 pn=1 
[2025-09-11T19:18:49.063751992Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 path ID 0 now see SCID with seq num 1
[2025-09-11T19:18:49.063758213Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm HANDSHAKE_DONE
[2025-09-11T19:18:49.063764886Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 dropped epoch 1 state
[2025-09-11T19:18:49.063769214Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm ACK delay=18 blocks=[4..4] ecn_counts=None
[2025-09-11T19:18:49.063774965Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 packet newly acked 4
[2025-09-11T19:18:49.063780946Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm CRYPTO off=0 len=356
[2025-09-11T19:18:49.063817925Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm RETIRE_CONNECTION_ID seq_num=0
[2025-09-11T19:18:49.063885561Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 406 bytes
[2025-09-11T19:18:49.063890300Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:49.063892735Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:49.063895260Z INFO  quiche_apps::client] Retiring source CID c8b38a69830d591d595273557138094b4ab3eac6
[2025-09-11T19:18:49.063912892Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Short dcid=e5476cca76f71f24 key_phase=false len=45 pn=6 
[2025-09-11T19:18:49.063919966Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm ACK delay=23 blocks=[1..1] ecn_counts=None
[2025-09-11T19:18:49.063923242Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=1 conn_id=[a1, 46, 1d, fe, df, 70, 81, a7, 8b, 79, 7a, f5, 99, 4d, 46, 52, d3, 51, 58, 54] reset_token=[e0, 91, 15, 45, 6b, ed, 5e, 06, f1, 8c, 19, 91, 3a, 5e, 2b, cc]
[2025-09-11T19:18:49.063936366Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=3.807646478s latest_rtt=1.495074276s srtt=1.506739345s min_rtt=1.495074276s rttvar=568.985046ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=71 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1522, delivered_time: Instant { tv_sec: 304, tv_nsec: 739457524 }, first_sent_time: Instant { tv_sec: 304, tv_nsec: 739457524 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { bandwidth: 6.26 Kbps, is_app_limited: true, interval: 1.518034951s, delivered: 1189, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 303, tv_nsec: 128287390 }), send_elapsed: 1.518034951s, ack_elapsed: 1.504703442s, rtt: 1.495074276s } } pacer=Pacer { enabled: true, capacity: 13500, used: 71, rate: 11199, last_update: Instant { tv_sec: 304, tv_nsec: 123276999 }, next_time: Instant { tv_sec: 304, tv_nsec: 739457524 }, max_datagram_size: 1350, last_packet_size: Some(71), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:49.063999374Z TRACE quiche_apps::client] written 71 bytes from 0.0.0.0:38331 to 193.167.100.100:443
[2025-09-11T19:18:49.064006898Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:49.064575831Z TRACE quiche_apps::client] got 1066 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:49.064585940Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx pkt Short dcid=a3e6b4f1bc28eab886ff47cc7a8ed2d4aaf8561a key_phase=false len=1045 pn=2 
[2025-09-11T19:18:49.064593975Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm STREAM id=0 off=0 len=1024 fin=false
[2025-09-11T19:18:49.064602781Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 1066 bytes
[2025-09-11T19:18:49.064607360Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:49.064610485Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx pkt Short dcid=a3e6b4f1bc28eab886ff47cc7a8ed2d4aaf8561a key_phase=false len=22 pn=3 
[2025-09-11T19:18:49.064614493Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 rx frm STREAM id=0 off=1024 len=0 fin=true
[2025-09-11T19:18:49.064619322Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 43 bytes
[2025-09-11T19:18:49.064622719Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:49.064625103Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:49.064631665Z TRACE quiche_apps::common] received 1024 bytes
[2025-09-11T19:18:49.064634521Z TRACE quiche_apps::common] stream 0 has 1024 bytes (fin? true)
[2025-09-11T19:18:49.064637125Z DEBUG quiche_apps::common] 1/1 responses received
[2025-09-11T19:18:49.064639480Z INFO  quiche_apps::common] 1/1 response(s) received in 3.013881521s, closing...
[2025-09-11T19:18:49.064647345Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx pkt Short dcid=e5476cca76f71f24 key_phase=false len=10 pn=7 
[2025-09-11T19:18:49.064650230Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-09-11T19:18:49.064664887Z TRACE quiche::recovery::congestion::recovery] c8b38a69830d591d595273557138094b4ab3eac6 timer=3.807658169s latest_rtt=1.495074276s srtt=1.506739345s min_rtt=1.495074276s rttvar=568.985046ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=107 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1522, delivered_time: Instant { tv_sec: 304, tv_nsec: 739457524 }, first_sent_time: Instant { tv_sec: 304, tv_nsec: 739457524 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { bandwidth: 6.26 Kbps, is_app_limited: true, interval: 1.518034951s, delivered: 1189, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 303, tv_nsec: 128287390 }), send_elapsed: 1.518034951s, ack_elapsed: 1.504703442s, rtt: 1.495074276s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11199, last_update: Instant { tv_sec: 304, tv_nsec: 633913576 }, next_time: Instant { tv_sec: 304, tv_nsec: 739457524 }, max_datagram_size: 1350, last_packet_size: None, iv: 9.554425ms, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-09-11T19:18:49.064713618Z TRACE quiche_apps::client] written 36 bytes from 0.0.0.0:38331 to 193.167.100.100:443
[2025-09-11T19:18:49.064720621Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:50.564801578Z TRACE quiche_apps::client] got 43 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:50.564833567Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 43 bytes
[2025-09-11T19:18:50.564840961Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:50.564845850Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:50.564854967Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:18:50.565296061Z TRACE quiche_apps::client] got 47 bytes from 193.167.100.100:443 to 0.0.0.0:38331
[2025-09-11T19:18:50.565309956Z TRACE quiche_apps::client] 0.0.0.0:38331: processed 47 bytes
[2025-09-11T19:18:50.565316719Z TRACE quiche_apps::client] 0.0.0.0:38331: recv() would block
[2025-09-11T19:18:50.565321368Z TRACE quiche_apps::client] done reading
[2025-09-11T19:18:50.565328010Z TRACE quiche_apps::client] 0.0.0.0:38331 -> 193.167.100.100:443: done writing
[2025-09-11T19:19:00.423233114Z TRACE quiche_apps::client] timed out
[2025-09-11T19:19:00.423267899Z TRACE quiche] c8b38a69830d591d595273557138094b4ab3eac6 draining timeout expired
[2025-09-11T19:19:00.423311390Z TRACE quiche_apps::client] done reading
[2025-09-11T19:19:00.423319435Z INFO  quiche_apps::client] connection closed, recv=7 sent=8 lost=0 retrans=1 sent_bytes=2184 recv_bytes=3740 lost_bytes=0 [local_addr=0.0.0.0:38331 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=7 sent=8 lost=0 retrans=1 rtt=1.506739345s min_rtt=Some(1.495074276s) rttvar=568.985046ms cwnd=13500 sent_bytes=2184 recv_bytes=3740 lost_bytes=0 stream_retrans_bytes=266 pmtu=1350 delivery_rate=783]