[2025-04-30T08:42:17.918213356Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T08:42:17.918505000Z INFO  quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:56621 with scid f9236bd22d42aa89512cf77b29d1874d8e4ac4cb
[2025-04-30T08:42:17.918545195Z TRACE quiche::tls] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb write message lvl=Initial len=266
[2025-04-30T08:42:17.918564581Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Initial version=1 dcid=93633eefa84675a00a26ac26cce298cd scid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb len=270 pn=0 
[2025-04-30T08:42:17.918568138Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm CRYPTO off=0 len=266
[2025-04-30T08:42:17.918582404Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=998.929038ms 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: 272, tv_nsec: 286637782 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, 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: 272, tv_nsec: 286637782 }, next_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, 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:42:17.918663806Z TRACE quiche_apps::client] written 1200
[2025-04-30T08:42:18.918727803Z TRACE quiche_apps::client] timed out
[2025-04-30T08:42:18.918758531Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb loss detection timeout expired
[2025-04-30T08:42:18.918766546Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=997.744356ms 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: 272, tv_nsec: 286637782 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, 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: 272, tv_nsec: 286637782 }, next_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, 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:42:18.918788697Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:18.918827690Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Initial version=1 dcid=93633eefa84675a00a26ac26cce298cd scid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb len=270 pn=1 
[2025-04-30T08:42:18.918832238Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm CRYPTO off=0 len=266
[2025-04-30T08:42:18.918850162Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=1.997954445s latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=666 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, 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: 273, tv_nsec: 286930616 }, next_time: Instant { tv_sec: 273, tv_nsec: 286930616 }, 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:42:18.918997196Z TRACE quiche_apps::client] written 1200 bytes from 0.0.0.0:56621 to 193.167.100.100:443
[2025-04-30T08:42:18.919006403Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:19.428524979Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:19.428561627Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx pkt Initial version=1 dcid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb scid=e8d8f67e4082480150c9a3d10792b7be88e7 token= len=119 pn=1710379362 
[2025-04-30T08:42:19.428579430Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm ACK delay=0 blocks=[0..0] ecn_counts=None
[2025-04-30T08:42:19.428586794Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb packet newly acked 0
[2025-04-30T08:42:19.428593567Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm CRYPTO off=0 len=90
[2025-04-30T08:42:19.428714843Z TRACE quiche::tls] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb set write secret lvl=Handshake
[2025-04-30T08:42:19.428727236Z TRACE quiche::tls] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb set read secret lvl=Handshake
[2025-04-30T08:42:19.428768433Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx pkt Handshake version=1 dcid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb scid=e8d8f67e4082480150c9a3d10792b7be88e7 len=736 pn=1710379362 
[2025-04-30T08:42:19.428776307Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm CRYPTO off=0 len=712
[2025-04-30T08:42:19.429048345Z TRACE quiche::tls] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb write message lvl=Handshake len=36
[2025-04-30T08:42:19.429053665Z TRACE quiche::tls] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb set write secret lvl=OneRTT
[2025-04-30T08:42:19.429062031Z TRACE quiche::tls] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb set read secret lvl=OneRTT
[2025-04-30T08:42:19.429080525Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb 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(93633eefa84675a00a26ac26cce298cd), max_idle_timeout: 30000, stateless_reset_token: Some(6715693729913255492500804085459799767), 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(e8d8f67e4082480150c9a3d10792b7be88e7), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T08:42:19.429107726Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx pkt Short dcid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb key_phase=false len=225 pn=1710379362 
[2025-04-30T08:42:19.429116112Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=0 conn_id=[a3, d4, 23, 25, b0, 22, 5f, d8, 8d, 0f, 35, 41, 49, 7a, 83, 35, 55, f4] reset_token=[5a, cb, b1, ff, 9b, 1a, 5f, 50, 88, 01, 78, 08, 70, ad, e8, 5b]
[2025-04-30T08:42:19.429132211Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[48, 0b, fe, 77, 8e, eb, 56, 12, 00, 71, 64, 59, 2c, f6, a9, 78, 2e, 51] reset_token=[88, 94, 2a, a2, e9, 44, 23, ed, f0, f9, ad, 01, f0, 98, 30, 89]
[2025-04-30T08:42:19.429139585Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[7a, 87, 3b, c4, f3, c6, 05, 82, 64, 0a, 2a, 89, d6, 90, c3, 25, a8, df] reset_token=[95, 4f, b7, 4c, ee, 1c, 09, c5, 05, a2, 61, 30, 10, 53, de, 42]
[2025-04-30T08:42:19.429146458Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[a1, ba, a1, d3, ee, 2a, 9d, f0, 0d, 43, cb, 78, f0, 6e, f2, 25, 41, 7d] reset_token=[0f, fc, 4f, fe, 95, 76, 90, a1, 79, 4e, ea, b6, b8, a1, c4, 8d]
[2025-04-30T08:42:19.429153622Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[e7, 1b, 56, 7e, e8, 54, 02, 25, e9, ca, 6a, 41, 5f, ec, e6, 93, 39, 10] reset_token=[3a, ad, 2f, 88, ff, 56, 92, 65, 8d, a9, c8, f4, 5d, e8, d6, 01]
[2025-04-30T08:42:19.429159052Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm PADDING len=15
[2025-04-30T08:42:19.429167577Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 1200 bytes
[2025-04-30T08:42:19.429173228Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:19.429176605Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:19.429185852Z DEBUG quiche_apps::common] sending HTTP request "GET /zirvqetkle\r\n"
[2025-04-30T08:42:19.429276230Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Initial version=1 dcid=e8d8f67e4082480150c9a3d10792b7be88e7 scid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb len=13 pn=2 
[2025-04-30T08:42:19.429283915Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm ACK delay=89 blocks=[1710379362..1710379362] ecn_counts=None
[2025-04-30T08:42:19.429300295Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=4.019633456s latest_rtt=1.510043322s srtt=1.510043322s min_rtt=1.510043322s rttvar=755.021661ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=333 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 273, tv_nsec: 796681104 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510043322s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 272, tv_nsec: 286637782 }), send_elapsed: 0ns, ack_elapsed: 1.510043322s, rtt: 1.510043322s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11175, last_update: Instant { tv_sec: 273, tv_nsec: 797203779 }, next_time: Instant { tv_sec: 273, tv_nsec: 797203819 }, 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:42:19.429341292Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Handshake version=1 dcid=e8d8f67e4082480150c9a3d10792b7be88e7 scid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb len=53 pn=3 
[2025-04-30T08:42:19.429347123Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm ACK delay=71 blocks=[1710379362..1710379362] ecn_counts=None
[2025-04-30T08:42:19.429352893Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm CRYPTO off=0 len=36
[2025-04-30T08:42:19.429366168Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=4.019567874s latest_rtt=1.510043322s srtt=1.510043322s min_rtt=1.510043322s rttvar=755.021661ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 273, tv_nsec: 796681104 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510043322s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 272, tv_nsec: 286637782 }), send_elapsed: 0ns, ack_elapsed: 1.510043322s, rtt: 1.510043322s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11175, last_update: Instant { tv_sec: 273, tv_nsec: 797389075 }, next_time: Instant { tv_sec: 273, tv_nsec: 797203819 }, max_datagram_size: 1350, last_packet_size: None, iv: 10.469799ms, 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:42:19.429392036Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb dropped epoch 0 state
[2025-04-30T08:42:19.429398999Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13383 out_len=1155 left=1107
[2025-04-30T08:42:19.429413116Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Short dcid=e8d8f67e4082480150c9a3d10792b7be88e7 key_phase=false len=1119 pn=4 
[2025-04-30T08:42:19.429416372Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm ACK delay=36 blocks=[1710379362..1710379362] ecn_counts=None
[2025-04-30T08:42:19.429419738Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[47, e3, 46, 64, db, 42, 51, 87, 2b, ec, cf, 99, 11, 01, 92, 64, ea, 65, 88, 79] reset_token=[64, 9e, fe, 1d, 7e, 0e, f7, c6, 66, 38, 0f, 76, 57, c1, cb, d6]
[2025-04-30T08:42:19.429427232Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[83, e0, 7f, 10, a4, b3, f4, 3a, 2e, 19, 14, b0, 69, f6, 3b, e0, 1b, 3c, 4f, 8e] reset_token=[94, 27, 9e, bb, e0, ac, 5c, 56, 10, 8f, bc, 68, e4, 38, 0b, 42]
[2025-04-30T08:42:19.429433925Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[87, 9b, ff, 46, cb, fc, 59, 0d, 27, cc, 07, c7, 25, 2b, a3, 34, f0, f5, 28, ab] reset_token=[e3, cb, 80, 01, 2e, 56, 84, 58, fd, ad, a1, db, dc, ab, 6b, b0]
[2025-04-30T08:42:19.429440607Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=0 conn_id=[59, 2d, 71, f6, f7, a5, ea, 2d, ee, 6f, ac, 40, d0, ab, 4b, e3, 96, 8b, ab, 61] reset_token=[35, ab, d8, 31, eb, e1, 6b, a1, c3, 7f, ef, ae, 10, 94, c6, 0f]
[2025-04-30T08:42:19.429447089Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=0 conn_id=[26, 41, ad, f0, 2e, 9e, 4d, 25, b0, c9, b0, e1, 03, eb, f0, 17, 86, 5b, f4, e6] reset_token=[38, 63, 79, 19, 9c, b9, 7b, 97, 27, 68, 77, 47, cb, ce, a9, 94]
[2025-04-30T08:42:19.429453521Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=0 conn_id=[a5, cf, 0d, e0, dd, a7, 5b, 1d, 78, bc, 0e, 91, 79, 63, a6, 31, 82, 29, 32, 2e] reset_token=[79, ff, bf, 40, ea, 4f, 8e, bf, c5, 0f, 94, f6, 49, 16, 8c, a2]
[2025-04-30T08:42:19.429460103Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T08:42:19.429463259Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm PADDING len=845
[2025-04-30T08:42:19.429474270Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=4.529918852s latest_rtt=1.510043322s srtt=1.510043322s min_rtt=1.510043322s rttvar=755.021661ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1272 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 273, tv_nsec: 796681104 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510043322s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 272, tv_nsec: 286637782 }), send_elapsed: 0ns, ack_elapsed: 1.510043322s, rtt: 1.510043322s } } pacer=Pacer { enabled: true, capacity: 13500, used: 1155, rate: 11175, last_update: Instant { tv_sec: 273, tv_nsec: 797389075 }, next_time: Instant { tv_sec: 273, tv_nsec: 807858874 }, max_datagram_size: 1350, last_packet_size: Some(1155), 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:42:19.429537187Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:56621 to 193.167.100.100:443
[2025-04-30T08:42:19.429542818Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:19.429552165Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:19.429556253Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx pkt Short dcid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb key_phase=false len=1179 pn=1710379363 
[2025-04-30T08:42:19.429563747Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[12, c1, b8, e7, d8, 09, 8a, 40, b6, d4, c5, c7, 09, f8, d8, b2, 84, aa] reset_token=[8a, 9c, b7, bf, c0, fa, ef, 32, a3, 76, cd, 50, e4, 8b, 3c, 26]
[2025-04-30T08:42:19.429570269Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[f1, 78, 97, ce, 1d, 7d, 05, ea, 6d, 4f, fb, af, 68, aa, 97, 2a, 08, 6f] reset_token=[2e, b7, e7, 80, a3, 5b, e1, ad, 24, 47, 91, 65, 59, 43, 16, 90]
[2025-04-30T08:42:19.429581289Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm PADDING len=1083
[2025-04-30T08:42:19.429614782Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 1200 bytes
[2025-04-30T08:42:19.429620773Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:19.429623859Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:19.429632695Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12228 out_len=1350 left=1302
[2025-04-30T08:42:19.429637334Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Short dcid=e8d8f67e4082480150c9a3d10792b7be88e7 key_phase=false len=12 pn=5 
[2025-04-30T08:42:19.429640860Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm ACK delay=9 blocks=[1710379362..1710379363] ecn_counts=None
[2025-04-30T08:42:19.429650959Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=4.529741862s latest_rtt=1.510043322s srtt=1.510043322s min_rtt=1.510043322s rttvar=755.021661ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1272 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 273, tv_nsec: 796681104 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510043322s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 272, tv_nsec: 286637782 }), send_elapsed: 0ns, ack_elapsed: 1.510043322s, rtt: 1.510043322s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11175, last_update: Instant { tv_sec: 273, tv_nsec: 797754296 }, next_time: Instant { tv_sec: 273, tv_nsec: 807858874 }, max_datagram_size: 1350, last_packet_size: None, iv: 103.355705ms, 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:42:19.429696014Z TRACE quiche_apps::client] written 48 bytes from 0.0.0.0:56621 to 193.167.100.100:443
[2025-04-30T08:42:19.429700632Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:19.728372618Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:19.728401122Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb dropped invalid packet
[2025-04-30T08:42:19.728406702Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 1200 bytes
[2025-04-30T08:42:19.728411871Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:19.728415198Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:19.728423713Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:20.422029695Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:20.422064900Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb dropped invalid packet
[2025-04-30T08:42:20.422070441Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 1200 bytes
[2025-04-30T08:42:20.422075761Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:20.422079087Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:20.422087873Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:20.933634180Z TRACE quiche_apps::client] got 1342 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:20.933670437Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx pkt Short dcid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb key_phase=false len=1321 pn=1710379366 
[2025-04-30T08:42:20.933686086Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm PING mtu_probe=None
[2025-04-30T08:42:20.933696115Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm PADDING len=1303
[2025-04-30T08:42:20.933711894Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 1342 bytes
[2025-04-30T08:42:20.933717234Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:20.933720561Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:20.933734336Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb pmtud probe status false hs_con=false hs_sent=false cwnd_avail=12228 out_len=1350 left=1300
[2025-04-30T08:42:20.933740728Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Short dcid=e8d8f67e4082480150c9a3d10792b7be88e7 key_phase=false len=14 pn=6 
[2025-04-30T08:42:20.933743914Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm ACK delay=8 blocks=[1710379362..1710379363, 1710379366..1710379366] ecn_counts=None
[2025-04-30T08:42:20.933756658Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=3.025636033s latest_rtt=1.510043322s srtt=1.510043322s min_rtt=1.510043322s rttvar=755.021661ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1272 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 273, tv_nsec: 796681104 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, end_of_app_limited: 3, last_sent_packet: 6, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510043322s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 272, tv_nsec: 286637782 }), send_elapsed: 0ns, ack_elapsed: 1.510043322s, rtt: 1.510043322s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11175, last_update: Instant { tv_sec: 275, tv_nsec: 301851849 }, next_time: Instant { tv_sec: 275, tv_nsec: 405207554 }, 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:42:20.933837228Z TRACE quiche_apps::client] written 50 bytes from 0.0.0.0:56621 to 193.167.100.100:443
[2025-04-30T08:42:20.933843620Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:20.934487710Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:20.934497148Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx pkt Short dcid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb key_phase=false len=1179 pn=1710379367 
[2025-04-30T08:42:20.934504351Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm HANDSHAKE_DONE
[2025-04-30T08:42:20.934510803Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb dropped epoch 1 state
[2025-04-30T08:42:20.934516324Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm NEW_TOKEN len=41
[2025-04-30T08:42:20.934519940Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm CRYPTO off=0 len=237
[2025-04-30T08:42:20.934545057Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm STREAM id=0 off=0 len=873 fin=false
[2025-04-30T08:42:20.934557020Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 1200 bytes
[2025-04-30T08:42:20.934561157Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:20.934563632Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:20.934568782Z TRACE quiche_apps::common] received 873 bytes
[2025-04-30T08:42:20.934571537Z TRACE quiche_apps::common] stream 0 has 873 bytes (fin? false)
[2025-04-30T08:42:20.934578890Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=12345 out_len=1350 left=1300
[2025-04-30T08:42:20.934582457Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Short dcid=e8d8f67e4082480150c9a3d10792b7be88e7 key_phase=false len=14 pn=7 
[2025-04-30T08:42:20.934585012Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm ACK delay=10 blocks=[1710379362..1710379363, 1710379366..1710379367] ecn_counts=None
[2025-04-30T08:42:20.934592315Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=3.049800777s latest_rtt=1.510043322s srtt=1.510043322s min_rtt=1.510043322s rttvar=755.021661ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1155 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 273, tv_nsec: 796681104 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, end_of_app_limited: 3, last_sent_packet: 7, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510043322s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 272, tv_nsec: 286637782 }), send_elapsed: 0ns, ack_elapsed: 1.510043322s, rtt: 1.510043322s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11175, last_update: Instant { tv_sec: 275, tv_nsec: 301851849 }, next_time: Instant { tv_sec: 275, tv_nsec: 405207554 }, 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:42:20.934632029Z TRACE quiche_apps::client] written 50 bytes from 0.0.0.0:56621 to 193.167.100.100:443
[2025-04-30T08:42:20.934636658Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:20.935474029Z TRACE quiche_apps::client] got 1200 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:20.935492072Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx pkt Short dcid=f9236bd22d42aa89512cf77b29d1874d8e4ac4cb key_phase=false len=1179 pn=1710379368 
[2025-04-30T08:42:20.935499546Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm STREAM id=0 off=873 len=151 fin=true
[2025-04-30T08:42:20.935507060Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb rx frm PADDING len=1005
[2025-04-30T08:42:20.935514685Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 1200 bytes
[2025-04-30T08:42:20.935518652Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:20.935521137Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:20.935525585Z TRACE quiche_apps::common] received 151 bytes
[2025-04-30T08:42:20.935528019Z TRACE quiche_apps::common] stream 0 has 151 bytes (fin? true)
[2025-04-30T08:42:20.935530384Z DEBUG quiche_apps::common] 1/1 responses received
[2025-04-30T08:42:20.935532798Z INFO  quiche_apps::common] 1/1 response(s) received in 3.016864474s, closing...
[2025-04-30T08:42:20.935540162Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb pmtud probe status false hs_con=true hs_sent=false cwnd_avail=12345 out_len=1350 left=1314
[2025-04-30T08:42:20.935544039Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx pkt Short dcid=e8d8f67e4082480150c9a3d10792b7be88e7 key_phase=false len=10 pn=8 
[2025-04-30T08:42:20.935546554Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T08:42:20.935555000Z TRACE quiche::recovery::congestion::recovery] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb timer=4.555111763s latest_rtt=1.510043322s srtt=1.510043322s min_rtt=1.510043322s rttvar=755.021661ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1201 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 273, tv_nsec: 796681104 }, first_sent_time: Instant { tv_sec: 272, tv_nsec: 286637782 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 0, rate_sample: RateSample { delivery_rate: 220, is_app_limited: true, interval: 1.510043322s, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 272, tv_nsec: 286637782 }), send_elapsed: 0ns, ack_elapsed: 1.510043322s, rtt: 1.510043322s } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 11175, last_update: Instant { tv_sec: 275, tv_nsec: 303662735 }, next_time: Instant { tv_sec: 275, tv_nsec: 405207554 }, max_datagram_size: 1350, last_packet_size: None, iv: 4.116331ms, 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:42:20.935594303Z TRACE quiche_apps::client] written 46 bytes from 0.0.0.0:56621 to 193.167.100.100:443
[2025-04-30T08:42:20.935598370Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:20.957018232Z TRACE quiche_apps::client] got 44 bytes from 193.167.100.100:443 to 0.0.0.0:56621
[2025-04-30T08:42:20.957033030Z TRACE quiche_apps::client] 0.0.0.0:56621: processed 44 bytes
[2025-04-30T08:42:20.957038370Z TRACE quiche_apps::client] 0.0.0.0:56621: recv() would block
[2025-04-30T08:42:20.957041526Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:20.957046385Z TRACE quiche_apps::client] 0.0.0.0:56621 -> 193.167.100.100:443: done writing
[2025-04-30T08:42:34.538956632Z TRACE quiche_apps::client] timed out
[2025-04-30T08:42:34.539002117Z TRACE quiche] f9236bd22d42aa89512cf77b29d1874d8e4ac4cb draining timeout expired
[2025-04-30T08:42:34.539065014Z TRACE quiche_apps::client] done reading
[2025-04-30T08:42:34.539071867Z INFO  quiche_apps::client] connection closed, recv=7 sent=9 lost=0 retrans=1 sent_bytes=2210 recv_bytes=6142 lost_bytes=0 [local_addr=0.0.0.0:56621 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=7 sent=9 lost=0 retrans=1 rtt=1.510043322s min_rtt=Some(1.510043322s) rttvar=755.021661ms cwnd=13500 sent_bytes=2210 recv_bytes=6142 lost_bytes=0 stream_retrans_bytes=266 pmtu=1350 delivery_rate=220]