diff --git a/docs/data.md b/docs/data.md index e3f0868b5a..5e032e8f6d 100644 --- a/docs/data.md +++ b/docs/data.md @@ -111,6 +111,18 @@ the level and type of the log is listed. - `cache-status` - If the response was pulled from the cache or regenerated. `"hit"`, `"miss"`, `"error"`, or `"none"`. +- `cache.memory.hit` - A counter that is incremented every time the in-memory + cache is queried and a cached suggestion is found. + +- `cache.memory.miss` - A counter that is incremented every time the in-memory + cache is queried and a cached suggestion is not found. + +- `cache.memory.pointers-len` - A gauge representing the number of entries in + the first level of hashing in the in-memory deduped hashmap. + +- `cache.memory.storage-len` - A gauge representing the number of entries in the + second level of hashing in the in-memory deduped hashmap. + - `cache.redis.duration-us` - A histogram that records the amount of time, in microseconds, that the Redis cache took to provide a suggestion. Includes the time it takes to fallback to the inner provider for cache misses and errors. @@ -119,3 +131,9 @@ the level and type of the log is listed. - `cache-status` - If the response was pulled from the cache or regenerated. `"hit"`, `"miss"`, `"error"`, or `"none"`. + +- `cache.redis.hit` - A counter that is incremented every time the redis cache + is queried and a cached suggestion is found. + +- `cache.redis.miss` - A counter that is incremented every time the redis cache + is queried and a cached suggestion is not found. diff --git a/merino-cache/src/memory.rs b/merino-cache/src/memory.rs index c86c668fdb..3e29a0b023 100644 --- a/merino-cache/src/memory.rs +++ b/merino-cache/src/memory.rs @@ -7,7 +7,7 @@ use anyhow::anyhow; use async_trait::async_trait; -use cadence::{Histogrammed, StatsdClient}; +use cadence::{CountedExt, Gauged, Histogrammed, StatsdClient}; use deduped_dashmap::{ControlFlow, DedupedMap}; use lazy_static::lazy_static; use merino_settings::providers::MemoryCacheConfig; @@ -108,6 +108,7 @@ impl Suggester { let items = Arc::new(DedupedMap::new()); { + let metrics = metrics_client.clone(); let task_items = items.clone(); let task_interval = config.cleanup_interval; tokio::spawn(async move { @@ -118,7 +119,7 @@ impl Suggester { timer.tick().await; loop { timer.tick().await; - Self::remove_expired_entries(&task_items); + Self::remove_expired_entries(&task_items, &metrics); } }); } @@ -138,6 +139,7 @@ impl Suggester { #[tracing::instrument(level = "debug", skip(items))] fn remove_expired_entries( items: &Arc>>, + metrics_client: &StatsdClient, ) { let start = Instant::now(); let count_before_storage = items.len_storage(); @@ -174,6 +176,13 @@ impl Suggester { ?removed_storage, "finished removing expired entries from cache" ); + + metrics_client + .gauge("cache.memory.storage-len", items.len_storage() as u64) + .ok(); + metrics_client + .gauge("cache.memory.pointers-len", items.len_pointers() as u64) + .ok(); } } @@ -207,6 +216,7 @@ impl SuggestionProvider for Suggester { } Some((expiration, suggestions)) => { tracing::debug!("cache hit"); + self.metrics_client.incr("cache.memory.hit").ok(); rv = Some(SuggestionResponse { cache_status: CacheStatus::Hit, cache_ttl: Some(expiration - now), @@ -215,6 +225,7 @@ impl SuggestionProvider for Suggester { } None => { tracing::debug!("cache miss"); + self.metrics_client.incr("cache.memory.miss").ok(); } } @@ -271,6 +282,7 @@ impl SuggestionProvider for Suggester { #[cfg(test)] mod tests { use super::{Suggester, LOCK_TABLE}; + use cadence::{SpyMetricSink, StatsdClient}; use deduped_dashmap::DedupedMap; use fake::{Fake, Faker}; use merino_suggest::Suggestion; @@ -299,12 +311,27 @@ mod tests { assert!(cache.contains_key(&"current".to_owned())); assert!(cache.contains_key(&"expired".to_owned())); - Suggester::remove_expired_entries(&cache); + // Provide an inspectable metrics sink to validate the collected data. + let (rx, sink) = SpyMetricSink::new(); + let metrics_client = StatsdClient::from_sink("merino-test", sink); + + Suggester::remove_expired_entries(&cache, &metrics_client); assert_eq!(cache.len_storage(), 1); assert_eq!(cache.len_pointers(), 1); assert!(cache.contains_key(&"current".to_owned())); assert!(!cache.contains_key(&"expired".to_owned())); + + // Verify the reported metric. + assert_eq!(rx.len(), 2); + let collected_data: Vec = rx + .iter() + .take(2) + .map(|x| String::from_utf8(x).unwrap()) + .collect(); + dbg!(&collected_data); + assert!(collected_data.contains(&"merino-test.cache.memory.storage-len:1|g".to_string())); + assert!(collected_data.contains(&"merino-test.cache.memory.pointers-len:1|g".to_string())); } #[test] diff --git a/merino-cache/src/redis/mod.rs b/merino-cache/src/redis/mod.rs index 7ff14c4481..3f26ca8b45 100644 --- a/merino-cache/src/redis/mod.rs +++ b/merino-cache/src/redis/mod.rs @@ -10,7 +10,7 @@ use std::{ use crate::redis::domain::RedisSuggestions; use anyhow::Context; use async_trait::async_trait; -use cadence::{Histogrammed, StatsdClient}; +use cadence::{CountedExt, Histogrammed, StatsdClient}; use fix_hidden_lifetime_bug::fix_hidden_lifetime_bug; use merino_settings::{providers::RedisCacheConfig, Settings}; use merino_suggest::{ @@ -380,6 +380,7 @@ impl SuggestionProvider for Suggester { let rv = if let CacheCheckResult::Hit(suggestions) = cache_result { tracing::debug!(%key, "cache hit"); + self.metrics_client.incr("cache.redis.hit").ok(); suggestions } else if rlock.is_locked(&key).await? { tracing::debug!(%key, "cache updating..."); @@ -396,6 +397,7 @@ impl SuggestionProvider for Suggester { if let CacheCheckResult::Miss = cache_result { tracing::debug!(%key, "cache miss"); + self.metrics_client.incr("cache.redis.miss").ok(); response.with_cache_status(CacheStatus::Miss) } else { debug_assert!(matches!(cache_result, CacheCheckResult::ErrorAsMiss));