quic: update receive_duration hist within fd_quic

akhinvasara-jumptrading · akhinvasara-jumptrading · commit d2aec3e655b0 · 2025-07-11T16:11:24.000Z
diff --git a/book/api/metrics-generated.md b/book/api/metrics-generated.md
@@ -144,7 +144,7 @@
 | <span class="metrics-name">quic_&#8203;ack_&#8203;tx</span><br/>{quic_&#8203;ack_&#8203;tx="<span class="metrics-enum">drop</span>"} | counter | ACK events (out of buffers) |
 | <span class="metrics-name">quic_&#8203;ack_&#8203;tx</span><br/>{quic_&#8203;ack_&#8203;tx="<span class="metrics-enum">cancel</span>"} | counter | ACK events (ACK suppressed by handler) |
 | <span class="metrics-name">quic_&#8203;service_&#8203;duration_&#8203;seconds</span> | histogram | Duration spent in service |
-| <span class="metrics-name">quic_&#8203;receive_&#8203;duration_&#8203;seconds</span> | histogram | Duration spent receiving packets |
+| <span class="metrics-name">quic_&#8203;receive_&#8203;duration_&#8203;seconds</span> | histogram | Duration spent processing packets |
 | <span class="metrics-name">quic_&#8203;frame_&#8203;fail_&#8203;parse</span> | counter | Number of QUIC frames failed to parse. |
 | <span class="metrics-name">quic_&#8203;pkt_&#8203;crypto_&#8203;failed</span><br/>{quic_&#8203;enc_&#8203;level="<span class="metrics-enum">initial</span>"} | counter | Number of packets that failed decryption. (initial) |
 | <span class="metrics-name">quic_&#8203;pkt_&#8203;crypto_&#8203;failed</span><br/>{quic_&#8203;enc_&#8203;level="<span class="metrics-enum">early</span>"} | counter | Number of packets that failed decryption. (early data) |
@@ -788,7 +788,7 @@
 | <span class="metrics-name">send_&#8203;ack_&#8203;tx</span><br/>{quic_&#8203;ack_&#8203;tx="<span class="metrics-enum">drop</span>"} | counter | Total count of ACK frames transmitted (out of buffers) |
 | <span class="metrics-name">send_&#8203;ack_&#8203;tx</span><br/>{quic_&#8203;ack_&#8203;tx="<span class="metrics-enum">cancel</span>"} | counter | Total count of ACK frames transmitted (ACK suppressed by handler) |
 | <span class="metrics-name">send_&#8203;service_&#8203;duration_&#8203;seconds</span> | histogram | Duration spent in service |
-| <span class="metrics-name">send_&#8203;receive_&#8203;duration_&#8203;seconds</span> | histogram | Duration spent receiving packets |
+| <span class="metrics-name">send_&#8203;receive_&#8203;duration_&#8203;seconds</span> | histogram | Duration spent processing packets |
 
 </div>
 
@@ -798,7 +798,7 @@
 
 | Metric | Type | Description |
 |--------|------|-------------|
-| <span class="metrics-name">snaprd_&#8203;state</span> | gauge | State of the tile. 0 = waiting for at least one peer from gossip, 1 = collecting peers from gossip, 2 = pinging peers, 3 = collecting ping responses, 4 = reading full snapshot file, 5 = reading incremental snapshot file, 6 = downloading full snapshot file, 7 = downloading incremental snapshot file, 8 = pinging peers before loading the incremental snapshot, 0 = collecting ping responses before loading the incremental snapshot, 10 = waiting for full snapshot to finish loading, 11 = waiting for incremental snapshot to finish loading, 12 = done  |
+| <span class="metrics-name">snaprd_&#8203;state</span> | gauge | State of the tile. 0 = waiting for at least one peer from gossip, 1 = collecting peers from gossip, 2 = pinging peers, 3 = collecting ping responses, 4 = reading full snapshot file, 5 = reading incremental snapshot file, 6 = downloading full snapshot file, 7 = downloading incremental snapshot file, 8 = pinging peers before loading the incremental snapshot, 0 = collecting ping responses before loading the incremental snapshot, 10 = waiting for full snapshot to finish loading, 11 = waiting for incremental snapshot to finish loading, 12 = done. |
 | <span class="metrics-name">snaprd_&#8203;full_&#8203;num_&#8203;retries</span> | counter | Number of times we aborted and retried full snapshot download because the peer was too slow |
 | <span class="metrics-name">snaprd_&#8203;incremental_&#8203;num_&#8203;retries</span> | counter | Number of times we aborted and retried incremental snapshot download because the peer was too slow |
 | <span class="metrics-name">snaprd_&#8203;full_&#8203;bytes_&#8203;read</span> | gauge | Number of bytes read so far from the full snapshot. Might decrease if snapshot load is aborted and restarted |
