[2025-04-30T12:24:41.390425314Z INFO quiche_server] listening on [::]:443 [2025-04-30T12:24:41.390450992Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-04-30T12:24:41.390458065Z TRACE quiche_server] GSO detected: false [2025-04-30T12:24:42.234159659Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:51977 to [::]:443 [2025-04-30T12:24:42.234192460Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:24:42.234200766Z WARN quiche_server] Doing version negotiation [2025-04-30T12:24:42.234297697Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:51977 to [::]:443 [2025-04-30T12:24:42.234303898Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:24:42.234307745Z WARN quiche_server] Doing version negotiation [2025-04-30T12:24:42.234328043Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:51977 to [::]:443 [2025-04-30T12:24:42.234332101Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-04-30T12:24:42.234335347Z WARN quiche_server] Doing version negotiation [2025-04-30T12:24:42.234355224Z TRACE quiche_server] recv() would block [2025-04-30T12:24:43.166409316Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:57729 to [::]:443 [2025-04-30T12:24:43.166437639Z TRACE quiche_server] got packet Initial version=1 dcid=822cd04c6de5a6a1 scid=0c44af4a282d1fff token= [2025-04-30T12:24:43.166452697Z DEBUG quiche_server] New connection: dcid=822cd04c6de5a6a1 scid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b [2025-04-30T12:24:43.166674711Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Initial version=1 dcid=822cd04c6de5a6a1 scid=0c44af4a282d1fff token= len=270 pn=0 [2025-04-30T12:24:43.166686513Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm CRYPTO off=0 len=249 [2025-04-30T12:24:43.166713393Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-04-30T12:24:43.166720046Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-04-30T12:24:43.166828608Z TRACE quiche::tls] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b write message lvl=Initial len=90 [2025-04-30T12:24:43.166858574Z TRACE quiche::tls] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b set write secret lvl=Handshake [2025-04-30T12:24:43.166923425Z TRACE quiche::tls] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b write message lvl=Handshake len=697 [2025-04-30T12:24:43.166926421Z TRACE quiche::tls] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b set write secret lvl=OneRTT [2025-04-30T12:24:43.166932823Z TRACE quiche::tls] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b set read secret lvl=Handshake [2025-04-30T12:24:43.166964451Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b dropped invalid packet [2025-04-30T12:24:43.166967467Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b processed 1200 bytes [2025-04-30T12:24:43.166975893Z TRACE quiche_server] recv() would block [2025-04-30T12:24:43.167012281Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx pkt Initial version=1 dcid=0c44af4a282d1fff scid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b len=99 pn=0 [2025-04-30T12:24:43.167019164Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm ACK delay=44 blocks=[0..0] ecn_counts=None [2025-04-30T12:24:43.167024263Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm CRYPTO off=0 len=90 [2025-04-30T12:24:43.167035123Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b timer=998.941831ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=154 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, first_sent_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, 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: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 285, tv_nsec: 666997230 }, next_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, 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-30T12:24:43.167064328Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx pkt Handshake version=1 dcid=0c44af4a282d1fff scid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b len=701 pn=1 [2025-04-30T12:24:43.167067193Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm CRYPTO off=0 len=697 [2025-04-30T12:24:43.167072713Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b timer=998.905153ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=909 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, first_sent_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, 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: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 285, tv_nsec: 666997230 }, next_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, 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-30T12:24:43.167127987Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:57729, at: Instant { tv_sec: 285, tv_nsec: 666997230 } }) [2025-04-30T12:24:43.167134408Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:43.167139528Z TRACE quiche_server] recv() would block [2025-04-30T12:24:43.167143315Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b done writing [2025-04-30T12:24:43.167145629Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:44.160652861Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:57729 to [::]:443 [2025-04-30T12:24:44.160686153Z TRACE quiche_server] got packet Initial version=1 dcid=822cd04c6de5a6a1 scid=0c44af4a282d1fff token= [2025-04-30T12:24:44.160700781Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Initial version=1 dcid=822cd04c6de5a6a1 scid=0c44af4a282d1fff token= len=270 pn=1 [2025-04-30T12:24:44.160714346Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm CRYPTO off=0 len=249 [2025-04-30T12:24:44.160741937Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b dropped invalid packet [2025-04-30T12:24:44.160746185Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b processed 1200 bytes [2025-04-30T12:24:44.160752627Z TRACE quiche_server] recv() would block [2025-04-30T12:24:44.160765702Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx pkt Initial version=1 dcid=0c44af4a282d1fff scid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b len=5 pn=2 [2025-04-30T12:24:44.160769409Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm ACK delay=8 blocks=[0..1] ecn_counts=None [2025-04-30T12:24:44.160781672Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b timer=5.195583ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=909 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, first_sent_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, end_of_app_limited: 1, last_sent_packet: 2, 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: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 286, tv_nsec: 660774626 }, next_time: Instant { tv_sec: 286, tv_nsec: 660774626 }, 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-30T12:24:44.160870347Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:57729, at: Instant { tv_sec: 286, tv_nsec: 660774626 } }) [2025-04-30T12:24:44.160877881Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:44.160883692Z TRACE quiche_server] recv() would block [2025-04-30T12:24:44.160887859Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b done writing [2025-04-30T12:24:44.160890685Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:44.166978628Z TRACE quiche_server] timed out [2025-04-30T12:24:44.167011509Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b loss detection timeout expired [2025-04-30T12:24:44.167017249Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b timer=997.960316ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=909 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, first_sent_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, end_of_app_limited: 1, last_sent_packet: 2, 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: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 286, tv_nsec: 660774626 }, next_time: Instant { tv_sec: 286, tv_nsec: 660774626 }, 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-30T12:24:44.167040002Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx pkt Initial version=1 dcid=0c44af4a282d1fff scid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b len=100 pn=3 [2025-04-30T12:24:44.167043278Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm ACK delay=792 blocks=[0..1] ecn_counts=None [2025-04-30T12:24:44.167046955Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm CRYPTO off=0 len=90 [2025-04-30T12:24:44.167061011Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b timer=997.916805ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1064 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, first_sent_time: Instant { tv_sec: 285, tv_nsec: 666997230 }, end_of_app_limited: 2, last_sent_packet: 3, 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: false, capacity: 13500, used: 0, rate: 0, last_update: Instant { tv_sec: 286, tv_nsec: 667048405 }, next_time: Instant { tv_sec: 286, tv_nsec: 667048405 }, 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-30T12:24:44.167107227Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:57729, at: Instant { tv_sec: 286, tv_nsec: 667048405 } }) [2025-04-30T12:24:44.167113299Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:44.167118078Z TRACE quiche_server] recv() would block [2025-04-30T12:24:44.167121594Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b done writing [2025-04-30T12:24:44.167123868Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:44.670658056Z TRACE quiche_server] got 1200 bytes from [::ffff:193.167.0.100]:57729 to [::]:443 [2025-04-30T12:24:44.670691298Z TRACE quiche_server] got packet Initial version=1 dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b scid=0c44af4a282d1fff token= [2025-04-30T12:24:44.670705996Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Initial version=1 dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b scid=0c44af4a282d1fff token= len=22 pn=2 [2025-04-30T12:24:44.670719260Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm ACK delay=0 blocks=[0..0] ecn_counts=None [2025-04-30T12:24:44.670726824Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b packet newly acked 0 [2025-04-30T12:24:44.670754145Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Handshake version=1 dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b scid=0c44af4a282d1fff len=61 pn=0 [2025-04-30T12:24:44.670760267Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm ACK delay=0 blocks=[1..1] ecn_counts=None [2025-04-30T12:24:44.670763853Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b packet newly acked 1 [2025-04-30T12:24:44.670768071Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm CRYPTO off=0 len=36 [2025-04-30T12:24:44.670788449Z TRACE quiche::tls] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b set read secret lvl=OneRTT [2025-04-30T12:24:44.670817333Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b dropped epoch 1 state [2025-04-30T12:24:44.670823555Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b connection established: proto=Ok("hq-interop") cipher=Some(AES128_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 0, stateless_reset_token: None, max_udp_payload_size: 1472, initial_max_data: 1048576, initial_max_stream_data_bidi_local: 1048576, initial_max_stream_data_bidi_remote: 1048576, initial_max_stream_data_uni: 1048576, initial_max_streams_bidi: 0, initial_max_streams_uni: 0, ack_delay_exponent: 3, max_ack_delay: 25, disable_active_migration: true, active_conn_id_limit: 2, initial_source_connection_id: Some(0c44af4a282d1fff), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-04-30T12:24:44.670845937Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b dropped epoch 0 state [2025-04-30T12:24:44.670849573Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Short dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b key_phase=false len=1021 pn=0 [2025-04-30T12:24:44.670856666Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[74, ab, 48, 55, 81, 23, 8b, 10] reset_token=[b3, a4, 6c, eb, 22, 79, 26, 97, c1, 76, c3, 8f, c0, f9, 1d, b7] [2025-04-30T12:24:44.670865373Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[f1, 59, 4c, 66, ce, 8e, 44, ab] reset_token=[65, f3, 0a, 9a, 1a, 56, 4a, 92, b1, 86, 64, 33, f4, 8b, 87, 86] [2025-04-30T12:24:44.670881783Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[61, ac, 05, d2, f9, 3b, c5, a1] reset_token=[6b, a4, d6, 13, 42, 72, 88, 99, e5, 1f, 89, 7b, 31, f8, 29, 7f] [2025-04-30T12:24:44.670889698Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm PADDING len=920 [2025-04-30T12:24:44.670898124Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b processed 1200 bytes [2025-04-30T12:24:44.670907461Z TRACE quiche_server] got 58 bytes from [::ffff:193.167.0.100]:57729 to [::]:443 [2025-04-30T12:24:44.670911408Z TRACE quiche_server] got packet Short dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b key_phase=false [2025-04-30T12:24:44.670916248Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Short dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b key_phase=false len=37 pn=1 [2025-04-30T12:24:44.670921177Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm STREAM id=0 off=0 len=17 fin=true [2025-04-30T12:24:44.670928631Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b processed 58 bytes [2025-04-30T12:24:44.670932027Z DEBUG quiche_apps::common] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b response stream 0 is writable with capacity Ok(13500) [2025-04-30T12:24:44.670939421Z TRACE quiche_apps::common] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b received 17 bytes [2025-04-30T12:24:44.670942497Z TRACE quiche_apps::common] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b stream 0 has 17 bytes (fin? true) [2025-04-30T12:24:44.670947917Z INFO quiche_apps::common] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b got GET request for "/www/oaqspjeyvh" on stream 0 [2025-04-30T12:24:44.671012908Z INFO quiche_apps::common] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b sending response of size 1024 on stream 0 [2025-04-30T12:24:44.671027615Z TRACE quiche_server] recv() would block [2025-04-30T12:24:44.671037474Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b pmtud probe status false hs_con=true hs_sent=false cwnd_avail=13500 out_len=1350 left=1319 [2025-04-30T12:24:44.671046480Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx pkt Short dcid=0c44af4a282d1fff key_phase=false len=1075 pn=4 [2025-04-30T12:24:44.671049897Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm ACK delay=14 blocks=[0..1] ecn_counts=None [2025-04-30T12:24:44.671053904Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[34, 55, 23, f4, 68, 83, 2a, c7, b4, 5f, c5, af, 7d, 7a, 8b, 8f, 5d, 2e, 37, 6c] reset_token=[0a, 4c, 24, 3c, f5, e6, 49, 79, c2, e6, 8f, 0a, f5, cb, bf, df] [2025-04-30T12:24:44.671060817Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm HANDSHAKE_DONE [2025-04-30T12:24:44.671063602Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b tx frm STREAM id=0 off=0 len=1024 fin=true [2025-04-30T12:24:44.671075635Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b timer=3.784322443s latest_rtt=1.503775317s srtt=1.503730757s min_rtt=1.503724392s rttvar=563.909378ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1101 app_limited=true congestion_recovery_start_time=None Rate { delivered: 909, delivered_time: Instant { tv_sec: 286, tv_nsec: 667048405 }, first_sent_time: Instant { tv_sec: 286, tv_nsec: 667048405 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { delivery_rate: 604, is_app_limited: true, interval: 1.503724392s, delivered: 909, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 285, tv_nsec: 666997230 }), send_elapsed: 0ns, ack_elapsed: 1.503724392s, rtt: 1.503724392s } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 11222, last_update: Instant { tv_sec: 286, tv_nsec: 667048405 }, next_time: Instant { tv_sec: 286, tv_nsec: 667048405 }, 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-30T12:24:44.671151286Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b written 1101 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:57729, at: Instant { tv_sec: 286, tv_nsec: 667048405 } }) [2025-04-30T12:24:44.671158790Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:44.671164370Z TRACE quiche_server] recv() would block [2025-04-30T12:24:44.671167897Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b done writing [2025-04-30T12:24:44.671171043Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:46.172924605Z TRACE quiche_server] got 43 bytes from [::ffff:193.167.0.100]:57729 to [::]:443 [2025-04-30T12:24:46.172952166Z TRACE quiche_server] got packet Short dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b key_phase=false [2025-04-30T12:24:46.172964890Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Short dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b key_phase=false len=22 pn=2 [2025-04-30T12:24:46.172976732Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm ACK delay=0 blocks=[4..4] ecn_counts=None [2025-04-30T12:24:46.173000767Z TRACE quiche::recovery::congestion::recovery] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b packet newly acked 4 [2025-04-30T12:24:46.173026184Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b processed 43 bytes [2025-04-30T12:24:46.173034349Z TRACE quiche_server] got 42 bytes from [::ffff:193.167.0.100]:57729 to [::]:443 [2025-04-30T12:24:46.173037615Z TRACE quiche_server] got packet Short dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b key_phase=false [2025-04-30T12:24:46.173041593Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx pkt Short dcid=33b80dc182e133aec3b3d60bb7c7a36aae8bf11b key_phase=false len=21 pn=3 [2025-04-30T12:24:46.173046472Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b rx frm CONNECTION_CLOSE err=0 frame=0 reason=[] [2025-04-30T12:24:46.173052483Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b processed 42 bytes [2025-04-30T12:24:46.173056401Z TRACE quiche_server] recv() would block [2025-04-30T12:24:46.173058995Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b done writing [2025-04-30T12:24:46.173061640Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:57.466399138Z TRACE quiche_server] timed out [2025-04-30T12:24:57.466435055Z TRACE quiche] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b draining timeout expired [2025-04-30T12:24:57.466493024Z TRACE quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b done writing [2025-04-30T12:24:57.466498584Z TRACE quiche_server] Collecting garbage [2025-04-30T12:24:57.466504094Z INFO quiche_server] 33b80dc182e133aec3b3d60bb7c7a36aae8bf11b connection collected recv=8 sent=5 lost=0 retrans=1 sent_bytes=2225 recv_bytes=1935 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:57729 validation_state=Validated active=true recv=8 sent=5 lost=0 retrans=1 rtt=1.566505976s min_rtt=Some(1.503724392s) rttvar=548.482472ms cwnd=13500 sent_bytes=2225 recv_bytes=1935 lost_bytes=0 stream_retrans_bytes=90 pmtu=1350 delivery_rate=548]