[2025-04-30T18:34:10.575751530Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T18:34:10.576056841Z INFO  quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:38519 with scid b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3
[2025-04-30T18:34:10.576100603Z TRACE quiche::tls] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 write message lvl=Initial len=266
[2025-04-30T18:34:10.576120450Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Initial version=1 dcid=d46b6aeb344726ee972c28b6b34291cd scid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 len=270 pn=0 
[2025-04-30T18:34:10.576123977Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm CRYPTO off=0 len=266
[2025-04-30T18:34:10.576139436Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=998.923948ms 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: 312, tv_nsec: 45496946 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 45496946 }, 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: 312, tv_nsec: 45496946 }, next_time: Instant { tv_sec: 312, tv_nsec: 45496946 }, 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-30T18:34:10.576223122Z TRACE quiche_apps::client] written 1200
[2025-04-30T18:34:10.612914235Z TRACE quiche_apps::client] got 132 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.612957426Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Retry version=1 dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 scid=daacf13ad0ccd0e54f token=4a9ef40f2d03000045317571dcc6183bb469e17afa0424e7f29f54f326b2ecddf3bdcd6ffb61b0c173fc3549e03d2f9c3689c26e21e14be68255390a078c654471faa8bb0760593221d8d87200000000
[2025-04-30T18:34:10.612991029Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 dropped epoch 0 state
[2025-04-30T18:34:10.613003642Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 132 bytes
[2025-04-30T18:34:10.613008812Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.613012078Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.613061360Z TRACE quiche::tls] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 write message lvl=Initial len=266
[2025-04-30T18:34:10.613082239Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Initial version=1 dcid=daacf13ad0ccd0e54f scid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 token=4a9ef40f2d03000045317571dcc6183bb469e17afa0424e7f29f54f326b2ecddf3bdcd6ffb61b0c173fc3549e03d2f9c3689c26e21e14be68255390a078c654471faa8bb0760593221d8d87200000000 len=270 pn=1 
[2025-04-30T18:34:10.613086507Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm CRYPTO off=0 len=266
[2025-04-30T18:34:10.613103359Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=998.917035ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=407 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 312, tv_nsec: 82454137 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 82454137 }, 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: 312, tv_nsec: 82454137 }, next_time: Instant { tv_sec: 312, tv_nsec: 82454137 }, 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-30T18:34:10.613175564Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.613182267Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.646619123Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.646641024Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Initial version=1 dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 scid=4b714b9294a9995cad token= len=119 pn=0 
[2025-04-30T18:34:10.646654880Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm ACK delay=3 blocks=[1..1] ecn_counts=None
[2025-04-30T18:34:10.646661402Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 packet newly acked 1
[2025-04-30T18:34:10.646668726Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm CRYPTO off=0 len=90
[2025-04-30T18:34:10.646784854Z TRACE quiche::tls] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 set write secret lvl=Handshake
[2025-04-30T18:34:10.646797497Z TRACE quiche::tls] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 set read secret lvl=Handshake
[2025-04-30T18:34:10.646833094Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Handshake version=1 dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 scid=4b714b9294a9995cad len=1024 pn=1 
[2025-04-30T18:34:10.646840668Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm CRYPTO off=0 len=751
[2025-04-30T18:34:10.647079265Z TRACE quiche::tls] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 write message lvl=Handshake len=52
[2025-04-30T18:34:10.647084014Z TRACE quiche::tls] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 set write secret lvl=OneRTT
[2025-04-30T18:34:10.647093602Z TRACE quiche::tls] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 set read secret lvl=OneRTT
[2025-04-30T18:34:10.647114992Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 connection established: proto=Ok("hq-interop") cipher=Some(AES256_GCM) curve=Some("X25519") sigalg=Some("ecdsa_secp256r1_sha256") resumed=false TransportParams { original_destination_connection_id: Some(d46b6aeb344726ee972c28b6b34291cd), max_idle_timeout: 30000, stateless_reset_token: Some(139638204667989163387848034819617057415), max_udp_payload_size: 1472, initial_max_data: 16777216, initial_max_stream_data_bidi_local: 65536, initial_max_stream_data_bidi_remote: 65536, initial_max_stream_data_uni: 65536, initial_max_streams_bidi: 100, initial_max_streams_uni: 100, ack_delay_exponent: 8, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(4b714b9294a9995cad), retry_source_connection_id: Some(daacf13ad0ccd0e54f), max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T18:34:10.647129850Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm PADDING len=249
[2025-04-30T18:34:10.647146410Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.647152312Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.647155628Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.647166418Z DEBUG quiche_apps::common] sending HTTP request "GET /qkacxqhpuw\r\n"
[2025-04-30T18:34:10.647244705Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Initial version=1 dcid=4b714b9294a9995cad scid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 token=4a9ef40f2d03000045317571dcc6183bb469e17afa0424e7f29f54f326b2ecddf3bdcd6ffb61b0c173fc3549e03d2f9c3689c26e21e14be68255390a078c654471faa8bb0760593221d8d87200000000 len=6 pn=2 
[2025-04-30T18:34:10.647255274Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=75 blocks=[0..0] ecn_counts=None
[2025-04-30T18:34:10.647265433Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=100.218094ms latest_rtt=33.615661ms srtt=33.615661ms min_rtt=33.615661ms rttvar=16.80783ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 407, delivered_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12107, is_app_limited: true, interval: 33.615661ms, delivered: 407, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 82454137 }), send_elapsed: 0ns, ack_elapsed: 33.615661ms, rtt: 33.615661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 501998, last_update: Instant { tv_sec: 312, tv_nsec: 116545429 }, next_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, 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-30T18:34:10.647289649Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Handshake version=1 dcid=4b714b9294a9995cad scid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 len=61 pn=3 
[2025-04-30T18:34:10.647293195Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=56 blocks=[1..1] ecn_counts=None
[2025-04-30T18:34:10.647296471Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm CRYPTO off=0 len=52
[2025-04-30T18:34:10.647303555Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=100.774936ms latest_rtt=33.615661ms srtt=33.615661ms min_rtt=33.615661ms rttvar=16.80783ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=116 app_limited=true congestion_recovery_start_time=None Rate { delivered: 407, delivered_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12107, is_app_limited: true, interval: 33.615661ms, delivered: 407, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 82454137 }), send_elapsed: 0ns, ack_elapsed: 33.615661ms, rtt: 33.615661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 501998, last_update: Instant { tv_sec: 312, tv_nsec: 116664652 }, next_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, max_datagram_size: 1350, last_packet_size: None, iv: 231.077µ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-30T18:34:10.647318062Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 dropped epoch 0 state
[2025-04-30T18:34:10.647323803Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13384 out_len=1091 left=1064
[2025-04-30T18:34:10.647336076Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=1064 pn=4 
[2025-04-30T18:34:10.647339502Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[cf, db, 35, 17, db, b8, f8, 3d, b2, 24, c7, 56, 74, 38, f7, 25, 6f, 72, 8e, fa] reset_token=[c8, 05, 4d, 54, 12, ff, e4, 62, ae, b8, 27, 0e, 60, 2a, c8, e0]
[2025-04-30T18:34:10.647352677Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[9e, ec, 57, f0, 90, f6, 8f, 7a, f2, b5, ea, d2, 6a, 8c, 7d, c1, 53, 74, 36, 0f] reset_token=[42, 8f, 5e, 75, ac, 8a, 5c, 06, ba, ee, be, ac, 36, 67, ac, 9a]
[2025-04-30T18:34:10.647359970Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[2e, c2, d2, c0, 14, 1d, c2, 40, 7f, e7, cb, 5a, 26, 98, 9f, 31, 14, d9, 32, a4] reset_token=[9a, 90, 41, 53, 2c, b3, c6, ef, eb, 23, 6b, 2c, 31, 1a, 5d, 31]
[2025-04-30T18:34:10.647367014Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T18:34:10.647370310Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm PADDING len=922
[2025-04-30T18:34:10.647379206Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=100.699224ms latest_rtt=33.615661ms srtt=33.615661ms min_rtt=33.615661ms rttvar=16.80783ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1207 app_limited=true congestion_recovery_start_time=None Rate { delivered: 407, delivered_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 116545459 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 12107, is_app_limited: true, interval: 33.615661ms, delivered: 407, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 82454137 }), send_elapsed: 0ns, ack_elapsed: 33.615661ms, rtt: 33.615661ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1091, rate: 501998, last_update: Instant { tv_sec: 312, tv_nsec: 116664652 }, next_time: Instant { tv_sec: 312, tv_nsec: 116895729 }, max_datagram_size: 1350, last_packet_size: Some(1091), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T18:34:10.647430202Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.647436153Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.679918310Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.679935452Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=2 
[2025-04-30T18:34:10.679945090Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm ACK delay=0 blocks=[4..4] ecn_counts=None
[2025-04-30T18:34:10.679949608Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 packet newly acked 4
[2025-04-30T18:34:10.679954577Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm HANDSHAKE_DONE
[2025-04-30T18:34:10.679959116Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 dropped epoch 1 state
[2025-04-30T18:34:10.679963925Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[4b, 71, 7a, 9d, c4, 37, 83, 45, 0b] reset_token=[6a, ab, 5d, b7, 9a, 32, a5, 5c, 4d, 03, 38, 10, 80, be, c8, 46]
[2025-04-30T18:34:10.679971399Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[4b, 71, ca, 04, a0, 47, 1d, 93, 45] reset_token=[98, a3, 79, 80, 52, 78, 8d, cf, 54, 52, 62, 7d, e6, 32, 8e, 1b]
[2025-04-30T18:34:10.679977020Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[4b, 71, 42, 43, 89, 04, a9, 6e, 18] reset_token=[e1, 2a, b0, 8a, 9e, 6e, 49, 2e, 9a, b1, 2a, 2d, 42, d7, 5d, a8]
[2025-04-30T18:34:10.679984744Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm PADDING len=1086
[2025-04-30T18:34:10.680008809Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.680013287Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.680016012Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.680024188Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.680028736Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=5 
[2025-04-30T18:34:10.680031221Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=11 blocks=[2..2] ecn_counts=None
[2025-04-30T18:34:10.680038124Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.680080463Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.680085483Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.680899226Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.680909505Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=3 
[2025-04-30T18:34:10.680915697Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm PING mtu_probe=None
[2025-04-30T18:34:10.680922469Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm PADDING len=1178
[2025-04-30T18:34:10.680928812Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.680932388Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.680934763Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.680941115Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.680944461Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=6 
[2025-04-30T18:34:10.680946895Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=4 blocks=[2..3] ecn_counts=None
[2025-04-30T18:34:10.680953097Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 6, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.680992932Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.680997049Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.681183478Z TRACE quiche_apps::client] got 366 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.681191002Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=345 pn=4 
[2025-04-30T18:34:10.681196903Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm CRYPTO off=0 len=321
[2025-04-30T18:34:10.681220257Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 366 bytes
[2025-04-30T18:34:10.681224265Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.681226769Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.681232981Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.681236217Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=7 
[2025-04-30T18:34:10.681238661Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=5 blocks=[2..4] ecn_counts=None
[2025-04-30T18:34:10.681245013Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 7, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.681279849Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.681284037Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.682214358Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.682224587Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=5 
[2025-04-30T18:34:10.682231310Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=0 len=1175 fin=false
[2025-04-30T18:34:10.682261667Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.682265674Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.682268069Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.682272918Z TRACE quiche_apps::common] received 1175 bytes
[2025-04-30T18:34:10.682275392Z TRACE quiche_apps::common] stream 0 has 1175 bytes (fin? false)
[2025-04-30T18:34:10.682282355Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.682285661Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=8 
[2025-04-30T18:34:10.682288106Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=7 blocks=[2..5] ecn_counts=None
[2025-04-30T18:34:10.682294648Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 8, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.682329614Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.682333611Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.683215402Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.683225611Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=6 
[2025-04-30T18:34:10.683232564Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=1175 len=1173 fin=false
[2025-04-30T18:34:10.683240048Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.683243685Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.683246099Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.683250438Z TRACE quiche_apps::common] received 1173 bytes
[2025-04-30T18:34:10.683252762Z TRACE quiche_apps::common] stream 0 has 1173 bytes (fin? false)
[2025-04-30T18:34:10.683259044Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.683262430Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=9 
[2025-04-30T18:34:10.683264905Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=4 blocks=[2..6] ecn_counts=None
[2025-04-30T18:34:10.683271497Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 9, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.683310711Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.683314828Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.684215525Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.684225433Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=7 
[2025-04-30T18:34:10.684231965Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=2348 len=1173 fin=false
[2025-04-30T18:34:10.684239179Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.684242756Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.684245160Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.684249288Z TRACE quiche_apps::common] received 1173 bytes
[2025-04-30T18:34:10.684251532Z TRACE quiche_apps::common] stream 0 has 1173 bytes (fin? false)
[2025-04-30T18:34:10.684257914Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.684261070Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=10 
[2025-04-30T18:34:10.684263534Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=4 blocks=[2..7] ecn_counts=None
[2025-04-30T18:34:10.684269535Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 10, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.684302888Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.684306745Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.685214896Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.685225325Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=8 
[2025-04-30T18:34:10.685232138Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=3521 len=1173 fin=false
[2025-04-30T18:34:10.685239391Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.685243048Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.685245453Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.685249500Z TRACE quiche_apps::common] received 1173 bytes
[2025-04-30T18:34:10.685251765Z TRACE quiche_apps::common] stream 0 has 1173 bytes (fin? false)
[2025-04-30T18:34:10.685257956Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.685261142Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=11 
[2025-04-30T18:34:10.685263567Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=4 blocks=[2..8] ecn_counts=None
[2025-04-30T18:34:10.685269638Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 11, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.685303642Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.685307639Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.686212733Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.686222642Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=9 
[2025-04-30T18:34:10.686229214Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=4694 len=1173 fin=false
[2025-04-30T18:34:10.686236358Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.686239955Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.686242319Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.686246396Z TRACE quiche_apps::common] received 1173 bytes
[2025-04-30T18:34:10.686248701Z TRACE quiche_apps::common] stream 0 has 1173 bytes (fin? false)
[2025-04-30T18:34:10.686254932Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.686258088Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=12 
[2025-04-30T18:34:10.686265923Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=4 blocks=[2..9] ecn_counts=None
[2025-04-30T18:34:10.686272325Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 12, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.686306439Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.686310436Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.687214138Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.687223997Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=10 
[2025-04-30T18:34:10.687230639Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=5867 len=1173 fin=false
[2025-04-30T18:34:10.687237913Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.687241530Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.687243934Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.687247902Z TRACE quiche_apps::common] received 1173 bytes
[2025-04-30T18:34:10.687250135Z TRACE quiche_apps::common] stream 0 has 1173 bytes (fin? false)
[2025-04-30T18:34:10.687256558Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.687259774Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=13 
[2025-04-30T18:34:10.687262198Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=4 blocks=[2..10] ecn_counts=None
[2025-04-30T18:34:10.687268450Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 13, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.687307924Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.687312011Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.688213519Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.688223428Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=11 
[2025-04-30T18:34:10.688229950Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=7040 len=1173 fin=false
[2025-04-30T18:34:10.688237544Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.688241111Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.688243515Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.688247613Z TRACE quiche_apps::common] received 1173 bytes
[2025-04-30T18:34:10.688249817Z TRACE quiche_apps::common] stream 0 has 1173 bytes (fin? false)
[2025-04-30T18:34:10.688271658Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.688275154Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=14 
[2025-04-30T18:34:10.688277559Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=6 blocks=[2..11] ecn_counts=None
[2025-04-30T18:34:10.688283851Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 14, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.688318406Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.688322363Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.689213221Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.689223159Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=1199 pn=12 
[2025-04-30T18:34:10.689229782Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=8213 len=1173 fin=false
[2025-04-30T18:34:10.689236875Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1220 bytes
[2025-04-30T18:34:10.689240432Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.689242836Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.689251793Z TRACE quiche_apps::common] received 1173 bytes
[2025-04-30T18:34:10.689254037Z TRACE quiche_apps::common] stream 0 has 1173 bytes (fin? false)
[2025-04-30T18:34:10.689260519Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:34:10.689263725Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=5 pn=15 
[2025-04-30T18:34:10.689266170Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm ACK delay=4 blocks=[2..12] ecn_counts=None
[2025-04-30T18:34:10.689272201Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=none latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 4, last_sent_packet: 15, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 149452711 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, 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-30T18:34:10.689306024Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.689310072Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.689957504Z TRACE quiche_apps::client] got 901 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.689964888Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx pkt Short dcid=b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 key_phase=false len=880 pn=13 
[2025-04-30T18:34:10.689971250Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 rx frm STREAM id=0 off=9386 len=854 fin=true
[2025-04-30T18:34:10.689978704Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 901 bytes
[2025-04-30T18:34:10.689982230Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.689984635Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.689990135Z TRACE quiche_apps::common] received 854 bytes
[2025-04-30T18:34:10.689992460Z TRACE quiche_apps::common] stream 0 has 854 bytes (fin? true)
[2025-04-30T18:34:10.689994764Z DEBUG quiche_apps::common] 1/1 responses received
[2025-04-30T18:34:10.689997148Z INFO  quiche_apps::common] 1/1 response(s) received in 113.768385ms, closing...
[2025-04-30T18:34:10.690003310Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1323
[2025-04-30T18:34:10.690006887Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx pkt Short dcid=4b714b9294a9995cad key_phase=false len=10 pn=16 
[2025-04-30T18:34:10.690009301Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T18:34:10.690016514Z TRACE quiche::recovery::congestion::recovery] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 timer=111.026035ms latest_rtt=32.469929ms srtt=33.472444ms min_rtt=32.469929ms rttvar=12.892305ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=37 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1498, delivered_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, first_sent_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, end_of_app_limited: 15, last_sent_packet: 16, largest_acked: 4, rate_sample: RateSample { delivery_rate: 33241, is_app_limited: true, interval: 32.820199ms, delivered: 1091, prior_delivered: 407, prior_time: Some(Instant { tv_sec: 312, tv_nsec: 116545459 }), send_elapsed: 350.27µs, ack_elapsed: 32.820199ms, rtt: 32.469929ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 504146, last_update: Instant { tv_sec: 312, tv_nsec: 159433987 }, next_time: Instant { tv_sec: 312, tv_nsec: 149452711 }, max_datagram_size: 1350, last_packet_size: None, iv: 73.391µ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-30T18:34:10.690055888Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:38519 to 193.167.100.100:443
[2025-04-30T18:34:10.690059575Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.712396832Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.712412782Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 1252 bytes
[2025-04-30T18:34:10.712416930Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.712419956Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.712425136Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.720503940Z TRACE quiche_apps::client] got 57 bytes from 193.167.100.100:443 to 0.0.0.0:38519
[2025-04-30T18:34:10.720518868Z TRACE quiche_apps::client] 0.0.0.0:38519: processed 57 bytes
[2025-04-30T18:34:10.720523085Z TRACE quiche_apps::client] 0.0.0.0:38519: recv() would block
[2025-04-30T18:34:10.720526181Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.720531211Z TRACE quiche_apps::client] 0.0.0.0:38519 -> 193.167.100.100:443: done writing
[2025-04-30T18:34:10.945815398Z TRACE quiche_apps::client] timed out
[2025-04-30T18:34:10.945852247Z TRACE quiche] b4e78ae0eb3d39681510585bc3f3f0fb41d1dda3 draining timeout expired
[2025-04-30T18:34:10.945906068Z TRACE quiche_apps::client] done reading
[2025-04-30T18:34:10.945911027Z INFO  quiche_apps::client] connection closed, recv=14 sent=17 lost=0 retrans=0 sent_bytes=2479 recv_bytes=14687 lost_bytes=0 [local_addr=0.0.0.0:38519 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=14 sent=17 lost=0 retrans=0 rtt=33.472444ms min_rtt=Some(32.469929ms) rttvar=12.892305ms cwnd=13500 sent_bytes=2479 recv_bytes=14687 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=33241]