@@ -816,7 +816,7 @@
 
 | Metric | Type | Description |
 |--------|------|-------------|
-| <span class="metrics-name">snapdc_&#8203;state</span> | gauge | State of the tile. 0 = waiting for compressed byte stream, 1 = decompressing full snapshot, 2 = decompressing incremental snapshot, 3 = Done |
+| <span class="metrics-name">snapdc_&#8203;state</span> | gauge | State of the tile. 0 = waiting for compressed byte stream, 1 = decompressing full snapshot, 2 = decompressing incremental snapshot, 3 = done. |
 | <span class="metrics-name">snapdc_&#8203;full_&#8203;compressed_&#8203;bytes_&#8203;read</span> | gauge | Number of bytes read so far from the compressed full snapshot file. Might decrease if snapshot load is aborted and restarted |
 | <span class="metrics-name">snapdc_&#8203;full_&#8203;decompressed_&#8203;bytes_&#8203;read</span> | gauge | Number of bytes read so far from the decompressed file. Might decrease if snapshot load is aborted and restarted |
 | <span class="metrics-name">snapdc_&#8203;full_&#8203;decompressed_&#8203;bytes_&#8203;total</span> | gauge | Total size of the decompressed full snapshot file. Might change if snapshot load is aborted and restarted |
@@ -832,7 +832,7 @@
 
 | Metric | Type | Description |
 |--------|------|-------------|
-| <span class="metrics-name">snapin_&#8203;state</span> | gauge | State of the tile. 0 = waiting for decompressed snapshot bytestream, 1 = processing full snapshot, 2 = processing incremental snapshot, 3 = Done |
+| <span class="metrics-name">snapin_&#8203;state</span> | gauge | State of the tile. 0 = waiting for decompressed snapshot bytestream, 1 = processing full snapshot, 2 = processing incremental snapshot, 3 = done. |
 | <span class="metrics-name">snapin_&#8203;full_&#8203;accounts_&#8203;files_&#8203;processed</span> | gauge | Number of accounts files (appendvecs) processed in the full snapshot. Might decrease if snapshot load is aborted and restarted |
 | <span class="metrics-name">snapin_&#8203;full_&#8203;accounts_&#8203;files_&#8203;total</span> | gauge | Total number of accounts files in the full snapshot. Might change if snapshot load is aborted and restarted |
 | <span class="metrics-name">snapin_&#8203;incremental_&#8203;accounts_&#8203;files_&#8203;processed</span> | gauge | Number of accounts files (appendvecs) processed in the incremental snapshot. Might decrease if snapshot load is aborted and restarted |
diff --git a/src/disco/metrics/generated/fd_metrics_quic.h b/src/disco/metrics/generated/fd_metrics_quic.h
@@ -253,7 +253,7 @@
 #define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_OFF  (95UL)
 #define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_NAME "quic_receive_duration_seconds"
 #define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_TYPE (FD_METRICS_TYPE_HISTOGRAM)
-#define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_DESC "Duration spent receiving packets"
+#define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_DESC "Duration spent processing packets"
 #define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_CVT  (FD_METRICS_CONVERTER_SECONDS)
 #define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_MIN  (1e-08)
 #define FD_METRICS_HISTOGRAM_QUIC_RECEIVE_DURATION_SECONDS_MAX  (0.1)
diff --git a/src/disco/metrics/generated/fd_metrics_send.h b/src/disco/metrics/generated/fd_metrics_send.h
@@ -296,7 +296,7 @@
 #define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_OFF  (109UL)
 #define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_NAME "send_receive_duration_seconds"
 #define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_TYPE (FD_METRICS_TYPE_HISTOGRAM)
-#define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_DESC "Duration spent receiving packets"
+#define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_DESC "Duration spent processing packets"
 #define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_CVT  (FD_METRICS_CONVERTER_SECONDS)
 #define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_MIN  (1e-08)
 #define FD_METRICS_HISTOGRAM_SEND_RECEIVE_DURATION_SECONDS_MAX  (0.1)
