[2025-04-30T08:41:41.109222287Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T08:41:41.109515505Z INFO  quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:56902 with scid 5343b25a68716eebd05b305d6269acf7a401ad29
[2025-04-30T08:41:41.109555770Z TRACE quiche::tls] 5343b25a68716eebd05b305d6269acf7a401ad29 write message lvl=Initial len=266
[2025-04-30T08:41:41.109574616Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Initial version=1 dcid=7c3adf109252d5ba5a24250554293a88 scid=5343b25a68716eebd05b305d6269acf7a401ad29 len=270 pn=0 
[2025-04-30T08:41:41.109577752Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm CRYPTO off=0 len=266
[2025-04-30T08:41:41.109591718Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=998.930701ms 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: 235, tv_nsec: 477648578 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 477648578 }, 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: 235, tv_nsec: 477648578 }, next_time: Instant { tv_sec: 235, tv_nsec: 477648578 }, max_datagram_size: 1350, last_packet_size: None, iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.109665075Z TRACE quiche_apps::client] written 1200
[2025-04-30T08:41:41.149109081Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56902
[2025-04-30T08:41:41.149135921Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx pkt Initial version=1 dcid=5343b25a68716eebd05b305d6269acf7a401ad29 scid=38ef6cd01d48266e33b8ed7331942ecf9d41 token= len=119 pn=1633564916 
[2025-04-30T08:41:41.149151721Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T08:41:41.149158593Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 packet newly acked 0
[2025-04-30T08:41:41.149164244Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm CRYPTO off=0 len=90
[2025-04-30T08:41:41.149258180Z TRACE quiche::tls] 5343b25a68716eebd05b305d6269acf7a401ad29 set write secret lvl=Handshake
[2025-04-30T08:41:41.149268369Z TRACE quiche::tls] 5343b25a68716eebd05b305d6269acf7a401ad29 set read secret lvl=Handshake
[2025-04-30T08:41:41.149301280Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx pkt Handshake version=1 dcid=5343b25a68716eebd05b305d6269acf7a401ad29 scid=38ef6cd01d48266e33b8ed7331942ecf9d41 len=736 pn=1633564916 
[2025-04-30T08:41:41.149307432Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm CRYPTO off=0 len=712
[2025-04-30T08:41:41.149530940Z TRACE quiche::tls] 5343b25a68716eebd05b305d6269acf7a401ad29 write message lvl=Handshake len=36
[2025-04-30T08:41:41.149535077Z TRACE quiche::tls] 5343b25a68716eebd05b305d6269acf7a401ad29 set write secret lvl=OneRTT
[2025-04-30T08:41:41.149541750Z TRACE quiche::tls] 5343b25a68716eebd05b305d6269acf7a401ad29 set read secret lvl=OneRTT
[2025-04-30T08:41:41.149556949Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 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(7c3adf109252d5ba5a24250554293a88), max_idle_timeout: 30000, stateless_reset_token: Some(183109906347380896113083139575761994619), max_udp_payload_size: 65527, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 0, initial_max_stream_data_bidi_remote: 262144, initial_max_stream_data_uni: 262144, initial_max_streams_bidi: 100, initial_max_streams_uni: 0, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: false, active_conn_id_limit: 7, initial_source_connection_id: Some(38ef6cd01d48266e33b8ed7331942ecf9d41), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T08:41:41.149587045Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx pkt Short dcid=5343b25a68716eebd05b305d6269acf7a401ad29 key_phase=false len=225 pn=1633564916 
[2025-04-30T08:41:41.149594198Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[e1, 0e, 88, 18, 43, 9c, f3, 3e, 7a, b3, f8, 87, 30, 53, 87, 36, 07, 08] reset_token=[ae, d0, 86, 2e, e4, a5, 19, b2, 25, ca, 4d, 1c, 9c, 74, 01, 08]
[2025-04-30T08:41:41.149602043Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[25, 00, 71, 7c, cf, f5, 7e, 61, 8c, 69, 5e, 22, a4, 11, df, f4, 14, ca] reset_token=[a3, 7b, b3, 3e, 51, a8, 54, 50, a2, 84, ff, 3a, 2f, b1, fa, 73]
[2025-04-30T08:41:41.149607773Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[75, 29, 34, 7c, 88, 13, 2f, a9, 6c, aa, ea, b4, d1, a7, b4, 63, 2c, 99] reset_token=[1b, d9, 4d, a0, 01, 15, 97, a3, 4e, 74, e0, 6e, 91, a9, 26, 50]
[2025-04-30T08:41:41.149613063Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[9a, 77, b9, d5, ba, 33, 8c, 24, f7, 35, 83, 75, d5, 2d, 44, d9, 13, 3b] reset_token=[5d, b2, a9, bb, 30, e7, d5, fe, 8a, d8, 48, 19, 4c, 68, d4, 7e]
[2025-04-30T08:41:41.149618754Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[3a, c7, 8b, a8, 73, e7, 9e, d9, 89, 3f, 2b, ba, cb, 88, 5b, 55, fc, 0a] reset_token=[cf, d7, 0b, 88, 1f, 19, eb, 17, 5b, c2, 46, 82, 92, c4, 0d, 38]
[2025-04-30T08:41:41.149623042Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm PADDING len=15
[2025-04-30T08:41:41.149630065Z TRACE quiche_apps::client] 0.0.0.0:56902: processed 1200 bytes
[2025-04-30T08:41:41.149634884Z TRACE quiche_apps::client] 0.0.0.0:56902: recv() would block
[2025-04-30T08:41:41.149637479Z TRACE quiche_apps::client] done reading
[2025-04-30T08:41:41.149646045Z DEBUG quiche_apps::common] sending HTTP request "GET /clefoptdgg\r\n"
[2025-04-30T08:41:41.149713291Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Initial version=1 dcid=38ef6cd01d48266e33b8ed7331942ecf9d41 scid=5343b25a68716eebd05b305d6269acf7a401ad29 len=13 pn=1 
[2025-04-30T08:41:41.149717098Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm ACK delay=72 blocks=[1633564916..1633564916] ecn_counts=None
[2025-04-30T08:41:41.149726135Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=118.226386ms latest_rtt=39.607491ms srtt=39.607491ms min_rtt=39.607491ms rttvar=19.803745ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8407, is_app_limited: true, interval: 39.607491ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 235, tv_nsec: 477648578 }), send_elapsed: 0ns, ack_elapsed: 39.607491ms, rtt: 39.607491ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426055, last_update: Instant { tv_sec: 235, tv_nsec: 517680553 }, next_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.149752384Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Handshake version=1 dcid=38ef6cd01d48266e33b8ed7331942ecf9d41 scid=5343b25a68716eebd05b305d6269acf7a401ad29 len=52 pn=2 
[2025-04-30T08:41:41.149755209Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm ACK delay=56 blocks=[1633564916..1633564916] ecn_counts=None
[2025-04-30T08:41:41.149757814Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm CRYPTO off=0 len=36
[2025-04-30T08:41:41.149763705Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=118.762509ms latest_rtt=39.607491ms srtt=39.607491ms min_rtt=39.607491ms rttvar=19.803745ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=116 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8407, is_app_limited: true, interval: 39.607491ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 235, tv_nsec: 477648578 }), send_elapsed: 0ns, ack_elapsed: 39.607491ms, rtt: 39.607491ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426055, last_update: Instant { tv_sec: 235, tv_nsec: 517829552 }, next_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, max_datagram_size: 1350, last_packet_size: None, iv: 272.265µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.149775157Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 dropped epoch 0 state
[2025-04-30T08:41:41.149779875Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13384 out_len=1156 left=1108
[2025-04-30T08:41:41.149791447Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Short dcid=38ef6cd01d48266e33b8ed7331942ecf9d41 key_phase=false len=1120 pn=3 
[2025-04-30T08:41:41.149794062Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm ACK delay=24 blocks=[1633564916..1633564916] ecn_counts=None
[2025-04-30T08:41:41.149796617Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[be, ab, c9, 77, fc, 98, 92, eb, f5, 44, 9f, 50, 95, 81, 7e, 9e, 91, e4, 1f, 47] reset_token=[1c, 3d, fd, 57, 33, 89, a1, 76, 27, cf, 78, 40, e6, fb, d7, 20]
[2025-04-30T08:41:41.149802408Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[58, 7a, d0, e0, 8a, 03, 27, e0, a5, 37, 20, 96, 89, b9, e8, 03, 6d, e6, 85, e7] reset_token=[c9, 96, 67, f4, 92, a1, 79, c7, 09, 33, 17, 6e, 38, 41, 56, a8]
[2025-04-30T08:41:41.149807938Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[c4, e6, c1, ee, b6, 24, 0b, fc, a9, 20, 6c, 68, 9c, 92, 48, 5f, 1b, 28, a3, f8] reset_token=[f4, ba, d8, e5, 04, 2f, 50, d2, e3, a9, 07, 72, b0, 83, d9, ef]
[2025-04-30T08:41:41.149813328Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[1a, aa, b3, b8, bc, 7f, 32, 4c, 93, 19, bc, 97, 18, 94, f9, 85, 4e, ef, f9, 79] reset_token=[c6, bc, e0, 28, bb, cb, 14, 0b, f9, ba, 3c, 45, ed, 4a, 3a, a9]
[2025-04-30T08:41:41.149818548Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[c0, a8, 38, fa, 19, 16, 4b, 12, 1f, 41, b5, 41, e7, e1, b5, e4, 10, 71, e8, 4b] reset_token=[21, ce, 54, 74, 95, c0, 23, c1, 2f, 6c, e9, 39, ab, 37, bd, 44]
[2025-04-30T08:41:41.149826943Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[59, 1d, df, 7f, 11, 79, 26, f0, 63, 9d, 0f, 83, 38, ef, b7, 00, 02, a6, 69, 39] reset_token=[a2, 55, b5, f8, e0, 79, c8, 58, ad, d0, 42, fe, c7, 00, d5, 35]
[2025-04-30T08:41:41.149832333Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T08:41:41.149834938Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm PADDING len=846
[2025-04-30T08:41:41.149843314Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=118.68291ms latest_rtt=39.607491ms srtt=39.607491ms min_rtt=39.607491ms rttvar=19.803745ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1272 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8407, is_app_limited: true, interval: 39.607491ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 235, tv_nsec: 477648578 }), send_elapsed: 0ns, ack_elapsed: 39.607491ms, rtt: 39.607491ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1156, rate: 426055, last_update: Instant { tv_sec: 235, tv_nsec: 517829552 }, next_time: Instant { tv_sec: 235, tv_nsec: 518101817 }, max_datagram_size: 1350, last_packet_size: Some(1156), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.149911181Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:56902 to 193.167.100.100:443
[2025-04-30T08:41:41.149921801Z TRACE quiche_apps::client] 0.0.0.0:56902 -> 193.167.100.100:443: done writing
[2025-04-30T08:41:41.150069256Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56902
[2025-04-30T08:41:41.150074076Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx pkt Short dcid=5343b25a68716eebd05b305d6269acf7a401ad29 key_phase=false len=1179 pn=1633564917 
[2025-04-30T08:41:41.150081860Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[8e, 57, 9b, 79, c3, 91, 8f, ef, 5a, 89, c9, 75, 72, 35, e7, 15, eb, 8d] reset_token=[96, a6, 44, 9a, 32, 4f, e8, de, 17, e4, 5a, cc, 45, 7c, 43, 6d]
[2025-04-30T08:41:41.150088523Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[d3, 37, 61, b6, 33, ba, 5d, 30, cc, 89, 36, 0f, 82, 40, e8, 61, b4, df] reset_token=[d9, 82, 09, 08, 56, 5b, f8, 72, f3, fe, 4b, 53, 60, 31, 81, 75]
[2025-04-30T08:41:41.150096658Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm PADDING len=1083
[2025-04-30T08:41:41.150103831Z TRACE quiche_apps::client] 0.0.0.0:56902: processed 1200 bytes
[2025-04-30T08:41:41.150107478Z TRACE quiche_apps::client] 0.0.0.0:56902: recv() would block
[2025-04-30T08:41:41.150109803Z TRACE quiche_apps::client] done reading
[2025-04-30T08:41:41.150115783Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12228 out_len=1350 left=1302
[2025-04-30T08:41:41.150118960Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Short dcid=38ef6cd01d48266e33b8ed7331942ecf9d41 key_phase=false len=12 pn=4 
[2025-04-30T08:41:41.150121404Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm ACK delay=5 blocks=[1633564916..1633564917] ecn_counts=None
[2025-04-30T08:41:41.150127586Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=118.398508ms latest_rtt=39.607491ms srtt=39.607491ms min_rtt=39.607491ms rttvar=19.803745ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1272 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, end_of_app_limited: 2, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8407, is_app_limited: true, interval: 39.607491ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 235, tv_nsec: 477648578 }), send_elapsed: 0ns, ack_elapsed: 39.607491ms, rtt: 39.607491ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426055, last_update: Instant { tv_sec: 235, tv_nsec: 518238697 }, next_time: Instant { tv_sec: 235, tv_nsec: 518101817 }, max_datagram_size: 1350, last_packet_size: None, iv: 2.713265ms, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.150167039Z TRACE quiche_apps::client] written 48 bytes from 0.0.0.0:56902 to 193.167.100.100:443
[2025-04-30T08:41:41.150171398Z TRACE quiche_apps::client] 0.0.0.0:56902 -> 193.167.100.100:443: done writing
[2025-04-30T08:41:41.183562773Z TRACE quiche_apps::client] got 1342 bytes from 193.167.100.100:443 to 0.0.0.0:56902
[2025-04-30T08:41:41.183588361Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx pkt Short dcid=5343b25a68716eebd05b305d6269acf7a401ad29 key_phase=false len=1321 pn=1633564918 
[2025-04-30T08:41:41.183603580Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm PING mtu_probe=None
[2025-04-30T08:41:41.183613137Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm PADDING len=1303
[2025-04-30T08:41:41.183657280Z TRACE quiche_apps::client] 0.0.0.0:56902: processed 1342 bytes
[2025-04-30T08:41:41.183663161Z TRACE quiche_apps::client] 0.0.0.0:56902: recv() would block
[2025-04-30T08:41:41.183666437Z TRACE quiche_apps::client] done reading
[2025-04-30T08:41:41.183679542Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12228 out_len=1350 left=1302
[2025-04-30T08:41:41.183686234Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Short dcid=38ef6cd01d48266e33b8ed7331942ecf9d41 key_phase=false len=12 pn=5 
[2025-04-30T08:41:41.183689290Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm ACK delay=11 blocks=[1633564916..1633564918] ecn_counts=None
[2025-04-30T08:41:41.183701182Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=84.824611ms latest_rtt=39.607491ms srtt=39.607491ms min_rtt=39.607491ms rttvar=19.803745ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1272 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, end_of_app_limited: 2, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8407, is_app_limited: true, interval: 39.607491ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 235, tv_nsec: 477648578 }), send_elapsed: 0ns, ack_elapsed: 39.607491ms, rtt: 39.607491ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426055, last_update: Instant { tv_sec: 235, tv_nsec: 551797686 }, next_time: Instant { tv_sec: 235, tv_nsec: 554510951 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.183759191Z TRACE quiche_apps::client] written 48 bytes from 0.0.0.0:56902 to 193.167.100.100:443
[2025-04-30T08:41:41.183764611Z TRACE quiche_apps::client] 0.0.0.0:56902 -> 193.167.100.100:443: done writing
[2025-04-30T08:41:41.184505907Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56902
[2025-04-30T08:41:41.184513642Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx pkt Short dcid=5343b25a68716eebd05b305d6269acf7a401ad29 key_phase=false len=1179 pn=1633564919 
[2025-04-30T08:41:41.184519522Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm HANDSHAKE_DONE
[2025-04-30T08:41:41.184525724Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 dropped epoch 1 state
[2025-04-30T08:41:41.184531024Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm NEW_TOKEN len=41
[2025-04-30T08:41:41.184533960Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm CRYPTO off=0 len=237
[2025-04-30T08:41:41.184557764Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm STREAM id=0 off=0 len=873 fin=false
[2025-04-30T08:41:41.184568173Z TRACE quiche_apps::client] 0.0.0.0:56902: processed 1200 bytes
[2025-04-30T08:41:41.184571971Z TRACE quiche_apps::client] 0.0.0.0:56902: recv() would block
[2025-04-30T08:41:41.184574505Z TRACE quiche_apps::client] done reading
[2025-04-30T08:41:41.184579735Z TRACE quiche_apps::common] received 873 bytes
[2025-04-30T08:41:41.184582330Z TRACE quiche_apps::common] stream 0 has 873 bytes (fin? false)
[2025-04-30T08:41:41.184589373Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=12344 out_len=1350 left=1302
[2025-04-30T08:41:41.184592659Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Short dcid=38ef6cd01d48266e33b8ed7331942ecf9d41 key_phase=false len=12 pn=6 
[2025-04-30T08:41:41.184595044Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm ACK delay=9 blocks=[1633564916..1633564919] ecn_counts=None
[2025-04-30T08:41:41.184601997Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=108.924067ms latest_rtt=39.607491ms srtt=39.607491ms min_rtt=39.607491ms rttvar=19.803745ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1156 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, end_of_app_limited: 2, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8407, is_app_limited: true, interval: 39.607491ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 235, tv_nsec: 477648578 }), send_elapsed: 0ns, ack_elapsed: 39.607491ms, rtt: 39.607491ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426055, last_update: Instant { tv_sec: 235, tv_nsec: 551797686 }, next_time: Instant { tv_sec: 235, tv_nsec: 554510951 }, max_datagram_size: 1350, last_packet_size: Some(0), iv: 0ns, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.184639136Z TRACE quiche_apps::client] written 48 bytes from 0.0.0.0:56902 to 193.167.100.100:443
[2025-04-30T08:41:41.184643514Z TRACE quiche_apps::client] 0.0.0.0:56902 -> 193.167.100.100:443: done writing
[2025-04-30T08:41:41.185478135Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56902
[2025-04-30T08:41:41.185485729Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx pkt Short dcid=5343b25a68716eebd05b305d6269acf7a401ad29 key_phase=false len=1179 pn=1633564920 
[2025-04-30T08:41:41.185491861Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm STREAM id=0 off=873 len=151 fin=true
[2025-04-30T08:41:41.185498754Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 rx frm PADDING len=1005
[2025-04-30T08:41:41.185513231Z TRACE quiche_apps::client] 0.0.0.0:56902: processed 1200 bytes
[2025-04-30T08:41:41.185516867Z TRACE quiche_apps::client] 0.0.0.0:56902: recv() would block
[2025-04-30T08:41:41.185519292Z TRACE quiche_apps::client] done reading
[2025-04-30T08:41:41.185523540Z TRACE quiche_apps::common] received 151 bytes
[2025-04-30T08:41:41.185525804Z TRACE quiche_apps::common] stream 0 has 151 bytes (fin? true)
[2025-04-30T08:41:41.185528108Z DEBUG quiche_apps::common] 1/1 responses received
[2025-04-30T08:41:41.185530393Z INFO  quiche_apps::common] 1/1 response(s) received in 75.86092ms, closing...
[2025-04-30T08:41:41.185538328Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 pmtud probe status false hs_con=true hs_sent=false cwnd_avail=12344 out_len=1350 left=1314
[2025-04-30T08:41:41.185541985Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx pkt Short dcid=38ef6cd01d48266e33b8ed7331942ecf9d41 key_phase=false len=10 pn=7 
[2025-04-30T08:41:41.185544439Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T08:41:41.185554207Z TRACE quiche::recovery::congestion::recovery] 5343b25a68716eebd05b305d6269acf7a401ad29 timer=143.803075ms latest_rtt=39.607491ms srtt=39.607491ms min_rtt=39.607491ms rttvar=19.803745ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1202 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, first_sent_time: Instant { tv_sec: 235, tv_nsec: 517680593 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8407, is_app_limited: true, interval: 39.607491ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 235, tv_nsec: 477648578 }), send_elapsed: 0ns, ack_elapsed: 39.607491ms, rtt: 39.607491ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 426055, last_update: Instant { tv_sec: 235, tv_nsec: 553660750 }, next_time: Instant { tv_sec: 235, tv_nsec: 554510951 }, max_datagram_size: 1350, last_packet_size: None, iv: 107.967µs, max_pacing_rate: None } hystart=window_end=Some(0) last_round_min_rtt=18446744073709551615.999999999s current_round_min_rtt=18446744073709551615.999999999s css_baseline_min_rtt=18446744073709551615.999999999s rtt_sample_count=0 css_start_time=None css_round_count=0 cubic={ k=0 w_max=0 } 
[2025-04-30T08:41:41.185592379Z TRACE quiche_apps::client] written 46 bytes from 0.0.0.0:56902 to 193.167.100.100:443
[2025-04-30T08:41:41.185596286Z TRACE quiche_apps::client] 0.0.0.0:56902 -> 193.167.100.100:443: done writing
[2025-04-30T08:41:41.185856493Z TRACE quiche_apps::client] got 44 bytes from 193.167.100.100:443 to 0.0.0.0:56902
[2025-04-30T08:41:41.185860941Z TRACE quiche_apps::client] 0.0.0.0:56902: processed 44 bytes
[2025-04-30T08:41:41.185864127Z TRACE quiche_apps::client] 0.0.0.0:56902: recv() would block
[2025-04-30T08:41:41.185866471Z TRACE quiche_apps::client] done reading
[2025-04-30T08:41:41.185869898Z TRACE quiche_apps::client] 0.0.0.0:56902 -> 193.167.100.100:443: done writing
[2025-04-30T08:41:41.543312948Z TRACE quiche_apps::client] timed out
[2025-04-30T08:41:41.543347192Z TRACE quiche] 5343b25a68716eebd05b305d6269acf7a401ad29 draining timeout expired
[2025-04-30T08:41:41.543396044Z TRACE quiche_apps::client] done reading
[2025-04-30T08:41:41.543400723Z INFO  quiche_apps::client] connection closed, recv=7 sent=8 lost=0 retrans=0 sent_bytes=1873 recv_bytes=6142 lost_bytes=0 [local_addr=0.0.0.0:56902 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=7 sent=8 lost=0 retrans=0 rtt=39.607491ms min_rtt=Some(39.607491ms) rttvar=19.803745ms cwnd=13500 sent_bytes=1873 recv_bytes=6142 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=8407]