[2025-09-12T04:42:03.008540762Z INFO quiche_server] listening on [::]:443 [2025-09-12T04:42:03.008561400Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE [2025-09-12T04:42:03.008567882Z TRACE quiche_server] GSO detected: false [2025-09-12T04:42:03.340672222Z TRACE quiche_server] got 1207 bytes from [::ffff:193.167.100.2]:54511 to [::]:443 [2025-09-12T04:42:03.340720201Z TRACE quiche_server] got packet Initial version=57414954 dcid= scid= token= [2025-09-12T04:42:03.340727274Z WARN quiche_server] Doing version negotiation [2025-09-12T04:42:03.340803586Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.048222806Z TRACE quiche_server] got 1220 bytes from [::ffff:193.167.0.100]:37078 to [::]:443 [2025-09-12T04:42:04.048246981Z TRACE quiche_server] got packet Initial version=1 dcid=4e23dc6cb1deedd7 scid= token= [2025-09-12T04:42:04.048262991Z DEBUG quiche_server] New connection: dcid=4e23dc6cb1deedd7 scid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 [2025-09-12T04:42:04.048484464Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx pkt Initial version=1 dcid=4e23dc6cb1deedd7 scid= token= len=1202 pn=86 [2025-09-12T04:42:04.048503309Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm CRYPTO off=0 len=297 [2025-09-12T04:42:04.048535328Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-09-12T04:42:04.048540438Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-09-12T04:42:04.048651655Z TRACE quiche::tls] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 write message lvl=Initial len=90 [2025-09-12T04:42:04.048683705Z TRACE quiche::tls] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 set write secret lvl=Handshake [2025-09-12T04:42:04.048765637Z TRACE quiche::tls] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 write message lvl=Handshake len=713 [2025-09-12T04:42:04.048769124Z TRACE quiche::tls] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 set write secret lvl=OneRTT [2025-09-12T04:42:04.048778371Z TRACE quiche::tls] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 set read secret lvl=Handshake [2025-09-12T04:42:04.048802496Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm PADDING len=881 [2025-09-12T04:42:04.048821852Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 processed 1220 bytes [2025-09-12T04:42:04.048834716Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.048848972Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx pkt Initial version=1 dcid= scid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 len=100 pn=0 [2025-09-12T04:42:04.048852950Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm ACK delay=48 blocks=[86..86] ecn_counts=None [2025-09-12T04:42:04.048858069Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm CRYPTO off=0 len=90 [2025-09-12T04:42:04.048868669Z TRACE quiche::recovery::congestion::recovery] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 timer=998.968782ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=147 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 304, tv_nsec: 995453339 }, first_sent_time: Instant { tv_sec: 304, tv_nsec: 995453339 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 304, tv_nsec: 995453339 }, next_time: Instant { tv_sec: 304, tv_nsec: 995453339 }, 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-09-12T04:42:04.048892544Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx pkt Handshake version=1 dcid= scid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 len=717 pn=1 [2025-09-12T04:42:04.048903815Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm CRYPTO off=0 len=713 [2025-09-12T04:42:04.048910868Z TRACE quiche::recovery::congestion::recovery] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 timer=998.926964ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=910 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 304, tv_nsec: 995453339 }, first_sent_time: Instant { tv_sec: 304, tv_nsec: 995453339 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 304, tv_nsec: 995453339 }, next_time: Instant { tv_sec: 304, tv_nsec: 995453339 }, 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-09-12T04:42:04.048954609Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:37078, at: Instant { tv_sec: 304, tv_nsec: 995453339 } }) [2025-09-12T04:42:04.048961302Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.048966421Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.048971110Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 done writing [2025-09-12T04:42:04.048973955Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.081033890Z TRACE quiche_server] got 109 bytes from [::ffff:193.167.0.100]:37078 to [::]:443 [2025-09-12T04:42:04.081059558Z TRACE quiche_server] got packet Handshake version=1 dcid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 scid= [2025-09-12T04:42:04.081072622Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx pkt Handshake version=1 dcid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 scid= len=80 pn=87 [2025-09-12T04:42:04.081084304Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm ACK delay=1 blocks=[1..1] ecn_counts=None [2025-09-12T04:42:04.081091618Z TRACE quiche::recovery::congestion::recovery] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 packet newly acked 1 [2025-09-12T04:42:04.081097799Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm CRYPTO off=0 len=52 [2025-09-12T04:42:04.081119931Z TRACE quiche::tls] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 set read secret lvl=OneRTT [2025-09-12T04:42:04.081162600Z TRACE quiche::tls] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 write message lvl=OneRTT len=428 [2025-09-12T04:42:04.081172048Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 dropped epoch 1 state [2025-09-12T04:42:04.081176416Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 connection established: proto=Ok("hq-interop") cipher=Some(AES256_GCM) curve=Some("X25519") sigalg=None resumed=false TransportParams { original_destination_connection_id: None, max_idle_timeout: 10000, stateless_reset_token: None, 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: 0, initial_max_streams_uni: 3, ack_delay_exponent: 8, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-09-12T04:42:04.081207223Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 dropped epoch 0 state [2025-09-12T04:42:04.081220989Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 processed 109 bytes [2025-09-12T04:42:04.081228172Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.081241888Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx pkt Short dcid= key_phase=false len=553 pn=2 [2025-09-12T04:42:04.081245685Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[4c, ca, b6, 75, 08, 79, 94, 47, ee, 45, 64, 57, f6, ef, 12, 71, 1f, 3d, 83, ac] reset_token=[ed, cc, d9, 17, 78, ce, 54, 0c, a8, c0, 73, 51, 71, 60, 54, d9] [2025-09-12T04:42:04.081254040Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[8e, 6b, f7, fd, 57, ae, ef, 35, 14, 0a, b5, e9, c6, 28, 3d, 51, ba, aa, 53, 60] reset_token=[98, 47, e3, b9, 5b, 7d, 5d, fa, d4, db, 10, fb, 85, d4, 8c, 48] [2025-09-12T04:42:04.081260402Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[a5, 8b, 22, 82, 9f, 08, d1, ce, 20, 03, de, 73, 75, 0a, 94, cd, 30, 08, 64, 31] reset_token=[d8, e6, 3e, 95, 73, 18, 97, 94, 95, 70, 8a, e4, 92, c9, c5, bb] [2025-09-12T04:42:04.081266574Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm HANDSHAKE_DONE [2025-09-12T04:42:04.081269349Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm CRYPTO off=0 len=428 [2025-09-12T04:42:04.081282012Z TRACE quiche::recovery::congestion::recovery] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 timer=122.641181ms latest_rtt=32.230823ms srtt=32.230823ms min_rtt=32.230823ms rttvar=16.115411ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=571 app_limited=true congestion_recovery_start_time=None Rate { delivered: 763, delivered_time: Instant { tv_sec: 305, tv_nsec: 27846354 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 27846354 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { bandwidth: 189.38 Kbps, is_app_limited: true, interval: 32.230823ms, delivered: 763, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 304, tv_nsec: 995453339 }), send_elapsed: 0ns, ack_elapsed: 32.230823ms, rtt: 32.230823ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 523567, last_update: Instant { tv_sec: 305, tv_nsec: 27846354 }, next_time: Instant { tv_sec: 305, tv_nsec: 27846354 }, 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-09-12T04:42:04.081334159Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 written 571 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:37078, at: Instant { tv_sec: 305, tv_nsec: 27846354 } }) [2025-09-12T04:42:04.081341042Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.081346312Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.081349999Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 done writing [2025-09-12T04:42:04.081352804Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.082025106Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:37078 to [::]:443 [2025-09-12T04:42:04.082031909Z TRACE quiche_server] got packet Short dcid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 key_phase=false [2025-09-12T04:42:04.082037119Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx pkt Short dcid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 key_phase=false len=1231 pn=88 [2025-09-12T04:42:04.082042709Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm PING mtu_probe=None [2025-09-12T04:42:04.082048831Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm PADDING len=1210 [2025-09-12T04:42:04.082054621Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 processed 1252 bytes [2025-09-12T04:42:04.082063208Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.082068578Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx pkt Short dcid= key_phase=false len=6 pn=3 [2025-09-12T04:42:04.082071202Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 tx frm ACK delay=3 blocks=[88..88] ecn_counts=None [2025-09-12T04:42:04.082077925Z TRACE quiche::recovery::congestion::recovery] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 timer=121.845549ms latest_rtt=32.230823ms srtt=32.230823ms min_rtt=32.230823ms rttvar=16.115411ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=571 app_limited=true congestion_recovery_start_time=None Rate { delivered: 763, delivered_time: Instant { tv_sec: 305, tv_nsec: 27846354 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 27846354 }, end_of_app_limited: 1, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { bandwidth: 189.38 Kbps, is_app_limited: true, interval: 32.230823ms, delivered: 763, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 304, tv_nsec: 995453339 }), send_elapsed: 0ns, ack_elapsed: 32.230823ms, rtt: 32.230823ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 523567, last_update: Instant { tv_sec: 305, tv_nsec: 27846354 }, next_time: Instant { tv_sec: 305, tv_nsec: 27846354 }, 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-09-12T04:42:04.082107951Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:37078, at: Instant { tv_sec: 305, tv_nsec: 27846354 } }) [2025-09-12T04:42:04.082112499Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.082115926Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.082118641Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 done writing [2025-09-12T04:42:04.082120835Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.112553461Z TRACE quiche_server] got 49 bytes from [::ffff:193.167.0.100]:37078 to [::]:443 [2025-09-12T04:42:04.112566846Z TRACE quiche_server] got packet Short dcid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 key_phase=false [2025-09-12T04:42:04.112574389Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx pkt Short dcid=f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 key_phase=false len=28 pn=89 [2025-09-12T04:42:04.112582114Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm ACK delay=0 blocks=[2..3] ecn_counts=None [2025-09-12T04:42:04.112586883Z TRACE quiche::recovery::congestion::recovery] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 packet newly acked 2 [2025-09-12T04:42:04.112590369Z TRACE quiche::recovery::congestion::recovery] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 packet newly acked 3 [2025-09-12T04:42:04.112596090Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-09-12T04:42:04.112609365Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 processed 49 bytes [2025-09-12T04:42:04.112614685Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.112617760Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 done writing [2025-09-12T04:42:04.112620686Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.357916691Z TRACE quiche_server] timed out [2025-09-12T04:42:04.357941237Z TRACE quiche] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 draining timeout expired [2025-09-12T04:42:04.357991450Z TRACE quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 done writing [2025-09-12T04:42:04.357995358Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.358000247Z INFO quiche_server] f9ff6c52153e8eae5318d05c294ffc1ca247b6c4 connection collected recv=4 sent=4 lost=0 retrans=0 sent_bytes=1505 recv_bytes=2630 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:37078 validation_state=Validated active=true recv=4 sent=4 lost=0 retrans=0 rtt=32.119667ms min_rtt=Some(31.341579ms) rttvar=12.308869ms cwnd=13500 sent_bytes=1505 recv_bytes=2630 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=23672] [2025-09-12T04:42:04.529987041Z TRACE quiche_server] got 1220 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.530009823Z TRACE quiche_server] got packet Initial version=1 dcid=7fc19d371bbdfd64 scid= token= [2025-09-12T04:42:04.530017959Z DEBUG quiche_server] New connection: dcid=7fc19d371bbdfd64 scid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 [2025-09-12T04:42:04.530170472Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Initial version=1 dcid=7fc19d371bbdfd64 scid= token= len=1202 pn=112 [2025-09-12T04:42:04.530185350Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm CRYPTO off=0 len=552 [2025-09-12T04:42:04.530215536Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("h3") [2025-09-12T04:42:04.530220185Z TRACE quiche::tls] checking peer ALPN Ok("hq-interop") against Ok("hq-interop") [2025-09-12T04:42:04.530351971Z TRACE quiche::tls] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 write message lvl=Initial len=96 [2025-09-12T04:42:04.530372729Z TRACE quiche::tls] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 set write secret lvl=Handshake [2025-09-12T04:42:04.530447699Z TRACE quiche::tls] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 write message lvl=Handshake len=164 [2025-09-12T04:42:04.530453580Z TRACE quiche::tls] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 set write secret lvl=OneRTT [2025-09-12T04:42:04.530463999Z TRACE quiche::tls] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 set read secret lvl=Handshake [2025-09-12T04:42:04.530484868Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm PADDING len=626 [2025-09-12T04:42:04.530505136Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 1220 bytes [2025-09-12T04:42:04.530516006Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.530528299Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Initial version=1 dcid= scid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 len=106 pn=0 [2025-09-12T04:42:04.530532006Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=46 blocks=[112..112] ecn_counts=None [2025-09-12T04:42:04.530536124Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm CRYPTO off=0 len=96 [2025-09-12T04:42:04.530544780Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=998.97329ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=153 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 305, tv_nsec: 477133637 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 477133637 }, end_of_app_limited: 1, last_sent_packet: 0, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 305, tv_nsec: 477133637 }, next_time: Instant { tv_sec: 305, tv_nsec: 477133637 }, 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-09-12T04:42:04.530564477Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Handshake version=1 dcid= scid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 len=168 pn=1 [2025-09-12T04:42:04.530567252Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm CRYPTO off=0 len=164 [2025-09-12T04:42:04.530572512Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=998.945758ms latest_rtt=0ns srtt=333ms min_rtt=333ms rttvar=166.5ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=367 app_limited=true congestion_recovery_start_time=None Rate { delivered: 0, delivered_time: Instant { tv_sec: 305, tv_nsec: 477133637 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 477133637 }, end_of_app_limited: 1, last_sent_packet: 1, largest_acked: 0, rate_sample: RateSample { bandwidth: 0.00 Kbps, 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: 305, tv_nsec: 477133637 }, next_time: Instant { tv_sec: 305, tv_nsec: 477133637 }, 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-09-12T04:42:04.530614019Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 1200 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 477133637 } }) [2025-09-12T04:42:04.530620220Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.530626111Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.530632153Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.530635930Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.562284592Z TRACE quiche_server] got 109 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.562296374Z TRACE quiche_server] got packet Handshake version=1 dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 scid= [2025-09-12T04:42:04.562303497Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Handshake version=1 dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 scid= len=80 pn=113 [2025-09-12T04:42:04.562309589Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[1..1] ecn_counts=None [2025-09-12T04:42:04.562314007Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 1 [2025-09-12T04:42:04.562318174Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm CRYPTO off=0 len=52 [2025-09-12T04:42:04.562329476Z TRACE quiche::tls] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 set read secret lvl=OneRTT [2025-09-12T04:42:04.562356716Z TRACE quiche::tls] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 write message lvl=OneRTT len=428 [2025-09-12T04:42:04.562363218Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 dropped epoch 1 state [2025-09-12T04:42:04.562366515Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 connection established: proto=Ok("hq-interop") cipher=Some(AES256_GCM) curve=Some("X25519") sigalg=None resumed=true TransportParams { original_destination_connection_id: None, max_idle_timeout: 10000, stateless_reset_token: None, 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: 0, initial_max_streams_uni: 3, ack_delay_exponent: 8, max_ack_delay: 26, disable_active_migration: false, active_conn_id_limit: 4, initial_source_connection_id: Some(), retry_source_connection_id: None, max_datagram_frame_size: None, unknown_params: None } [2025-09-12T04:42:04.562406018Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 dropped epoch 0 state [2025-09-12T04:42:04.562411999Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 109 bytes [2025-09-12T04:42:04.562417530Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.562426677Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=553 pn=2 [2025-09-12T04:42:04.562435553Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm NEW_CONNECTION_ID seq_num=1 retire_prior_to=0 conn_id=[a5, 5d, 6f, 3f, a1, 9b, 25, 55, 8d, cf, 22, bf, 93, 85, 29, 07, 6f, 72, 98, 38] reset_token=[a6, 65, af, e4, bd, c0, 35, fe, 25, bf, a0, 75, 4d, e4, 82, ef] [2025-09-12T04:42:04.562442145Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm NEW_CONNECTION_ID seq_num=2 retire_prior_to=0 conn_id=[ec, 27, ab, bf, 26, 4b, 38, 55, 36, 1d, f8, 0f, 89, 51, b0, 0a, b5, 9e, 39, 56] reset_token=[cf, 16, fb, e9, 00, 6c, 44, ae, f0, eb, ce, 47, 7b, 84, 56, 6c] [2025-09-12T04:42:04.562447425Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm NEW_CONNECTION_ID seq_num=3 retire_prior_to=0 conn_id=[2d, d5, 3c, 26, fe, 33, 7a, b1, 91, 66, 05, d6, d7, f6, cd, 98, 9d, 29, 95, b2] reset_token=[9c, 01, 56, 92, 89, f9, 4e, 15, c2, 57, 35, 0e, f3, 53, 88, 3b] [2025-09-12T04:42:04.562452715Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm HANDSHAKE_DONE [2025-09-12T04:42:04.562454989Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm CRYPTO off=0 len=428 [2025-09-12T04:42:04.562464698Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=121.305107ms latest_rtt=31.783454ms srtt=31.783454ms min_rtt=31.783454ms rttvar=15.891727ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=571 app_limited=true congestion_recovery_start_time=None Rate { delivered: 214, delivered_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, end_of_app_limited: 1, last_sent_packet: 2, largest_acked: 1, rate_sample: RateSample { bandwidth: 53.86 Kbps, is_app_limited: true, interval: 31.783454ms, delivered: 214, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 477133637 }), send_elapsed: 0ns, ack_elapsed: 31.783454ms, rtt: 31.783454ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 530936, last_update: Instant { tv_sec: 305, tv_nsec: 509034890 }, next_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, 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-09-12T04:42:04.562502899Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 571 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 509034890 } }) [2025-09-12T04:42:04.562508159Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.562512006Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.562515783Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.562519119Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.563294092Z TRACE quiche_server] got 1252 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.563305744Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.563316304Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=1231 pn=114 [2025-09-12T04:42:04.563327474Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm PING mtu_probe=None [2025-09-12T04:42:04.563340349Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm PADDING len=1210 [2025-09-12T04:42:04.563352291Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 1252 bytes [2025-09-12T04:42:04.563359093Z TRACE quiche_server] got 45 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.563363321Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.563375654Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=24 pn=115 [2025-09-12T04:42:04.563381315Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm STREAM id=0 off=0 len=0 fin=false [2025-09-12T04:42:04.563412292Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 45 bytes [2025-09-12T04:42:04.563420197Z DEBUG quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 response stream 0 is writable with capacity Ok(12929) [2025-09-12T04:42:04.563426750Z TRACE quiche_server] got 62 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.563430747Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.563435846Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=41 pn=116 [2025-09-12T04:42:04.563441277Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm STREAM id=0 off=0 len=17 fin=true [2025-09-12T04:42:04.563447298Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 62 bytes [2025-09-12T04:42:04.563450534Z DEBUG quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 response stream 0 is writable with capacity Ok(12929) [2025-09-12T04:42:04.563457006Z TRACE quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 received 17 bytes [2025-09-12T04:42:04.563460142Z TRACE quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 stream 0 has 17 bytes (fin? true) [2025-09-12T04:42:04.563465492Z INFO quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 got GET request for "/www/xglbpjopbg" on stream 0 [2025-09-12T04:42:04.563491190Z INFO quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 sending response of size 5120 on stream 0 [2025-09-12T04:42:04.563499956Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.563509814Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=3 [2025-09-12T04:42:04.563513531Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=8 blocks=[114..116] ecn_counts=None [2025-09-12T04:42:04.563517839Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=0 off=0 len=1321 fin=false [2025-09-12T04:42:04.563527828Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=121.325135ms latest_rtt=31.783454ms srtt=31.783454ms min_rtt=31.783454ms rttvar=15.891727ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1921 app_limited=true congestion_recovery_start_time=None Rate { delivered: 214, delivered_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, end_of_app_limited: 2, last_sent_packet: 3, largest_acked: 1, rate_sample: RateSample { bandwidth: 53.86 Kbps, is_app_limited: true, interval: 31.783454ms, delivered: 214, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 477133637 }), send_elapsed: 0ns, ack_elapsed: 31.783454ms, rtt: 31.783454ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 530936, last_update: Instant { tv_sec: 305, tv_nsec: 509034890 }, next_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, 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-09-12T04:42:04.563547294Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=4 [2025-09-12T04:42:04.563550850Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=0 off=1321 len=1326 fin=false [2025-09-12T04:42:04.563557152Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=121.337668ms latest_rtt=31.783454ms srtt=31.783454ms min_rtt=31.783454ms rttvar=15.891727ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=3271 app_limited=true congestion_recovery_start_time=None Rate { delivered: 214, delivered_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, end_of_app_limited: 3, last_sent_packet: 4, largest_acked: 1, rate_sample: RateSample { bandwidth: 53.86 Kbps, is_app_limited: true, interval: 31.783454ms, delivered: 214, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 477133637 }), send_elapsed: 0ns, ack_elapsed: 31.783454ms, rtt: 31.783454ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 530936, last_update: Instant { tv_sec: 305, tv_nsec: 509034890 }, next_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, 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-09-12T04:42:04.563575687Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=5 [2025-09-12T04:42:04.563578282Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=0 off=2647 len=1326 fin=false [2025-09-12T04:42:04.563582850Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=121.341586ms latest_rtt=31.783454ms srtt=31.783454ms min_rtt=31.783454ms rttvar=15.891727ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4621 app_limited=true congestion_recovery_start_time=None Rate { delivered: 214, delivered_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, end_of_app_limited: 4, last_sent_packet: 5, largest_acked: 1, rate_sample: RateSample { bandwidth: 53.86 Kbps, is_app_limited: true, interval: 31.783454ms, delivered: 214, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 477133637 }), send_elapsed: 0ns, ack_elapsed: 31.783454ms, rtt: 31.783454ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 530936, last_update: Instant { tv_sec: 305, tv_nsec: 509034890 }, next_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, 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-09-12T04:42:04.563593119Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1153 pn=6 [2025-09-12T04:42:04.563595554Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=0 off=3973 len=1147 fin=true [2025-09-12T04:42:04.563600403Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=121.341645ms latest_rtt=31.783454ms srtt=31.783454ms min_rtt=31.783454ms rttvar=15.891727ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5792 app_limited=true congestion_recovery_start_time=None Rate { delivered: 214, delivered_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, end_of_app_limited: 5, last_sent_packet: 6, largest_acked: 1, rate_sample: RateSample { bandwidth: 53.86 Kbps, is_app_limited: true, interval: 31.783454ms, delivered: 214, prior_delivered: 0, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 477133637 }), send_elapsed: 0ns, ack_elapsed: 31.783454ms, rtt: 31.783454ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 530936, last_update: Instant { tv_sec: 305, tv_nsec: 509034890 }, next_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, 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-09-12T04:42:04.563676815Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 5221 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 509034890 } }) [2025-09-12T04:42:04.563686423Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.563692965Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.563697895Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.563701611Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.595093544Z TRACE quiche_server] got 46 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.595107259Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.595114813Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=25 pn=117 [2025-09-12T04:42:04.595122197Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[2..3] ecn_counts=None [2025-09-12T04:42:04.595126936Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 2 [2025-09-12T04:42:04.595130172Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 3 [2025-09-12T04:42:04.595145511Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 46 bytes [2025-09-12T04:42:04.595150861Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.595155178Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.595158144Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.596165851Z TRACE quiche_server] got 1332 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.596172293Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.596176921Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=1311 pn=118 [2025-09-12T04:42:04.596182031Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm PING mtu_probe=None [2025-09-12T04:42:04.596188323Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm PADDING len=1290 [2025-09-12T04:42:04.596193853Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 1332 bytes [2025-09-12T04:42:04.596197510Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.596203110Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=6 pn=7 [2025-09-12T04:42:04.596205715Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=3 blocks=[117..118] ecn_counts=None [2025-09-12T04:42:04.596212157Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=73.861891ms latest_rtt=32.693587ms srtt=31.89722ms min_rtt=31.783454ms rttvar=12.146328ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=3871 app_limited=true congestion_recovery_start_time=None Rate { delivered: 2135, delivered_time: Instant { tv_sec: 305, tv_nsec: 541728477 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, end_of_app_limited: 6, last_sent_packet: 7, largest_acked: 3, rate_sample: RateSample { bandwidth: 470.06 Kbps, is_app_limited: true, interval: 32.693587ms, delivered: 1921, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 32.693587ms, rtt: 32.693587ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 529042, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.596253745Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 542814550 } }) [2025-09-12T04:42:04.596258934Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.596262481Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.596265326Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.596267540Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.597269016Z TRACE quiche_server] got 57 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.597275327Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.597280357Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=36 pn=119 [2025-09-12T04:42:04.597285617Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[2..5] ecn_counts=None [2025-09-12T04:42:04.597289063Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 4 [2025-09-12T04:42:04.597291508Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 5 [2025-09-12T04:42:04.597294884Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_DATA max=16781189 [2025-09-12T04:42:04.597297509Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_STREAM_DATA stream=0 max=69509 [2025-09-12T04:42:04.597323417Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 57 bytes [2025-09-12T04:42:04.597327675Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.597332845Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=6 pn=8 [2025-09-12T04:42:04.597335459Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=6 blocks=[117..119] ecn_counts=None [2025-09-12T04:42:04.597341561Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=63.918986ms latest_rtt=34.859682ms srtt=32.267527ms min_rtt=31.783454ms rttvar=9.850361ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1171 app_limited=true congestion_recovery_start_time=None Rate { delivered: 4835, delivered_time: Instant { tv_sec: 305, tv_nsec: 543894572 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 509034890 }, end_of_app_limited: 7, last_sent_packet: 8, largest_acked: 5, rate_sample: RateSample { bandwidth: 1.06 Mbps, is_app_limited: true, interval: 34.859682ms, delivered: 4621, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 34.859682ms, rtt: 34.859682ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 522971, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.597372138Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 542814550 } }) [2025-09-12T04:42:04.597380714Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.597384281Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.597410429Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.597414777Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.598350991Z TRACE quiche_server] got 67 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.598354768Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.598359737Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=46 pn=120 [2025-09-12T04:42:04.598364767Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[2..6] ecn_counts=None [2025-09-12T04:42:04.598368013Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 6 [2025-09-12T04:42:04.598371660Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm STREAM id=4 off=0 len=17 fin=true [2025-09-12T04:42:04.598382229Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 67 bytes [2025-09-12T04:42:04.598385034Z DEBUG quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 response stream 4 is writable with capacity Ok(13500) [2025-09-12T04:42:04.598405052Z TRACE quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 received 17 bytes [2025-09-12T04:42:04.598407406Z TRACE quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 stream 4 has 17 bytes (fin? true) [2025-09-12T04:42:04.598410842Z INFO quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 got GET request for "/www/capejqwcjw" on stream 4 [2025-09-12T04:42:04.598429567Z INFO quiche_apps::common] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 sending response of size 10240 on stream 4 [2025-09-12T04:42:04.598436791Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.598443724Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=9 [2025-09-12T04:42:04.598446419Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=10 blocks=[117..120] ecn_counts=None [2025-09-12T04:42:04.598449304Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=0 len=1321 fin=false [2025-09-12T04:42:04.598456558Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.93118ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=1350 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 8, last_sent_packet: 9, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598469281Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=10 [2025-09-12T04:42:04.598471816Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=1321 len=1326 fin=false [2025-09-12T04:42:04.598476515Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.939867ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2700 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 9, last_sent_packet: 10, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598491643Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=11 [2025-09-12T04:42:04.598494198Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=2647 len=1326 fin=false [2025-09-12T04:42:04.598498676Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.940358ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=4050 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 11, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598508785Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=12 [2025-09-12T04:42:04.598511220Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=3973 len=1326 fin=false [2025-09-12T04:42:04.598515397Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.940999ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5400 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 12, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598528412Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=13 [2025-09-12T04:42:04.598530926Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=5299 len=1326 fin=false [2025-09-12T04:42:04.598535244Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.940628ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=6750 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 13, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598544962Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=14 [2025-09-12T04:42:04.598547357Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=6625 len=1326 fin=false [2025-09-12T04:42:04.598551544Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.941099ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=8100 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 14, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598561213Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=1332 pn=15 [2025-09-12T04:42:04.598563667Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=7951 len=1326 fin=false [2025-09-12T04:42:04.598568556Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.940348ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=9450 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 15, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598581390Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=969 pn=16 [2025-09-12T04:42:04.598584015Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm STREAM id=4 off=9277 len=963 fin=true [2025-09-12T04:42:04.598588463Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=91.940418ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10437 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 16, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 542814550 }, next_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, 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-09-12T04:42:04.598670917Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 10437 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 542814550 } }) [2025-09-12T04:42:04.598675916Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.598679433Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.598682258Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.598684412Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.627711061Z TRACE quiche_server] got 1350 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.627724927Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.627733113Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=1329 pn=121 [2025-09-12T04:42:04.627741067Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm PING mtu_probe=None [2025-09-12T04:42:04.627749673Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm PADDING len=1308 [2025-09-12T04:42:04.627758931Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 1350 bytes [2025-09-12T04:42:04.627772787Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.627781583Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=6 pn=17 [2025-09-12T04:42:04.627785290Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=5 blocks=[117..121] ecn_counts=None [2025-09-12T04:42:04.627794637Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=62.733884ms latest_rtt=35.938992ms srtt=32.72646ms min_rtt=31.783454ms rttvar=8.305636ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=10437 app_limited=true congestion_recovery_start_time=None Rate { delivered: 6006, delivered_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 17, largest_acked: 6, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 35.938992ms, delivered: 5792, prior_delivered: 214, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 509034890 }), send_elapsed: 0ns, ack_elapsed: 35.938992ms, rtt: 35.938992ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 515637, last_update: Instant { tv_sec: 305, tv_nsec: 574391039 }, next_time: Instant { tv_sec: 305, tv_nsec: 574391039 }, 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-09-12T04:42:04.627840863Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 574391039 } }) [2025-09-12T04:42:04.627847556Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.627852324Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.627856071Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.627859027Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.631175044Z TRACE quiche_server] got 57 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.631184050Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.631190913Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=36 pn=122 [2025-09-12T04:42:04.631197646Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[7..10] ecn_counts=None [2025-09-12T04:42:04.631202335Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 7 [2025-09-12T04:42:04.631205691Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 8 [2025-09-12T04:42:04.631208646Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 9 [2025-09-12T04:42:04.631211642Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 10 [2025-09-12T04:42:04.631217523Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_DATA max=16784983 [2025-09-12T04:42:04.631220939Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_STREAM_DATA stream=4 max=68183 [2025-09-12T04:42:04.631234494Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 57 bytes [2025-09-12T04:42:04.631239804Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.631246537Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=6 pn=18 [2025-09-12T04:42:04.631249983Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=6 blocks=[121..122] ecn_counts=None [2025-09-12T04:42:04.631257146Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=53.512823ms latest_rtt=34.990377ms srtt=33.009449ms min_rtt=31.783454ms rttvar=6.795206ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=7737 app_limited=true congestion_recovery_start_time=None Rate { delivered: 8706, delivered_time: Instant { tv_sec: 305, tv_nsec: 577804927 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 10, last_sent_packet: 18, largest_acked: 10, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 34.990377ms, delivered: 2700, prior_delivered: 6006, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 542814550 }), send_elapsed: 0ns, ack_elapsed: 34.990377ms, rtt: 34.990377ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 511217, last_update: Instant { tv_sec: 305, tv_nsec: 574391039 }, next_time: Instant { tv_sec: 305, tv_nsec: 574391039 }, 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-09-12T04:42:04.631303453Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 574391039 } }) [2025-09-12T04:42:04.631309664Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.631314253Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.631317950Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.631320825Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.633374120Z TRACE quiche_server] got 57 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.633380201Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.633385060Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=36 pn=123 [2025-09-12T04:42:04.633406931Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[7..12] ecn_counts=None [2025-09-12T04:42:04.633410237Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 11 [2025-09-12T04:42:04.633412612Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 12 [2025-09-12T04:42:04.633415968Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_DATA max=16787635 [2025-09-12T04:42:04.633418502Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_STREAM_DATA stream=4 max=70835 [2025-09-12T04:42:04.633427740Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 57 bytes [2025-09-12T04:42:04.633431557Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.633436446Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=6 pn=19 [2025-09-12T04:42:04.633438981Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=6 blocks=[121..123] ecn_counts=None [2025-09-12T04:42:04.633444380Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=49.227749ms latest_rtt=37.184775ms srtt=33.531363ms min_rtt=31.783454ms rttvar=6.140235ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=5037 app_limited=true congestion_recovery_start_time=None Rate { delivered: 11406, delivered_time: Instant { tv_sec: 305, tv_nsec: 579999325 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 0, last_sent_packet: 19, largest_acked: 12, rate_sample: RateSample { bandwidth: 1.29 Mbps, is_app_limited: true, interval: 37.184775ms, delivered: 5400, prior_delivered: 6006, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 542814550 }), send_elapsed: 0ns, ack_elapsed: 37.184775ms, rtt: 37.184775ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 503260, last_update: Instant { tv_sec: 305, tv_nsec: 574391039 }, next_time: Instant { tv_sec: 305, tv_nsec: 574391039 }, 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-09-12T04:42:04.633478744Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 574391039 } }) [2025-09-12T04:42:04.633483263Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.633486719Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.633489505Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.633491679Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.635586621Z TRACE quiche_server] got 57 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.635592953Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.635597922Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=36 pn=124 [2025-09-12T04:42:04.635602711Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[7..14] ecn_counts=None [2025-09-12T04:42:04.635606007Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 13 [2025-09-12T04:42:04.635608382Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 14 [2025-09-12T04:42:04.635611718Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_DATA max=16790287 [2025-09-12T04:42:04.635614242Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_STREAM_DATA stream=4 max=73487 [2025-09-12T04:42:04.635622608Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 57 bytes [2025-09-12T04:42:04.635626285Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.635630954Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=6 pn=20 [2025-09-12T04:42:04.635633438Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=4 blocks=[121..124] ecn_counts=None [2025-09-12T04:42:04.635638598Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=47.492804ms latest_rtt=39.397567ms srtt=34.264637ms min_rtt=31.783454ms rttvar=6.071727ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=2337 app_limited=true congestion_recovery_start_time=None Rate { delivered: 14106, delivered_time: Instant { tv_sec: 305, tv_nsec: 582212117 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 542814550 }, end_of_app_limited: 19, last_sent_packet: 20, largest_acked: 14, rate_sample: RateSample { bandwidth: 1.64 Mbps, is_app_limited: true, interval: 39.397567ms, delivered: 8100, prior_delivered: 6006, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 542814550 }), send_elapsed: 0ns, ack_elapsed: 39.397567ms, rtt: 39.397567ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 492490, last_update: Instant { tv_sec: 305, tv_nsec: 574391039 }, next_time: Instant { tv_sec: 305, tv_nsec: 574391039 }, 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-09-12T04:42:04.635688240Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 574391039 } }) [2025-09-12T04:42:04.635699271Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.635704120Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.635707707Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.635710642Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.637502510Z TRACE quiche_server] got 51 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.637508491Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.637513360Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=30 pn=125 [2025-09-12T04:42:04.637518309Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm ACK delay=0 blocks=[7..16] ecn_counts=None [2025-09-12T04:42:04.637521605Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 15 [2025-09-12T04:42:04.637524060Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 packet newly acked 16 [2025-09-12T04:42:04.637529740Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm MAX_DATA max=16792576 [2025-09-12T04:42:04.637546121Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 51 bytes [2025-09-12T04:42:04.637549848Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.637554476Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx pkt Short dcid= key_phase=false len=6 pn=21 [2025-09-12T04:42:04.637557011Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 tx frm ACK delay=5 blocks=[121..125] ecn_counts=None [2025-09-12T04:42:04.637562121Z TRACE quiche::recovery::congestion::recovery] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 timer=none latest_rtt=41.313014ms srtt=35.145683ms min_rtt=31.783454ms rttvar=6.315889ms cwnd=13500 ssthresh=18446744073709551615 bytes_in_flight=0 app_limited=true congestion_recovery_start_time=None Rate { delivered: 16443, delivered_time: Instant { tv_sec: 305, tv_nsec: 574391039 }, first_sent_time: Instant { tv_sec: 305, tv_nsec: 574391039 }, end_of_app_limited: 20, last_sent_packet: 21, largest_acked: 16, rate_sample: RateSample { bandwidth: 2.02 Mbps, is_app_limited: true, interval: 41.313014ms, delivered: 10437, prior_delivered: 6006, prior_time: Some(Instant { tv_sec: 305, tv_nsec: 542814550 }), send_elapsed: 0ns, ack_elapsed: 41.313014ms, rtt: 41.313014ms } } pacer=Pacer { enabled: false, capacity: 13500, used: 0, rate: 480144, last_update: Instant { tv_sec: 305, tv_nsec: 574391039 }, next_time: Instant { tv_sec: 305, tv_nsec: 574391039 }, 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-09-12T04:42:04.637590714Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 written 24 bytes with Some(SendInfo { from: [::]:443, to: [::ffff:193.167.0.100]:56721, at: Instant { tv_sec: 305, tv_nsec: 574391039 } }) [2025-09-12T04:42:04.637595042Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.637599761Z TRACE quiche_server] got 44 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.637602536Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.637606764Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx pkt Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false len=23 pn=126 [2025-09-12T04:42:04.637611172Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 rx frm APPLICATION_CLOSE err=0 reason=[] [2025-09-12T04:42:04.637621992Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 44 bytes [2025-09-12T04:42:04.637625579Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.637627783Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.637629947Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.658235669Z TRACE quiche_server] got 49 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.658249655Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.658263921Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 49 bytes [2025-09-12T04:42:04.658269361Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.658272577Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.658275603Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.663845578Z TRACE quiche_server] got 49 bytes from [::ffff:193.167.0.100]:56721 to [::]:443 [2025-09-12T04:42:04.663861157Z TRACE quiche_server] got packet Short dcid=c5e5ecd5cf51939999c76be0516c08dfc9ac8603 key_phase=false [2025-09-12T04:42:04.663868842Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 processed 49 bytes [2025-09-12T04:42:04.663874672Z TRACE quiche_server] recv() would block [2025-09-12T04:42:04.663878169Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.663881395Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.819057262Z TRACE quiche_server] timed out [2025-09-12T04:42:04.819071789Z TRACE quiche] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 draining timeout expired [2025-09-12T04:42:04.819099661Z TRACE quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 done writing [2025-09-12T04:42:04.819102656Z TRACE quiche_server] Collecting garbage [2025-09-12T04:42:04.819106493Z INFO quiche_server] c5e5ecd5cf51939999c76be0516c08dfc9ac8603 connection collected recv=15 sent=22 lost=0 retrans=0 sent_bytes=16764 recv_bytes=5806 lost_bytes=0 [local_addr=[::]:443 peer_addr=[::ffff:193.167.0.100]:56721 validation_state=Validated active=true recv=15 sent=22 lost=0 retrans=0 rtt=35.145683ms min_rtt=Some(31.783454ms) rttvar=6.315889ms cwnd=13500 sent_bytes=16764 recv_bytes=5806 lost_bytes=0 stream_retrans_bytes=0 pmtu=1350 delivery_rate=252632]