multilevel: track per-tier read failures

docs/MultiLevel.md

@@ -8,6 +8,7 @@ Multi-level caching enables hierarchical cache storage, similar to how CPUs use
 - [Architecture](#architecture)
 - [Use Cases](#use-cases)
 - [Configuration](#configuration)
+- [Statistics](#statistics)
 - [Best Practices](#best-practices)
 
 ## Overview
@@ -234,6 +235,29 @@ If `SCCACHE_MULTILEVEL_CHAIN` is not set, sccache uses the first configured cach
 export SCCACHE_DIR="/tmp/cache"
 ```
 
+## Statistics
+
+`sccache --show-stats` and `--show-adv-stats` report each level's completed
+read outcomes:
+
+- **Hits**: the level returned a cached entry or raw cached bytes.
+- **Misses**: the level completed the read without finding the key.
+- **Read failures**: the level's read returned an error.
+
+A failed read is not also counted as a miss. Levels after a hit are not
+consulted and their counters do not change. The per-level hit rate is
+`hits / (hits + misses)`; read failures are excluded. JSON statistics expose
+the failure count as `stats.multi_level[].read_failures`.
+
+Completed reads are counted even if a later level stalls and the lookup is
+cancelled. A still-pending read is not counted as a completed outcome.
+
+Read failures do not change fallback behavior: the next level is tried, and
+exhausting the chain still returns an overall miss, even if every level
+failed. Per-level failures are therefore distinct from the aggregate
+`Cache read errors` counter, which counts lookup errors reported to the
+compilation pipeline.
+
 ## Best Practices
 
 ### 1. Order Levels by Latency (Fastest First)

src/cache/multilevel.rs

@@ -44,6 +44,7 @@ struct AtomicLevelStats {
     location: String,
     hits: AtomicU64,
     misses: AtomicU64,
+    read_failures: AtomicU64,
     writes: AtomicU64,
     write_failures: AtomicU64,
     backfills_from: AtomicU64,
@@ -59,6 +60,7 @@ impl AtomicLevelStats {
             location,
             hits: Default::default(),
             misses: Default::default(),
+            read_failures: Default::default(),
             writes: Default::default(),
             write_failures: Default::default(),
             backfills_from: Default::default(),
@@ -92,6 +94,7 @@ impl AtomicLevelStats {
             location: self.location.clone(),
             hits: self.hits.load(Ordering::Relaxed),
             misses: self.misses.load(Ordering::Relaxed),
+            read_failures: self.read_failures.load(Ordering::Relaxed),
             writes: self.writes.load(Ordering::Relaxed),
             write_failures: self.write_failures.load(Ordering::Relaxed),
             backfills_from: self.backfills_from.load(Ordering::Relaxed),
@@ -113,6 +116,8 @@ pub struct LevelStats {
     pub hits: u64,
     /// Number of cache misses (checked but not found) at this level
     pub misses: u64,
+    /// Number of failed reads at this level
+    pub read_failures: u64,
     /// Number of successful writes to this level
     pub writes: u64,
     /// Number of failed writes to this level
@@ -155,6 +160,7 @@ impl std::ops::AddAssign for LevelStats {
         // name and location identify the level — keep lhs values
         self.hits += rhs.hits;
         self.misses += rhs.misses;
+        self.read_failures += rhs.read_failures;
         self.writes += rhs.writes;
         self.write_failures += rhs.write_failures;
         self.backfills_from += rhs.backfills_from;
@@ -178,7 +184,7 @@ impl std::ops::AddAssign for MultiLevelStats {
 }
 
 impl LevelStats {
-    /// Calculate hit rate as a percentage
+    /// Calculate hit rate among successful reads (hits and misses), excluding failures.
     pub fn hit_rate(&self) -> f64 {
         let total = self.hits + self.misses;
         if total > 0 {
@@ -209,7 +215,7 @@ impl LevelStats {
     /// Format stats for human-readable display
     /// Returns a vector of (label, value_with_suffix, suffix_length) tuples
     /// suffix_length is used for width calculations in formatting
-    /// Order: hits, misses, rate, writes, failures, backfills, write timing, read timing
+    /// Order: hits, misses, read failures, rate, writes, failures, backfills, write timing, read timing
     pub fn format_stats(&self) -> Vec<(String, String, usize)> {
         let mut stats = vec![];
 
@@ -220,6 +226,11 @@ impl LevelStats {
             self.misses.to_string(),
             0,
         ));
+        stats.push((
+            format!("  {} read failures", self.name),
+            self.read_failures.to_string(),
+            0,
+        ));
 
         let total_checks = self.hits + self.misses;
         if total_checks > 0 {
@@ -477,15 +488,6 @@ impl MultiLevelStorage {
             hit_duration_nanos,
             duration.as_nanos() as u64
         );
-        for miss_idx in 0..hit_level {
-            inc_stat!(self.atomic_stats.get(miss_idx), misses, 1);
-        }
-    }
-
-    fn record_all_read_misses(&self) {
-        for idx in 0..self.levels.len() {
-            inc_stat!(self.atomic_stats.get(idx), misses, 1);
-        }
     }
 
     fn backfill_raw_hit(&self, key: &str, raw_bytes: &Bytes, hit_level: usize) {
@@ -601,13 +603,15 @@ impl Storage for MultiLevelStorage {
                     return Ok(Cache::Hit(entry));
                 }
                 Ok(Cache::Miss) => {
+                    inc_stat!(self.atomic_stats.get(idx), misses, 1);
                     trace!("Cache miss at level {}, trying next level", idx);
                     continue;
                 }
                 Ok(other) => {
                     return Ok(other);
                 }
                 Err(e) => {
+                    inc_stat!(self.atomic_stats.get(idx), read_failures, 1);
                     warn!(
                         "Error checking cache level {}: {}, trying next level",
                         idx, e
@@ -618,8 +622,6 @@ impl Storage for MultiLevelStorage {
         }
         debug!("Cache miss at all levels");
 
-        self.record_all_read_misses();
-
         Ok(Cache::Miss)
     }
 
@@ -632,8 +634,11 @@ impl Storage for MultiLevelStorage {
                     self.backfill_raw_hit(key, &bytes, idx);
                     return Ok(Some(bytes));
                 }
-                Ok(None) => {}
+                Ok(None) => {
+                    inc_stat!(self.atomic_stats.get(idx), misses, 1);
+                }
                 Err(error) => {
+                    inc_stat!(self.atomic_stats.get(idx), read_failures, 1);
                     warn!(
                         "Error checking cache level {}: {}, trying next level",
                         idx, error
@@ -642,7 +647,6 @@ impl Storage for MultiLevelStorage {
             }
         }
 
-        self.record_all_read_misses();
         Ok(None)
     }
 

src/cache/multilevel_test.rs

@@ -1776,27 +1776,134 @@ fn test_multilevel_get_raw_records_per_level_stats() {
     assert_eq!(stats.0[1].misses, 0);
 }
 
+fn assert_read_outcomes(stats: &MultiLevelStats, expected: &[(u64, u64, u64)]) {
+    let actual: Vec<_> = stats
+        .0
+        .iter()
+        .map(|level| (level.hits, level.misses, level.read_failures))
+        .collect();
+    assert_eq!(actual, expected);
+}
+
 #[test]
-fn test_multilevel_get_raw_continues_after_level_error() {
+fn test_multilevel_read_outcomes_and_fallback() {
     let runtime = RuntimeBuilder::new_current_thread()
         .enable_all()
         .build()
         .unwrap();
-    let l0 = Arc::new(CheckFailingStorage);
-    let l1 = Arc::new(InMemoryStorage::new());
-    let storage =
-        MultiLevelStorage::new(vec![l0 as Arc<dyn Storage>, l1.clone() as Arc<dyn Storage>]);
 
     runtime.block_on(async {
-        l1.put("hit", CacheWrite::default()).await.unwrap();
-        assert!(storage.get_raw("hit").await.unwrap().is_some());
+        for raw in [false, true] {
+            for (chain, expected) in [
+                ("me", vec![(0, 1, 0), (0, 0, 1)]),
+                ("ee", vec![(0, 0, 1), (0, 0, 1)]),
+                ("eh", vec![(0, 0, 1), (1, 0, 0)]),
+                ("he", vec![(1, 0, 0), (0, 0, 0)]),
+                ("meh", vec![(0, 1, 0), (0, 0, 1), (1, 0, 0)]),
+            ] {
+                let bytes: Bytes = CacheWrite::default().finish().unwrap().into();
+                let mut levels: Vec<Arc<dyn Storage>> = Vec::new();
+                let mut memory_levels = Vec::new();
+                for outcome in chain.chars() {
+                    if outcome == 'e' {
+                        levels.push(Arc::new(CheckFailingStorage));
+                    } else {
+                        let level = Arc::new(InMemoryStorage::new());
+                        if outcome == 'h' {
+                            level.put_raw("key", bytes.clone()).await.unwrap();
+                        }
+                        levels.push(level.clone());
+                        memory_levels.push(level);
+                    }
+                }
+                let storage = MultiLevelStorage::new(levels);
+                let expect_hit = chain.contains('h');
+                if raw {
+                    assert_eq!(
+                        storage.get_raw("key").await.unwrap(),
+                        expect_hit.then(|| bytes.clone())
+                    );
+                } else {
+                    let result = storage.get("key").await.unwrap();
+                    if expect_hit {
+                        assert!(matches!(result, Cache::Hit(_)));
+                    } else {
+                        assert!(matches!(result, Cache::Miss));
+                    }
+                }
+                let stats = storage.stats();
+                assert_read_outcomes(&stats, &expected);
+
+                let mut merged = stats.clone();
+                merged += stats;
+                let doubled: Vec<_> = expected
+                    .iter()
+                    .map(|&(hits, misses, failures)| (hits * 2, misses * 2, failures * 2))
+                    .collect();
+                assert_read_outcomes(&merged, &doubled);
+                let json = serde_json::to_value(&merged).unwrap();
+                for (level, &(_, _, failures)) in json.as_array().unwrap().iter().zip(&doubled) {
+                    assert_eq!(level["read_failures"], serde_json::json!(failures));
+                }
+                let decoded: MultiLevelStats = serde_json::from_value(json).unwrap();
+                assert_read_outcomes(&decoded, &doubled);
+
+                if chain == "meh" {
+                    // A failed intervening tier must not stop a later hit backfilling L0.
+                    tokio::time::timeout(Duration::from_secs(1), async {
+                        loop {
+                            let data = memory_levels[0].data.lock().await;
+                            if data.get("key").map(Vec::as_slice) == Some(bytes.as_ref()) {
+                                break;
+                            }
+                            drop(data);
+                            tokio::task::yield_now().await;
+                        }
+                    })
+                    .await
+                    .expect("later hit should backfill the earlier missing tier");
+                }
+            }
+        }
     });
+}
 
-    let stats = storage.stats();
-    assert_eq!(stats.0[0].hits, 0);
-    assert_eq!(stats.0[0].misses, 1);
-    assert_eq!(stats.0[1].hits, 1);
-    assert_eq!(stats.0[1].misses, 0);
+#[test]
+fn test_multilevel_completed_reads_survive_cancellation() {
+    let runtime = RuntimeBuilder::new_current_thread()
+        .enable_all()
+        .build()
+        .unwrap();
+
+    runtime.block_on(async {
+        for raw in [false, true] {
+            let stalled = Arc::new(InMemoryStorage::new());
+            let storage = MultiLevelStorage::new(vec![
+                Arc::new(InMemoryStorage::new()) as Arc<dyn Storage>,
+                Arc::new(CheckFailingStorage) as Arc<dyn Storage>,
+                stalled.clone() as Arc<dyn Storage>,
+            ]);
+            // Holding the data lock makes the final read pending without relying on timing.
+            let _guard = stalled.data.lock().await;
+            {
+                let lookup = async {
+                    if raw {
+                        storage.get_raw("key").await.map(|_| ())
+                    } else {
+                        storage.get("key").await.map(|_| ())
+                    }
+                };
+                tokio::pin!(lookup);
+                tokio::select! {
+                    biased;
+                    result = &mut lookup => panic!("lookup should remain pending: {:?}", result),
+                    _ = std::future::ready(()) => {}
+                }
+                assert_read_outcomes(&storage.stats(), &[(0, 1, 0), (0, 0, 1), (0, 0, 0)]);
+            }
+            assert_read_outcomes(&storage.stats(), &[(0, 1, 0), (0, 0, 1), (0, 0, 0)]);
+        }
+    });
 }
 
 #[test]