core, graph: Log more details about the entity cache

Author: lutter

core/src/subgraph/runner.rs

@@ -215,8 +215,7 @@ where
         ));
 
         debug!(logger, "Start processing block";
-               "triggers" => triggers.len(),
-               "cached_entities" => self.state.entity_lfu_cache.len());
+               "triggers" => triggers.len());
 
         let proof_of_indexing = if self.inputs.store.supports_proof_of_indexing().await? {
             Some(Arc::new(AtomicRefCell::new(ProofOfIndexing::new(
@@ -400,12 +399,20 @@ where
         let ModificationsAndCache {
             modifications: mut mods,
             entity_lfu_cache: cache,
+            evict_stats,
         } = block_state
             .entity_cache
             .as_modifications()
             .map_err(|e| BlockProcessingError::Unknown(e.into()))?;
         section.end();
 
+        debug!(self.logger, "Entity cache statistics";
+            "weight" => evict_stats.new_weight,
+            "evicted_weight" => evict_stats.evicted_weight,
+            "count" => evict_stats.new_count,
+            "evicted_count" => evict_stats.evicted_count,
+            "stale_update" => evict_stats.stale_update);
+
         // Check for offchain events and process them, including their entity modifications in the
         // set to be transacted.
         let offchain_events = self.ctx.offchain_monitor.ready_offchain_events()?;

graph/src/components/store/entity_cache.rs

@@ -7,7 +7,7 @@ use crate::components::store::{self as s, Entity, EntityKey, EntityOp, EntityOpe
 use crate::data::store::IntoEntityIterator;
 use crate::prelude::ENV_VARS;
 use crate::schema::InputSchema;
-use crate::util::lfu_cache::LfuCache;
+use crate::util::lfu_cache::{EvictStats, LfuCache};
 
 use super::{DerivedEntityQuery, EntityType, LoadRelatedRequest, StoreError};
 
@@ -58,6 +58,7 @@ impl Debug for EntityCache {
 pub struct ModificationsAndCache {
     pub modifications: Vec<s::EntityModification>,
     pub entity_lfu_cache: LfuCache<EntityKey, Option<Entity>>,
+    pub evict_stats: EvictStats,
 }
 
 impl EntityCache {
@@ -332,11 +333,14 @@ impl EntityCache {
                 mods.push(modification)
             }
         }
-        self.current.evict(ENV_VARS.mappings.entity_cache_size);
+        let evict_stats = self
+            .current
+            .evict_and_stats(ENV_VARS.mappings.entity_cache_size);
 
         Ok(ModificationsAndCache {
             modifications: mods,
             entity_lfu_cache: self.current,
+            evict_stats,
         })
     }
 }

graph/src/util/lfu_cache.rs

@@ -187,6 +187,18 @@ impl<K: Clone + Ord + Eq + Hash + Debug + CacheWeight, V: CacheWeight + Default>
         self.queue.len()
     }
 
+    pub fn evict_and_stats(&mut self, max_weight: usize) -> EvictStats {
+        self.evict_with_period(max_weight, STALE_PERIOD)
+            .unwrap_or_else(|| EvictStats {
+                new_weight: self.total_weight,
+                evicted_weight: 0,
+                new_count: self.len(),
+                evicted_count: 0,
+                stale_update: false,
+                evict_time: Duration::from_millis(0),
+            })
+    }
+
     /// Same as `evict_with_period(max_weight, STALE_PERIOD)`
     pub fn evict(&mut self, max_weight: usize) -> Option<EvictStats> {
         self.evict_with_period(max_weight, STALE_PERIOD)