cache: preserve and count lookup read errors

docs/Architecture.md

@@ -160,6 +160,16 @@ are exchanged with `StorageGetPreprocessorEntry` / `StoragePutPreprocessorEntry`
 Because each CLI process accumulates its own statistics, it flushes them to the
 daemon with `RecordStats` before exiting.
 
+`StorageGetRaw` preserves backend read errors across IPC; an error is not an
+ordinary missing key. Invalid cached archives also produce lookup errors,
+whether the CLI reads a local path or receives raw bytes.
+
+In both execution modes, a cache read error followed by a successful local
+compilation increments `Cache read errors` as well as the existing `Cache errors`
+and `Cache misses` counters. Ordinary misses do not increment the read-error
+counter, and overall lookup timeouts are recorded separately as `Cache timeouts`.
+Errors handled inside a multilevel tier walk are not aggregate lookup errors.
+
 Client-side mode is enabled with the `SCCACHE_CLIENT_SIDE` environment variable
 (or the `client_side_mode` config key). It is expected to become the only
 supported configuration in the future, with server-side mode eventually

src/cache/ipc_storage.rs

@@ -75,18 +75,12 @@ impl Storage for IpcStorage {
             GetPathResult::Found(path) => {
                 let file = std::fs::File::open(&path)
                     .with_context(|| format!("IpcStorage::get: open {}", path.display()))?;
-                match CacheRead::from(file) {
-                    Ok(entry) => Ok(Cache::Hit(entry)),
-                    Err(_) => Ok(Cache::Miss),
-                }
+                Ok(Cache::Hit(CacheRead::from(file)?))
             }
             GetPathResult::Miss => Ok(Cache::Miss),
             // Backend doesn't support paths (S3, Redis, …); fall back to bytes over IPC.
             GetPathResult::Unsupported => match self.get_raw(key).await? {
-                Some(bytes) => match CacheRead::from(Cursor::new(bytes)) {
-                    Ok(entry) => Ok(Cache::Hit(entry)),
-                    Err(_) => Ok(Cache::Miss),
-                },
+                Some(bytes) => Ok(Cache::Hit(CacheRead::from(Cursor::new(bytes))?)),
                 None => Ok(Cache::Miss),
             },
         }
@@ -115,7 +109,8 @@ impl Storage for IpcStorage {
             })
             .await?;
         match resp {
-            Response::StorageGetRaw(opt) => Ok(opt.map(Bytes::from)),
+            Response::StorageGetRaw(Ok(opt)) => Ok(opt.map(Bytes::from)),
+            Response::StorageGetRaw(Err(e)) => bail!("IpcStorage::get_raw: daemon error: {e}"),
             other => bail!("IpcStorage::get_raw: unexpected response: {other:?}"),
         }
     }

src/protocol.rs

@@ -58,8 +58,8 @@ pub enum Response {
     StorageHandshake(StorageHandshakeInfo),
     /// Response for `Request::StorageGetPath`.
     StorageGetPath(GetPathResult),
-    /// Response for `Request::StorageGetRaw`: zip bytes on hit, `None` on miss.
-    StorageGetRaw(Option<Vec<u8>>),
+    /// Response for `Request::StorageGetRaw`: zip bytes on hit, `None` on miss, or a read error.
+    StorageGetRaw(Result<Option<Vec<u8>>, String>),
     /// Response for `Request::StoragePutRaw`.
     StoragePutRaw(Result<(), String>),
     /// Response for `Request::StorageGetPreprocessorEntry`.

src/server.rs

@@ -955,14 +955,13 @@ where
                 }
                 Request::StorageGetRaw { key } => {
                     debug!("handle_client: storage_get_raw key={}", key);
-                    let resp = match me.storage.get_raw(&key).await {
-                        Ok(opt) => Response::StorageGetRaw(opt.map(|b| b.to_vec())),
-                        Err(e) => {
-                            warn!("storage_get_raw error: {e:#}");
-                            Response::StorageGetRaw(None)
-                        }
-                    };
-                    Ok(Message::WithoutBody(resp))
+                    let result = me
+                        .storage
+                        .get_raw(&key)
+                        .await
+                        .map(|opt| opt.map(|b| b.to_vec()))
+                        .map_err(|e| format!("{e:#}"));
+                    Ok(Message::WithoutBody(Response::StorageGetRaw(result)))
                 }
                 Request::StoragePutRaw { key, data } => {
                     debug!("handle_client: storage_put_raw key={}", key);
@@ -1618,6 +1617,7 @@ where
                                     stats.cache_timeouts += 1;
                                 }
                                 MissType::CacheReadError => {
+                                    stats.cache_read_errors += 1;
                                     stats.cache_errors.increment(&kind, &lang);
                                 }
                             }
