[2025-04-30T18:32:36.514704445Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE
[2025-04-30T18:32:36.515010989Z INFO  quiche_apps::client] connecting to 193.167.100.100:443 from 0.0.0.0:46398 with scid aee8513ac40fbc12689c0b16e6a9d737f971141c
[2025-04-30T18:32:36.515052717Z TRACE quiche::tls] aee8513ac40fbc12689c0b16e6a9d737f971141c write message lvl=Initial len=266
[2025-04-30T18:32:36.515073767Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Initial version=1 dcid=f05659ad1e0a9da9e4b062e34932e4b0 scid=aee8513ac40fbc12689c0b16e6a9d737f971141c len=270 pn=0 
[2025-04-30T18:32:36.515076923Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm CRYPTO off=0 len=266
[2025-04-30T18:32:36.515092352Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=998.92539ms 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: 217, tv_nsec: 984451535 }, first_sent_time: Instant { tv_sec: 217, tv_nsec: 984451535 }, 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: 217, tv_nsec: 984451535 }, next_time: Instant { tv_sec: 217, tv_nsec: 984451535 }, 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:32:36.515177942Z TRACE quiche_apps::client] written 1200
[2025-04-30T18:32:36.553666359Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.553707536Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx pkt Initial version=1 dcid=aee8513ac40fbc12689c0b16e6a9d737f971141c scid=a13079e9c44609c782 token= len=119 pn=0 
[2025-04-30T18:32:36.553729928Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm ACK delay=3 blocks=[0..0] ecn_counts=None
[2025-04-30T18:32:36.553739877Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c packet newly acked 0
[2025-04-30T18:32:36.553749324Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm CRYPTO off=0 len=90
[2025-04-30T18:32:36.553887924Z TRACE quiche::tls] aee8513ac40fbc12689c0b16e6a9d737f971141c set write secret lvl=Handshake
[2025-04-30T18:32:36.553903393Z TRACE quiche::tls] aee8513ac40fbc12689c0b16e6a9d737f971141c set read secret lvl=Handshake
[2025-04-30T18:32:36.553943768Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx pkt Handshake version=1 dcid=aee8513ac40fbc12689c0b16e6a9d737f971141c scid=a13079e9c44609c782 len=1024 pn=1 
[2025-04-30T18:32:36.553951603Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm CRYPTO off=0 len=739
[2025-04-30T18:32:36.554209165Z TRACE quiche::tls] aee8513ac40fbc12689c0b16e6a9d737f971141c write message lvl=Handshake len=52
[2025-04-30T18:32:36.554213974Z TRACE quiche::tls] aee8513ac40fbc12689c0b16e6a9d737f971141c set write secret lvl=OneRTT
[2025-04-30T18:32:36.554223602Z TRACE quiche::tls] aee8513ac40fbc12689c0b16e6a9d737f971141c set read secret lvl=OneRTT
[2025-04-30T18:32:36.554245473Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c 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(f05659ad1e0a9da9e4b062e34932e4b0), max_idle_timeout: 30000, stateless_reset_token: Some(284214054013417561476047231821257925400), 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(a13079e9c44609c782), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None }
[2025-04-30T18:32:36.554269498Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm PADDING len=261
[2025-04-30T18:32:36.554286590Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 1220 bytes
[2025-04-30T18:32:36.554292481Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.554295998Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.554306507Z DEBUG quiche_apps::common] sending HTTP request "GET /oosypobawd\r\n"
[2025-04-30T18:32:36.554380416Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Initial version=1 dcid=a13079e9c44609c782 scid=aee8513ac40fbc12689c0b16e6a9d737f971141c len=6 pn=1 
[2025-04-30T18:32:36.554384964Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm ACK delay=84 blocks=[0..0] ecn_counts=None
[2025-04-30T18:32:36.554395564Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=115.349322ms latest_rtt=38.681699ms srtt=38.681699ms min_rtt=38.681699ms rttvar=19.340849ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, first_sent_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8608, is_app_limited: true, interval: 38.681699ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 217, tv_nsec: 984451535 }), send_elapsed: 0ns, ack_elapsed: 38.681699ms, rtt: 38.681699ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 436252, last_update: Instant { tv_sec: 218, tv_nsec: 23676010 }, next_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, 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:32:36.554421492Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Handshake version=1 dcid=a13079e9c44609c782 scid=aee8513ac40fbc12689c0b16e6a9d737f971141c len=61 pn=2 
[2025-04-30T18:32:36.554424829Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm ACK delay=59 blocks=[1..1] ecn_counts=None
[2025-04-30T18:32:36.554428706Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm CRYPTO off=0 len=52
[2025-04-30T18:32:36.554436020Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=115.97848ms latest_rtt=38.681699ms srtt=38.681699ms min_rtt=38.681699ms rttvar=19.340849ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=116 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, first_sent_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8608, is_app_limited: true, interval: 38.681699ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 217, tv_nsec: 984451535 }), send_elapsed: 0ns, ack_elapsed: 38.681699ms, rtt: 38.681699ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 436252, last_update: Instant { tv_sec: 218, tv_nsec: 23802447 }, next_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, max_datagram_size: 1350, last_packet_size: None, iv: 265.901µ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:32:36.554452591Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c dropped epoch 0 state
[2025-04-30T18:32:36.554457270Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c pmtud probe status false hs_con=false hs_sent=false cwnd_avail=13384 out_len=1172 left=1145
[2025-04-30T18:32:36.554469352Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Short dcid=a13079e9c44609c782 key_phase=false len=1145 pn=3 
[2025-04-30T18:32:36.554471967Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[2e, 81, 41, 5c, 5a, a3, fa, 82, 53, 8a, 6b, d3, 1c, 1a, 7c, ca, d9, 97, 88, 1c] reset_token=[b3, ab, 6e, 2a, dd, 23, 7b, cf, 9a, 71, 8a, 62, 74, 1d, 5f, 16]
[2025-04-30T18:32:36.554478820Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[99, 87, d5, 8d, a3, 7a, 41, 9c, 94, 86, 7f, 21, 19, 59, ed, ad, 09, 02, 6c, 90] reset_token=[44, b5, ad, 18, 78, 66, 57, 63, d6, 18, 33, d7, 42, 75, fc, 20]
[2025-04-30T18:32:36.554484611Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[0b, 25, 71, 70, 43, 92, 46, b1, 9f, ae, 6d, 0d, 37, 68, 5f, 62, 90, 4c, ab, c4] reset_token=[4e, ff, 17, 60, 99, 8e, 29, 69, 4e, 0d, ef, cf, a7, d5, d6, 21]
[2025-04-30T18:32:36.554490372Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm STREAM id=0 off=0 len=17 fin=true
[2025-04-30T18:32:36.554492986Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm PADDING len=1003
[2025-04-30T18:32:36.554500370Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=115.91416ms latest_rtt=38.681699ms srtt=38.681699ms min_rtt=38.681699ms rttvar=19.340849ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1288 app_limited=true congestion_recovery_start_time=None Rate { delivered: 333, delivered_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, first_sent_time: Instant { tv_sec: 218, tv_nsec: 23676050 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 0, rate_sample: RateSample { delivery_rate: 8608, is_app_limited: true, interval: 38.681699ms, delivered: 333, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 217, tv_nsec: 984451535 }), send_elapsed: 0ns, ack_elapsed: 38.681699ms, rtt: 38.681699ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 1172, rate: 436252, last_update: Instant { tv_sec: 218, tv_nsec: 23802447 }, next_time: Instant { tv_sec: 218, tv_nsec: 24068348 }, max_datagram_size: 1350, last_packet_size: Some(1172), 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:32:36.554546727Z TRACE quiche_apps::client] written 1350 bytes from 0.0.0.0:46398 to 193.167.100.100:443
[2025-04-30T18:32:36.554556014Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.587265136Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.587295232Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx pkt Short dcid=aee8513ac40fbc12689c0b16e6a9d737f971141c key_phase=false len=1199 pn=2 
[2025-04-30T18:32:36.587309669Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm ACK delay=0 blocks=[3..3] ecn_counts=None
[2025-04-30T18:32:36.587318656Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c packet newly acked 3
[2025-04-30T18:32:36.587324908Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm HANDSHAKE_DONE
[2025-04-30T18:32:36.587341309Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c dropped epoch 1 state
[2025-04-30T18:32:36.587347741Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[a1, 30, 46, 93, 1b, 13, 61, 54, 5d] reset_token=[a0, 66, 9c, 37, 89, 16, 5c, 3a, 33, 2f, ec, 48, d9, 1a, 37, 97]
[2025-04-30T18:32:36.587355886Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[a1, 30, c1, 5b, a8, 7f, 44, a8, 34] reset_token=[ea, f9, 1e, 9e, 15, d1, e9, 1d, 3f, d9, 49, 26, 8f, 65, 89, 11]
[2025-04-30T18:32:36.587361777Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[a1, 30, f3, 27, 77, 1e, b5, 7e, 1d] reset_token=[53, 2a, 10, 45, 46, 0a, 5c, 01, e4, 94, 3b, 20, d7, 4c, f1, ad]
[2025-04-30T18:32:36.587366766Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm NEW_CONNECTION_ID seq_num=4 retire_prior_to=1 conn_id=[f3, 52, 4d, ed, a3, 0f, aa, 49, 63] reset_token=[32, 9d, 75, 7b, 8c, e0, 83, d3, 4c, 54, 94, 58, 98, 83, c3, a1]
[2025-04-30T18:32:36.587372247Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c path ID 0 changed DCID: old seq num 0 new seq num 1
[2025-04-30T18:32:36.587375923Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm NEW_CONNECTION_ID seq_num=5 retire_prior_to=2 conn_id=[f3, 52, 2d, 64, 79, 86, 7e, 94, 0c] reset_token=[11, 2c, 2e, 5d, 28, 3c, 4a, 25, 2f, fe, d9, 66, cb, 7b, c9, 83]
[2025-04-30T18:32:36.587379831Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c path ID 0 changed DCID: old seq num 1 new seq num 2
[2025-04-30T18:32:36.587383187Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm NEW_CONNECTION_ID seq_num=6 retire_prior_to=3 conn_id=[f3, 52, 49, 5c, d3, 72, 61, d8, 7c] reset_token=[09, 01, 06, 58, 6c, fb, 1b, 49, ea, 02, 8f, 4c, dc, af, ce, 8c]
[2025-04-30T18:32:36.587387034Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c path ID 0 changed DCID: old seq num 2 new seq num 3
[2025-04-30T18:32:36.587390611Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm NEW_CONNECTION_ID seq_num=7 retire_prior_to=4 conn_id=[f3, 52, d7, fc, 98, 7f, 0a, 3b, f6] reset_token=[79, e3, 0d, db, ff, 47, 9e, e0, 49, 99, d0, 18, f4, 65, 7c, 45]
[2025-04-30T18:32:36.587394618Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c path ID 0 changed DCID: old seq num 3 new seq num 4
[2025-04-30T18:32:36.587400329Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm PADDING len=970
[2025-04-30T18:32:36.587423432Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 1220 bytes
[2025-04-30T18:32:36.587427971Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.587430676Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.587441065Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1318
[2025-04-30T18:32:36.587447548Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Short dcid=f3524deda30faa4963 key_phase=false len=13 pn=4 
[2025-04-30T18:32:36.587450122Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm ACK delay=18 blocks=[2..2] ecn_counts=None
[2025-04-30T18:32:36.587453368Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm RETIRE_CONNECTION_ID seq_num=0
[2025-04-30T18:32:36.587455653Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm RETIRE_CONNECTION_ID seq_num=3
[2025-04-30T18:32:36.587457797Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm RETIRE_CONNECTION_ID seq_num=2
[2025-04-30T18:32:36.587459920Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm RETIRE_CONNECTION_ID seq_num=1
[2025-04-30T18:32:36.587467775Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=127.945766ms latest_rtt=32.653885ms srtt=37.928221ms min_rtt=32.653885ms rttvar=16.012589ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=40 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1505, delivered_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, first_sent_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 3, rate_sample: RateSample { delivery_rate: 35465, is_app_limited: true, interval: 33.046183ms, delivered: 1172, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 218, tv_nsec: 23676050 }), send_elapsed: 392.298µs, ack_elapsed: 33.046183ms, rtt: 32.653885ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 40, rate: 444919, last_update: Instant { tv_sec: 218, tv_nsec: 56868236 }, next_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, max_datagram_size: 1350, last_packet_size: Some(40), 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:32:36.587526766Z TRACE quiche_apps::client] written 40 bytes from 0.0.0.0:46398 to 193.167.100.100:443
[2025-04-30T18:32:36.587532035Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.588219613Z TRACE quiche_apps::client] got 1220 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.588227447Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx pkt Short dcid=aee8513ac40fbc12689c0b16e6a9d737f971141c key_phase=false len=1199 pn=3 
[2025-04-30T18:32:36.588233268Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm PING mtu_probe=None
[2025-04-30T18:32:36.588239901Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm PADDING len=1178
[2025-04-30T18:32:36.588245671Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 1220 bytes
[2025-04-30T18:32:36.588249168Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.588251613Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.588257694Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13460 out_len=1350 left=1318
[2025-04-30T18:32:36.588260830Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Short dcid=f3524deda30faa4963 key_phase=false len=5 pn=5 
[2025-04-30T18:32:36.588263224Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm ACK delay=3 blocks=[2..3] ecn_counts=None
[2025-04-30T18:32:36.588269235Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=127.144486ms latest_rtt=32.653885ms srtt=37.928221ms min_rtt=32.653885ms rttvar=16.012589ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=40 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1505, delivered_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, first_sent_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, end_of_app_limited: 3, last_sent_packet: 5, largest_acked: 3, rate_sample: RateSample { delivery_rate: 35465, is_app_limited: true, interval: 33.046183ms, delivered: 1172, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 218, tv_nsec: 23676050 }), send_elapsed: 392.298µs, ack_elapsed: 33.046183ms, rtt: 32.653885ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 444919, last_update: Instant { tv_sec: 218, tv_nsec: 57687670 }, next_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, max_datagram_size: 1350, last_packet_size: None, iv: 89.904µ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:32:36.588303720Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:46398 to 193.167.100.100:443
[2025-04-30T18:32:36.588307858Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.588478718Z TRACE quiche_apps::client] got 366 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.588483717Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx pkt Short dcid=aee8513ac40fbc12689c0b16e6a9d737f971141c key_phase=false len=345 pn=4 
[2025-04-30T18:32:36.588489518Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm CRYPTO off=0 len=321
[2025-04-30T18:32:36.588544791Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 366 bytes
[2025-04-30T18:32:36.588548939Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.588551283Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.588557826Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13460 out_len=1350 left=1318
[2025-04-30T18:32:36.588560881Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Short dcid=f3524deda30faa4963 key_phase=false len=5 pn=6 
[2025-04-30T18:32:36.588563226Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm ACK delay=9 blocks=[2..4] ecn_counts=None
[2025-04-30T18:32:36.588588593Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=126.824847ms latest_rtt=32.653885ms srtt=37.928221ms min_rtt=32.653885ms rttvar=16.012589ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=40 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1505, delivered_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, first_sent_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, end_of_app_limited: 3, last_sent_packet: 6, largest_acked: 3, rate_sample: RateSample { delivery_rate: 35465, is_app_limited: true, interval: 33.046183ms, delivered: 1172, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 218, tv_nsec: 23676050 }), send_elapsed: 392.298µs, ack_elapsed: 33.046183ms, rtt: 32.653885ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 444919, last_update: Instant { tv_sec: 218, tv_nsec: 57687670 }, next_time: Instant { tv_sec: 218, tv_nsec: 58077425 }, 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:32:36.588625743Z TRACE quiche_apps::client] written 32 bytes from 0.0.0.0:46398 to 193.167.100.100:443
[2025-04-30T18:32:36.588630452Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.589401946Z TRACE quiche_apps::client] got 1069 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.589407687Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx pkt Short dcid=aee8513ac40fbc12689c0b16e6a9d737f971141c key_phase=false len=1048 pn=5 
[2025-04-30T18:32:36.589413958Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c rx frm STREAM id=0 off=0 len=1024 fin=true
[2025-04-30T18:32:36.589422494Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 1069 bytes
[2025-04-30T18:32:36.589425901Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.589428205Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.589435058Z TRACE quiche_apps::common] received 1024 bytes
[2025-04-30T18:32:36.589437733Z TRACE quiche_apps::common] stream 0 has 1024 bytes (fin? true)
[2025-04-30T18:32:36.589440688Z DEBUG quiche_apps::common] 1/1 responses received
[2025-04-30T18:32:36.589443143Z INFO  quiche_apps::common] 1/1 response(s) received in 74.260182ms, closing...
[2025-04-30T18:32:36.589449204Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13460 out_len=1350 left=1323
[2025-04-30T18:32:36.589452501Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx pkt Short dcid=f3524deda30faa4963 key_phase=false len=10 pn=7 
[2025-04-30T18:32:36.589460105Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c tx frm APPLICATION_CLOSE err=0 reason=[6b, 74, 68, 78, 62, 79, 65]
[2025-04-30T18:32:36.589466807Z TRACE quiche::recovery::congestion::recovery] aee8513ac40fbc12689c0b16e6a9d737f971141c timer=127.95857ms latest_rtt=32.653885ms srtt=37.928221ms min_rtt=32.653885ms rttvar=16.012589ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=77 app_limited=true congestion_recovery_start_time=None Rate { delivered: 1505, delivered_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, first_sent_time: Instant { tv_sec: 218, tv_nsec: 56868236 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 3, rate_sample: RateSample { delivery_rate: 35465, is_app_limited: true, interval: 33.046183ms, delivered: 1172, prior_delivered: 333, prior_time: Some(Instant { tv_sec: 218, tv_nsec: 23676050 }), send_elapsed: 392.298µs, ack_elapsed: 33.046183ms, rtt: 32.653885ms } } pacer=Pacer { enabled: true, capacity: 13500, used: 0, rate: 444919, last_update: Instant { tv_sec: 218, tv_nsec: 58879842 }, next_time: Instant { tv_sec: 218, tv_nsec: 58077425 }, max_datagram_size: 1350, last_packet_size: None, iv: 83.161µ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:32:36.589504638Z TRACE quiche_apps::client] written 37 bytes from 0.0.0.0:46398 to 193.167.100.100:443
[2025-04-30T18:32:36.589508415Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.618096950Z TRACE quiche_apps::client] got 48 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.618120705Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 48 bytes
[2025-04-30T18:32:36.618127558Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.618130984Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.618137046Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.619683833Z TRACE quiche_apps::client] got 1252 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.619696046Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 1252 bytes
[2025-04-30T18:32:36.619699823Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.619702358Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.619706195Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.619911239Z TRACE quiche_apps::client] got 57 bytes from 193.167.100.100:443 to 0.0.0.0:46398
[2025-04-30T18:32:36.619914806Z TRACE quiche_apps::client] 0.0.0.0:46398: processed 57 bytes
[2025-04-30T18:32:36.619917871Z TRACE quiche_apps::client] 0.0.0.0:46398: recv() would block
[2025-04-30T18:32:36.619920136Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.619923201Z TRACE quiche_apps::client] 0.0.0.0:46398 -> 193.167.100.100:443: done writing
[2025-04-30T18:32:36.896254103Z TRACE quiche_apps::client] timed out
[2025-04-30T18:32:36.896289449Z TRACE quiche] aee8513ac40fbc12689c0b16e6a9d737f971141c draining timeout expired
[2025-04-30T18:32:36.896341146Z TRACE quiche_apps::client] done reading
[2025-04-30T18:32:36.896346135Z INFO  quiche_apps::client] connection closed, recv=6 sent=8 lost=0 retrans=0 sent_bytes=1824 recv_bytes=5095 lost_bytes=0 [local_addr=0.0.0.0:46398 peer_addr=193.167.100.100:443 validation_state=Validated active=true recv=6 sent=8 lost=0 retrans=0 rtt=37.928221ms min_rtt=Some(32.653885ms) rttvar=16.012589ms cwnd=13500 sent_bytes=1824 recv_bytes=5095 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=35465]