WIP: Add database read/write/delete timing metrics

ledger/store/Cargo.toml

@@ -60,6 +60,9 @@ workspace = true
 [dependencies.snarkvm-ledger-puzzle]
 workspace = true
 
+[dependencies.snarkvm-metrics]
+workspace = true
+
 [dependencies.snarkvm-synthesizer-program]
 workspace = true
 

ledger/store/src/helpers/memory/internal/map.rs

@@ -100,7 +100,16 @@ impl<
             }
             // Otherwise, insert the key-value pair directly into the map.
             false => {
-                self.map.write().insert(bincode::serialize(&key)?, value);
+                let serialized_key = bincode::serialize(&key)?;
+                let start = std::time::Instant::now();
+                self.map.write().insert(serialized_key, value);
+                let duration = start.elapsed().as_secs_f64();
+                snarkvm_metrics::histogram_label(
+                    snarkvm_metrics::database::WRITE_DURATION,
+                    "map_type",
+                    "memory".to_string(),
+                    duration,
+                );
             }
         }
 
@@ -119,7 +128,16 @@ impl<
             }
             // Otherwise, remove the key-value pair directly from the map.
             false => {
-                self.map.write().remove(&bincode::serialize(&key)?);
+                let serialized_key = bincode::serialize(&key)?;
+                let start = std::time::Instant::now();
+                self.map.write().remove(&serialized_key);
+                let duration = start.elapsed().as_secs_f64();
+                snarkvm_metrics::histogram_label(
+                    snarkvm_metrics::database::DELETE_DURATION,
+                    "map_type",
+                    "memory".to_string(),
+                    duration,
+                );
             }
         }
 
@@ -217,12 +235,24 @@ impl<
                 .collect::<Result<Vec<_>>>()?;
 
             // Perform all the queued operations.
+            let start = std::time::Instant::now();
             for (key, value) in prepared_operations {
                 match value {
-                    Some(value) => locked_map.insert(key, value),
-                    None => locked_map.remove(&key),
+                    Some(value) => {
+                        locked_map.insert(key, value);
+                    }
+                    None => {
+                        locked_map.remove(&key);
+                    }
                 };
             }
+            let duration = start.elapsed().as_secs_f64();
+            snarkvm_metrics::histogram_label(
+                snarkvm_metrics::database::WRITE_DURATION,
+                "map_type",
+                "memory_batch".to_string(),
+                duration,
+            );
         }
 
         // Clear the checkpoint stack.
@@ -315,7 +345,17 @@ impl<
         K: Borrow<Q>,
         Q: PartialEq + Eq + Hash + Serialize + ?Sized,
     {
-        Ok(self.map.read().get(&bincode::serialize(key)?).cloned().map(Cow::Owned))
+        let serialized_key = bincode::serialize(key)?;
+        let start = std::time::Instant::now();
+        let result = self.map.read().get(&serialized_key).cloned();
+        let duration = start.elapsed().as_secs_f64();
+        snarkvm_metrics::histogram_label(
+            snarkvm_metrics::database::READ_DURATION,
+            "map_type",
+            "memory".to_string(),
+            duration,
+        );
+        Ok(result.map(Cow::Owned))
     }
 
     ///

ledger/store/src/helpers/rocksdb/internal/map.rs

@@ -53,6 +53,33 @@ impl<K: Serialize + DeserializeOwned, V: Serialize + DeserializeOwned> InnerData
         let checkpoint = rocksdb::checkpoint::Checkpoint::new(&self.database)?;
         checkpoint.create_checkpoint(path).map_err(|e| e.into_string())
     }
+
+    /// Returns a human-readable map type label for metrics based on the context.
+    fn map_type_label(&self) -> &'static str {
+        // Extract the map_id from context (bytes 2-4 contain the u16 map_id)
+        if self.context.len() >= 4 {
+            let map_id_bytes = [self.context[2], self.context[3]];
+            let map_id = u16::from_le_bytes(map_id_bytes);
+
+            // Map the ID ranges to categories based on DataID enum ordering
+            match map_id {
+                0..=1 => "bft",
+                2..=18 => "block",
+                19..=21 => "committee",
+                22..=29 => "deployment",
+                30..=32 => "execution",
+                33..=34 => "fee",
+                35..=42 => "input",
+                43..=51 => "output",
+                52 => "transaction",
+                53..=57 => "transition",
+                58..=59 => "program",
+                _ => "unknown",
+            }
+        } else {
+            "unknown"
+        }
+    }
 }
 
 impl<
@@ -76,7 +103,16 @@ impl<
                 // Prepare the prefixed key and serialized value.
                 let raw_key = self.create_prefixed_key(&key)?;
                 let raw_value = bincode::serialize(&value)?;