diff --git a/src/disco/metrics/generated/fd_metrics_snapdc.h b/src/disco/metrics/generated/fd_metrics_snapdc.h
@@ -6,7 +6,7 @@
 #define FD_METRICS_GAUGE_SNAPDC_STATE_OFF  (16UL)
 #define FD_METRICS_GAUGE_SNAPDC_STATE_NAME "snapdc_state"
 #define FD_METRICS_GAUGE_SNAPDC_STATE_TYPE (FD_METRICS_TYPE_GAUGE)
-#define FD_METRICS_GAUGE_SNAPDC_STATE_DESC "State of the tile. 0 = waiting for compressed byte stream, 1 = decompressing full snapshot, 2 = decompressing incremental snapshot, 3 = Done"
+#define FD_METRICS_GAUGE_SNAPDC_STATE_DESC "State of the tile. 0 = waiting for compressed byte stream, 1 = decompressing full snapshot, 2 = decompressing incremental snapshot, 3 = done."
 #define FD_METRICS_GAUGE_SNAPDC_STATE_CVT  (FD_METRICS_CONVERTER_NONE)
 
 #define FD_METRICS_GAUGE_SNAPDC_FULL_COMPRESSED_BYTES_READ_OFF  (17UL)
diff --git a/src/disco/metrics/generated/fd_metrics_snapin.h b/src/disco/metrics/generated/fd_metrics_snapin.h
@@ -6,7 +6,7 @@
 #define FD_METRICS_GAUGE_SNAPIN_STATE_OFF  (16UL)
 #define FD_METRICS_GAUGE_SNAPIN_STATE_NAME "snapin_state"
 #define FD_METRICS_GAUGE_SNAPIN_STATE_TYPE (FD_METRICS_TYPE_GAUGE)
-#define FD_METRICS_GAUGE_SNAPIN_STATE_DESC "State of the tile. 0 = waiting for decompressed snapshot bytestream, 1 = processing full snapshot, 2 = processing incremental snapshot, 3 = Done"
+#define FD_METRICS_GAUGE_SNAPIN_STATE_DESC "State of the tile. 0 = waiting for decompressed snapshot bytestream, 1 = processing full snapshot, 2 = processing incremental snapshot, 3 = done."
 #define FD_METRICS_GAUGE_SNAPIN_STATE_CVT  (FD_METRICS_CONVERTER_NONE)
 
 #define FD_METRICS_GAUGE_SNAPIN_FULL_ACCOUNTS_FILES_PROCESSED_OFF  (17UL)
diff --git a/src/disco/metrics/generated/fd_metrics_snaprd.h b/src/disco/metrics/generated/fd_metrics_snaprd.h
@@ -6,7 +6,7 @@
 #define FD_METRICS_GAUGE_SNAPRD_STATE_OFF  (16UL)
 #define FD_METRICS_GAUGE_SNAPRD_STATE_NAME "snaprd_state"
 #define FD_METRICS_GAUGE_SNAPRD_STATE_TYPE (FD_METRICS_TYPE_GAUGE)
-#define FD_METRICS_GAUGE_SNAPRD_STATE_DESC "State of the tile. 0 = waiting for at least one peer from gossip, 1 = collecting peers from gossip, 2 = pinging peers, 3 = collecting ping responses, 4 = reading full snapshot file, 5 = reading incremental snapshot file, 6 = downloading full snapshot file, 7 = downloading incremental snapshot file, 8 = pinging peers before loading the incremental snapshot, 0 = collecting ping responses before loading the incremental snapshot, 10 = waiting for full snapshot to finish loading, 11 = waiting for incremental snapshot to finish loading, 12 = done"
+#define FD_METRICS_GAUGE_SNAPRD_STATE_DESC "State of the tile. 0 = waiting for at least one peer from gossip, 1 = collecting peers from gossip, 2 = pinging peers, 3 = collecting ping responses, 4 = reading full snapshot file, 5 = reading incremental snapshot file, 6 = downloading full snapshot file, 7 = downloading incremental snapshot file, 8 = pinging peers before loading the incremental snapshot, 0 = collecting ping responses before loading the incremental snapshot, 10 = waiting for full snapshot to finish loading, 11 = waiting for incremental snapshot to finish loading, 12 = done."
 #define FD_METRICS_GAUGE_SNAPRD_STATE_CVT  (FD_METRICS_CONVERTER_NONE)
 
 #define FD_METRICS_COUNTER_SNAPRD_FULL_NUM_RETRIES_OFF  (17UL)
diff --git a/src/disco/metrics/metrics.xml b/src/disco/metrics/metrics.xml
@@ -209,7 +209,7 @@ metric introduced.
       <summary>Duration spent in service</summary>
     </histogram>
     <histogram name="ReceiveDurationSeconds" min="0.00000001" max="0.1" converter="seconds">
