diff --git a/rs/config/src/execution_environment.rs b/rs/config/src/execution_environment.rs index 050838874a8..00296668090 100644 --- a/rs/config/src/execution_environment.rs +++ b/rs/config/src/execution_environment.rs @@ -101,7 +101,14 @@ const QUERY_SCHEDULING_TIME_SLICE_PER_CANISTER: Duration = Duration::from_millis const QUERY_CACHE_CAPACITY: NumBytes = NumBytes::new(200 * MIB); /// The upper limit on how long the cache entry stays valid in the query cache. -const QUERY_CACHE_MAX_EXPIRY_TIME: Duration = Duration::from_secs(290); +const QUERY_CACHE_MAX_EXPIRY_TIME: Duration = Duration::from_secs(600); +/// The upper limit on how long the data certificate stays valid in the query cache. +/// +/// The [HTTP Gateway Protocol Specification](https://internetcomputer.org/docs/current/references/http-gateway-protocol-spec#certificate-validation) +/// states that the certified timestamp must be recent, e.g. 5 minutes. +/// So queries using the `ic0.data_certificate_copy()` System API call +/// should not be cached for more than 5 minutes. +const QUERY_CACHE_DATA_CERTIFICATE_EXPIRY_TIME: Duration = Duration::from_secs(60); /// Length of an epoch of query statistics in blocks pub const QUERY_STATS_EPOCH_LENGTH: u64 = 1800; @@ -233,6 +240,9 @@ pub struct Config { /// The upper limit on how long the cache entry stays valid in the query cache. pub query_cache_max_expiry_time: Duration, + /// The upper limit on how long the data certificate stays valid in the query cache. + pub query_cache_data_certificate_expiry_time: Duration, + /// The capacity of the Wasm compilation cache. pub max_compilation_cache_size: NumBytes, @@ -317,6 +327,7 @@ impl Default for Config { query_caching: FlagStatus::Enabled, query_cache_capacity: QUERY_CACHE_CAPACITY, query_cache_max_expiry_time: QUERY_CACHE_MAX_EXPIRY_TIME, + query_cache_data_certificate_expiry_time: QUERY_CACHE_DATA_CERTIFICATE_EXPIRY_TIME, max_compilation_cache_size: MAX_COMPILATION_CACHE_SIZE, query_stats_aggregation: FlagStatus::Disabled, query_stats_epoch_length: QUERY_STATS_EPOCH_LENGTH, diff --git a/rs/execution_environment/src/metrics.rs b/rs/execution_environment/src/metrics.rs index 1d4871b4e5e..bd3761ce780 100644 --- a/rs/execution_environment/src/metrics.rs +++ b/rs/execution_environment/src/metrics.rs @@ -11,6 +11,7 @@ use prometheus::{Histogram, IntCounter, IntCounterVec}; use std::{cell::RefCell, rc::Rc, time::Instant}; pub(crate) const QUERY_HANDLER_CRITICAL_ERROR: &str = "query_handler_critical_error"; +pub(crate) const SYSTEM_API_DATA_CERTIFICATE_COPY: &str = "data_certificate_copy"; pub(crate) const SYSTEM_API_CALL_PERFORM: &str = "call_perform"; pub(crate) const SYSTEM_API_CANISTER_CYCLE_BALANCE: &str = "canister_cycle_balance"; pub(crate) const SYSTEM_API_CANISTER_CYCLE_BALANCE128: &str = "canister_cycle_balance128"; diff --git a/rs/execution_environment/src/query_handler.rs b/rs/execution_environment/src/query_handler.rs index 5fdef8a8f41..5a516e6ed9b 100644 --- a/rs/execution_environment/src/query_handler.rs +++ b/rs/execution_environment/src/query_handler.rs @@ -133,7 +133,8 @@ impl InternalHttpQueryHandler { local_query_execution_stats: QueryStatsCollector, ) -> Self { let query_cache_capacity = config.query_cache_capacity; - let query_cache_max_expiry_time = config.query_cache_max_expiry_time; + let query_max_expiry_time = config.query_cache_max_expiry_time; + let query_data_certificate_expiry_time = config.query_cache_data_certificate_expiry_time; Self { log, hypervisor, @@ -146,7 +147,8 @@ impl InternalHttpQueryHandler { query_cache: query_cache::QueryCache::new( metrics_registry, query_cache_capacity, - query_cache_max_expiry_time, + query_max_expiry_time, + query_data_certificate_expiry_time, ), } } diff --git a/rs/execution_environment/src/query_handler/query_cache.rs b/rs/execution_environment/src/query_handler/query_cache.rs index 9a19db5e12b..01cc163d81d 100644 --- a/rs/execution_environment/src/query_handler/query_cache.rs +++ b/rs/execution_environment/src/query_handler/query_cache.rs @@ -25,6 +25,7 @@ pub(crate) struct QueryCacheMetrics { pub invalidated_entries: IntCounter, pub invalidated_entries_by_time: IntCounter, pub invalidated_entries_by_max_expiry_time: IntCounter, + pub invalidated_entries_by_data_certificate_expiry_time: IntCounter, pub invalidated_entries_by_canister_version: IntCounter, pub invalidated_entries_by_canister_balance: IntCounter, pub invalidated_entries_by_nested_call: IntCounter, @@ -73,6 +74,10 @@ impl QueryCacheMetrics { "execution_query_cache_invalidated_entries_by_max_expiry_time_total", "The total number of invalidated entries due to the max expiry time", ), + invalidated_entries_by_data_certificate_expiry_time: metrics_registry.int_counter( + "execution_query_cache_invalidated_entries_by_data_certificate_expiry_time_total", + "The total number of invalidated entries due to the data certificate expiry time", + ), invalidated_entries_by_canister_version: metrics_registry.int_counter( "execution_query_cache_invalidated_entries_by_canister_version_total", "The total number of invalidated entries due to the changed canister version", @@ -171,6 +176,8 @@ pub(crate) struct EntryValue { env: EntryEnv, /// The result produced by the query. result: Result, + /// If set, the cached entry should be expired after `data_certificate_expiry_time`. + includes_data_certificate: bool, /// If set, the `env.batch_time` might be ignored. ignore_batch_time: bool, /// If set, the `env.canister_balance` might be ignored. @@ -189,6 +196,8 @@ impl EntryValue { result: Result, system_api_call_counters: &SystemApiCallCounters, ) -> EntryValue { + // The cached entry should be expired after `data_certificate_expiry_time`. + let includes_data_certificate = system_api_call_counters.data_certificate_copy > 0; // It's safe to ignore `batch_time` changes if the query never calls `ic0.time()`. let ignore_batch_time = system_api_call_counters.time == 0; // It's safe to ignore `canister_balance` changes if the query never checks the balance. @@ -197,14 +206,21 @@ impl EntryValue { EntryValue { env, result, + includes_data_certificate, ignore_batch_time, ignore_canister_balance, } } - fn is_valid(&self, env: &EntryEnv, max_expiry_time: Duration) -> bool { + fn is_valid( + &self, + env: &EntryEnv, + max_expiry_time: Duration, + data_certificate_expiry_time: Duration, + ) -> bool { self.is_valid_time(env) - && self.is_not_expired(env, max_expiry_time) + && !self.is_expired(env, max_expiry_time) + && !self.is_expired_data_certificate(env, data_certificate_expiry_time) && self.is_valid_canister_version(env) && self.is_valid_canister_balance(env) } @@ -214,12 +230,24 @@ impl EntryValue { } /// Check cache entry max expiration time. - fn is_not_expired(&self, env: &EntryEnv, max_expiry_time: Duration) -> bool { + fn is_expired(&self, env: &EntryEnv, max_expiry_time: Duration) -> bool { if let Some(duration) = env.batch_time.checked_duration_since(self.env.batch_time) { - duration <= max_expiry_time + duration > max_expiry_time } else { - true + false + } + } + + /// Check cache entry data certificate expiration time. + fn is_expired_data_certificate( + &self, + env: &EntryEnv, + data_certificate_expiry_time: Duration, + ) -> bool { + if self.includes_data_certificate { + return self.is_expired(env, data_certificate_expiry_time); } + false } fn is_valid_canister_version(&self, env: &EntryEnv) -> bool { @@ -258,6 +286,8 @@ pub(crate) struct QueryCache { cache: Mutex>, /// The upper limit on how long the cache entry stays valid in the query cache. max_expiry_time: Duration, + /// The upper limit on how long the data certificate stays valid in the query cache. + data_certificate_expiry_time: Duration, /// Query cache metrics (public for tests) pub(crate) metrics: QueryCacheMetrics, } @@ -274,10 +304,12 @@ impl QueryCache { metrics_registry: &MetricsRegistry, capacity: NumBytes, max_expiry_time: Duration, + data_certificate_expiry_time: Duration, ) -> Self { QueryCache { cache: Mutex::new(LruCache::new(capacity)), max_expiry_time, + data_certificate_expiry_time, metrics: QueryCacheMetrics::new(metrics_registry), } } @@ -292,7 +324,7 @@ impl QueryCache { let now = env.batch_time; if let Some(value) = cache.get(key) { - if value.is_valid(env, self.max_expiry_time) { + if value.is_valid(env, self.max_expiry_time, self.data_certificate_expiry_time) { let res = value.result(); // Update the metrics. self.metrics.hits.inc(); @@ -315,9 +347,14 @@ impl QueryCache { if !value.is_valid_time(env) { self.metrics.invalidated_entries_by_time.inc(); } - if !value.is_not_expired(env, self.max_expiry_time) { + if value.is_expired(env, self.max_expiry_time) { self.metrics.invalidated_entries_by_max_expiry_time.inc(); } + if value.is_expired_data_certificate(env, self.data_certificate_expiry_time) { + self.metrics + .invalidated_entries_by_data_certificate_expiry_time + .inc(); + } if !value.is_valid_canister_version(env) { self.metrics.invalidated_entries_by_canister_version.inc(); } diff --git a/rs/execution_environment/src/query_handler/query_cache/tests.rs b/rs/execution_environment/src/query_handler/query_cache/tests.rs index 3aa8b0fa0a3..722ae056a04 100644 --- a/rs/execution_environment/src/query_handler/query_cache/tests.rs +++ b/rs/execution_environment/src/query_handler/query_cache/tests.rs @@ -16,6 +16,8 @@ use std::{sync::Arc, time::Duration}; const MAX_EXPIRY_TIME: Duration = Duration::from_secs(10); const MORE_THAN_MAX_EXPIRY_TIME: Duration = Duration::from_secs(11); +const DATA_CERTIFICATE_EXPIRY_TIME: Duration = Duration::from_secs(2); +const MORE_THAN_DATA_CERTIFICATE_EXPIRY_TIME: Duration = Duration::from_secs(3); const ITERATIONS: usize = 5; const REPLY_SIZE: usize = 10_000; const BIG_REPLY_SIZE: usize = 1_000_000; @@ -87,9 +89,11 @@ fn builder_with_query_cache_capacity(capacity: usize) -> ExecutionTestBuilder { builder_with_query_caching().with_query_cache_capacity(capacity as u64) } -/// Return `ExecutionTestBuilder` with query cache max expiry time. -fn builder_with_query_cache_max_expiry_time() -> ExecutionTestBuilder { - builder_with_query_caching().with_query_cache_max_expiry_time(MAX_EXPIRY_TIME) +/// Return `ExecutionTestBuilder` with query cache expiry times. +fn builder_with_query_cache_expiry_times() -> ExecutionTestBuilder { + builder_with_query_caching() + .with_query_cache_max_expiry_time(MAX_EXPIRY_TIME) + .with_query_cache_data_certificate_expiry_time(DATA_CERTIFICATE_EXPIRY_TIME) } #[test] @@ -380,6 +384,10 @@ fn query_cache_different_batch_times_return_different_results() { assert_eq!(1, m.invalidated_entries.get()); assert_eq!(1, m.invalidated_entries_by_time.get()); assert_eq!(0, m.invalidated_entries_by_max_expiry_time.get()); + assert_eq!( + 0, + m.invalidated_entries_by_data_certificate_expiry_time.get() + ); assert_eq!(0, m.invalidated_entries_by_canister_version.get()); assert_eq!(0, m.invalidated_entries_by_canister_balance.get()); assert_eq!(1, m.invalidated_entries_duration.get_sample_sum() as u64); @@ -417,7 +425,7 @@ fn query_cache_different_batch_times_return_the_same_idempotent_result() { #[test] fn query_cache_different_batch_times_return_different_idempotent_results_after_expiry_time() { - let mut test = builder_with_query_cache_max_expiry_time().build(); + let mut test = builder_with_query_cache_expiry_times().build(); let id = test.universal_canister().unwrap(); // The query does not depend on time. let q = wasm().reply_data(&[42]).build(); @@ -444,7 +452,7 @@ fn query_cache_different_batch_times_return_different_idempotent_results_after_e #[test] fn query_cache_always_returns_different_idempotent_results_after_expiry_time() { - let mut test = builder_with_query_cache_max_expiry_time().build(); + let mut test = builder_with_query_cache_expiry_times().build(); let id = test.universal_canister().unwrap(); let q = wasm().reply_data(&[42]).build(); @@ -462,6 +470,10 @@ fn query_cache_always_returns_different_idempotent_results_after_expiry_time() { assert_eq!(1, m.invalidated_entries.get()); assert_eq!(0, m.invalidated_entries_by_time.get()); assert_eq!(1, m.invalidated_entries_by_max_expiry_time.get()); + assert_eq!( + 0, + m.invalidated_entries_by_data_certificate_expiry_time.get() + ); assert_eq!(0, m.invalidated_entries_by_canister_version.get()); assert_eq!(0, m.invalidated_entries_by_canister_balance.get()); assert_eq!( @@ -471,6 +483,39 @@ fn query_cache_always_returns_different_idempotent_results_after_expiry_time() { assert_eq!(1, m.invalidated_entries_duration.get_sample_count()); } +#[test] +fn query_cache_always_returns_different_results_after_data_certificate_expiry_time() { + let mut test = builder_with_query_cache_expiry_times().build(); + let id = test.universal_canister().unwrap(); + let q = wasm().data_certificate().reply().build(); + + let res_1 = test.non_replicated_query(id, "query", q.clone()); + assert_eq!(query_cache_metrics(&test).misses.get(), 1); + assert_eq!(res_1, Ok(WasmResult::Reply(vec![]))); + + // Change the batch time more than the max expiry time. + test.state_mut().metadata.batch_time += MORE_THAN_DATA_CERTIFICATE_EXPIRY_TIME; + + let res_2 = test.non_replicated_query(id, "query", q); + let m = query_cache_metrics(&test); + assert_eq!(2, m.misses.get()); + assert_eq!(res_1, res_2); + assert_eq!(1, m.invalidated_entries.get()); + assert_eq!(0, m.invalidated_entries_by_time.get()); + assert_eq!(0, m.invalidated_entries_by_max_expiry_time.get()); + assert_eq!( + 1, + m.invalidated_entries_by_data_certificate_expiry_time.get() + ); + assert_eq!(0, m.invalidated_entries_by_canister_version.get()); + assert_eq!(0, m.invalidated_entries_by_canister_balance.get()); + assert_eq!( + MORE_THAN_DATA_CERTIFICATE_EXPIRY_TIME.as_secs(), + m.invalidated_entries_duration.get_sample_sum() as u64 + ); + assert_eq!(1, m.invalidated_entries_duration.get_sample_count()); +} + #[test] fn query_cache_invalidated_entries_work_with_negative_durations() { let mut test = builder_with_query_caching().build(); @@ -491,6 +536,10 @@ fn query_cache_invalidated_entries_work_with_negative_durations() { assert_eq!(res_1, res_2); assert_eq!(1, m.invalidated_entries_by_time.get()); assert_eq!(0, m.invalidated_entries_by_max_expiry_time.get()); + assert_eq!( + 0, + m.invalidated_entries_by_data_certificate_expiry_time.get() + ); // Negative durations should give just 0. assert_eq!(0, m.invalidated_entries_duration.get_sample_sum() as usize); assert_eq!(1, m.invalidated_entries_duration.get_sample_count()); @@ -516,6 +565,10 @@ fn query_cache_different_canister_versions_return_different_results() { assert_eq!(1, m.invalidated_entries.get()); assert_eq!(0, m.invalidated_entries_by_time.get()); assert_eq!(0, m.invalidated_entries_by_max_expiry_time.get()); + assert_eq!( + 0, + m.invalidated_entries_by_data_certificate_expiry_time.get() + ); assert_eq!(1, m.invalidated_entries_by_canister_version.get()); assert_eq!(0, m.invalidated_entries_by_canister_balance.get()); assert_eq!(0, m.invalidated_entries_duration.get_sample_sum() as usize); @@ -604,6 +657,10 @@ fn query_cache_different_canister_balance128s_return_different_results() { assert_eq!(1, m.invalidated_entries.get()); assert_eq!(0, m.invalidated_entries_by_time.get()); assert_eq!(0, m.invalidated_entries_by_max_expiry_time.get()); + assert_eq!( + 0, + m.invalidated_entries_by_data_certificate_expiry_time.get() + ); assert_eq!(0, m.invalidated_entries_by_canister_version.get()); assert_eq!(1, m.invalidated_entries_by_canister_balance.get()); assert_eq!(0, m.invalidated_entries_duration.get_sample_sum() as usize); @@ -612,10 +669,15 @@ fn query_cache_different_canister_balance128s_return_different_results() { #[test] fn query_cache_combined_invalidation_works() { - let mut test = builder_with_query_cache_max_expiry_time().build(); + let mut test = builder_with_query_cache_expiry_times().build(); let id = test.universal_canister().unwrap(); // The query must get the time and balance, otherwise the entry won't be invalidated. - let q = wasm().time().cycles_balance().reply_data(&[42]).build(); + let q = wasm() + .time() + .cycles_balance() + .data_certificate() + .reply() + .build(); let res_1 = test.non_replicated_query(id, "query", q.clone()); @@ -633,6 +695,10 @@ fn query_cache_combined_invalidation_works() { assert_eq!(1, m.invalidated_entries.get()); assert_eq!(1, m.invalidated_entries_by_time.get()); assert_eq!(1, m.invalidated_entries_by_max_expiry_time.get()); + assert_eq!( + 1, + m.invalidated_entries_by_data_certificate_expiry_time.get() + ); assert_eq!(1, m.invalidated_entries_by_canister_version.get()); assert_eq!(1, m.invalidated_entries_by_canister_balance.get()); } @@ -752,6 +818,9 @@ fn query_cache_metrics_system_api_calls_work_on_composite_query() { let a = wasm() // Fist group of System API calls. + .data_certificate() + .data_certificate() + .data_certificate() .cycles_balance() .cycles_balance128() .time() @@ -782,6 +851,10 @@ fn query_cache_metrics_system_api_calls_work_on_composite_query() { ), ) // Second group of System API calls. + .data_certificate() + .data_certificate() + .data_certificate() + .data_certificate() .cycles_balance() .cycles_balance128() .time() @@ -818,6 +891,13 @@ fn query_cache_metrics_system_api_calls_work_on_composite_query() { .with_label_values(&[metrics::SYSTEM_API_TIME]) .get() ); + // Seven `ic0.data_certificate_copy()` calls. + assert_eq!( + 7, + m.query_system_api_calls + .with_label_values(&[metrics::SYSTEM_API_DATA_CERTIFICATE_COPY]) + .get() + ); } #[test] @@ -879,7 +959,7 @@ fn query_cache_composite_queries_return_the_same_result() { #[test] fn query_cache_composite_queries_return_different_results_after_expiry_time() { - let mut test = builder_with_query_cache_max_expiry_time().build(); + let mut test = builder_with_query_cache_expiry_times().build(); let id = test.universal_canister().unwrap(); // The query has no time or balance dependencies. let q = wasm().reply_data(&[42]).build(); diff --git a/rs/execution_environment/src/query_handler/query_context.rs b/rs/execution_environment/src/query_handler/query_context.rs index b97eb519a32..f9bc5c82f65 100644 --- a/rs/execution_environment/src/query_handler/query_context.rs +++ b/rs/execution_environment/src/query_handler/query_context.rs @@ -7,7 +7,7 @@ use crate::{ metrics::{ CallTreeMetricsNoOp, MeasurementScope, QueryHandlerMetrics, QUERY_HANDLER_CRITICAL_ERROR, SYSTEM_API_CALL_PERFORM, SYSTEM_API_CANISTER_CYCLE_BALANCE, - SYSTEM_API_CANISTER_CYCLE_BALANCE128, SYSTEM_API_TIME, + SYSTEM_API_CANISTER_CYCLE_BALANCE128, SYSTEM_API_DATA_CERTIFICATE_COPY, SYSTEM_API_TIME, }, NonReplicatedQueryKind, RoundInstructions, }; @@ -489,6 +489,9 @@ impl<'a> QueryContext<'a> { /// Observe System API call counters in the corresponding metrics. pub(super) fn observe_system_api_calls(&mut self, query_system_api_calls: &IntCounterVec) { + query_system_api_calls + .with_label_values(&[SYSTEM_API_DATA_CERTIFICATE_COPY]) + .inc_by(self.system_api_call_counters.data_certificate_copy as u64); query_system_api_calls .with_label_values(&[SYSTEM_API_CALL_PERFORM]) .inc_by(self.system_api_call_counters.call_perform as u64); diff --git a/rs/interfaces/src/execution_environment.rs b/rs/interfaces/src/execution_environment.rs index 0cf2ea11e0a..46e898f0961 100644 --- a/rs/interfaces/src/execution_environment.rs +++ b/rs/interfaces/src/execution_environment.rs @@ -199,6 +199,8 @@ pub enum SystemApiCallId { /// was invoked. #[derive(Clone, Debug, Default, Deserialize, Serialize)] pub struct SystemApiCallCounters { + /// Counter for `ic0.data_certificate_copy()` + pub data_certificate_copy: usize, /// Counter for `ic0.call_perform()` pub call_perform: usize, /// Counter for `ic0.canister_cycle_balance()` @@ -211,6 +213,9 @@ pub struct SystemApiCallCounters { impl SystemApiCallCounters { pub fn saturating_add(&mut self, rhs: Self) { + self.data_certificate_copy = self + .data_certificate_copy + .saturating_add(rhs.data_certificate_copy); self.call_perform = self.call_perform.saturating_add(rhs.call_perform); self.canister_cycle_balance = self .canister_cycle_balance @@ -1044,7 +1049,7 @@ pub trait SystemApi { /// (i.e. data_certificate_present returns 1). /// Traps if data_certificate_present returns 0. fn ic0_data_certificate_copy( - &self, + &mut self, dst: u32, offset: u32, size: u32, diff --git a/rs/system_api/src/lib.rs b/rs/system_api/src/lib.rs index 8cace1355bd..bc1b7775dcc 100644 --- a/rs/system_api/src/lib.rs +++ b/rs/system_api/src/lib.rs @@ -1330,26 +1330,6 @@ impl SystemApiImpl { } } - /// Increase `ic0.call_perform()` system API call counter. - fn inc_call_perform_counter(&mut self) { - self.call_counters.call_perform += 1; - } - - /// Increase `ic0.canister_cycle_balance()` system API call counter. - fn inc_canister_cycle_balance_counter(&mut self) { - self.call_counters.canister_cycle_balance += 1; - } - - /// Increase `ic0.canister_cycle_balance128()` system API call counter. - fn inc_canister_cycle_balance128_counter(&mut self) { - self.call_counters.canister_cycle_balance128 += 1; - } - - /// Increase `ic0.time()` system API call counter. - fn inc_time_counter(&mut self) { - self.call_counters.time += 1; - } - /// Return tracked System API call counters. pub fn call_counters(&self) -> SystemApiCallCounters { self.call_counters.clone() @@ -2050,7 +2030,7 @@ impl SystemApi for SystemApiImpl { // or the output queues are full. In this case, we need to perform the // necessary cleanups. fn ic0_call_perform(&mut self) -> HypervisorResult { - self.inc_call_perform_counter(); + self.call_counters.call_perform += 1; let result = match &mut self.api_type { ApiType::Start { .. } | ApiType::Init { .. } @@ -2288,7 +2268,7 @@ impl SystemApi for SystemApiImpl { } fn ic0_time(&mut self) -> HypervisorResult