+                let map_type = self.map_type_label();
+                let start = std::time::Instant::now();
                 self.database.put(raw_key, raw_value)?;
+                let duration = start.elapsed().as_secs_f64();
+                snarkvm_metrics::histogram_label(
+                    snarkvm_metrics::database::WRITE_DURATION,
+                    "map_type",
+                    map_type.to_string(),
+                    duration,
+                );
             }
         }
 
@@ -97,7 +133,16 @@ impl<
             false => {
                 // Prepare the prefixed key.
                 let raw_key = self.create_prefixed_key(key)?;
+                let map_type = self.map_type_label();
+                let start = std::time::Instant::now();
                 self.database.delete(raw_key)?;
+                let duration = start.elapsed().as_secs_f64();
+                snarkvm_metrics::histogram_label(
+                    snarkvm_metrics::database::DELETE_DURATION,
+                    "map_type",
+                    map_type.to_string(),
+                    duration,
+                );
             }
         }
 
@@ -236,7 +281,15 @@ impl<
             // Empty the collection of pending operations.
             let batch = mem::take(&mut *self.database.atomic_batch.lock());
             // Execute all the operations atomically.
+            let start = std::time::Instant::now();
             self.database.rocksdb.write(batch)?;
+            let duration = start.elapsed().as_secs_f64();
+            snarkvm_metrics::histogram_label(
+                snarkvm_metrics::database::WRITE_DURATION,
+                "map_type",
+                "batch".to_string(),
+                duration,
+            );
             // Ensure that the database atomic batch is empty.
             assert!(self.database.atomic_batch.lock().is_empty());
         }
@@ -543,10 +596,17 @@ impl<K: Serialize + DeserializeOwned, V: Serialize + DeserializeOwned> DataMap<K
         Q: Serialize + ?Sized,
     {
         let raw_key = self.create_prefixed_key(key)?;
-        match self.database.get_pinned_opt(&raw_key, &self.database.default_readopts)? {
-            Some(data) => Ok(Some(data)),
-            None => Ok(None),
-        }
+        let map_type = self.map_type_label();
+        let start = std::time::Instant::now();
+        let result = self.database.get_pinned_opt(&raw_key, &self.database.default_readopts)?;
+        let duration = start.elapsed().as_secs_f64();
+        snarkvm_metrics::histogram_label(
+            snarkvm_metrics::database::READ_DURATION,
+            "map_type",
+            map_type.to_string(),
+            duration,
+        );
+        Ok(result)
     }
 }
 
@@ -560,9 +620,7 @@ impl<K: Serialize + DeserializeOwned, V: Serialize + DeserializeOwned> fmt::Debu
 mod tests {
     use super::*;
     use crate::{
-        FinalizeMode,
-        atomic_batch_scope,
-        atomic_finalize,
+        FinalizeMode, atomic_batch_scope, atomic_finalize,
         helpers::rocksdb::{MapID, TestMap},
     };
     use console::{

metrics/src/lib.rs

@@ -16,16 +16,26 @@
 #![forbid(unsafe_code)]
 
 const GAUGE_NAMES: [&str; 1] = [committee::TOTAL_STAKE];
+const HISTOGRAM_NAMES: [&str; 3] = [database::READ_DURATION, database::WRITE_DURATION, database::DELETE_DURATION];
 
 pub mod committee {
     pub const TOTAL_STAKE: &str = "snarkvm_ledger_committee_total_stake";
 }
 
+pub mod database {
+    pub const READ_DURATION: &str = "snarkvm_database_read_duration_seconds";
+    pub const WRITE_DURATION: &str = "snarkvm_database_write_duration_seconds";
+    pub const DELETE_DURATION: &str = "snarkvm_database_delete_duration_seconds";
+}
+
 /// Registers all snarkVM metrics.
 pub fn register_metrics() {
     for name in GAUGE_NAMES {
         register_gauge(name);
     }
+    for name in HISTOGRAM_NAMES {
+        register_histogram(name);
+    }
 }
 
 /******** Counter ********/
@@ -103,3 +113,15 @@ pub fn histogram<V: Into<f64>>(name: &'static str, value: V) {
 pub fn histogram_label<V: Into<f64>>(name: &'static str, label_key: &'static str, label_value: String, value: V) {
     ::metrics::histogram!(name, label_key => label_value).record(value.into());
 }
+
+/// Times a database operation and records the duration with the given map type label.
+pub fn time_database_operation<F, R>(metric_name: &'static str, map_type: &str, operation: F) -> R
+where
+    F: FnOnce() -> R,
+{
+    let start = std::time::Instant::now();
+    let result = operation();
+    let duration = start.elapsed().as_secs_f64();
+    histogram_label(metric_name, "map_type", map_type.to_string(), duration);
+    result
+}