-      <summary>Duration spent receiving packets</summary>
+      <summary>Duration spent processing packets</summary>
     </histogram>
 
     <counter name="FrameFailParse" summary="Number of QUIC frames failed to parse." />
@@ -300,7 +300,7 @@ metric introduced.
       <summary>Duration spent in service</summary>
     </histogram>
     <histogram name="ReceiveDurationSeconds" min="0.00000001" max="0.1" converter="seconds">
-      <summary>Duration spent receiving packets</summary>
+      <summary>Duration spent processing packets</summary>
     </histogram>
 </tile>
 
diff --git a/src/disco/quic/fd_quic_tile.c b/src/disco/quic/fd_quic_tile.c
@@ -223,12 +223,7 @@ after_frag( fd_quic_ctx_t *     ctx,
     ulong   ip_sz  = sz - sizeof(fd_eth_hdr_t);
 
     fd_quic_t * quic = ctx->quic;
-    long dt = -fd_tickcount();
     fd_quic_process_packet( quic, ip_pkt, ip_sz );
-    dt += fd_tickcount();
-    fd_histf_sample( quic->metrics.receive_duration, (ulong)dt );
-    quic->metrics.net_rx_byte_cnt += sz;
-    quic->metrics.net_rx_pkt_cnt++;
   } else if( FD_LIKELY( proto==DST_PROTO_TPU_UDP ) ) {
     ulong network_hdr_sz = fd_disco_netmux_sig_hdr_sz( sig );
     if( FD_UNLIKELY( sz<=network_hdr_sz ) ) {
@@ -557,6 +552,7 @@ unprivileged_init( fd_topo_t *      topo,
   if( FD_UNLIKELY( scratch_top > (ulong)scratch + scratch_footprint( tile ) ) )
     FD_LOG_ERR(( "scratch overflow %lu %lu %lu", scratch_top - (ulong)scratch - scratch_footprint( tile ), scratch_top, (ulong)scratch + scratch_footprint( tile ) ));
 
+  /* Call new/join here rather than in fd_quic so min/max can differ across uses */
   fd_histf_join( fd_histf_new( ctx->quic->metrics.service_duration, FD_MHIST_SECONDS_MIN( QUIC, SERVICE_DURATION_SECONDS ),
                                                                     FD_MHIST_SECONDS_MAX( QUIC, SERVICE_DURATION_SECONDS ) ) );
   fd_histf_join( fd_histf_new( ctx->quic->metrics.receive_duration, FD_MHIST_SECONDS_MIN( QUIC, RECEIVE_DURATION_SECONDS ),
diff --git a/src/disco/quic/test_quic_metrics.txt b/src/disco/quic/test_quic_metrics.txt
@@ -180,7 +180,7 @@ quic_service_duration_seconds_bucket{kind="quic",kind_id="0",le="+Inf"} 1368
 quic_service_duration_seconds_sum{kind="quic",kind_id="0"} 9.3999999999999995e-08
 quic_service_duration_seconds_count{kind="quic",kind_id="0"} 1368
 
-# HELP quic_receive_duration_seconds Duration spent receiving packets
+# HELP quic_receive_duration_seconds Duration spent processing packets
 # TYPE quic_receive_duration_seconds histogram
 quic_receive_duration_seconds_bucket{kind="quic",kind_id="0",le="8.9999999999999995e-09"} 95
 quic_receive_duration_seconds_bucket{kind="quic",kind_id="0",le="3.1e-08"} 191
diff --git a/src/discof/send/fd_send_tile.c b/src/discof/send/fd_send_tile.c
@@ -383,10 +383,7 @@ after_frag( fd_send_tile_ctx_t * ctx,
     ulong       ip_sz  = sz - sizeof(fd_eth_hdr_t);
     fd_quic_t * quic   = ctx->quic;
 
-    long dt = -fd_tickcount();
     fd_quic_process_packet( quic, ip_pkt, ip_sz );
-    dt += fd_tickcount();
-    fd_histf_sample( quic->metrics.receive_duration, (ulong)dt );
   }
 
   if( FD_UNLIKELY( kind==IN_KIND_TOWER ) ) {
@@ -530,10 +527,11 @@ unprivileged_init( fd_topo_t *      topo,
   fd_quic_set_clock_tickcount( quic );
   FD_TEST_CUSTOM( fd_quic_init( quic ), "fd_quic_init failed" );
 
+  /* Call new/join here rather than in fd_quic so min/max can differ across uses */
   fd_histf_join( fd_histf_new( quic->metrics.service_duration, FD_MHIST_SECONDS_MIN( SEND, SERVICE_DURATION_SECONDS ),
-                                                                    FD_MHIST_SECONDS_MAX( SEND, SERVICE_DURATION_SECONDS ) ) );
+                                                               FD_MHIST_SECONDS_MAX( SEND, SERVICE_DURATION_SECONDS ) ) );
   fd_histf_join( fd_histf_new( quic->metrics.receive_duration, FD_MHIST_SECONDS_MIN( SEND, RECEIVE_DURATION_SECONDS ),
-                                                                    FD_MHIST_SECONDS_MAX( SEND, RECEIVE_DURATION_SECONDS ) ) );
+                                                               FD_MHIST_SECONDS_MAX( SEND, RECEIVE_DURATION_SECONDS ) ) );
 
   ctx->quic = quic;
 
diff --git a/src/waltz/quic/fd_quic.c b/src/waltz/quic/fd_quic.c
@@ -2399,10 +2399,10 @@ is_version_invalid( fd_quic_t * quic, uint version ) {
   return 0;
 }
 
-void
-fd_quic_process_packet( fd_quic_t * quic,
-                        uchar *     data,
-                        ulong       data_sz ) {
+static inline void
+fd_quic_process_packet_impl( fd_quic_t * quic,
+                             uchar *     data,
+                             ulong       data_sz ) {
 
   fd_quic_state_t * state = fd_quic_get_state( quic );
   state->now = fd_quic_now( quic );
@@ -2569,6 +2569,19 @@ fd_quic_process_packet( fd_quic_t * quic,
   fd_quic_process_quic_packet_v1( quic, &pkt, cur_ptr, cur_sz );
 }
 
+void
+fd_quic_process_packet( fd_quic_t * quic,
+                        uchar *     data,
+                        ulong       data_sz ) {
+  long dt = -fd_tickcount();
+  fd_quic_process_packet_impl( quic, data, data_sz );
+  dt += fd_tickcount();
+  fd_histf_sample( quic->metrics.receive_duration, (ulong)dt );
+
+  quic->metrics.net_rx_byte_cnt += data_sz;
+  quic->metrics.net_rx_pkt_cnt++;
+}
+
 /* main receive-side entry point */
 int
 fd_quic_aio_cb_receive( void *                    context,
@@ -2580,9 +2593,6 @@ fd_quic_aio_cb_receive( void *                    context,
 
   fd_quic_t * quic = context;
 
-  /* need tickcount for metrics */
-  long  now_ticks = fd_tickcount();
-
   FD_DEBUG(
     fd_quic_state_t * state = fd_quic_get_state( quic );
     static ulong t0 = 0;
@@ -2595,7 +2605,6 @@ fd_quic_aio_cb_receive( void *                    context,
      as such, we simply forward each individual packet to a handling function */
   for( ulong j = 0; j < batch_cnt; ++j ) {
     fd_quic_process_packet( quic, batch[ j ].buf, batch[ j ].buf_sz );
-    quic->metrics.net_rx_byte_cnt += batch[ j ].buf_sz;
   }
 
   /* the assumption here at present is that any packet that could not be processed
@@ -2605,8 +2614,6 @@ fd_quic_aio_cb_receive( void *                    context,
     *opt_batch_idx = batch_cnt;
   }
 
-  quic->metrics.net_rx_pkt_cnt += batch_cnt;
-
   FD_DEBUG(
     t1 = fd_quic_now( quic );
     ulong delta = t1 - t0;
@@ -2615,10 +2622,6 @@ fd_quic_aio_cb_receive( void *                    context,
     }
   )
 
-  long delta_ticks = fd_tickcount() - now_ticks;
-
-  fd_histf_sample( quic->metrics.receive_duration, (ulong)delta_ticks );
-
   return FD_AIO_SUCCESS;
 }
 
diff --git a/src/waltz/quic/fd_quic.h b/src/waltz/quic/fd_quic.h
@@ -372,7 +372,7 @@ union fd_quic_metrics {
 
     /* Performance metrics */
     fd_histf_t service_duration[ 1 ]; /* time spent in service */
-    fd_histf_t receive_duration[ 1 ]; /* time spent in RX calls */
+    fd_histf_t receive_duration[ 1 ]; /* time spent in process_packet calls */
   };
 };
 typedef union fd_quic_metrics fd_quic_metrics_t;
