diff --git a/pageserver/src/context.rs b/pageserver/src/context.rs index d21a56f247..16d072754c 100644 --- a/pageserver/src/context.rs +++ b/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. diff --git a/pageserver/src/tenant/block_io.rs b/pageserver/src/tenant/block_io.rs index 37c84be342..89c91c6893 100644 --- a/pageserver/src/tenant/block_io.rs +++ b/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?; diff --git a/pageserver/src/tenant/timeline.rs b/pageserver/src/tenant/timeline.rs index 0975686d5c..726fec0e9f 100644 --- a/pageserver/src/tenant/timeline.rs +++ b/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() {