cas: fix metric accounting for duplicate keys

Summary: If multiple `(path, node)` keys map to the same CAS digest, we were recording the number of digests as "fetch" (i.e. attempt) count, but the number of keys as the "hit" count. This could lead to hit count greater than fetch count. Fix by recording the number of keys as "fetch" count.

Reviewed By: liubov-dmitrieva

Differential Revision: D65067201

fbshipit-source-id: 7db173e8de7d41787f78beb5e9342d90e6331adc

eden/scm/lib/revisionstore/src/scmstore/file/fetch.rs

@@ -764,7 +764,9 @@ impl FetchState {
             .collect();
 
         // Include the duplicates in the count.
-        span.record("keys", digest_with_keys.len());
+        let keys_fetch_count = digest_with_keys.len();
+
+        span.record("keys", keys_fetch_count);
 
         let mut digest_to_key: HashMap<CasDigest, Vec<Key>> = HashMap::default();
 
@@ -778,7 +780,7 @@ impl FetchState {
 
         let digests: Vec<CasDigest> = digest_to_key.keys().cloned().collect();
 
-        let mut found = 0;
+        let mut keys_found_count = 0;
         let mut error = 0;
         let mut reqs = 0;
 
@@ -800,7 +802,7 @@ impl FetchState {
                                 tracing::error!("got CAS result for unrequested digest {:?}", digest);
                                 continue;
                             };
-                            found += keys.len();
+                            keys_found_count += keys.len();
                             tracing::trace!(target: "cas", ?keys, ?digest, "file(s) prefetched in cas");
                             for key in keys {
                                 self.found_attributes(
@@ -848,7 +850,7 @@ impl FetchState {
                                     // miss
                                 }
                                 Ok(Some(data)) => {
-                                    found += keys.len();
+                                    keys_found_count += keys.len();
                                     tracing::trace!(target: "cas", ?keys, ?digest, "file(s) found in cas");
                                     if !keys.is_empty() {
                                         let last = keys.pop().unwrap();
@@ -888,14 +890,14 @@ impl FetchState {
             });
         }
 
-        span.record("hits", found);
+        span.record("hits", keys_found_count);
         span.record("requests", reqs);
         span.record("time", start_time.elapsed().as_millis() as u64);
 
         let _ = self.metrics.cas.time_from_duration(start_time.elapsed());
-        self.metrics.cas.fetch(digests.len());
+        self.metrics.cas.fetch(keys_fetch_count);
         self.metrics.cas.err(error);
-        self.metrics.cas.hit(found);
+        self.metrics.cas.hit(keys_found_count);
         self.metrics
             .cas_backend
             .zdb_bytes(total_stats.total_bytes_zdb);

eden/scm/lib/revisionstore/src/scmstore/tree/fetch.rs

@@ -206,7 +206,9 @@ impl FetchState {
             .collect();
 
         // Include the duplicates in the count.
-        span.record("keys", digest_with_keys.len());
+        let keys_fetch_count = digest_with_keys.len();
+
+        span.record("keys", keys_fetch_count);
 
         let mut digest_to_key: HashMap<CasDigest, Vec<Key>> = HashMap::default();
 
@@ -220,7 +222,7 @@ impl FetchState {
 
         let digests: Vec<CasDigest> = digest_to_key.keys().cloned().collect();
 
-        let mut found = 0;
+        let mut keys_found_count = 0;
         let mut error = 0;
         let mut reqs = 0;
 
@@ -251,7 +253,7 @@ impl FetchState {
                             }
                             Ok(Some(data)) => match AugmentedTree::try_deserialize(&*data) {
                                 Ok(tree) => {
-                                    found += keys.len();
+                                    keys_found_count += keys.len();
                                     tracing::trace!(target: "cas", ?keys, ?digest, "tree found in cas");
 
                                     let lazy_tree = LazyTree::Cas(AugmentedTreeWithDigest {
@@ -311,14 +313,14 @@ impl FetchState {
             }).await;
         });
 
-        span.record("hits", found);
+        span.record("hits", keys_found_count);
         span.record("requests", reqs);
         span.record("time", start_time.elapsed().as_millis() as u64);
 
         let _ = self.metrics.cas.time_from_duration(start_time.elapsed());
-        self.metrics.cas.fetch(digests.len());
+        self.metrics.cas.fetch(keys_fetch_count);
         self.metrics.cas.err(error);
-        self.metrics.cas.hit(found);
+        self.metrics.cas.hit(keys_found_count);
         self.metrics
             .cas_backend
             .zdb_bytes(total_stats.total_bytes_zdb);

eden/scm/tests/test-scmstore-cas.t

@@ -161,3 +161,10 @@ And sanity check the counter we are looking for exists:
   scmstore.tree.fetch.indexedlog.cache.keys: 1
   $ hg debugscmstore -r $A --mode file "dir/file" --config devel.print-metrics=scmstore.file.fetch.indexedlog.cache.keys --config scmstore.fetch-from-cas=false >/dev/null
   scmstore.file.fetch.indexedlog.cache.keys: 1
+
+Count duplicate key fetches properly:
+  $ hg dbsh -c "n = repo['$A']['dir/file'].filenode(); repo.fileslog.filestore.prefetch([('foo', n), ('bar', n)])" --config devel.print-metrics=scmstore.file.fetch.cas >/dev/null
+  scmstore.file.fetch.cas.hits: 2
+  scmstore.file.fetch.cas.keys: 2
+  scmstore.file.fetch.cas.requests: 1
+  scmstore.file.fetch.cas.time: * (glob)