From 49dcf2616cf8dbe3979a3a1ea596266c37b12c16 Mon Sep 17 00:00:00 2001 From: rock Date: Sun, 13 Sep 2026 21:54:26 +0900 Subject: [PATCH] feat: metrics snapshot test harness for scenario verification - MetricsSnapshot::capture() snapshots all metric values - assert_counter_inc(): verify counter delta after scenario - assert_gauge_eq(): verify gauge value - assert_histogram_count_inc(): verify histogram observations - assert_gauge_f64_approx(): verify f64 gauges with tolerance - print_deltas(): debug helper for all changed metrics - 9 scenario tests: ingest, query error, relevance batch, write - Histogram fields made pub for snapshot access - 515 total tests passing --- crates/mem-cli/src/lib.rs | 1 + crates/mem-cli/src/metrics.rs | 12 +- crates/mem-cli/src/metrics_snapshot.rs | 418 +++++++++++++++++++++++++ 3 files changed, 425 insertions(+), 6 deletions(-) create mode 100644 crates/mem-cli/src/metrics_snapshot.rs diff --git a/crates/mem-cli/src/lib.rs b/crates/mem-cli/src/lib.rs index eee6c61..46e9908 100644 --- a/crates/mem-cli/src/lib.rs +++ b/crates/mem-cli/src/lib.rs @@ -2,6 +2,7 @@ pub mod endpoints; pub mod handlers; pub mod http_server; pub mod metrics; +pub mod metrics_snapshot; pub mod relevance_judge; pub mod query; pub mod auth; diff --git a/crates/mem-cli/src/metrics.rs b/crates/mem-cli/src/metrics.rs index 62e2500..5d3dbbe 100644 --- a/crates/mem-cli/src/metrics.rs +++ b/crates/mem-cli/src/metrics.rs @@ -62,12 +62,12 @@ impl GaugeF64 { /// Histogram with fixed buckets for latency tracking pub struct Histogram { - buckets: &'static [f64], - counts: Vec, - sum: AtomicU64, // stored as f64 bits - count: AtomicU64, - name: &'static str, - help: &'static str, + pub buckets: &'static [f64], + pub counts: Vec, + pub sum: AtomicU64, // stored as f64 bits + pub count: AtomicU64, + pub name: &'static str, + pub help: &'static str, } impl Histogram { diff --git a/crates/mem-cli/src/metrics_snapshot.rs b/crates/mem-cli/src/metrics_snapshot.rs new file mode 100644 index 0000000..9d1f5f7 --- /dev/null +++ b/crates/mem-cli/src/metrics_snapshot.rs @@ -0,0 +1,418 @@ +//! Metrics Snapshot & Assertion (Test Harness) +//! +//! Captures metric state before/after a test scenario, +//! then asserts expected deltas per metric. +//! +//! Usage: +//! ```rust +//! let snap = MetricsSnapshot::capture(); +//! // ... run handler / scenario ... +//! snap.assert_counter_inc("memory_ingest_requests_total", 1); +//! snap.assert_counter_inc("memory_ingest_errors_total", 0); +//! snap.assert_gauge_eq("memory_ingest_in_flight", 0); +//! snap.assert_histogram_count_inc("memory_ingest_duration_seconds", 1); +//! ``` + +use std::collections::HashMap; +use std::sync::atomic::Ordering; + +use crate::metrics; + +/// Snapshot of all metric values at a point in time +#[derive(Debug, Clone)] +pub struct MetricsSnapshot { + counters: HashMap<&'static str, u64>, + gauges: HashMap<&'static str, u64>, + gauges_f64: HashMap<&'static str, f64>, + histogram_counts: HashMap<&'static str, u64>, +} + +impl MetricsSnapshot { + /// Capture current state of all metrics + pub fn capture() -> Self { + let mut counters = HashMap::new(); + let mut gauges = HashMap::new(); + let mut gauges_f64 = HashMap::new(); + let mut histogram_counts = HashMap::new(); + + // O1: Ingest counters + counters.insert("memory_ingest_requests_total", metrics::INGEST_REQUESTS_TOTAL.get()); + counters.insert("memory_ingest_errors_total", metrics::INGEST_ERRORS_TOTAL.get()); + counters.insert("memory_ingest_records_total", metrics::INGEST_RECORDS_TOTAL.get()); + counters.insert("memory_ingest_entities_extracted_total", metrics::INGEST_ENTITIES_EXTRACTED.get()); + counters.insert("memory_ingest_edges_extracted_total", metrics::INGEST_EDGES_EXTRACTED.get()); + counters.insert("memory_ingest_duplicates_total", metrics::INGEST_DUPLICATES_TOTAL.get()); + counters.insert("memory_ingest_bytes_total", metrics::INGEST_BYTES_TOTAL.get()); + counters.insert("memory_ingest_auth_failures_total", metrics::INGEST_AUTH_FAILURES.get()); + counters.insert("memory_ingest_rate_limited_total", metrics::INGEST_RATE_LIMITED.get()); + + // O1: Ingest gauges + gauges.insert("memory_ingest_in_flight", metrics::INGEST_IN_FLIGHT.get()); + gauges.insert("memory_ingest_queue_size", metrics::INGEST_QUEUE_SIZE.get()); + + // O1: Ingest histogram (force Lazy init) + histogram_counts.insert("memory_ingest_duration_seconds", + { let _ = &*metrics::INGEST_DURATION; metrics::INGEST_DURATION.count.load(Ordering::Relaxed) }); + + // O2: Query counters + counters.insert("memory_query_requests_total", metrics::QUERY_REQUESTS_TOTAL.get()); + counters.insert("memory_query_errors_total", metrics::QUERY_ERRORS_TOTAL.get()); + counters.insert("memory_query_results_total", metrics::QUERY_RESULTS_TOTAL.get()); + counters.insert("memory_query_empty_results_total", metrics::QUERY_EMPTY_RESULTS.get()); + counters.insert("memory_query_embedding_failures_total", metrics::QUERY_EMBEDDING_FAILURES.get()); + counters.insert("memory_query_auth_failures_total", metrics::QUERY_AUTH_FAILURES.get()); + counters.insert("memory_query_rate_limited_total", metrics::QUERY_RATE_LIMITED.get()); + counters.insert("memory_query_cache_hits_total", metrics::QUERY_CACHE_HITS.get()); + counters.insert("memory_query_cache_misses_total", metrics::QUERY_CACHE_MISSES.get()); + + // O2: Query gauges + gauges.insert("memory_query_in_flight", metrics::QUERY_IN_FLIGHT.get()); + + // O2: Query histograms + histogram_counts.insert("memory_query_duration_seconds", + { let _ = &*metrics::QUERY_DURATION; metrics::QUERY_DURATION.count.load(Ordering::Relaxed) }); + histogram_counts.insert("memory_query_embedding_duration_seconds", + { let _ = &*metrics::QUERY_EMBEDDING_DURATION; metrics::QUERY_EMBEDDING_DURATION.count.load(Ordering::Relaxed) }); + + // O3: Context + counters.insert("memory_context_requests_total", metrics::CONTEXT_REQUESTS_TOTAL.get()); + counters.insert("memory_context_errors_total", metrics::CONTEXT_ERRORS_TOTAL.get()); + counters.insert("memory_context_semantic_hits_total", metrics::CONTEXT_SEMANTIC_HITS.get()); + counters.insert("memory_context_bm25_hits_total", metrics::CONTEXT_BM25_HITS.get()); + counters.insert("memory_context_graph_hits_total", metrics::CONTEXT_GRAPH_HITS.get()); + counters.insert("memory_context_empty_results_total", metrics::CONTEXT_EMPTY_RESULTS.get()); + histogram_counts.insert("memory_context_duration_seconds", + { let _ = &*metrics::CONTEXT_DURATION; metrics::CONTEXT_DURATION.count.load(Ordering::Relaxed) }); + + // O4: Relevance histograms + histogram_counts.insert("memory_relevance_eval_duration_seconds", + { let _ = &*metrics::RELEVANCE_EVAL_DURATION; metrics::RELEVANCE_EVAL_DURATION.count.load(Ordering::Relaxed) }); + + // O5: Write histogram + histogram_counts.insert("memory_write_duration_seconds", + { let _ = &*metrics::WRITE_DURATION; metrics::WRITE_DURATION.count.load(Ordering::Relaxed) }); + + // O7: Dependency latency + histogram_counts.insert("memory_dependency_db_latency_seconds", + { let _ = &*metrics::DEP_DB_LATENCY; metrics::DEP_DB_LATENCY.count.load(Ordering::Relaxed) }); + + // O4: Relevance + counters.insert("memory_relevance_evals_total", metrics::RELEVANCE_EVALS_TOTAL.get()); + counters.insert("memory_relevance_errors_total", metrics::RELEVANCE_ERRORS_TOTAL.get()); + counters.insert("memory_relevance_relevant_total", metrics::RELEVANCE_RELEVANT_TOTAL.get()); + counters.insert("memory_relevance_irrelevant_total", metrics::RELEVANCE_IRRELEVANT_TOTAL.get()); + gauges_f64.insert("memory_relevance_precision", metrics::RELEVANCE_PRECISION.get()); + gauges_f64.insert("memory_relevance_recall", metrics::RELEVANCE_RECALL.get()); + gauges_f64.insert("memory_relevance_f1_score", metrics::RELEVANCE_F1.get()); + + // O5: Write + counters.insert("memory_write_entities_total", metrics::WRITE_ENTITIES_TOTAL.get()); + counters.insert("memory_write_edges_total", metrics::WRITE_EDGES_TOTAL.get()); + counters.insert("memory_write_chunks_total", metrics::WRITE_CHUNKS_TOTAL.get()); + counters.insert("memory_write_errors_total", metrics::WRITE_ERRORS_TOTAL.get()); + counters.insert("memory_write_bytes_total", metrics::WRITE_BYTES_TOTAL.get()); + + // O7: Health + counters.insert("memory_health_checks_total", metrics::HEALTH_CHECKS_TOTAL.get()); + counters.insert("memory_health_check_failures_total", metrics::HEALTH_CHECK_FAILURES.get()); + gauges.insert("memory_dependency_db_up", metrics::DEP_DB_UP.get()); + gauges.insert("memory_dependency_embedding_up", metrics::DEP_EMBEDDING_UP.get()); + + // O8: Ingest rate + counters.insert("memory_ingest_dedup_total", metrics::INGEST_DEDUP_TOTAL.get()); + counters.insert("memory_ingest_contradiction_total", metrics::INGEST_CONTRADICTION_TOTAL.get()); + + // O9: DB + counters.insert("memory_db_queries_total", metrics::DB_QUERY_TOTAL.get()); + counters.insert("memory_db_query_errors_total", metrics::DB_QUERY_ERRORS.get()); + + Self { counters, gauges, gauges_f64, histogram_counts } + } + + /// Assert a counter increased by exactly `expected` since snapshot + pub fn assert_counter_inc(&self, name: &str, expected: u64) { + let before = self.counters.get(name) + .unwrap_or_else(|| panic!("Unknown counter: {}", name)); + let after = Self::get_current_counter(name); + let delta = after - before; + assert_eq!(delta, expected, + "Counter {} expected +{} but got +{} (before={}, after={})", + name, expected, delta, before, after); + } + + /// Assert a counter increased by at least `min` since snapshot + pub fn assert_counter_inc_at_least(&self, name: &str, min: u64) { + let before = self.counters.get(name) + .unwrap_or_else(|| panic!("Unknown counter: {}", name)); + let after = Self::get_current_counter(name); + let delta = after - before; + assert!(delta >= min, + "Counter {} expected at least +{} but got +{} (before={}, after={})", + name, min, delta, before, after); + } + + /// Assert a gauge equals exactly `expected` + pub fn assert_gauge_eq(&self, name: &str, expected: u64) { + let current = Self::get_current_gauge(name); + assert_eq!(current, expected, + "Gauge {} expected {} but got {}", name, expected, current); + } + + /// Assert a histogram observation count increased by `expected` + pub fn assert_histogram_count_inc(&self, name: &str, expected: u64) { + let before = self.histogram_counts.get(name) + .unwrap_or_else(|| panic!("Unknown histogram: {}", name)); + let after = Self::get_current_histogram_count(name); + let delta = after - before; + assert_eq!(delta, expected, + "Histogram {} count expected +{} but got +{} (before={}, after={})", + name, expected, delta, before, after); + } + + /// Assert a f64 gauge is within tolerance + pub fn assert_gauge_f64_approx(&self, name: &str, expected: f64, tolerance: f64) { + let current = Self::get_current_gauge_f64(name); + assert!((current - expected).abs() <= tolerance, + "Gauge {} expected {:.4} (±{}) but got {:.4}", + name, expected, tolerance, current); + } + + /// Get delta for a counter since snapshot + pub fn counter_delta(&self, name: &str) -> u64 { + let before = self.counters.get(name).copied().unwrap_or(0); + let after = Self::get_current_counter(name); + after - before + } + + /// Print all deltas since snapshot (for debugging) + pub fn print_deltas(&self) { + println!("=== Metrics Deltas ==="); + for (name, before) in &self.counters { + let after = Self::get_current_counter(name); + let delta = after - before; + if delta > 0 { + println!(" {} +{} ({} -> {})", name, delta, before, after); + } + } + for (name, before) in &self.histogram_counts { + let after = Self::get_current_histogram_count(name); + let delta = after - before; + if delta > 0 { + println!(" {} count +{}", name, delta); + } + } + } + + // ─── Internal helpers ─────────────────────────────────── + + fn get_current_counter(name: &str) -> u64 { + match name { + "memory_ingest_requests_total" => metrics::INGEST_REQUESTS_TOTAL.get(), + "memory_ingest_errors_total" => metrics::INGEST_ERRORS_TOTAL.get(), + "memory_ingest_records_total" => metrics::INGEST_RECORDS_TOTAL.get(), + "memory_ingest_entities_extracted_total" => metrics::INGEST_ENTITIES_EXTRACTED.get(), + "memory_ingest_edges_extracted_total" => metrics::INGEST_EDGES_EXTRACTED.get(), + "memory_ingest_duplicates_total" => metrics::INGEST_DUPLICATES_TOTAL.get(), + "memory_ingest_bytes_total" => metrics::INGEST_BYTES_TOTAL.get(), + "memory_ingest_auth_failures_total" => metrics::INGEST_AUTH_FAILURES.get(), + "memory_ingest_rate_limited_total" => metrics::INGEST_RATE_LIMITED.get(), + "memory_query_requests_total" => metrics::QUERY_REQUESTS_TOTAL.get(), + "memory_query_errors_total" => metrics::QUERY_ERRORS_TOTAL.get(), + "memory_query_results_total" => metrics::QUERY_RESULTS_TOTAL.get(), + "memory_query_empty_results_total" => metrics::QUERY_EMPTY_RESULTS.get(), + "memory_query_embedding_failures_total" => metrics::QUERY_EMBEDDING_FAILURES.get(), + "memory_query_auth_failures_total" => metrics::QUERY_AUTH_FAILURES.get(), + "memory_query_rate_limited_total" => metrics::QUERY_RATE_LIMITED.get(), + "memory_query_cache_hits_total" => metrics::QUERY_CACHE_HITS.get(), + "memory_query_cache_misses_total" => metrics::QUERY_CACHE_MISSES.get(), + "memory_context_requests_total" => metrics::CONTEXT_REQUESTS_TOTAL.get(), + "memory_context_errors_total" => metrics::CONTEXT_ERRORS_TOTAL.get(), + "memory_context_semantic_hits_total" => metrics::CONTEXT_SEMANTIC_HITS.get(), + "memory_context_bm25_hits_total" => metrics::CONTEXT_BM25_HITS.get(), + "memory_context_graph_hits_total" => metrics::CONTEXT_GRAPH_HITS.get(), + "memory_context_empty_results_total" => metrics::CONTEXT_EMPTY_RESULTS.get(), + "memory_relevance_evals_total" => metrics::RELEVANCE_EVALS_TOTAL.get(), + "memory_relevance_errors_total" => metrics::RELEVANCE_ERRORS_TOTAL.get(), + "memory_relevance_relevant_total" => metrics::RELEVANCE_RELEVANT_TOTAL.get(), + "memory_relevance_irrelevant_total" => metrics::RELEVANCE_IRRELEVANT_TOTAL.get(), + "memory_write_entities_total" => metrics::WRITE_ENTITIES_TOTAL.get(), + "memory_write_edges_total" => metrics::WRITE_EDGES_TOTAL.get(), + "memory_write_chunks_total" => metrics::WRITE_CHUNKS_TOTAL.get(), + "memory_write_errors_total" => metrics::WRITE_ERRORS_TOTAL.get(), + "memory_write_bytes_total" => metrics::WRITE_BYTES_TOTAL.get(), + "memory_health_checks_total" => metrics::HEALTH_CHECKS_TOTAL.get(), + "memory_health_check_failures_total" => metrics::HEALTH_CHECK_FAILURES.get(), + "memory_ingest_dedup_total" => metrics::INGEST_DEDUP_TOTAL.get(), + "memory_ingest_contradiction_total" => metrics::INGEST_CONTRADICTION_TOTAL.get(), + "memory_db_queries_total" => metrics::DB_QUERY_TOTAL.get(), + "memory_db_query_errors_total" => metrics::DB_QUERY_ERRORS.get(), + _ => panic!("Unknown counter: {}", name), + } + } + + fn get_current_gauge(name: &str) -> u64 { + match name { + "memory_ingest_in_flight" => metrics::INGEST_IN_FLIGHT.get(), + "memory_ingest_queue_size" => metrics::INGEST_QUEUE_SIZE.get(), + "memory_query_in_flight" => metrics::QUERY_IN_FLIGHT.get(), + "memory_dependency_db_up" => metrics::DEP_DB_UP.get(), + "memory_dependency_embedding_up" => metrics::DEP_EMBEDDING_UP.get(), + "memory_dependency_opensearch_up" => metrics::DEP_OPENSEARCH_UP.get(), + "memory_dependency_llm_up" => metrics::DEP_LLM_UP.get(), + "memory_app_uptime_seconds" => metrics::APP_UPTIME_SECONDS.get(), + "memory_db_pool_size" => metrics::DB_POOL_SIZE.get(), + "memory_db_pool_idle" => metrics::DB_POOL_IDLE.get(), + "memory_db_table_entity_rows" => metrics::DB_TABLE_ENTITY_ROWS.get(), + "memory_db_table_edge_rows" => metrics::DB_TABLE_EDGE_ROWS.get(), + "memory_db_table_chunk_rows" => metrics::DB_TABLE_CHUNK_ROWS.get(), + _ => panic!("Unknown gauge: {}", name), + } + } + + fn get_current_gauge_f64(name: &str) -> f64 { + match name { + "memory_relevance_precision" => metrics::RELEVANCE_PRECISION.get(), + "memory_relevance_recall" => metrics::RELEVANCE_RECALL.get(), + "memory_relevance_f1_score" => metrics::RELEVANCE_F1.get(), + "memory_ingest_rate_1m" => metrics::INGEST_RATE_1M.get(), + "memory_ingest_rate_5m" => metrics::INGEST_RATE_5M.get(), + _ => panic!("Unknown gauge_f64: {}", name), + } + } + + fn get_current_histogram_count(name: &str) -> u64 { + match name { + "memory_ingest_duration_seconds" => + metrics::INGEST_DURATION.count.load(Ordering::Relaxed), + "memory_query_duration_seconds" => + metrics::QUERY_DURATION.count.load(Ordering::Relaxed), + "memory_query_embedding_duration_seconds" => + metrics::QUERY_EMBEDDING_DURATION.count.load(Ordering::Relaxed), + "memory_context_duration_seconds" => + metrics::CONTEXT_DURATION.count.load(Ordering::Relaxed), + "memory_relevance_eval_duration_seconds" => + metrics::RELEVANCE_EVAL_DURATION.count.load(Ordering::Relaxed), + "memory_write_duration_seconds" => { + // Force Lazy init + let _ = &*metrics::WRITE_DURATION; + metrics::WRITE_DURATION.count.load(Ordering::Relaxed) + } + "memory_dependency_db_latency_seconds" => { + let _ = &*metrics::DEP_DB_LATENCY; + metrics::DEP_DB_LATENCY.count.load(Ordering::Relaxed) + } + _ => panic!("Unknown histogram: {}", name), + } + } +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::relevance_judge::RelevanceJudge; + + #[test] + fn test_snapshot_captures_state() { + let snap = MetricsSnapshot::capture(); + assert!(snap.counters.contains_key("memory_ingest_requests_total")); + assert!(snap.counters.contains_key("memory_query_requests_total")); + assert!(snap.gauges.contains_key("memory_ingest_in_flight")); + assert!(snap.histogram_counts.contains_key("memory_ingest_duration_seconds")); + } + + #[test] + fn test_counter_delta_zero_when_no_change() { + let snap = MetricsSnapshot::capture(); + snap.assert_counter_inc("memory_write_entities_total", 0); + } + + #[test] + fn test_counter_tracks_increment() { + let snap = MetricsSnapshot::capture(); + metrics::WRITE_ENTITIES_TOTAL.inc_by(3); + snap.assert_counter_inc("memory_write_entities_total", 3); + } + + #[test] + fn test_counter_delta_method() { + let snap = MetricsSnapshot::capture(); + metrics::WRITE_EDGES_TOTAL.inc_by(7); + assert_eq!(snap.counter_delta("memory_write_edges_total"), 7); + } + + #[test] + fn test_histogram_count_tracks() { + let snap = MetricsSnapshot::capture(); + metrics::WRITE_DURATION.observe(0.05); + metrics::WRITE_DURATION.observe(0.10); + snap.assert_histogram_count_inc("memory_write_duration_seconds", 2); + } + + #[test] + fn test_relevance_scenario_metrics() { + let snap = MetricsSnapshot::capture(); + + let judge = RelevanceJudge::new(0.5); + let results = vec![ + ("good result".to_string(), 0.9), + ("bad result".to_string(), 0.1), + ("ok result".to_string(), 0.6), + ]; + let summary = judge.evaluate_batch("test query", &results); + + // Verify metrics match scenario + snap.assert_counter_inc("memory_relevance_evals_total", 3); + snap.assert_counter_inc("memory_relevance_relevant_total", 2); // 0.9 + 0.6 + snap.assert_counter_inc("memory_relevance_irrelevant_total", 1); // 0.1 + + // Verify precision gauge + snap.assert_gauge_f64_approx("memory_relevance_precision", summary.precision, 0.01); + + assert_eq!(summary.total, 3); + assert_eq!(summary.relevant, 2); + } + + #[test] + fn test_ingest_counter_scenario() { + let snap = MetricsSnapshot::capture(); + + // Simulate ingest scenario + metrics::INGEST_REQUESTS_TOTAL.inc(); + metrics::INGEST_RECORDS_TOTAL.inc_by(5); + metrics::INGEST_BYTES_TOTAL.inc_by(1024); + metrics::INGEST_ENTITIES_EXTRACTED.inc_by(3); + metrics::INGEST_EDGES_EXTRACTED.inc_by(2); + + snap.assert_counter_inc("memory_ingest_requests_total", 1); + snap.assert_counter_inc("memory_ingest_records_total", 5); + snap.assert_counter_inc("memory_ingest_bytes_total", 1024); + snap.assert_counter_inc("memory_ingest_entities_extracted_total", 3); + snap.assert_counter_inc("memory_ingest_edges_extracted_total", 2); + snap.assert_counter_inc("memory_ingest_errors_total", 0); + } + + #[test] + fn test_query_error_scenario() { + let snap = MetricsSnapshot::capture(); + + // Simulate query that fails at embedding + metrics::QUERY_REQUESTS_TOTAL.inc(); + metrics::QUERY_IN_FLIGHT.inc(); + metrics::QUERY_EMBEDDING_FAILURES.inc(); + metrics::QUERY_ERRORS_TOTAL.inc(); + metrics::QUERY_IN_FLIGHT.dec(); + + snap.assert_counter_inc("memory_query_requests_total", 1); + snap.assert_counter_inc("memory_query_embedding_failures_total", 1); + snap.assert_counter_inc("memory_query_errors_total", 1); + snap.assert_counter_inc("memory_query_results_total", 0); + snap.assert_gauge_eq("memory_query_in_flight", 0); + } + + #[test] + fn test_print_deltas_works() { + let snap = MetricsSnapshot::capture(); + metrics::HEALTH_CHECKS_TOTAL.inc(); + snap.print_deltas(); // Should not panic + } +}