wip: more data

pageserver/src/context.rs

@@ -117,6 +117,9 @@ pub struct ReadPathStatsInner {
     pub plan_read_time: AtomicU32,
     pub read_time: AtomicU32,
     pub sort_reconstruct_data_time: AtomicU32,
+    pub layer_search_time: AtomicU32,
+    pub keyspace_manipulation_time: AtomicU32,
+    pub buffer_cache_hits: AtomicU32,
     pub layers_visited: AtomicU32,
 }
 
@@ -124,13 +127,19 @@ impl std::fmt::Display for ReadPathStatsInner {
     fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
         write!(
             f,
-            "get_reconstruct_data_time={} plan_read_time={} read_time={} sort_time={} layers_visited={}",
+            "get_reconstruct_data_time={} plan_read_time={} read_time={} sort_time={} layer_search_time={} keyspace_manipulation_time={} buffer_cache_hits={} layers_visited={}",
             self.get_reconstruct_data_time.load(std::sync::atomic::Ordering::Relaxed),
             self.plan_read_time
                 .load(std::sync::atomic::Ordering::Relaxed),
             self.read_time.load(std::sync::atomic::Ordering::Relaxed),
             self.sort_reconstruct_data_time
                 .load(std::sync::atomic::Ordering::Relaxed),
+            self.layer_search_time
+                .load(std::sync::atomic::Ordering::Relaxed),
+            self.keyspace_manipulation_time
+                .load(std::sync::atomic::Ordering::Relaxed),
+            self.buffer_cache_hits
+                .load(std::sync::atomic::Ordering::Relaxed),
             self.layers_visited
                 .load(std::sync::atomic::Ordering::Relaxed)
         )
@@ -153,7 +162,7 @@ impl ReadPathStatsInner {
     }
 
     pub fn add_read_time(&self, dur: Duration) {
-        self.plan_read_time.fetch_add(
+        self.read_time.fetch_add(
             dur.as_micros().try_into().unwrap(),
             std::sync::atomic::Ordering::Relaxed,
         );
@@ -166,10 +175,29 @@ impl ReadPathStatsInner {
         );
     }
 
+    pub fn add_layer_search_time(&self, dur: Duration) {
+        self.layer_search_time.fetch_add(
+            dur.as_micros().try_into().unwrap(),
+            std::sync::atomic::Ordering::Relaxed,
+        );
+    }
+
+    pub fn add_keyspace_manipulation_timer(&self, dur: Duration) {
+        self.keyspace_manipulation_time.fetch_add(
+            dur.as_micros().try_into().unwrap(),
+            std::sync::atomic::Ordering::Relaxed,
+        );
+    }
+
     pub fn inc_layer_visited(&self) {
         self.layers_visited
             .fetch_add(1, std::sync::atomic::Ordering::Relaxed);
     }
+
+    pub fn inc_buffer_cache_hits(&self) {
+        self.buffer_cache_hits
+            .fetch_add(1, std::sync::atomic::Ordering::Relaxed);
+    }
 }
 
 /// The kind of access to the page cache.

pageserver/src/tenant/block_io.rs

@@ -203,7 +203,10 @@ impl<'a> FileBlockReader<'a> {
                     format!("Failed to read immutable buf: {e:#}"),
                 )
             })? {
-            ReadBufResult::Found(guard) => Ok(guard.into()),
+            ReadBufResult::Found(guard) => {
+                ctx.read_path_stats.inner.inc_buffer_cache_hits();
+                Ok(guard.into())
+            }
             ReadBufResult::NotFound(write_guard) => {
                 // Read the page from disk into the buffer
                 let write_guard = self.fill_buffer(write_guard, blknum).await?;

pageserver/src/tenant/timeline.rs

@@ -3182,11 +3182,19 @@ impl Timeline {
                 return Err(GetVectoredError::Cancelled);
             }
 
+            let keyspace_manip_timer = Instant::now();
+
             let keys_done_last_step = reconstruct_state.consume_done_keys();
             unmapped_keyspace.remove_overlapping_with(&keys_done_last_step);
             completed_keyspace.merge(&keys_done_last_step);
 
+            ctx.read_path_stats
+                .inner
+                .add_keyspace_manipulation_timer(keyspace_manip_timer.elapsed());
+
             if unmapped_keyspace.start().is_some() {
+                let layer_search_timer = Instant::now();
+
                 let guard = timeline.layers.read().await;
                 let layers = guard.layer_map();
 
@@ -3241,6 +3249,10 @@ impl Timeline {
                 // range at *a particular point in time*. It is fine for the answer to be different
                 // at two different time points.
                 drop(guard);
+
+                ctx.read_path_stats
+                    .inner
+                    .add_layer_search_time(layer_search_timer.elapsed());
             }
 
             if let Some((layer_to_read, keyspace_to_read, lsn_range)) = fringe.next_layer() {