@@ -2893,6 +2893,152 @@ mod tests {
         (body, finished)
     }
 
+    fn connect_ipc_storage(
+        runtime: &Runtime,
+        storage: Arc<dyn Storage>,
+    ) -> (
+        crate::cache::IpcStorage,
+        tokio::task::JoinHandle<Result<()>>,
+    ) {
+        let listener = runtime
+            .block_on(tokio::net::TcpListener::bind("127.0.0.1:0"))
+            .unwrap();
+        let addr = crate::net::SocketAddr::Net(listener.local_addr().unwrap());
+        let service = MockService::mock_with_storage(storage, runtime.handle().clone());
+        let server = runtime.spawn(async move {
+            let (socket, _) = listener.accept().await?;
+            service.bind(socket).await
+        });
+        let connection = crate::client::connect_to_server(&addr).unwrap();
+        let storage = crate::cache::ipc_storage::IpcStorage::connect(connection).unwrap();
+        (storage, server)
+    }
+
+    #[test_case::test_case(Err(anyhow!("backend read failed")), true; "backend_error")]
+    #[test_case::test_case(Ok(Some(bytes::Bytes::from_static(b"not a zip"))), true; "invalid_archive")]
+    #[test_case::test_case(Ok(None), false; "normal_miss")]
+    fn ipc_lookup_outcomes_reach_service_stats(
+        lookup: Result<Option<bytes::Bytes>>,
+        read_error: bool,
+    ) {
+        use crate::test::mock_storage::MockStorage;
+
+        let (_f, runtime, mut service, compile) = rustc_miss_fixture();
+        let backend = Arc::new(MockStorage::new(None, false));
+        backend.next_get_raw(lookup);
+        let (storage, server) = connect_ipc_storage(&runtime, backend);
+        service.storage = Arc::new(storage);
+
+        let (response, finished, _) = runtime
+            .block_on(service.compile_direct(compile, &mut Vec::new()))
+            .unwrap();
+        assert!(matches!(response, CompileResponse::CompileStarted));
+        assert_eq!(finished.unwrap().retcode, Some(0));
+        assert_eq!(service.creator.lock().unwrap().children.len(), 0);
+        let stats = runtime.block_on(service.take_stats());
+        assert_eq!(stats.cache_read_errors, u64::from(read_error));
+        assert_eq!(stats.cache_errors.all(), u64::from(read_error));
+        assert_eq!(stats.cache_misses.all(), 1);
+        assert_eq!(stats.compilations, 1);
+        assert_eq!(stats.requests_executed, 1);
+        assert_eq!(stats.cache_timeouts, 0);
+        assert_eq!(stats.cache_hits.all(), 0);
+        assert_eq!(stats.compile_fails, 0);
+
+        drop(service);
+        runtime.block_on(server).unwrap().unwrap();
+    }
+
+    #[test]
+    fn ipc_disk_lookup_preserves_hits_misses_and_archive_errors() {
+        use crate::cache::{Cache, CacheWrite};
+
+        let (_f, runtime, service, _compile) = rustc_miss_fixture();
+        let (storage, server) = connect_ipc_storage(&runtime, service.storage.clone());
+        let key = "0123456789abcdef";
+        assert!(matches!(
+            runtime.block_on(storage.get(key)).unwrap(),
+            Cache::Miss
+        ));
+
+        let mut entry = CacheWrite::new();
+        entry.put_stdout(b"cached output").unwrap();
+        runtime.block_on(service.storage.put(key, entry)).unwrap();
+        match runtime.block_on(storage.get(key)).unwrap() {
+            Cache::Hit(mut entry) => assert_eq!(entry.get_stdout(), b"cached output"),
+            _ => panic!("expected a cache hit"),
+        }
+
+        runtime
+            .block_on(
+                service
+                    .storage
+                    .put_raw(key, bytes::Bytes::from_static(b"not a zip")),
+            )
+            .unwrap();
+        assert!(runtime.block_on(storage.get(key)).is_err());
+
+        drop(storage);
+        runtime.block_on(server).unwrap().unwrap();
+    }
+
+    #[test_case::test_case(true, false; "daemon_read_error")]
+    #[test_case::test_case(false, false; "daemon_normal_miss")]
+    #[test_case::test_case(true, true; "client_side_read_error")]
+    #[test_case::test_case(false, true; "client_side_normal_miss")]
+    fn cache_lookup_outcomes_preserve_service_stats(read_error: bool, client_side: bool) {
+        use crate::cache::Cache;
+        use crate::test::mock_storage::MockStorage;
+
+        let (f, runtime, mut service, compile) = rustc_miss_fixture();
+        let storage = Arc::new(MockStorage::new(None, false));
+        storage.next_get(if read_error {
+            Err(anyhow!("cache lookup failed"))
+        } else {
+            Ok(Cache::Miss)
+        });
+        service.storage = storage;
+
+        let (finished, stats) = if client_side {
+            let (response, finished, _) = runtime
+                .block_on(service.compile_direct(compile, &mut Vec::new()))
+                .unwrap();
+            assert!(matches!(response, CompileResponse::CompileStarted));
+            (
+                finished.expect("compile started"),
+                runtime.block_on(service.take_stats()),
+            )
+        } else {
+            let (_, finished) = compile_body(&runtime, &service, compile);
+            (
+                finished,
+                runtime.block_on(service.get_info()).unwrap().stats,
+            )
+        };
+
+        assert_eq!(finished.retcode, Some(0));
+        assert_eq!(
+            std::fs::read(f.tempdir.path().join("libdep.rlib")).unwrap(),
+            b"rlib"
+        );
+        assert_eq!(service.creator.lock().unwrap().children.len(), 0);
+        assert_eq!(stats.requests_executed, 1);
+        assert_eq!(stats.cache_read_errors, u64::from(read_error));
+        assert_eq!(stats.cache_errors.all(), u64::from(read_error));
+        assert_eq!(
+            stats.cache_errors.get("Rust").copied().unwrap_or(0),
+            u64::from(read_error)
+        );
+        assert_eq!(stats.cache_misses.all(), 1);
+        assert_eq!(stats.cache_misses.get("Rust"), Some(&1));
+        assert_eq!(stats.compilations, 1);
+        assert_eq!(stats.cache_hits.all(), 0);
+        assert_eq!(stats.cache_timeouts, 0);
+        assert_eq!(stats.compile_fails, 0);
+        assert_eq!(stats.cache_writes, 1);
+        assert_eq!(stats.cache_write_errors, 0);
+    }
+
     #[test]
     fn records_non_cacheable_crate_type_detail_in_existing_stats_map() {
         let mut stats = ServerStats::default();

src/test/mock_storage.rs

@@ -16,6 +16,7 @@ use crate::cache::{Cache, CacheWrite, Storage};
 use crate::config::PreprocessorCacheModeConfig;
 use crate::errors::*;
 use async_trait::async_trait;
+use bytes::Bytes;
 use futures::channel::mpsc;
 use std::sync::Arc;
 use std::time::Duration;
@@ -26,6 +27,8 @@ use tokio::time::sleep;
 pub struct MockStorage {
     rx: Arc<Mutex<mpsc::UnboundedReceiver<Result<Cache>>>>,
     tx: mpsc::UnboundedSender<Result<Cache>>,
+    raw_rx: Mutex<mpsc::UnboundedReceiver<Result<Option<Bytes>>>>,
+    raw_tx: mpsc::UnboundedSender<Result<Option<Bytes>>>,
     delay: Option<Duration>,
     preprocessor_cache_mode: bool,
 }
@@ -34,10 +37,13 @@ impl MockStorage {
     /// Create a new `MockStorage`. if `delay` is `Some`, wait for that amount of time before returning from operations.
     pub(crate) fn new(delay: Option<Duration>, preprocessor_cache_mode: bool) -> MockStorage {
         let (tx, rx) = mpsc::unbounded();
+        let (raw_tx, raw_rx) = mpsc::unbounded();
         Self {
             tx,
             rx: Arc::new(Mutex::new(rx)),
             delay,
+            raw_tx,
+            raw_rx: Mutex::new(raw_rx),
             preprocessor_cache_mode,
         }
     }
@@ -46,6 +52,11 @@ impl MockStorage {
     pub(crate) fn next_get(&self, res: Result<Cache>) {
         self.tx.unbounded_send(res).unwrap();
     }
+
+    /// Queue up `res` to be returned as the next result from `Storage::get_raw`.
+    pub(crate) fn next_get_raw(&self, res: Result<Option<Bytes>>) {
+        self.raw_tx.unbounded_send(res).unwrap();
+    }
 }
 
 #[async_trait]
@@ -58,6 +69,10 @@ impl Storage for MockStorage {
 
         next.expect("MockStorage get called but no get results available")
     }
+    async fn get_raw(&self, _key: &str) -> Result<Option<Bytes>> {
+        let next = self.raw_rx.lock().await.try_next().unwrap();
+        next.unwrap_or(Ok(None))
+    }
     async fn put(&self, _key: &str, _entry: CacheWrite) -> Result<Duration> {
         Ok(if let Some(delay) = self.delay {
             sleep(delay).await;