feat: Add metrics to measure compiled-contract cache hits/misses for chunk production vs. chunk validation.

chain/chain/src/chain_update.rs

@@ -14,6 +14,7 @@ use near_chain_primitives::error::Error;
 use near_epoch_manager::shard_tracker::ShardTracker;
 use near_epoch_manager::types::BlockHeaderInfo;
 use near_epoch_manager::EpochManagerAdapter;
+use near_primitives::apply::ApplyChunkReason;
 use near_primitives::block::{Block, Tip};
 use near_primitives::block_header::BlockHeader;
 #[cfg(feature = "new_epoch_sync")]
@@ -761,6 +762,7 @@ impl<'a> ChainUpdate<'a> {
 
         let apply_result = self.runtime_adapter.apply_chunk(
             RuntimeStorageConfig::new(chunk_header.prev_state_root(), true),
+            ApplyChunkReason::UpdateTrackedShard,
             ApplyChunkShardContext {
                 shard_id,
                 gas_limit,
@@ -869,6 +871,7 @@ impl<'a> ChainUpdate<'a> {
 
         let apply_result = self.runtime_adapter.apply_chunk(
             RuntimeStorageConfig::new(*chunk_extra.state_root(), true),
+            ApplyChunkReason::UpdateTrackedShard,
             ApplyChunkShardContext {
                 shard_id,
                 last_validator_proposals: chunk_extra.validator_proposals(),

chain/chain/src/runtime/mod.rs

@@ -15,6 +15,7 @@ use near_epoch_manager::{EpochManagerAdapter, EpochManagerHandle};
 use near_parameters::{ActionCosts, ExtCosts, RuntimeConfigStore};
 use near_pool::types::TransactionGroupIterator;
 use near_primitives::account::{AccessKey, Account};
+use near_primitives::apply::ApplyChunkReason;
 use near_primitives::checked_feature;
 use near_primitives::errors::{InvalidTxError, RuntimeError, StorageError};
 use near_primitives::hash::{hash, CryptoHash};
@@ -246,6 +247,7 @@ impl NightshadeRuntime {
     fn process_state_update(
         &self,
         trie: Trie,
+        apply_reason: ApplyChunkReason,
         chunk: ApplyChunkShardContext,
         block: ApplyChunkBlockContext,
         receipts: &[Receipt],
@@ -361,6 +363,7 @@ impl NightshadeRuntime {
         );
 
         let apply_state = ApplyState {
+            apply_reason: Some(apply_reason),
             block_height,
             prev_block_hash: *prev_block_hash,
             block_hash,
@@ -868,6 +871,7 @@ impl RuntimeAdapter for NightshadeRuntime {
     fn apply_chunk(
         &self,
         storage_config: RuntimeStorageConfig,
+        apply_reason: ApplyChunkReason,
         chunk: ApplyChunkShardContext,
         block: ApplyChunkBlockContext,
         receipts: &[Receipt],
@@ -907,6 +911,7 @@ impl RuntimeAdapter for NightshadeRuntime {
 
         match self.process_state_update(
             trie,
+            apply_reason,
             chunk,
             block,
             receipts,

chain/chain/src/runtime/tests.rs

@@ -9,6 +9,7 @@ use near_epoch_manager::{EpochManager, RngSeed};
 use near_pool::{
     InsertTransactionResult, PoolIteratorWrapper, TransactionGroupIteratorWrapper, TransactionPool,
 };
+use near_primitives::apply::ApplyChunkReason;
 use near_primitives::checked_feature;
 use near_primitives::test_utils::create_test_signer;
 use near_primitives::types::validator_stake::{ValidatorStake, ValidatorStakeIter};
@@ -83,6 +84,7 @@ impl NightshadeRuntime {
         let mut result = self
             .apply_chunk(
                 RuntimeStorageConfig::new(*state_root, true),
+                ApplyChunkReason::UpdateTrackedShard,
                 ApplyChunkShardContext {
                     shard_id,
                     last_validator_proposals,

chain/chain/src/test_utils/kv_runtime.rs

@@ -14,6 +14,7 @@ use near_epoch_manager::types::BlockHeaderInfo;
 use near_epoch_manager::{EpochManagerAdapter, RngSeed};
 use near_pool::types::TransactionGroupIterator;
 use near_primitives::account::{AccessKey, Account};
+use near_primitives::apply::ApplyChunkReason;
 use near_primitives::block::Tip;
 use near_primitives::block_header::{Approval, ApprovalInner};
 use near_primitives::congestion_info::CongestionInfo;
@@ -1110,6 +1111,7 @@ impl RuntimeAdapter for KeyValueRuntime {
     fn apply_chunk(
         &self,
         storage_config: RuntimeStorageConfig,
+        _apply_reason: ApplyChunkReason,
         chunk: ApplyChunkShardContext,
         block: ApplyChunkBlockContext,
         receipts: &[Receipt],

chain/chain/src/types.rs

@@ -7,6 +7,7 @@ use near_chain_configs::ReshardingConfig;
 use near_chain_primitives::Error;
 pub use near_epoch_manager::EpochManagerAdapter;
 use near_pool::types::TransactionGroupIterator;
+use near_primitives::apply::ApplyChunkReason;
 pub use near_primitives::block::{Block, BlockHeader, Tip};
 use near_primitives::challenge::{ChallengesResult, PartialState};
 use near_primitives::checked_feature;
@@ -450,6 +451,7 @@ pub trait RuntimeAdapter: Send + Sync {
     fn apply_chunk(
         &self,
         storage: RuntimeStorageConfig,
+        apply_reason: ApplyChunkReason,
         chunk: ApplyChunkShardContext,
         block: ApplyChunkBlockContext,
         receipts: &[Receipt],

chain/chain/src/update_shard.rs

@@ -6,6 +6,7 @@ use crate::types::{
 use near_async::time::Clock;
 use near_chain_primitives::Error;
 use near_epoch_manager::EpochManagerAdapter;
+use near_primitives::apply::ApplyChunkReason;
 use near_primitives::hash::CryptoHash;
 use near_primitives::receipt::Receipt;
 use near_primitives::sandbox::state_patch::SandboxStatePatch;
@@ -128,13 +129,15 @@ pub(crate) fn process_shard_update(
 ) -> Result<ShardUpdateResult, Error> {
     Ok(match shard_update_reason {
         ShardUpdateReason::NewChunk(data) => ShardUpdateResult::NewChunk(apply_new_chunk(
+            ApplyChunkReason::UpdateTrackedShard,
             parent_span,
             data,
             shard_context,
             runtime,
             epoch_manager,
         )?),
         ShardUpdateReason::OldChunk(data) => ShardUpdateResult::OldChunk(apply_old_chunk(
+            ApplyChunkReason::UpdateTrackedShard,
             parent_span,
             data,
             shard_context,
@@ -154,6 +157,7 @@ pub(crate) fn process_shard_update(
 /// Applies new chunk, which includes applying transactions from chunk and
 /// receipts filtered from outgoing receipts from previous chunks.
 pub fn apply_new_chunk(
+    apply_reason: ApplyChunkReason,
     parent_span: &tracing::Span,
     data: NewChunkData,
     shard_context: ShardContext,
@@ -187,6 +191,7 @@ pub fn apply_new_chunk(
     };
     match runtime.apply_chunk(
         storage_config,
+        apply_reason,
         ApplyChunkShardContext {
             shard_id,
             last_validator_proposals: chunk_header.prev_validator_proposals(),
@@ -225,6 +230,7 @@ pub fn apply_new_chunk(
 /// (logunov) From what I know, the state update may include only validator
 /// accounts update on epoch start.
 pub fn apply_old_chunk(
+    apply_reason: ApplyChunkReason,
     parent_span: &tracing::Span,
     data: OldChunkData,
     shard_context: ShardContext,
@@ -248,6 +254,7 @@ pub fn apply_old_chunk(
     };
     match runtime.apply_chunk(
         storage_config,
+        apply_reason,
         ApplyChunkShardContext {
             shard_id,
             last_validator_proposals: prev_chunk_extra.validator_proposals(),

chain/client/src/stateless_validation/chunk_validator/mod.rs

@@ -22,6 +22,7 @@ use near_chain_primitives::Error;
 use near_epoch_manager::EpochManagerAdapter;
 use near_network::types::{NetworkRequests, PeerManagerMessageRequest};
 use near_pool::TransactionGroupIteratorWrapper;
+use near_primitives::apply::ApplyChunkReason;
 use near_primitives::hash::{hash, CryptoHash};
 use near_primitives::merkle::merklize;
 use near_primitives::receipt::Receipt;
@@ -482,6 +483,7 @@ pub(crate) fn validate_chunk_state_witness(
         MainTransition::NewChunk(new_chunk_data) => {
             let chunk_header = new_chunk_data.chunk_header.clone();
             let NewChunkResult { apply_result: mut main_apply_result, .. } = apply_new_chunk(
+                ApplyChunkReason::ValidateChunkStateWitness,
                 &span,
                 new_chunk_data,
                 ShardContext {
@@ -529,6 +531,7 @@ pub(crate) fn validate_chunk_state_witness(
             },
         };
         let OldChunkResult { apply_result, .. } = apply_old_chunk(
+            ApplyChunkReason::ValidateChunkStateWitness,
             &span,
             old_chunk_data,
             ShardContext {

core/primitives-core/src/apply.rs

@@ -0,0 +1,30 @@
+use std::fmt::{Display, Formatter};
+
+/// Indicates the phase of block production the apply-chunk operation is invoked.
+/// This is currently used to analyze and compare the metrics collected while applying the receipts
+/// for different purposes, eg. while updating state of a tracked shard vs. validating a chunk.
+/// TODO: Consider combining ApplyChunkReason, ApplyChunkBlockContext, and ApplyChunkBlockContext
+/// under a common wrapper struct such as ApplyChunkContext.
+#[derive(Clone, Debug)]
+pub enum ApplyChunkReason {
+    /// Apply-chunk is invoked to update the state of a shards being tracked.
+    UpdateTrackedShard,
+    /// Apply-chunk is invoked to validate the state witness for a shard in the context of stateless validation.
+    ValidateChunkStateWitness,
+}
+
+impl ApplyChunkReason {
+    /// Returns a static, short string representation of the reason, to be used for metrics.
+    pub fn as_str(&self) -> &'static str {
+        match self {
+            ApplyChunkReason::UpdateTrackedShard => "update_shard",
+            ApplyChunkReason::ValidateChunkStateWitness => "validate_chunk",
+        }
+    }
+}
+
+impl Display for ApplyChunkReason {
+    fn fmt(&self, f: &mut Formatter<'_>) -> Result<(), std::fmt::Error> {
+        f.write_str(self.as_str())
+    }
+}

core/primitives-core/src/lib.rs

@@ -2,6 +2,7 @@ pub use borsh;
 pub use num_rational;
 
 pub mod account;
+pub mod apply;
 pub mod chains;
 pub mod config;
 pub mod hash;

core/primitives/src/lib.rs

@@ -1,4 +1,5 @@
 pub use near_primitives_core::account;
+pub use near_primitives_core::apply;
 pub use near_primitives_core::borsh;
 pub use near_primitives_core::config;
 pub use near_primitives_core::hash;

integration-tests/src/user/runtime_user.rs

@@ -155,6 +155,7 @@ impl RuntimeUser {
         let shard_id = 0;
 
         ApplyState {
+            apply_reason: None,
             block_height: 1,
             prev_block_hash: Default::default(),
             block_hash: Default::default(),

runtime/near-vm-runner/src/metrics.rs

@@ -1,11 +1,14 @@
-use near_o11y::metrics::{try_create_histogram_vec, HistogramVec};
+use near_o11y::metrics::{
+    try_create_histogram_vec, try_create_int_counter_vec, HistogramVec, IntCounterVec,
+};
 use once_cell::sync::Lazy;
 use std::{cell::RefCell, time::Duration};
 
 thread_local! {
     static METRICS: RefCell<Metrics> = const { RefCell::new(Metrics {
         near_vm_compilation_time: Duration::new(0, 0),
         wasmtime_compilation_time: Duration::new(0, 0),
+        compiled_contract_cache_hit: None,
     }) };
 }
 
@@ -19,10 +22,30 @@ pub static COMPILATION_TIME: Lazy<HistogramVec> = Lazy::new(|| {
     .unwrap()
 });
 
+pub static COMPILED_CONTRACT_CACHE_HIT: Lazy<IntCounterVec> = Lazy::new(|| {
+    try_create_int_counter_vec(
+        "near_vm_compiled_contract_cache_hits_total",
+        "The number of times the runtime finds compiled code in cache for the given caller context and shard_id",
+        &["context", "shard_id"],
+    )
+    .unwrap()
+});
+
+pub static COMPILED_CONTRACT_CACHE_MISS: Lazy<IntCounterVec> = Lazy::new(|| {
+    try_create_int_counter_vec(
+        "near_vm_compiled_contract_cache_misses_total",
+        "The number of times the runtime cannot find compiled code in cache for the given caller context and shard_id",
+        &["context", "shard_id"],
+    )
+    .unwrap()
+});
+
 #[derive(Default, Copy, Clone)]
 pub struct Metrics {
     near_vm_compilation_time: Duration,
     wasmtime_compilation_time: Duration,
+    /// True iff the runtime checked the compiled contract cache and found already-compiled code.
+    compiled_contract_cache_hit: Option<bool>,
 }
 
 impl Metrics {
@@ -37,7 +60,8 @@ impl Metrics {
         METRICS.with_borrow(|m| *m)
     }
 
-    pub fn report(&mut self, shard_id: &str) {
+    /// Report the current metrics at the end of a single VM invocation (eg. to run a function call).
+    pub fn report(&mut self, shard_id: &str, caller_context: &str) {
         if !self.near_vm_compilation_time.is_zero() {
             COMPILATION_TIME
                 .with_label_values(&["near_vm", shard_id])
@@ -50,6 +74,15 @@ impl Metrics {
                 .observe(self.wasmtime_compilation_time.as_secs_f64());
             self.wasmtime_compilation_time = Duration::default();
         }
+        match self.compiled_contract_cache_hit.take() {
+            Some(true) => {
+                COMPILED_CONTRACT_CACHE_HIT.with_label_values(&[caller_context, shard_id]).inc();
+            }
+            Some(false) => {
+                COMPILED_CONTRACT_CACHE_MISS.with_label_values(&[caller_context, shard_id]).inc();
+            }
+            None => {}
+        };
     }
 }
 
@@ -63,3 +96,15 @@ pub(crate) fn compilation_duration(kind: near_parameters::vm::VMKind, duration:
         VMKind::NearVm => m.near_vm_compilation_time += duration,
     });
 }
+
+/// Updates metrics to record a compiled-contract cache lookup that finds
+/// an entry in the cache (is_hit=true) or not (is_hit=false).
+pub(crate) fn record_compiled_contract_cache_lookup(is_hit: bool) {
+    METRICS.with_borrow_mut(|m| {
+        debug_assert!(
+            m.compiled_contract_cache_hit.is_none(),
+            "Compiled contract cache lookup should be reported once."
+        );
+        m.compiled_contract_cache_hit = Some(is_hit);
+    });
+}

runtime/near-vm-runner/src/near_vm_runner/runner.rs

@@ -239,10 +239,12 @@ impl NearVM {
                     let key = get_contract_cache_key(code_hash, &self.config);
                     let cache_record = cache.get(&key).map_err(CacheError::ReadError)?;
                     let Some(code) = cache_record else {
+                        crate::metrics::record_compiled_contract_cache_lookup(false);
                         return Err(VMRunnerError::CacheError(CacheError::ReadError(
                             std::io::Error::from(std::io::ErrorKind::NotFound),
                         )));
                     };
+                    crate::metrics::record_compiled_contract_cache_lookup(true);
 
                     match &code.compiled {
                         CompiledContract::CompileModuleError(err) => {
@@ -295,6 +297,7 @@ impl NearVM {
             move |value| {
                 let _span =
                     tracing::debug_span!(target: "vm", "NearVM::load_from_mem_cache").entered();
+                crate::metrics::record_compiled_contract_cache_lookup(true);
                 let &(wasm_bytes, ref downcast) = value
                     .downcast_ref::<MemoryCacheType>()
                     .expect("downcast should always succeed");

runtime/runtime-params-estimator/src/estimator_context.rs

@@ -147,6 +147,7 @@ impl<'c> EstimatorContext<'c> {
 
         let shard_id = ShardUId::single_shard().shard_id();
         ApplyState {
+            apply_reason: None,
             // Put each runtime into a separate shard.
             block_height: 1,
             // Epoch length is long enough to avoid corner cases.