[2025-04-30T10:28:17.851104112Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T10:28:17.851396447Z INFO quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:34193 with scid c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb [2025-04-30T10:28:17.851440319Z TRACE quiche::tls] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb write message lvl=Initial len=266 [2025-04-30T10:28:17.851460146Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Initial version=1 dcid=d31a296b107f2386e259877681277a9a scid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb len=270 pn=0 [2025-04-30T10:28:17.851463262Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm CRYPTO off=0 len=266 [2025-04-30T10:28:17.851478380Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=998.927635ms 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: 319, tv_nsec: 982450333 }, first_sent_time: Instant { tv_sec: 319, tv_nsec: 982450333 }, 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: 319, tv_nsec: 982450333 }, next_time: Instant { tv_sec: 319, tv_nsec: 982450333 }, 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-30T10:28:17.851534725Z TRACE quiche_apps::client] written 1200 [2025-04-30T10:28:17.888284083Z TRACE quiche_apps::client] got 112 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.888301897Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Retry version=1 dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb scid=e1a0b74948ea21c04476 token=526574727901009bc153a1410ba5f514e32b62c83c5fe4571042587fc60e7d8edb952d31227cad0d6cbf6ecbb96b334c1c57fda7db094b7ca44647 [2025-04-30T10:28:17.888327915Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb dropped epoch 0 state [2025-04-30T10:28:17.888335880Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 112 bytes [2025-04-30T10:28:17.888340829Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.888343975Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.888385853Z TRACE quiche::tls] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb write message lvl=Initial len=266 [2025-04-30T10:28:17.888400661Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Initial version=1 dcid=e1a0b74948ea21c04476 scid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb token=526574727901009bc153a1410ba5f514e32b62c83c5fe4571042587fc60e7d8edb952d31227cad0d6cbf6ecbb96b334c1c57fda7db094b7ca44647 len=270 pn=1 [2025-04-30T10:28:17.888404288Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm CRYPTO off=0 len=266 [2025-04-30T10:28:17.888415448Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=998.936401ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=386 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 320, tv_nsec: 19396028 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 19396028 }, 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: 320, tv_nsec: 19396028 }, next_time: Instant { tv_sec: 320, tv_nsec: 19396028 }, 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-30T10:28:17.888475440Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.888482473Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.924049366Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.924064184Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Initial version=1 dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb scid=a19598cd84d1e950b0b3 token= len=116 pn=0 [2025-04-30T10:28:17.924075124Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm ACK delay=0 blocks=[1..1] ecn_counts=None [2025-04-30T10:28:17.924081206Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb packet newly acked 1 [2025-04-30T10:28:17.924086486Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm CRYPTO off=0 len=90 [2025-04-30T10:28:17.924186332Z TRACE quiche::tls] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb set write secret lvl=Handshake [2025-04-30T10:28:17.924195990Z TRACE quiche::tls] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb set read secret lvl=Handshake [2025-04-30T10:28:17.924223611Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Handshake version=1 dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb scid=a19598cd84d1e950b0b3 len=765 pn=0 [2025-04-30T10:28:17.924230655Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm CRYPTO off=0 len=744 [2025-04-30T10:28:17.924453610Z TRACE quiche::tls] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb write message lvl=Handshake len=36 [2025-04-30T10:28:17.924458499Z TRACE quiche::tls] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb set write secret lvl=OneRTT [2025-04-30T10:28:17.924466635Z TRACE quiche::tls] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb set read secret lvl=OneRTT [2025-04-30T10:28:17.924484939Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb 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(d31a296b107f2386e259877681277a9a), max_idle_timeout: 30000, stateless_reset_token: None, max_udp_payload_size: 65527, initial_max_data: 4611686018427387903, initial_max_stream_data_bidi_local: 1048576, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 1048576, initial_max_streams_bidi: 16, initial_max_streams_uni: 16, ack_delay_exponent: 3, max_ack_delay: 20, disable_active_migration: false, active_conn_id_limit: 8, initial_source_connection_id: Some(a19598cd84d1e950b0b3), retry_source_connection_id: Some(e1a0b74948ea21c04476), max_datagram_frame_size: Some(0), unknown_params: None } [2025-04-30T10:28:17.924507441Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=0000000000000000000000000000000000000000 key_phase=true len=251 pn=1690580 [2025-04-30T10:28:17.924513482Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb dropped invalid packet [2025-04-30T10:28:17.924516718Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.924522048Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.924525124Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.924533429Z DEBUG quiche_apps::common] sending HTTP request "GET /kdbhcqhyhv\r\n" [2025-04-30T10:28:17.924600725Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Initial version=1 dcid=a19598cd84d1e950b0b3 scid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb token=526574727901009bc153a1410ba5f514e32b62c83c5fe4571042587fc60e7d8edb952d31227cad0d6cbf6ecbb96b334c1c57fda7db094b7ca44647 len=6 pn=2 [2025-04-30T10:28:17.924611415Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=67 blocks=[0..0] ecn_counts=None [2025-04-30T10:28:17.924621173Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=106.568611ms latest_rtt=35.709479ms srtt=35.709479ms min_rtt=35.709479ms rttvar=17.854739ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 386, delivered_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 10809, is_app_limited: true, interval: 35.709479ms, delivered: 386, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 19396028 }), send_elapsed: 0ns, ack_elapsed: 35.709479ms, rtt: 35.709479ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 472563, last_update: Instant { tv_sec: 320, tv_nsec: 55526763 }, next_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, 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-30T10:28:17.924642062Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Handshake version=1 dcid=a19598cd84d1e950b0b3 scid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb len=45 pn=3 [2025-04-30T10:28:17.924645508Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=52 blocks=[0..0] ecn_counts=None [2025-04-30T10:28:17.924648724Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm CRYPTO off=0 len=36 [2025-04-30T10:28:17.924655978Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=107.062732ms latest_rtt=35.709479ms srtt=35.709479ms min_rtt=35.709479ms rttvar=17.854739ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=101 app_limited=true congestion_recovery_start_time=None Rate { delivered: 386, delivered_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 10809, is_app_limited: true, interval: 35.709479ms, delivered: 386, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 19396028 }), send_elapsed: 0ns, ack_elapsed: 35.709479ms, rtt: 35.709479ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 472563, last_update: Instant { tv_sec: 320, tv_nsec: 55634273 }, next_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, max_datagram_size: 1350, last_packet_size: None, iv: 213.728µ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-30T10:28:17.924668561Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb dropped epoch 0 state [2025-04-30T10:28:17.924673641Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13399 out_len=1127 left=1099 [2025-04-30T10:28:17.924686935Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=1099 pn=4 [2025-04-30T10:28:17.924690091Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[b6, f7, f1, c2, 1e, 7b, 09, 99, 49, b1, 57, 51, a2, 6a, 10, 40, 37, a5, 2b, 8b] reset_token=[93, 30, a4, 1d, 24, 9a, a0, 27, fa, c1, a2, bb, 66, 4e, 10, b0] [2025-04-30T10:28:17.924702134Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[6b, 39, 91, 44, 48, 0b, 19, db, 94, 8d, 31, b3, 2f, 4f, fb, 54, c3, 6b, 99, fc] reset_token=[65, f6, 09, 27, e8, e8, 00, b2, 59, c9, c4, 50, 59, dd, 8a, 2b] [2025-04-30T10:28:17.924708866Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[76, a8, e2, 76, fd, ab, 44, 5b, bf, 74, 60, c0, fc, 97, 14, bb, 63, d5, 4b, ab] reset_token=[f9, ac, db, 3c, 0b, ca, 79, 97, 00, 0d, 17, 6f, 3d, f3, 89, c7] [2025-04-30T10:28:17.924715238Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[83, 50, 37, 73, a9, bf, 62, 56, c1, 95, 03, 62, 27, 03, 65, ce, 6d, b1, 2d, 41] reset_token=[8a, 96, 0e, 77, ce, 8d, 43, 70, ce, 56, 00, fd, 81, d8, 06, 20] [2025-04-30T10:28:17.924721510Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[70, 6e, a0, 48, 62, 98, 1e, f6, 0c, ee, cb, cc, 67, 30, 26, 63, f3, d3, 88, fd] reset_token=[f1, 6e, 4a, 16, 20, ba, ea, 68, 5e, b0, ff, cc, c8, c0, 2a, 05] [2025-04-30T10:28:17.924727561Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[79, b2, 37, 83, 93, a6, ad, 31, 71, 0f, 54, a6, 05, 04, cf, 9b, d1, fd, 72, d9] reset_token=[02, d8, ac, 8a, bc, 96, ab, b5, b9, ad, 20, 2c, ac, c5, 24, 0e] [2025-04-30T10:28:17.924733873Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[83, 4c, d5, 8b, 92, cb, 1e, 94, 99, 22, 4e, 58, ce, 41, 3d, 91, ed, b7, 5e, 23] reset_token=[b1, 13, 61, 17, 89, 9f, 4c, 3f, 8f, 62, 01, a7, d2, e1, 3f, 4c] [2025-04-30T10:28:17.924739804Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T10:28:17.924743000Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm PADDING len=797 [2025-04-30T10:28:17.924753810Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=106.96493ms latest_rtt=35.709479ms srtt=35.709479ms min_rtt=35.709479ms rttvar=17.854739ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1228 app_limited=true congestion_recovery_start_time=None Rate { delivered: 386, delivered_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 55526803 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 10809, is_app_limited: true, interval: 35.709479ms, delivered: 386, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 19396028 }), send_elapsed: 0ns, ack_elapsed: 35.709479ms, rtt: 35.709479ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1127, rate: 472563, last_update: Instant { tv_sec: 320, tv_nsec: 55634273 }, next_time: Instant { tv_sec: 320, tv_nsec: 55848001 }, max_datagram_size: 1350, last_packet_size: Some(1127), 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-30T10:28:17.924799626Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.924805296Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.958277590Z TRACE quiche_apps::client] got 1332 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.958290134Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Handshake version=1 dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb scid=a19598cd84d1e950b0b3 len=22 pn=1 [2025-04-30T10:28:17.958297587Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm ACK delay=0 blocks=[3..3] ecn_counts=None [2025-04-30T10:28:17.958307416Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb packet newly acked 3 [2025-04-30T10:28:17.958321031Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1250 pn=0 [2025-04-30T10:28:17.958326632Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm ACK delay=0 blocks=[4..4] ecn_counts=None [2025-04-30T10:28:17.958329577Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb packet newly acked 4 [2025-04-30T10:28:17.958332964Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm HANDSHAKE_DONE [2025-04-30T10:28:17.958335999Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb dropped epoch 1 state [2025-04-30T10:28:17.958339837Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[d4, 69, 59, e9, 7e, 57, 60, fb, 72, a0] reset_token=[3c, 34, 93, 0a, ee, 1f, c3, 7a, a3, 3b, fe, 27, 40, 8d, ed, 55] [2025-04-30T10:28:17.958345868Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[14, 27, 54, 38, b9, b7, 39, 1b, eb, b7] reset_token=[a4, 1e, 73, 4d, c1, d4, 1f, ad, 81, 1e, aa, b0, d9, 38, 46, 02] [2025-04-30T10:28:17.958351198Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[c1, 3b, 99, 73, 43, df, 92, 0d, 6c, 87] reset_token=[8a, e3, 12, fd, 1e, 4a, bb, 60, fe, 7a, db, 8b, 73, fe, e7, ac] [2025-04-30T10:28:17.958356117Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[0e, 2f, 4f, e9, 5a, 18, c8, 7e, d0, 13] reset_token=[6c, 0f, bb, a0, 8b, da, 31, fb, ef, ab, bc, 2e, d1, f1, 09, fe] [2025-04-30T10:28:17.958361156Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[96, 69, e1, 6c, 8c, b9, 65, bb, 32, 16] reset_token=[90, 83, 5d, e7, 41, 98, 65, 25, 08, c6, 1f, 7b, b3, 58, a5, 67] [2025-04-30T10:28:17.958366115Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[a1, b9, a2, 01, d4, 44, 15, a8, 5e, 0a] reset_token=[fd, 4c, 35, 1f, c6, 4e, 67, 6d, 65, 82, c7, ec, b3, 17, e6, 77] [2025-04-30T10:28:17.958371145Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[40, 8c, 50, 96, 75, eb, 80, c5, 26, 1a] reset_token=[3c, 39, 90, 97, 67, ca, 57, 62, 8b, 19, cb, 6d, d6, 6a, 05, 1c] [2025-04-30T10:28:17.958378539Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm PADDING len=1017 [2025-04-30T10:28:17.958404828Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1332 bytes [2025-04-30T10:28:17.958409146Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.958411731Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.958418764Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.958422380Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=5 [2025-04-30T10:28:17.958424885Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=12 blocks=[0..0] ecn_counts=None [2025-04-30T10:28:17.958431257Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.958478115Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.958485869Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.959359890Z TRACE quiche_apps::client] got 1332 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.959367695Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1311 pn=1 [2025-04-30T10:28:17.959373686Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm PING mtu_probe=None [2025-04-30T10:28:17.959380799Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm PADDING len=1293 [2025-04-30T10:28:17.959386860Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1332 bytes [2025-04-30T10:28:17.959390337Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.959392731Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.959398793Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.959402039Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=6 [2025-04-30T10:28:17.959404533Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=3 blocks=[0..1] ecn_counts=None [2025-04-30T10:28:17.959410725Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.959445981Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.959453134Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.960367029Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.960374063Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=2 [2025-04-30T10:28:17.960381036Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=0 len=1192 fin=false [2025-04-30T10:28:17.960392808Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.960396374Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.960398709Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.960403087Z TRACE quiche_apps::common] received 1192 bytes [2025-04-30T10:28:17.960405391Z TRACE quiche_apps::common] stream 0 has 1192 bytes (fin? false) [2025-04-30T10:28:17.960411913Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.960414999Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=7 [2025-04-30T10:28:17.960417343Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=4 blocks=[0..2] ecn_counts=None [2025-04-30T10:28:17.960423214Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.960458119Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.960465473Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.962251737Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.962260914Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=3 [2025-04-30T10:28:17.962268939Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=1192 len=1190 fin=false [2025-04-30T10:28:17.962277014Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.962281332Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.962284277Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.962289196Z TRACE quiche_apps::common] received 1190 bytes [2025-04-30T10:28:17.962292062Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false) [2025-04-30T10:28:17.962299796Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.962303694Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=8 [2025-04-30T10:28:17.962306699Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=4 blocks=[0..3] ecn_counts=None [2025-04-30T10:28:17.962313842Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.962360790Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.962369606Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.963255379Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.963263134Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=4 [2025-04-30T10:28:17.963269436Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=2382 len=1190 fin=false [2025-04-30T10:28:17.963276148Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.963279565Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.963281929Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.963285846Z TRACE quiche_apps::common] received 1190 bytes [2025-04-30T10:28:17.963288080Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false) [2025-04-30T10:28:17.963294072Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.963297177Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=9 [2025-04-30T10:28:17.963299532Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=3 blocks=[0..4] ecn_counts=None [2025-04-30T10:28:17.963305773Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.963339126Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.963351850Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.965577824Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.965586450Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=5 [2025-04-30T10:28:17.965593823Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=3572 len=1190 fin=false [2025-04-30T10:28:17.965601778Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.965605976Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.965608952Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.965613691Z TRACE quiche_apps::common] received 1190 bytes [2025-04-30T10:28:17.965616456Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false) [2025-04-30T10:28:17.965623729Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.965627536Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=10 [2025-04-30T10:28:17.965630532Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=4 blocks=[0..5] ecn_counts=None [2025-04-30T10:28:17.965637605Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 10, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.965678481Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.965686737Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.966583751Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.966592226Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=6 [2025-04-30T10:28:17.966599410Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=4762 len=1190 fin=false [2025-04-30T10:28:17.966607214Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.966611462Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.966614378Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.966619077Z TRACE quiche_apps::common] received 1190 bytes [2025-04-30T10:28:17.966621832Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false) [2025-04-30T10:28:17.966629025Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.966632772Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=11 [2025-04-30T10:28:17.966641478Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=4 blocks=[0..6] ecn_counts=None [2025-04-30T10:28:17.966648652Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 11, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.966699747Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.966708443Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.968816367Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.968824753Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=7 [2025-04-30T10:28:17.968831075Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=5952 len=1190 fin=false [2025-04-30T10:28:17.968838158Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.968841674Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.968844049Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.968848036Z TRACE quiche_apps::common] received 1190 bytes [2025-04-30T10:28:17.968850311Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false) [2025-04-30T10:28:17.968856592Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.968859758Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=12 [2025-04-30T10:28:17.968862162Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=4 blocks=[0..7] ecn_counts=None [2025-04-30T10:28:17.968868104Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 12, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.968910082Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.968918738Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.969829888Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.969838585Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=8 [2025-04-30T10:28:17.969845948Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=7142 len=1190 fin=false [2025-04-30T10:28:17.969853903Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.969858161Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.969861107Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.969865946Z TRACE quiche_apps::common] received 1190 bytes [2025-04-30T10:28:17.969868711Z TRACE quiche_apps::common] stream 0 has 1190 bytes (fin? false) [2025-04-30T10:28:17.969893106Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.969896473Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=13 [2025-04-30T10:28:17.969898907Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=6 blocks=[0..8] ecn_counts=None [2025-04-30T10:28:17.969905469Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 13, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.969939523Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.969946806Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.970724568Z TRACE quiche_apps::client] got 1093 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.970733084Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1072 pn=9 [2025-04-30T10:28:17.970739256Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=8332 len=1051 fin=false [2025-04-30T10:28:17.970746078Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1093 bytes [2025-04-30T10:28:17.970749555Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.970751949Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.970766336Z TRACE quiche_apps::common] received 1051 bytes [2025-04-30T10:28:17.970768740Z TRACE quiche_apps::common] stream 0 has 1051 bytes (fin? false) [2025-04-30T10:28:17.970774942Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1317 [2025-04-30T10:28:17.970778008Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=5 pn=14 [2025-04-30T10:28:17.970780322Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm ACK delay=5 blocks=[0..9] ecn_counts=None [2025-04-30T10:28:17.970786123Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=none latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, end_of_app_limited: 4, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 89459235 }, next_time: Instant { tv_sec: 320, tv_nsec: 89459235 }, 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-30T10:28:17.970821058Z TRACE quiche_apps::client] written 33 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.970828322Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.989941119Z TRACE quiche_apps::client] got 1232 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.989953151Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=1211 pn=10 [2025-04-30T10:28:17.989981895Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm STREAM id=0 off=9383 len=857 fin=true [2025-04-30T10:28:17.989990201Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm CRYPTO off=0 len=327 [2025-04-30T10:28:17.990000369Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1232 bytes [2025-04-30T10:28:17.990006020Z TRACE quiche_apps::client] got 97 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.990009867Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx pkt Short dcid=c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb key_phase=false len=76 pn=11 [2025-04-30T10:28:17.990014145Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm CRYPTO off=327 len=10 [2025-04-30T10:28:17.990030175Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb rx frm NEW_TOKEN len=43 [2025-04-30T10:28:17.990035655Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 97 bytes [2025-04-30T10:28:17.990039132Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.990041526Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.990046967Z TRACE quiche_apps::common] received 857 bytes [2025-04-30T10:28:17.990049331Z TRACE quiche_apps::common] stream 0 has 857 bytes (fin? true) [2025-04-30T10:28:17.990051735Z DEBUG quiche_apps::common] 1/1 responses received [2025-04-30T10:28:17.990054029Z INFO quiche_apps::common] 1/1 response(s) received in 138.515658ms, closing... [2025-04-30T10:28:17.990061023Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1322 [2025-04-30T10:28:17.990070911Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx pkt Short dcid=a19598cd84d1e950b0b3 key_phase=false len=10 pn=15 [2025-04-30T10:28:17.990073526Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65] [2025-04-30T10:28:17.990080770Z TRACE quiche::recovery::congestion::recovery] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb timer=98.761576ms latest_rtt=33.516057ms srtt=35.226981ms min_rtt=33.516057ms rttvar=10.889244ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=38 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1614, delivered_time: Instant { tv_sec: 320, tv_nsec: 121102396 }, first_sent_time: Instant { tv_sec: 320, tv_nsec: 121102396 }, end_of_app_limited: 14, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { delivery_rate: 36326, is_app_limited: true, interval: 33.804844ms, delivered: 1228, prior_delivered: 386, prior_time: Some(Instant { tv_sec: 320, tv_nsec: 55526803 }), send_elapsed: 0ns, ack_elapsed: 33.804844ms, rtt: 33.804844ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 38, rate: 479036, last_update: Instant { tv_sec: 320, tv_nsec: 121102396 }, next_time: Instant { tv_sec: 320, tv_nsec: 121102396 }, max_datagram_size: 1350, last_packet_size: Some(38), 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-30T10:28:17.990122788Z TRACE quiche_apps::client] written 38 bytes from 0.0.0.0:34193 to 193.167.100.100:443 [2025-04-30T10:28:17.990129090Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:17.991141128Z TRACE quiche_apps::client] got 1372 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:17.991148372Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 1372 bytes [2025-04-30T10:28:17.991151708Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:17.991154093Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:17.991157699Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:18.020608253Z TRACE quiche_apps::client] got 47 bytes from 193.167.100.100:443 to 0.0.0.0:34193 [2025-04-30T10:28:18.020621066Z TRACE quiche_apps::client] 0.0.0.0:34193: processed 47 bytes [2025-04-30T10:28:18.020626006Z TRACE quiche_apps::client] 0.0.0.0:34193: recv() would block [2025-04-30T10:28:18.020629222Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:18.020634191Z TRACE quiche_apps::client] 0.0.0.0:34193 -> 193.167.100.100:443: done writing [2025-04-30T10:28:18.226890937Z TRACE quiche_apps::client] timed out [2025-04-30T10:28:18.226909341Z TRACE quiche] c1c34dc037c27794ed0d7fc9c1f90dc19efb47fb draining timeout expired [2025-04-30T10:28:18.226946340Z TRACE quiche_apps::client] done reading [2025-04-30T10:28:18.226950899Z INFO quiche_apps::client] connection closed, recv=15 sent=16 lost=0 retrans=0 sent_bytes=2437 recv_bytes=14670 lost_bytes=0 [local_addr=0.0.0.0:34193 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=15 sent=16 lost=0 retrans=0 rtt=35.226981ms min_rtt=Some(33.516057ms) rttvar=10.889244ms cwnd=13500 sent_bytes=2437 recv_bytes=14670 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=36326]