From fc3530861ac28131e3b2db9c4125cc2e12e37fbe Mon Sep 17 00:00:00 2001 From: Martin Raszyk Date: Mon, 24 Aug 2026 06:59:04 +0000 Subject: [PATCH 1/4] fix: don't report the dropped ingress induction debit as consumed `apply_ingress_induction_cycles_debit()` may be called with a cycles balance that is smaller than the pending debit: after a cleanup callback, which is allowed to burn the balance below the debit and must always be able to succeed. As documented, the part of the debit that the balance cannot cover is then dropped, making some of the postponed ingress induction charges free. The dropped part was still reported as consumed, though: the full debit was passed to `consume_cycles()`, which saturates the balance subtraction at zero but records the full nominal amount in the consumed cycles metrics. The canister (and, transitively, the subnet) therefore over-reported consumed cycles by the dropped amount. Charge only the part of the debit that the balance can cover, so that the consumed cycles metrics match the cycles actually removed from the balance. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/canister_state/system_state.rs | 7 ++- .../src/canister_state/tests.rs | 44 +++++++++++++++++++ 2 files changed, 50 insertions(+), 1 deletion(-) diff --git a/rs/replicated_state/src/canister_state/system_state.rs b/rs/replicated_state/src/canister_state/system_state.rs index d9bfb3563510..555cb2be9b07 100644 --- a/rs/replicated_state/src/canister_state/system_state.rs +++ b/rs/replicated_state/src/canister_state/system_state.rs @@ -1042,8 +1042,13 @@ impl SystemState { // some of the postponed charges free. } } + // Charge only the part of the debit that the balance can cover. The remaining + // debit is dropped, so it must not be reported as consumed either: passing the + // full debit to `consume_cycles()` would saturate the balance at zero but still + // record the full amount in the consumed cycles metrics. + let charged_debit = self.ingress_induction_cycles_debit - remaining_debit; self.consume_cycles(CompoundCycles::::new( - self.ingress_induction_cycles_debit, + charged_debit, cost_schedule, )); self.ingress_induction_cycles_debit = Cycles::zero(); diff --git a/rs/replicated_state/src/canister_state/tests.rs b/rs/replicated_state/src/canister_state/tests.rs index 54cbc898899f..e00cff95ee49 100644 --- a/rs/replicated_state/src/canister_state/tests.rs +++ b/rs/replicated_state/src/canister_state/tests.rs @@ -857,6 +857,50 @@ fn canister_state_ingress_induction_cycles_debit() { ); } +#[test] +fn canister_state_ingress_induction_cycles_debit_exceeding_balance() { + let system_state = &mut CanisterStateFixture::new().canister_state.system_state; + let initial_balance = system_state.balance(); + let ingress_induction_debit = Cycles::new(42); + let cost_schedule = CanisterCyclesCostSchedule::Normal; + system_state.add_postponed_charge_to_ingress_induction_cycles_debit(ingress_induction_debit); + + // Mimic a cleanup callback burning the cycles balance below the pending debit. + let remaining_balance = Cycles::new(10); + system_state.remove_cycles(initial_balance - remaining_balance); + assert_eq!(remaining_balance, system_state.balance()); + assert_eq!(Cycles::zero(), system_state.debited_balance()); + + system_state.apply_ingress_induction_cycles_debit( + system_state.canister_id(), + cost_schedule, + false, // strict + &no_op_logger(), + &mock_metrics(), + ); + + // The whole balance is charged and the rest of the debit is dropped. + assert_eq!( + Cycles::zero(), + system_state.ingress_induction_cycles_debit() + ); + assert_eq!(Cycles::zero(), system_state.balance()); + // Only the charged part of the debit is reported as consumed; the dropped part + // must not show up in the consumed cycles metrics. + assert_eq!( + system_state.canister_metrics().consumed_cycles().get(), + remaining_balance.get() + ); + assert_eq!( + *system_state + .canister_metrics() + .consumed_cycles_by_use_cases() + .get(&CyclesUseCase::IngressInduction) + .unwrap(), + NominalCycles::new(remaining_balance.get()), + ); +} + const INITIAL_CYCLES: Cycles = Cycles::new(1 << 36); #[test] From b51f3754e25baf2dfe913da431302009328c7a2b Mon Sep 17 00:00:00 2001 From: Martin Raszyk Date: Mon, 24 Aug 2026 09:26:14 +0000 Subject: [PATCH 2/4] fix: cap the consumed cycles metrics at the cycles actually charged `consume_cycles()` subtracts the real amount from the balances with saturating arithmetic, but reported the full nominal amount as consumed. Whenever the balances cannot cover the request, the difference is never removed from any balance, yet it still showed up in the canister's (and, transitively, the subnet's) consumed cycles metrics. Compute the part that the balance cannot cover before draining it and report only the charged remainder, via the new `CompoundCycles::minus_uncharged()`, which reduces both the real and the nominal part. The two parts coincide under the normal cost schedule; under the free cost schedule the real part is zero, so nothing can be left uncharged and this is a no-op. This makes the fix in `apply_ingress_induction_cycles_debit()` from the previous commit hold for every use case, so update its comment accordingly: charging the covered part explicitly now only serves to keep the dropped debit visible at that call site. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/canister_state/system_state.rs | 18 ++++-- .../src/canister_state/tests.rs | 59 ++++++++++++++++++- rs/types/cycles/src/compound_cycles.rs | 21 +++++++ 3 files changed, 92 insertions(+), 6 deletions(-) diff --git a/rs/replicated_state/src/canister_state/system_state.rs b/rs/replicated_state/src/canister_state/system_state.rs index 555cb2be9b07..d755439add18 100644 --- a/rs/replicated_state/src/canister_state/system_state.rs +++ b/rs/replicated_state/src/canister_state/system_state.rs @@ -1043,9 +1043,10 @@ impl SystemState { } } // Charge only the part of the debit that the balance can cover. The remaining - // debit is dropped, so it must not be reported as consumed either: passing the - // full debit to `consume_cycles()` would saturate the balance at zero but still - // record the full amount in the consumed cycles metrics. + // debit is dropped, so it must not be reported as consumed either. (Passing + // the full debit would produce the same metrics, since `consume_cycles()` also + // only reports the part that the balance covers, but charging the covered part + // explicitly keeps the dropped debit visible here.) let charged_debit = self.ingress_induction_cycles_debit - remaining_debit; self.consume_cycles(CompoundCycles::::new( charged_debit, @@ -2049,6 +2050,9 @@ impl SystemState { /// the consumed amount. Should be used either for cases where a prepayment /// needs to be made (that will be refunded later with `refund_cycles`) or /// a direct charge happens without a prepayment (e.g. when paying for memory). + /// + /// The balances are not required to cover the requested amount: the part that + /// they cannot cover is not charged and is not reported as consumed either. pub fn consume_cycles(&mut self, requested_amount: CompoundCycles) { let requested_real = requested_amount.real(); let use_case = T::cycles_use_case(); @@ -2070,9 +2074,15 @@ impl SystemState { | CyclesUseCase::BurnedCycles | CyclesUseCase::DroppedMessages => requested_real, }; + // The balance may not cover the whole amount, in which case the subtraction + // below saturates at zero and the uncovered part is never actually charged. + // Report only the part that the balance could cover as consumed, so that the + // consumed cycles metrics never exceed the cycles removed from the balance. + let uncharged_amount = remaining_amount - self.cycles_balance; self.cycles_balance -= remaining_amount; + let charged_amount = requested_amount.minus_uncharged(uncharged_amount); self.observe_consumed_cycles_with_use_case( - requested_amount.nominal(), + charged_amount.nominal(), NominalCycles::zero(), use_case, ConsumingCycles::Prepayment, diff --git a/rs/replicated_state/src/canister_state/tests.rs b/rs/replicated_state/src/canister_state/tests.rs index e00cff95ee49..39a15a397c31 100644 --- a/rs/replicated_state/src/canister_state/tests.rs +++ b/rs/replicated_state/src/canister_state/tests.rs @@ -30,8 +30,8 @@ use ic_types::methods::{Callback, WasmClosure}; use ic_types::time::{CoarseTime, UNIX_EPOCH}; use ic_types::{CountBytes, Time}; use ic_types_cycles::{ - CanisterCyclesCostSchedule, CompoundCycles, Cycles, CyclesUseCase, Instructions, NominalCycles, - NominalCyclesTesting, + CanisterCyclesCostSchedule, CompoundCycles, Cycles, CyclesUseCase, Instructions, + Memory as MemoryUseCase, NominalCycles, NominalCyclesTesting, }; use ic_wasm_types::CanisterModule; use prometheus::IntCounter; @@ -956,6 +956,61 @@ fn update_balance_and_consumed_cycles_by_use_case_correctly() { ); } +#[test] +fn consume_cycles_exceeding_balance_reports_only_the_charged_amount() { + let mut system_state = CanisterStateFixture::new().canister_state.system_state; + let cost_schedule = CanisterCyclesCostSchedule::Normal; + // Request more cycles than the balance can cover. + let requested_cycles = + CompoundCycles::::new(INITIAL_CYCLES + Cycles::new(1000), cost_schedule); + system_state.consume_cycles(requested_cycles); + + // The balance is drained and only the drained amount is reported as consumed, + // i.e. the part of the request that the balance could not cover is not. + assert_eq!(Cycles::zero(), system_state.balance()); + assert_eq!( + NominalCycles::new(INITIAL_CYCLES.get()), + system_state.canister_metrics().consumed_cycles() + ); + assert_eq!( + *system_state + .canister_metrics() + .consumed_cycles_by_use_cases() + .get(&CyclesUseCase::Instructions) + .unwrap(), + NominalCycles::new(INITIAL_CYCLES.get()), + ); +} + +#[test] +fn consume_cycles_exceeding_balance_and_reserved_balance_reports_only_the_charged_amount() { + let mut system_state = CanisterStateFixture::new().canister_state.system_state; + let cost_schedule = CanisterCyclesCostSchedule::Normal; + let reserved_cycles = Cycles::new(1000); + system_state.reserve_cycles(reserved_cycles).unwrap(); + + // Request more cycles than the reserved balance and the balance together can cover. + let requested_cycles = + CompoundCycles::::new(INITIAL_CYCLES + Cycles::new(500), cost_schedule); + system_state.consume_cycles(requested_cycles); + + // Both balances are drained and only the drained amount is reported as consumed. + assert_eq!(Cycles::zero(), system_state.balance()); + assert_eq!(Cycles::zero(), system_state.reserved_balance()); + assert_eq!( + NominalCycles::new(INITIAL_CYCLES.get()), + system_state.canister_metrics().consumed_cycles() + ); + assert_eq!( + *system_state + .canister_metrics() + .consumed_cycles_by_use_cases() + .get(&CyclesUseCase::Memory) + .unwrap(), + NominalCycles::new(INITIAL_CYCLES.get()), + ); +} + #[test] fn canister_state_callback_round_trip() { use ic_protobuf::state::canister_state_bits::v1 as pb; diff --git a/rs/types/cycles/src/compound_cycles.rs b/rs/types/cycles/src/compound_cycles.rs index 9285b7512a47..87b52921d809 100644 --- a/rs/types/cycles/src/compound_cycles.rs +++ b/rs/types/cycles/src/compound_cycles.rs @@ -129,6 +129,27 @@ impl CompoundCycles { pub fn is_zero(&self) -> bool { self.real.is_zero() && self.nominal.is_zero() } + + /// Returns this amount reduced by the part of `real()` that could not be + /// charged, e.g. because the balance it was to be subtracted from did not + /// cover it. Such an amount is never removed from any balance, so it must + /// not be reported in the consumed cycles metrics either. + /// + /// Both parts are reduced by `uncharged`, saturating at zero: they coincide + /// under the normal cost schedule, while under the free cost schedule the + /// real part is zero, so nothing can be left uncharged and this is a no-op. + pub fn minus_uncharged(self, uncharged: Cycles) -> Self { + debug_assert!( + uncharged <= self.real, + "Expected the uncharged amount {uncharged} to be at most the real amount {}", + self.real + ); + Self { + real: self.real - uncharged, + nominal: self.nominal - NominalCycles::new_private(uncharged.get()), + _cycles_use_case_marker: self._cycles_use_case_marker, + } + } } impl Add for CompoundCycles { From ba16320fe99c857e9e087c9af63cecab8931ce2b Mon Sep 17 00:00:00 2001 From: Martin Raszyk Date: Mon, 24 Aug 2026 10:10:03 +0000 Subject: [PATCH 3/4] fix: report the cycles that `consume_cycles()` could not charge `consume_cycles()` charges only what the balances can cover and silently caps the consumed cycles metrics accordingly. Silently is the problem: for every caller that verified the balance beforehand, a shortfall is a bug that nobody gets to see. Return the uncharged amount and mark `consume_cycles()` `#[must_use]`, so that callers holding a logger and an error counter can report it as a critical error, and the rest have to acknowledge that they are ignoring it. `apply_ingress_induction_cycles_debit()` is such a caller: it now passes the full debit and drives its existing `[EXC-BUG]` report off the returned amount instead of pre-computing the covered part, making the return value the single source of truth for what was dropped. The report stays gated on `strict`, as dropping the debit that the balance cannot cover after a cleanup callback is legitimate and must remain silent. This also removes a false positive: postponed ingress induction charges are recorded unadjusted, so under the free cost schedule the previous nominal comparison could exceed the balance and trip the strict `debug_assert` and the error log even though nothing had to be charged. The returned amount is derived from the real part, which is zero under the free cost schedule. The remaining callers cover the requested amount by construction: the uninstall burn asserts it, the others acknowledge the result where they explain why the balance suffices. Co-Authored-By: Claude Opus 5 (1M context) --- rs/canonical_state/src/traversal.rs | 13 ++--- .../src/cycles_account_manager.rs | 3 +- .../system_api/sandbox_safe_system_state.rs | 7 +-- .../src/canister_manager.rs | 3 +- .../src/canister_manager/tests.rs | 24 ++++++---- .../src/query_handler/query_cache/tests.rs | 48 +++++++------------ .../src/scheduler/tests/metrics.rs | 6 ++- .../src/canister_state/system_state.rs | 48 ++++++++++--------- .../src/canister_state/tests.rs | 16 ++++--- .../src/canister_states/tests.rs | 2 +- 10 files changed, 89 insertions(+), 81 deletions(-) diff --git a/rs/canonical_state/src/traversal.rs b/rs/canonical_state/src/traversal.rs index 1cd22f3fb21c..30e3f2600de6 100644 --- a/rs/canonical_state/src/traversal.rs +++ b/rs/canonical_state/src/traversal.rs @@ -1234,12 +1234,13 @@ mod tests { INITIAL_CYCLES, NumSeconds::from(100_000), ); - canister_state - .system_state - .consume_cycles(CompoundCycles::::new( - Cycles::new(123_456), - CanisterCyclesCostSchedule::Normal, - )); + let _uncharged = + canister_state + .system_state + .consume_cycles(CompoundCycles::::new( + Cycles::new(123_456), + CanisterCyclesCostSchedule::Normal, + )); let consumed_by_canisters = canister_state .system_state .canister_metrics() diff --git a/rs/cycles_account_manager/src/cycles_account_manager.rs b/rs/cycles_account_manager/src/cycles_account_manager.rs index e730f565e808..a52f21b62706 100644 --- a/rs/cycles_account_manager/src/cycles_account_manager.rs +++ b/rs/cycles_account_manager/src/cycles_account_manager.rs @@ -995,7 +995,8 @@ impl CyclesAccountManager { reveal_top_up, )?; - system_state.consume_cycles(cycles); + // The balance was verified against the threshold above. + let _uncharged = system_state.consume_cycles(cycles); Ok(()) } diff --git a/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs b/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs index 24f93b6dec91..22852b3c4405 100644 --- a/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs +++ b/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs @@ -593,14 +593,15 @@ impl SystemStateModifications { instructions, request_and_response_transmission, } = self.consumed_cycles_by_use_case; + // The cycle changes were validated above, so the balance covers them. if let Some(x) = burned { - state.consume_cycles(x); + let _uncharged = state.consume_cycles(x); } if let Some(x) = instructions { - state.consume_cycles(x); + let _uncharged = state.consume_cycles(x); } if let Some(x) = request_and_response_transmission { - state.consume_cycles(x); + let _uncharged = state.consume_cycles(x); } // Apply the reserved cycles. This must succeed because the cycle diff --git a/rs/execution_environment/src/canister_manager.rs b/rs/execution_environment/src/canister_manager.rs index 485da60a882b..8458f9d6acc2 100644 --- a/rs/execution_environment/src/canister_manager.rs +++ b/rs/execution_environment/src/canister_manager.rs @@ -1557,7 +1557,8 @@ impl CanisterManager { Arc::clone(&self.fd_factory), ); - system_state.consume_cycles(creation_fee); + // The creation fee was already withdrawn from the sender's balance. + let _uncharged = system_state.consume_cycles(creation_fee); let mut new_canister = CanisterState::new( system_state, None, diff --git a/rs/execution_environment/src/canister_manager/tests.rs b/rs/execution_environment/src/canister_manager/tests.rs index fc18a9d41454..c5c6f5cb30fb 100644 --- a/rs/execution_environment/src/canister_manager/tests.rs +++ b/rs/execution_environment/src/canister_manager/tests.rs @@ -9218,14 +9218,16 @@ fn assert_canister_metrics_can_be_retrieved( ) { // Set dummy values for consumed cycles in the canister state. let memory_cycles = CompoundCycles::::new(Cycles::new(1), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(memory_cycles); // `Instructions` follow the prepay/refund flow where metrics are updated // only during the refund step. let instructions_cycles = CompoundCycles::::new(Cycles::new(2), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(instructions_cycles); test.canister_state_mut(canister_id) @@ -9237,24 +9239,28 @@ fn assert_canister_metrics_can_be_retrieved( let ingress_induction_cycles = CompoundCycles::::new(Cycles::new(3), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(ingress_induction_cycles); let compute_allocation_cycles = CompoundCycles::::new(Cycles::new(4), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(compute_allocation_cycles); let canister_creation_cycles = CompoundCycles::::new(Cycles::new(5), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(canister_creation_cycles); let uninstall_cycles = CompoundCycles::::new(Cycles::new(6), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(uninstall_cycles); @@ -9262,7 +9268,8 @@ fn assert_canister_metrics_can_be_retrieved( // metrics are updated only during the refund step. let request_and_response_transmission_cycles = CompoundCycles::::new(Cycles::new(8), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(request_and_response_transmission_cycles); test.canister_state_mut(canister_id) @@ -9278,7 +9285,8 @@ fn assert_canister_metrics_can_be_retrieved( .observe_consumed_cycles_for_https_outcall(http_outcalls_cycles.nominal()); let burned_cycles = CompoundCycles::::new(Cycles::new(10), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(burned_cycles); 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 622320999292..a69028a98cd5 100644 --- a/rs/execution_environment/src/query_handler/query_cache/tests.rs +++ b/rs/execution_environment/src/query_handler/query_cache/tests.rs @@ -613,12 +613,9 @@ fn query_cache_ignores_balance_changes_when_query_does_not_read_balance() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - test.canister_state_mut(b_id) - .system_state - .consume_cycles(CompoundCycles::::new( - 1_u64.into(), - CanisterCyclesCostSchedule::Normal, - )); + let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + ); // Run the same query for the second time. let res_2 = test.non_replicated_query(a_id, method, q); @@ -646,12 +643,9 @@ fn query_cache_ignores_balance_and_time_changes_when_query_is_static() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - test.canister_state_mut(b_id) - .system_state - .consume_cycles(CompoundCycles::::new( - 1_u64.into(), - CanisterCyclesCostSchedule::Normal, - )); + let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + ); // Change the time. test.state_mut().metadata.batch_time += Duration::from_secs(1); @@ -802,12 +796,9 @@ fn query_cache_returns_different_results_for_different_canister_balances() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - test.canister_state_mut(b_id) - .system_state - .consume_cycles(CompoundCycles::::new( - 1_u64.into(), - CanisterCyclesCostSchedule::Normal, - )); + let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + ); let res_2 = test.non_replicated_query(a_id, method, q); let m = query_cache_metrics(&test); @@ -832,12 +823,9 @@ fn query_cache_returns_different_results_for_different_canister_balance128s() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - test.canister_state_mut(b_id) - .system_state - .consume_cycles(CompoundCycles::::new( - 1_u64.into(), - CanisterCyclesCostSchedule::Normal, - )); + let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + ); let res_2 = test.non_replicated_query(a_id, method, q); let m = query_cache_metrics(&test); @@ -873,12 +861,9 @@ fn query_cache_returns_different_results_on_combined_invalidation() { test.canister_state_mut(b_id) .system_state .bump_canister_version(); - test.canister_state_mut(b_id) - .system_state - .consume_cycles(CompoundCycles::::new( - 1_u64.into(), - CanisterCyclesCostSchedule::Normal, - )); + let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + ); let res_2 = test.non_replicated_query(a_id, method, q); assert_eq!(res_1, res_2); @@ -924,7 +909,8 @@ fn query_cache_frees_memory_after_invalidated_entries() { assert_gt!(heap_bytes, BIG_RESPONSE_SIZE); // Set the canister balance to 42, so the second reply will have just 42 bytes. - test.canister_state_mut(id) + let _uncharged = test + .canister_state_mut(id) .system_state .consume_cycles(CompoundCycles::::new( ((BIG_RESPONSE_SIZE - SMALL_RESPONSE_SIZE) as u64).into(), diff --git a/rs/execution_environment/src/scheduler/tests/metrics.rs b/rs/execution_environment/src/scheduler/tests/metrics.rs index d55d70e000a8..167ae1feee99 100644 --- a/rs/execution_environment/src/scheduler/tests/metrics.rs +++ b/rs/execution_environment/src/scheduler/tests/metrics.rs @@ -1431,7 +1431,8 @@ fn consumed_cycles_for_instructions_are_updated_from_valid_canisters() { let removed_cycles = CompoundCycles::::new(Cycles::from(1000_u128), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(removed_cycles); @@ -1546,7 +1547,8 @@ fn consumed_cycles_are_updated_from_deleted_canisters() { let removed_cycles = CompoundCycles::::new(Cycles::from(1000_u128), cost_schedule); - test.canister_state_mut(canister_id) + let _uncharged = test + .canister_state_mut(canister_id) .system_state .consume_cycles(removed_cycles); diff --git a/rs/replicated_state/src/canister_state/system_state.rs b/rs/replicated_state/src/canister_state/system_state.rs index d755439add18..44cc1b0cc662 100644 --- a/rs/replicated_state/src/canister_state/system_state.rs +++ b/rs/replicated_state/src/canister_state/system_state.rs @@ -1024,11 +1024,17 @@ impl SystemState { log: &ReplicaLogger, charging_from_balance_error: &IntCounter, ) { - // We rely on saturating operations of `Cycles` here. - let remaining_debit = self.ingress_induction_cycles_debit - self.cycles_balance; + // `consume_cycles()` charges only the part of the debit that the balance can + // cover and hands back the rest, which is neither charged nor reported as + // consumed. Dropping it here makes some of the postponed charges free. + let uncharged_debit = self.consume_cycles(CompoundCycles::::new( + self.ingress_induction_cycles_debit, + cost_schedule, + )); + self.ingress_induction_cycles_debit = Cycles::zero(); if strict { - debug_assert_eq!(remaining_debit.get(), 0); - if remaining_debit.get() > 0 { + debug_assert_eq!(uncharged_debit.get(), 0); + if uncharged_debit.get() > 0 { // This case is unreachable and may happen only due to a bug: if the // caller has reduced the cycles balance below the cycles debit. charging_from_balance_error.inc(); @@ -1036,23 +1042,10 @@ impl SystemState { log, "[EXC-BUG]: Debited cycles exceed the cycles balance of {} by {}", canister_id, - remaining_debit, + uncharged_debit, ); - // Continue the execution by dropping the remaining debit, which makes - // some of the postponed charges free. } } - // Charge only the part of the debit that the balance can cover. The remaining - // debit is dropped, so it must not be reported as consumed either. (Passing - // the full debit would produce the same metrics, since `consume_cycles()` also - // only reports the part that the balance covers, but charging the covered part - // explicitly keeps the dropped debit visible here.) - let charged_debit = self.ingress_induction_cycles_debit - remaining_debit; - self.consume_cycles(CompoundCycles::::new( - charged_debit, - cost_schedule, - )); - self.ingress_induction_cycles_debit = Cycles::zero(); } /// This method is used for maintaining the backwards compatibility. @@ -2051,9 +2044,16 @@ impl SystemState { /// needs to be made (that will be refunded later with `refund_cycles`) or /// a direct charge happens without a prepayment (e.g. when paying for memory). /// - /// The balances are not required to cover the requested amount: the part that - /// they cannot cover is not charged and is not reported as consumed either. - pub fn consume_cycles(&mut self, requested_amount: CompoundCycles) { + /// The balances are not required to cover the requested amount. Returns the + /// part that they could not cover, which is neither charged nor reported as + /// consumed. Getting back a non-zero amount is a bug in every caller that + /// guarantees a sufficient balance, so such callers should report it as a + /// critical error if they have a logger and an error counter at hand. + #[must_use] + pub fn consume_cycles( + &mut self, + requested_amount: CompoundCycles, + ) -> Cycles { let requested_real = requested_amount.real(); let use_case = T::cycles_use_case(); let remaining_amount = match use_case { @@ -2087,6 +2087,7 @@ impl SystemState { use_case, ConsumingCycles::Prepayment, ); + uncharged_amount } /// Checks if the given amount of cycles from the main balance can be moved to the reserved balance. @@ -2134,7 +2135,10 @@ impl SystemState { cost_schedule: CanisterCyclesCostSchedule, ) { let balance = self.cycles_balance + self.reserved_balance; - self.consume_cycles(CompoundCycles::::new(balance, cost_schedule)); + let uncharged = + self.consume_cycles(CompoundCycles::::new(balance, cost_schedule)); + // The balances cover the whole amount by construction. + debug_assert_eq!(uncharged, Cycles::zero()); } /// Observes the consumed cycles for HTTPS outcalls. This should only be diff --git a/rs/replicated_state/src/canister_state/tests.rs b/rs/replicated_state/src/canister_state/tests.rs index 39a15a397c31..734c87d44da4 100644 --- a/rs/replicated_state/src/canister_state/tests.rs +++ b/rs/replicated_state/src/canister_state/tests.rs @@ -910,7 +910,7 @@ fn update_balance_and_consumed_cycles_correctly() { let cost_schedule = CanisterCyclesCostSchedule::Normal; let prepaid_cycles = CompoundCycles::::new(initial_consumed_cycles, cost_schedule); - system_state.consume_cycles(prepaid_cycles); + let _uncharged = system_state.consume_cycles(prepaid_cycles); assert_eq!( system_state.balance(), INITIAL_CYCLES - initial_consumed_cycles @@ -938,7 +938,7 @@ fn update_balance_and_consumed_cycles_by_use_case_correctly() { let cycles_to_consume = Cycles::from(1000_u128); let cost_schedule = CanisterCyclesCostSchedule::Normal; let prepaid_cycles = CompoundCycles::::new(cycles_to_consume, cost_schedule); - system_state.consume_cycles(prepaid_cycles); + let _uncharged = system_state.consume_cycles(prepaid_cycles); let refund = CompoundCycles::::new(Cycles::from(100_u128), cost_schedule); system_state.refund_cycles(prepaid_cycles, refund); @@ -961,12 +961,14 @@ fn consume_cycles_exceeding_balance_reports_only_the_charged_amount() { let mut system_state = CanisterStateFixture::new().canister_state.system_state; let cost_schedule = CanisterCyclesCostSchedule::Normal; // Request more cycles than the balance can cover. + let uncovered_cycles = Cycles::new(1000); let requested_cycles = - CompoundCycles::::new(INITIAL_CYCLES + Cycles::new(1000), cost_schedule); - system_state.consume_cycles(requested_cycles); + CompoundCycles::::new(INITIAL_CYCLES + uncovered_cycles, cost_schedule); + let uncharged_cycles = system_state.consume_cycles(requested_cycles); // The balance is drained and only the drained amount is reported as consumed, // i.e. the part of the request that the balance could not cover is not. + assert_eq!(uncovered_cycles, uncharged_cycles); assert_eq!(Cycles::zero(), system_state.balance()); assert_eq!( NominalCycles::new(INITIAL_CYCLES.get()), @@ -990,11 +992,13 @@ fn consume_cycles_exceeding_balance_and_reserved_balance_reports_only_the_charge system_state.reserve_cycles(reserved_cycles).unwrap(); // Request more cycles than the reserved balance and the balance together can cover. + let uncovered_cycles = Cycles::new(500); let requested_cycles = - CompoundCycles::::new(INITIAL_CYCLES + Cycles::new(500), cost_schedule); - system_state.consume_cycles(requested_cycles); + CompoundCycles::::new(INITIAL_CYCLES + uncovered_cycles, cost_schedule); + let uncharged_cycles = system_state.consume_cycles(requested_cycles); // Both balances are drained and only the drained amount is reported as consumed. + assert_eq!(uncovered_cycles, uncharged_cycles); assert_eq!(Cycles::zero(), system_state.balance()); assert_eq!(Cycles::zero(), system_state.reserved_balance()); assert_eq!( diff --git a/rs/replicated_state/src/canister_states/tests.rs b/rs/replicated_state/src/canister_states/tests.rs index fde77f4e9552..fbaf9d58bd6b 100644 --- a/rs/replicated_state/src/canister_states/tests.rs +++ b/rs/replicated_state/src/canister_states/tests.rs @@ -864,7 +864,7 @@ fn total_consumed_cycles_combines_hot_and_cold() { }; fn consume(canister: &mut Arc, amount: u128) { - Arc::make_mut(canister) + let _uncharged = Arc::make_mut(canister) .system_state .consume_cycles(CompoundCycles::::new( Cycles::new(amount), From bd0e2ca43e09c17bdaacf294aea89c316f3b26d0 Mon Sep 17 00:00:00 2001 From: Martin Raszyk Date: Mon, 24 Aug 2026 10:54:57 +0000 Subject: [PATCH 4/4] fix: report uncharged cycles as a critical error inside `consume_cycles()` Returning the uncharged amount from `consume_cycles()` left every caller with a `let _uncharged = ...` to acknowledge, and only the one caller that happened to hold a logger and an error counter could actually report a shortfall. Take the logger and the critical error counter in `consume_cycles()` instead and report there: the balances are now required to cover the requested amount, and whatever they cannot cover increments the counter and is logged as `[EXC-BUG]`, next to the cycles use case and the canister that could not pay. The consumed cycles metrics still only account for what was charged. Callers that legitimately charge only what the balances can cover must cap the amount themselves. `apply_ingress_induction_cycles_debit()` is the only such caller: it caps the debit with `CompoundCycles::minus_uncharged()`, keeping its own `[EXC-BUG]` report for the `strict` case and dropping the rest silently after a cleanup callback, as documented. Plumbing the logger and the counter to the remaining callers follows the existing convention of passing a component's critical error counter to the code that may hit it: * `CanisterManager` holds one next to its logger, registered as the `canister_manager_charging_from_balance` critical error; * `ValidSetRuleImpl` registers `mr_charging_from_balance` for the ingress induction charge; * the scheduler and the execution paths pass `execution_environment_charging_from_balance`, exposed on `ExecutionEnvironment` next to the existing `state_changes_error` accessor; * applying the system state modifications passes the state changes critical error, the counter that path already carries; * the cycles account manager forwards both to `SystemState::consume_cycles()` from the charging methods that reach it. Co-Authored-By: Claude Opus 5 (1M context) --- Cargo.lock | 2 + rs/canonical_state/BUILD.bazel | 2 + rs/canonical_state/Cargo.toml | 2 + rs/canonical_state/src/traversal.rs | 17 ++-- .../src/cycles_account_manager.rs | 53 ++++++++++++- .../tests/cycles_account_manager.rs | 79 ++++++++++++++++++- rs/embedders/BUILD.bazel | 1 + rs/embedders/fuzz/src/wasm_executor.rs | 7 +- .../system_api/sandbox_safe_system_state.rs | 43 +++++++--- .../tests/sandbox_safe_system_state.rs | 3 + rs/embedders/tests/system_api.rs | 8 ++ .../src/canister_manager.rs | 18 ++++- .../src/canister_manager/tests.rs | 45 +++++------ .../src/execution/call_or_task.rs | 3 + .../src/execution/common.rs | 5 ++ .../src/execution/install_code.rs | 1 + .../src/execution/response/tests.rs | 14 +++- .../src/execution_environment.rs | 12 +++ rs/execution_environment/src/lib.rs | 6 ++ .../src/query_handler/query_cache/tests.rs | 33 +++++--- rs/execution_environment/src/scheduler.rs | 9 ++- .../src/scheduler/tests/metrics.rs | 19 +++-- rs/messaging/src/scheduling/valid_set_rule.rs | 11 ++- .../src/canister_state/system_state.rs | 64 ++++++++++----- .../src/canister_state/tests.rs | 34 +++++--- .../src/canister_states/tests.rs | 12 ++- .../execution_environment/src/lib.rs | 2 + 27 files changed, 400 insertions(+), 105 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 634f2be8fc66..d56e6a6f0ca1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -6896,7 +6896,9 @@ dependencies = [ "ic-crypto-sha2", "ic-crypto-tree-hash", "ic-error-types 0.2.0", + "ic-logger", "ic-management-canister-types-private", + "ic-metrics", "ic-protobuf", "ic-registry-routing-table", "ic-registry-subnet-features", diff --git a/rs/canonical_state/BUILD.bazel b/rs/canonical_state/BUILD.bazel index 99d324ada733..3552348ce297 100644 --- a/rs/canonical_state/BUILD.bazel +++ b/rs/canonical_state/BUILD.bazel @@ -39,6 +39,8 @@ rust_test( deps = [ # Keep sorted. "//rs/crypto/sha2", + "//rs/monitoring/logger", + "//rs/monitoring/metrics", "//rs/registry/subnet_features", "//rs/sys", "//rs/test_utilities/state", diff --git a/rs/canonical_state/Cargo.toml b/rs/canonical_state/Cargo.toml index 8e4d6860e74c..ef9ba3254bf6 100644 --- a/rs/canonical_state/Cargo.toml +++ b/rs/canonical_state/Cargo.toml @@ -31,7 +31,9 @@ assert_matches = { workspace = true } hex = { workspace = true } ic-canonical-state-tree-hash-test-utils = { path = "tree_hash/test_utils" } ic-crypto-sha2 = { path = "../crypto/sha2/" } +ic-logger = { path = "../monitoring/logger" } ic-management-canister-types-private = { path = "../types/management_canister_types" } +ic-metrics = { path = "../monitoring/metrics" } ic-registry-subnet-features = { path = "../registry/subnet_features" } ic-sys = { path = "../sys" } ic-test-utilities-state = { path = "../test_utilities/state" } diff --git a/rs/canonical_state/src/traversal.rs b/rs/canonical_state/src/traversal.rs index 30e3f2600de6..4c5c69557329 100644 --- a/rs/canonical_state/src/traversal.rs +++ b/rs/canonical_state/src/traversal.rs @@ -54,7 +54,9 @@ mod tests { CertificationVersion::{self, *}, all_supported_versions, }; + use ic_logger::replica_logger::no_op_logger; use ic_management_canister_types_private::Global; + use ic_metrics::MetricsRegistry; use ic_registry_routing_table::{CanisterIdRange, RoutingTable}; use ic_registry_subnet_features::SubnetFeatures; use ic_registry_subnet_type::SubnetType; @@ -1234,13 +1236,14 @@ mod tests { INITIAL_CYCLES, NumSeconds::from(100_000), ); - let _uncharged = - canister_state - .system_state - .consume_cycles(CompoundCycles::::new( - Cycles::new(123_456), - CanisterCyclesCostSchedule::Normal, - )); + canister_state.system_state.consume_cycles( + CompoundCycles::::new( + Cycles::new(123_456), + CanisterCyclesCostSchedule::Normal, + ), + &no_op_logger(), + &MetricsRegistry::new().int_counter("error_counter", "Test error counter"), + ); let consumed_by_canisters = canister_state .system_state .canister_metrics() diff --git a/rs/cycles_account_manager/src/cycles_account_manager.rs b/rs/cycles_account_manager/src/cycles_account_manager.rs index a52f21b62706..da54e8b5a208 100644 --- a/rs/cycles_account_manager/src/cycles_account_manager.rs +++ b/rs/cycles_account_manager/src/cycles_account_manager.rs @@ -316,6 +316,8 @@ impl CyclesAccountManager { cycles: Cycles, subnet_cycles_config: CyclesAccountManagerSubnetConfig, reveal_top_up: bool, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result<(), CanisterOutOfCyclesError> { let threshold = self.freeze_threshold_cycles( canister.system_state.freeze_threshold, @@ -346,6 +348,8 @@ impl CyclesAccountManager { CompoundCycles::new(cycles, subnet_cycles_config.cost_schedule), threshold, reveal_top_up, + log, + charging_error, ) } } @@ -372,6 +376,8 @@ impl CyclesAccountManager { cycles: CompoundCycles, subnet_cycles_config: CyclesAccountManagerSubnetConfig, reveal_top_up: bool, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result<(), CanisterOutOfCyclesError> { self.consume_cycles_impl( system_state, @@ -380,6 +386,8 @@ impl CyclesAccountManager { cycles, subnet_cycles_config, reveal_top_up, + log, + charging_error, ) } @@ -394,6 +402,8 @@ impl CyclesAccountManager { cycles: CompoundCycles, subnet_cycles_config: CyclesAccountManagerSubnetConfig, reveal_top_up: bool, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result<(), CanisterOutOfCyclesError> { let threshold = self.freeze_threshold_cycles( system_state.freeze_threshold, @@ -404,7 +414,14 @@ impl CyclesAccountManager { subnet_cycles_config, system_state.reserved_balance(), ); - self.consume_with_threshold_impl(system_state, cycles, threshold, reveal_top_up) + self.consume_with_threshold_impl( + system_state, + cycles, + threshold, + reveal_top_up, + log, + charging_error, + ) } /// Consumes a direct, final `Instructions` charge (e.g. the cost of @@ -423,6 +440,8 @@ impl CyclesAccountManager { cycles: CompoundCycles, subnet_cycles_config: CyclesAccountManagerSubnetConfig, reveal_top_up: bool, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result<(), CanisterOutOfCyclesError> { self.consume_cycles_impl( system_state, @@ -431,6 +450,8 @@ impl CyclesAccountManager { cycles, subnet_cycles_config, reveal_top_up, + log, + charging_error, )?; let zero_refund = CompoundCycles::::new(Cycles::zero(), subnet_cycles_config.cost_schedule); @@ -446,6 +467,8 @@ impl CyclesAccountManager { canister: &mut CanisterState, amount: NumInstructions, subnet_cycles_config: CyclesAccountManagerSubnetConfig, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result<(), CanisterOutOfCyclesError> { let memory_usage = canister.memory_usage(); let message_memory = canister.message_memory_usage(); @@ -458,6 +481,8 @@ impl CyclesAccountManager { cycles, subnet_cycles_config, reveal_top_up, + log, + charging_error, ) } @@ -481,6 +506,8 @@ impl CyclesAccountManager { subnet_cycles_config: CyclesAccountManagerSubnetConfig, reveal_top_up: bool, execution_mode: WasmExecutionMode, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result, CanisterOutOfCyclesError> { let cost = self.execution_cost(num_instructions, subnet_cycles_config, execution_mode); self.consume_with_threshold_impl( @@ -496,6 +523,8 @@ impl CyclesAccountManager { system_state.reserved_balance(), ), reveal_top_up, + log, + charging_error, ) .map(|_| cost) } @@ -952,8 +981,17 @@ impl CyclesAccountManager { cycles: CompoundCycles, threshold: Cycles, reveal_top_up: bool, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result<(), CanisterOutOfCyclesError> { - self.consume_with_threshold_impl(system_state, cycles, threshold, reveal_top_up) + self.consume_with_threshold_impl( + system_state, + cycles, + threshold, + reveal_top_up, + log, + charging_error, + ) } /// Same as `consume_with_threshold` but without the restriction to @@ -965,6 +1003,8 @@ impl CyclesAccountManager { cycles: CompoundCycles, threshold: Cycles, reveal_top_up: bool, + log: &ReplicaLogger, + charging_error: &IntCounter, ) -> Result<(), CanisterOutOfCyclesError> { let use_case = T::cycles_use_case(); @@ -996,7 +1036,7 @@ impl CyclesAccountManager { )?; // The balance was verified against the threshold above. - let _uncharged = system_state.consume_cycles(cycles); + system_state.consume_cycles(cycles, log, charging_error); Ok(()) } @@ -1196,6 +1236,7 @@ impl CyclesAccountManager { &self, rate: CompoundCycles, log: &ReplicaLogger, + charging_error: &IntCounter, canister: &mut CanisterState, duration_since_last_charge: Duration, ) -> Result<(), CanisterOutOfCyclesError> { @@ -1207,6 +1248,8 @@ impl CyclesAccountManager { cycles, Cycles::zero(), false, // caller is system => no need to reveal top up balance + log, + charging_error, ) { info!( log, @@ -1226,6 +1269,7 @@ impl CyclesAccountManager { pub fn charge_canister_for_resource_allocation_and_usage( &self, log: &ReplicaLogger, + charging_error: &IntCounter, canister: &mut CanisterState, duration_since_last_charge: Duration, subnet_cycles_config: CyclesAccountManagerSubnetConfig, @@ -1245,18 +1289,21 @@ impl CyclesAccountManager { self.charge_canister_for_single_resource( memory, log, + charging_error, canister, duration_since_last_charge, )?; self.charge_canister_for_single_resource( message_memory, log, + charging_error, canister, duration_since_last_charge, )?; self.charge_canister_for_single_resource( compute_allocation, log, + charging_error, canister, duration_since_last_charge, )?; diff --git a/rs/cycles_account_manager/tests/cycles_account_manager.rs b/rs/cycles_account_manager/tests/cycles_account_manager.rs index 5c7e3379798d..7d91db452313 100644 --- a/rs/cycles_account_manager/tests/cycles_account_manager.rs +++ b/rs/cycles_account_manager/tests/cycles_account_manager.rs @@ -112,6 +112,7 @@ fn test_can_charge_application_subnets() { cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &log, + &IntCounter::new("no_op", "no_op").unwrap(), &mut canister, duration, subnet_cycles_config, @@ -322,6 +323,8 @@ fn verify_no_cycles_charged_for_message_execution_on_system_subnets() { subnet_cycles_config, false, WASM_EXECUTION_MODE, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.balance(), initial_balance); @@ -365,6 +368,8 @@ fn verify_no_cycles_charged_for_message_execution_on_free_schedule() { subnet_cycles_config, false, WASM_EXECUTION_MODE, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.balance(), initial_balance); @@ -451,6 +456,7 @@ fn charging_removes_canisters_with_insufficient_balance() { cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &log, + &IntCounter::new("no_op", "no_op").unwrap(), &mut canister, Duration::from_secs(1), subnet_cycles_config, @@ -468,6 +474,7 @@ fn charging_removes_canisters_with_insufficient_balance() { cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &log, + &IntCounter::new("no_op", "no_op").unwrap(), &mut canister, Duration::from_secs(1), subnet_cycles_config, @@ -485,6 +492,7 @@ fn charging_removes_canisters_with_insufficient_balance() { cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &log, + &IntCounter::new("no_op", "no_op").unwrap(), &mut canister, Duration::from_secs(1), subnet_cycles_config, @@ -538,6 +546,7 @@ fn charge_canister_for_memory_usage() { cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &log, + &IntCounter::new("no_op", "no_op").unwrap(), &mut canister, HOUR, subnet_cycles_config, @@ -603,6 +612,7 @@ fn do_not_charge_canister_for_memory_usage_free_schedule() { cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &log, + &IntCounter::new("no_op", "no_op").unwrap(), &mut canister, HOUR, subnet_cycles_config, @@ -661,6 +671,7 @@ fn do_not_charge_canister_for_compute_allocation_free_schedule() { cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &log, + &IntCounter::new("no_op", "no_op").unwrap(), &mut canister, HOUR, subnet_cycles_config, @@ -785,6 +796,8 @@ fn test_consume_with_threshold() { CompoundCycles::::new(Cycles::zero(), cost_schedule), threshold, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_ok() ); @@ -796,7 +809,14 @@ fn test_consume_with_threshold() { let amount = CompoundCycles::::new(Cycles::from(i128::MAX as u128), cost_schedule); assert!( cycles_account_manager - .consume_with_threshold(&mut system_state, amount, threshold, false) + .consume_with_threshold( + &mut system_state, + amount, + threshold, + false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap() + ) .is_ok() ); cycles_balance_expected -= amount.real(); @@ -807,7 +827,14 @@ fn test_consume_with_threshold() { assert!( cycles_account_manager - .consume_with_threshold(&mut system_state, amount, threshold, false) + .consume_with_threshold( + &mut system_state, + amount, + threshold, + false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap() + ) .is_ok() ); cycles_balance_expected -= amount.real(); @@ -816,7 +843,14 @@ fn test_consume_with_threshold() { let amount = CompoundCycles::::new(Cycles::new(1), cost_schedule); assert!( cycles_account_manager - .consume_with_threshold(&mut system_state, amount, threshold, false) + .consume_with_threshold( + &mut system_state, + amount, + threshold, + false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap() + ) .is_ok() ); cycles_balance_expected -= amount.real(); @@ -824,7 +858,14 @@ fn test_consume_with_threshold() { assert!( cycles_account_manager - .consume_with_threshold(&mut system_state, amount, threshold, false) + .consume_with_threshold( + &mut system_state, + amount, + threshold, + false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap() + ) .is_err() ); cycles_balance_expected -= amount.real(); @@ -879,6 +920,8 @@ fn cycles_withdraw_for_execution() { amount, subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_ok() ); @@ -892,6 +935,8 @@ fn cycles_withdraw_for_execution() { amount, subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_err() ); @@ -922,6 +967,8 @@ fn cycles_withdraw_for_execution() { compound_exec_cycles_max, subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_ok() ); @@ -955,6 +1002,8 @@ fn cycles_withdraw_for_execution() { compound_exec_cycles_max, subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_err() ); @@ -967,6 +1016,8 @@ fn cycles_withdraw_for_execution() { CompoundCycles::::new(Cycles::new(10), cost_schedule), subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_err() ); @@ -979,6 +1030,8 @@ fn cycles_withdraw_for_execution() { CompoundCycles::::new(Cycles::new(1), cost_schedule), subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_err() ); @@ -991,6 +1044,8 @@ fn cycles_withdraw_for_execution() { CompoundCycles::::new(Cycles::zero(), cost_schedule), subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_ok() ); @@ -1045,6 +1100,8 @@ fn do_not_withdraw_cycles_for_execution_free_schedule() { amount, subnet_cycles_config, false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .is_ok() ); @@ -1090,6 +1147,8 @@ fn withdraw_execution_cycles_consumes_cycles() { ), false, WASM_EXECUTION_MODE, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); let consumed_cycles_after = system_state.canister_metrics().consumed_cycles(); @@ -1151,6 +1210,8 @@ fn consume_cycles_updates_consumed_cycles() { DEFAULT_REFERENCE_SUBNET_SIZE, ), false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); let consumed_cycles_after = system_state.canister_metrics().consumed_cycles(); @@ -1177,6 +1238,8 @@ fn consume_cycles_for_memory_drains_reserved_balance() { CompoundCycles::::new(Cycles::new(2_000_000), cost_schedule), Cycles::new(0), false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.reserved_balance(), Cycles::new(0)); @@ -1202,6 +1265,8 @@ fn consume_cycles_for_compute_drains_reserved_balance() { ), Cycles::new(0), false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.reserved_balance(), Cycles::new(0)); @@ -1224,6 +1289,8 @@ fn consume_cycles_for_uninstall_drains_reserved_balance() { CompoundCycles::::new(Cycles::new(2_000_000), cost_schedule), Cycles::new(0), false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.reserved_balance(), Cycles::new(0)); @@ -1263,6 +1330,8 @@ fn consume_cycles_for_execution_does_not_drain_reserved_balance() { subnet_cycles_config, false, WASM_EXECUTION_MODE, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_ne!(prepaid.real(), Cycles::zero()); @@ -1637,6 +1706,8 @@ fn variable_execution_cost_matches_refund() { subnet_cycles_config, false, WASM_EXECUTION_MODE, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); diff --git a/rs/embedders/BUILD.bazel b/rs/embedders/BUILD.bazel index 0482ff920195..cdb5cfda6e69 100644 --- a/rs/embedders/BUILD.bazel +++ b/rs/embedders/BUILD.bazel @@ -250,6 +250,7 @@ rust_test( "//rs/types/types", "@crate_index//:maplit", "@crate_index//:more-asserts", + "@crate_index//:prometheus", "@crate_index//:strum", ], ) diff --git a/rs/embedders/fuzz/src/wasm_executor.rs b/rs/embedders/fuzz/src/wasm_executor.rs index e1867e907735..8229aebf4248 100644 --- a/rs/embedders/fuzz/src/wasm_executor.rs +++ b/rs/embedders/fuzz/src/wasm_executor.rs @@ -110,7 +110,12 @@ pub fn run_fuzzer(module: ICWasmModule) { } canister_state_changes .system_state_modifications - .apply_balance_changes(&mut system_state); + .apply_balance_changes( + &mut system_state, + &no_op_logger(), + &MetricsRegistry::new() + .int_counter("error_counter", "Fuzzing error counter"), + ); } WasmExecutionResult::Paused(_, _) => (), // Only possible via execute_dts } diff --git a/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs b/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs index 22852b3c4405..91c517ce0473 100644 --- a/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs +++ b/rs/embedders/src/wasmtime_embedder/system_api/sandbox_safe_system_state.rs @@ -35,6 +35,7 @@ use ic_types_cycles::{ Instructions, RequestAndResponseTransmission, }; use ic_wasm_types::WasmEngineError; +use prometheus::IntCounter; use serde::{Deserialize, Serialize}; use std::str::FromStr; use std::sync::Arc; @@ -390,6 +391,7 @@ impl SystemStateModifications { is_composite_query: bool, metrics: &Metrics, logger: &ReplicaLogger, + charging_error: &IntCounter, ) -> HypervisorResult { // Append delta logs. if !self.canister_log.is_empty() { @@ -401,7 +403,7 @@ impl SystemStateModifications { // Verify total cycle change is not positive and update cycles balance. self.validate_cycle_change(system_state.canister_id() == CYCLES_MINTING_CANISTER_ID)?; - self.apply_balance_changes(system_state); + self.apply_balance_changes(system_state, logger, charging_error); // Verify we don't accept more cycles than are available from call // context and update the call context balance. @@ -561,7 +563,12 @@ impl SystemStateModifications { } /// Applies the balance change to the given state. - pub fn apply_balance_changes(&self, state: &mut SystemState) { + pub fn apply_balance_changes( + &self, + state: &mut SystemState, + logger: &ReplicaLogger, + charging_error: &IntCounter, + ) { let initial_balance = state.balance(); // `self.cycles_balance_change` consists of: @@ -595,13 +602,13 @@ impl SystemStateModifications { } = self.consumed_cycles_by_use_case; // The cycle changes were validated above, so the balance covers them. if let Some(x) = burned { - let _uncharged = state.consume_cycles(x); + state.consume_cycles(x, logger, charging_error); } if let Some(x) = instructions { - let _uncharged = state.consume_cycles(x); + state.consume_cycles(x, logger, charging_error); } if let Some(x) = request_and_response_transmission { - let _uncharged = state.consume_cycles(x); + state.consume_cycles(x, logger, charging_error); } // Apply the reserved cycles. This must succeed because the cycle @@ -1438,6 +1445,7 @@ mod tests { use ic_config::subnet_config::CyclesAccountManagerConfig; use ic_cycles_account_manager::{CyclesAccountManager, CyclesAccountManagerSubnetConfig}; use ic_limits::SMALL_APP_SUBNET_MAX_SIZE; + use ic_logger::replica_logger::no_op_logger; use ic_registry_subnet_type::SubnetType; use ic_replicated_state::{NetworkTopology, SystemState}; use ic_test_utilities_types::ids::{canister_test_id, subnet_test_id, user_test_id}; @@ -1451,6 +1459,7 @@ mod tests { BurnedCycles, CanisterCyclesCostSchedule, CompoundCycles, Cycles, CyclesUseCase, CyclesUseCaseKind, Instructions, RequestAndResponseTransmission, }; + use prometheus::IntCounter; use super::{CanisterStatusView, SandboxSafeSystemState, SystemStateModifications}; use crate::wasmtime_embedder::system_api::{ @@ -1483,7 +1492,11 @@ mod tests { }, ); - system_state_modifications.apply_balance_changes(&mut system_state); + system_state_modifications.apply_balance_changes( + &mut system_state, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); assert_eq!(initial_cycles_balance - removed, system_state.balance()); @@ -1502,7 +1515,11 @@ mod tests { }, ); - system_state_modifications.apply_balance_changes(&mut system_state); + system_state_modifications.apply_balance_changes( + &mut system_state, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); assert_eq!(initial_cycles_balance - removed, system_state.balance()); @@ -1521,7 +1538,11 @@ mod tests { }, ); - system_state_modifications.apply_balance_changes(&mut system_state); + system_state_modifications.apply_balance_changes( + &mut system_state, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); assert_eq!(initial_cycles_balance + added, system_state.balance()); @@ -1540,7 +1561,11 @@ mod tests { }, ); - system_state_modifications.apply_balance_changes(&mut system_state); + system_state_modifications.apply_balance_changes( + &mut system_state, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); assert_eq!(initial_cycles_balance + added, system_state.balance()); } diff --git a/rs/embedders/tests/sandbox_safe_system_state.rs b/rs/embedders/tests/sandbox_safe_system_state.rs index 4efd9d87c89c..ccc07162ba45 100644 --- a/rs/embedders/tests/sandbox_safe_system_state.rs +++ b/rs/embedders/tests/sandbox_safe_system_state.rs @@ -265,6 +265,7 @@ fn correct_charging_source_canister_for_a_request() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); let no_op_counter: IntCounter = IntCounter::new("no_op", "no_op").unwrap(); @@ -483,6 +484,7 @@ fn call_increases_cycles_consumed_metric() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert!(system_state.canister_metrics().consumed_cycles().get() > 0); @@ -575,6 +577,7 @@ fn test_inter_canister_call( false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); diff --git a/rs/embedders/tests/system_api.rs b/rs/embedders/tests/system_api.rs index da0afe019c47..75935c83e43b 100644 --- a/rs/embedders/tests/system_api.rs +++ b/rs/embedders/tests/system_api.rs @@ -33,6 +33,7 @@ use ic_types::{ use ic_types_cycles::{CanisterCyclesCostSchedule, Cycles}; use maplit::btreemap; use more_asserts::assert_le; +use prometheus::IntCounter; use std::{ collections::{BTreeMap, BTreeSet}, convert::From, @@ -1303,6 +1304,7 @@ fn certified_data_set() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.certified_data, vec![10; 32]) @@ -1499,6 +1501,7 @@ fn call_perform_not_enough_cycles_does_not_trap() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.balance(), initial_cycles); @@ -1558,6 +1561,7 @@ fn cycles_burn128_clamps_to_available_cycles() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(system_state.balance(), freeze_limit); @@ -1720,6 +1724,7 @@ fn push_output_request_respects_memory_limits() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(1, system_state.queues().output_queues_len()); @@ -1821,6 +1826,7 @@ fn push_output_request_oversized_request_memory_limits() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!(1, system_state.queues().output_queues_len()); @@ -1859,6 +1865,7 @@ fn ic0_global_timer_set_is_propagated_from_sandbox() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); assert_eq!( @@ -2122,6 +2129,7 @@ fn ic0_call_with_best_effort_response() { false, &NoOpMetrics {}, &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); diff --git a/rs/execution_environment/src/canister_manager.rs b/rs/execution_environment/src/canister_manager.rs index 8458f9d6acc2..8c1b70c7c143 100644 --- a/rs/execution_environment/src/canister_manager.rs +++ b/rs/execution_environment/src/canister_manager.rs @@ -83,6 +83,8 @@ const MAX_SLICE_SIZE_BYTES: u64 = 2_000_000; pub(crate) struct CanisterManager { hypervisor: Arc, log: ReplicaLogger, + /// Critical error for charges exceeding the canister's cycles balance. + charging_from_balance_error: IntCounter, config: CanisterMgrConfig, cycles_account_manager: Arc, fd_factory: Arc, @@ -92,6 +94,7 @@ impl CanisterManager { pub(crate) fn new( hypervisor: Arc, log: ReplicaLogger, + charging_from_balance_error: IntCounter, config: CanisterMgrConfig, cycles_account_manager: Arc, fd_factory: Arc, @@ -99,6 +102,7 @@ impl CanisterManager { CanisterManager { hypervisor, log, + charging_from_balance_error, config, cycles_account_manager, fd_factory, @@ -941,6 +945,8 @@ impl CanisterManager { subnet_cycles_config, reveal_top_up, wasm_execution_mode, + &self.log, + round_counters.charging_from_balance_error, ) { Ok(cycles) => cycles, Err(err) => { @@ -1558,7 +1564,7 @@ impl CanisterManager { ); // The creation fee was already withdrawn from the sender's balance. - let _uncharged = system_state.consume_cycles(creation_fee); + system_state.consume_cycles(creation_fee, &self.log, &self.charging_from_balance_error); let mut new_canister = CanisterState::new( system_state, None, @@ -1788,6 +1794,8 @@ impl CanisterManager { canister, instructions, subnet_cycles_config, + &self.log, + &self.charging_from_balance_error, ) .map_err(|err| CanisterManagerError::WasmChunkStoreError { message: format!("Error charging for 'upload_chunk': {err}"), @@ -2014,6 +2022,8 @@ impl CanisterManager { cycles_for_instructions, subnet_cycles_config, reveal_top_up, + &self.log, + &self.charging_from_balance_error, ) .map_err(CanisterManagerError::NotEnoughCycles)?; @@ -2351,6 +2361,8 @@ impl CanisterManager { subnet_cycles_config, reveal_top_up, wasm_execution_mode, + &self.log, + &self.charging_from_balance_error, ) { Ok(cycles) => cycles, Err(err) => { @@ -2727,6 +2739,8 @@ impl CanisterManager { canister, num_instructions, subnet_cycles_config, + &self.log, + &self.charging_from_balance_error, ) .map_err(CanisterManagerError::NotEnoughCycles)?; let cost = self @@ -2952,6 +2966,8 @@ impl CanisterManager { canister, instructions, subnet_cycles_config, + &self.log, + &self.charging_from_balance_error, ) .map_err(CanisterManagerError::NotEnoughCycles)?; let cost = self diff --git a/rs/execution_environment/src/canister_manager/tests.rs b/rs/execution_environment/src/canister_manager/tests.rs index c5c6f5cb30fb..1a385ef692f1 100644 --- a/rs/execution_environment/src/canister_manager/tests.rs +++ b/rs/execution_environment/src/canister_manager/tests.rs @@ -276,6 +276,7 @@ impl CanisterManagerBuilder { CanisterManager::new( hypervisor, no_op_logger(), + no_op_counter(), canister_manager_config( self.subnet_id, subnet_type, @@ -9218,18 +9219,16 @@ fn assert_canister_metrics_can_be_retrieved( ) { // Set dummy values for consumed cycles in the canister state. let memory_cycles = CompoundCycles::::new(Cycles::new(1), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(memory_cycles); + .consume_cycles(memory_cycles, &no_op_logger(), &no_op_counter()); // `Instructions` follow the prepay/refund flow where metrics are updated // only during the refund step. let instructions_cycles = CompoundCycles::::new(Cycles::new(2), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(instructions_cycles); + .consume_cycles(instructions_cycles, &no_op_logger(), &no_op_counter()); test.canister_state_mut(canister_id) .system_state .refund_cycles( @@ -9239,39 +9238,38 @@ fn assert_canister_metrics_can_be_retrieved( let ingress_induction_cycles = CompoundCycles::::new(Cycles::new(3), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(ingress_induction_cycles); + .consume_cycles(ingress_induction_cycles, &no_op_logger(), &no_op_counter()); let compute_allocation_cycles = CompoundCycles::::new(Cycles::new(4), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(compute_allocation_cycles); + .consume_cycles(compute_allocation_cycles, &no_op_logger(), &no_op_counter()); let canister_creation_cycles = CompoundCycles::::new(Cycles::new(5), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(canister_creation_cycles); + .consume_cycles(canister_creation_cycles, &no_op_logger(), &no_op_counter()); let uninstall_cycles = CompoundCycles::::new(Cycles::new(6), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(uninstall_cycles); + .consume_cycles(uninstall_cycles, &no_op_logger(), &no_op_counter()); // `RequestAndResponseTransmission` follow the prepay/refund flow where // metrics are updated only during the refund step. let request_and_response_transmission_cycles = CompoundCycles::::new(Cycles::new(8), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(request_and_response_transmission_cycles); + .consume_cycles( + request_and_response_transmission_cycles, + &no_op_logger(), + &no_op_counter(), + ); test.canister_state_mut(canister_id) .system_state .refund_cycles( @@ -9285,10 +9283,9 @@ fn assert_canister_metrics_can_be_retrieved( .observe_consumed_cycles_for_https_outcall(http_outcalls_cycles.nominal()); let burned_cycles = CompoundCycles::::new(Cycles::new(10), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(burned_cycles); + .consume_cycles(burned_cycles, &no_op_logger(), &no_op_counter()); let expected_cycles_consumed = CyclesConsumed::new( memory_cycles.nominal(), diff --git a/rs/execution_environment/src/execution/call_or_task.rs b/rs/execution_environment/src/execution/call_or_task.rs index fc7a2964ff18..a5eca77a461e 100644 --- a/rs/execution_environment/src/execution/call_or_task.rs +++ b/rs/execution_environment/src/execution/call_or_task.rs @@ -81,6 +81,8 @@ pub fn execute_call_or_task( subnet_cycles_config, reveal_top_up, wasm_execution_mode, + round.log, + round.counters.charging_from_balance_error, ) { Ok(cycles) => cycles, Err(err) => { @@ -610,6 +612,7 @@ impl CallOrTaskHelper { false, round.hypervisor.metrics(), round.log, + round.counters.charging_from_balance_error, ) { return finish_err( diff --git a/rs/execution_environment/src/execution/common.rs b/rs/execution_environment/src/execution/common.rs index 6fe63760a695..6e43b7ab1826 100644 --- a/rs/execution_environment/src/execution/common.rs +++ b/rs/execution_environment/src/execution/common.rs @@ -633,6 +633,7 @@ fn try_apply_canister_state_changes( is_composite_query: bool, metrics: &HypervisorMetrics, log: &ReplicaLogger, + charging_error: &IntCounter, ) -> HypervisorResult { subnet_available_memory .try_decrement( @@ -650,6 +651,7 @@ fn try_apply_canister_state_changes( is_composite_query, metrics, log, + charging_error, ) } @@ -701,6 +703,9 @@ pub fn apply_canister_state_changes( is_composite_query, metrics, log, + // Applying the balance changes must not run into charges that the balance + // cannot cover: the cycle changes were validated before they are applied. + state_changes_error, ) { Ok(request_stats) => { if let Some(ExecutionStateChanges { diff --git a/rs/execution_environment/src/execution/install_code.rs b/rs/execution_environment/src/execution/install_code.rs index 22a3c4c190d9..9f12a2629d9b 100644 --- a/rs/execution_environment/src/execution/install_code.rs +++ b/rs/execution_environment/src/execution/install_code.rs @@ -712,6 +712,7 @@ impl InstallCodeHelper { false, // Install cannot happen in composite_query. round.hypervisor.metrics(), round.log, + round.counters.charging_from_balance_error, ); match output.wasm_result { diff --git a/rs/execution_environment/src/execution/response/tests.rs b/rs/execution_environment/src/execution/response/tests.rs index db3781cc48b2..a312fc3194c0 100644 --- a/rs/execution_environment/src/execution/response/tests.rs +++ b/rs/execution_environment/src/execution/response/tests.rs @@ -2,6 +2,7 @@ use assert_matches::assert_matches; use ic_base_types::{NumBytes, NumSeconds}; use ic_error_types::ErrorCode; use ic_interfaces::execution_environment::MessageMemoryUsage; +use ic_logger::replica_logger::no_op_logger; use ic_management_canister_types_private::CanisterStatusType; use ic_replicated_state::NumWasmPages; use ic_replicated_state::canister_state::NextExecution; @@ -22,6 +23,7 @@ use ic_types::{ComputeAllocation, MemoryAllocation}; use ic_types_cycles::{CanisterCyclesCostSchedule, Cycles, CyclesUseCase}; use ic_universal_canister::{call_args, wasm}; use more_asserts::{assert_ge, assert_gt, assert_lt}; +use prometheus::IntCounter; #[test] fn execute_response_when_stopping_status() { @@ -2644,7 +2646,11 @@ fn subnet_available_memory_does_not_change_on_response_resume_failure() { // Change the cycles balance to force the response resuming to fail. test.canister_state_mut(a_id) .system_state - .burn_remaining_balance_for_uninstall(CanisterCyclesCostSchedule::Normal); + .burn_remaining_balance_for_uninstall( + CanisterCyclesCostSchedule::Normal, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); test.execute_slice(a_id); assert_eq!( @@ -2733,7 +2739,11 @@ fn subnet_available_memory_does_not_change_on_cleanup_resume_failure() { // Change the cycles balance to force the cleanup resuming to fail. test.canister_state_mut(a_id) .system_state - .burn_remaining_balance_for_uninstall(CanisterCyclesCostSchedule::Normal); + .burn_remaining_balance_for_uninstall( + CanisterCyclesCostSchedule::Normal, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); test.execute_slice(a_id); assert_eq!( diff --git a/rs/execution_environment/src/execution_environment.rs b/rs/execution_environment/src/execution_environment.rs index 3c9c2f24ff21..498a49447be9 100644 --- a/rs/execution_environment/src/execution_environment.rs +++ b/rs/execution_environment/src/execution_environment.rs @@ -360,6 +360,8 @@ impl<'a> ConsumedCyclesForInstructions<'a> { round_limits: &mut RoundLimits, subnet_cycles_config: CyclesAccountManagerSubnetConfig, failed_charge: &IntCounter, + log: &ReplicaLogger, + charging_error: &IntCounter, ) { canister.scheduler_state.install_code_debit += self.install_code_debit; let memory_usage = canister.memory_usage(); @@ -371,6 +373,8 @@ impl<'a> ConsumedCyclesForInstructions<'a> { self.consumed_cycles, subnet_cycles_config, true, /* we only log the error, but do not return it to the user => do reveal top up balance */ + log, + charging_error, ); if let Err(err) = res { failed_charge.inc(); @@ -535,6 +539,10 @@ impl ExecutionEnvironment { &self.metrics.state_changes_error } + pub fn charging_from_balance_error(&self) -> &IntCounter { + &self.metrics.charging_from_balance_error + } + pub fn canister_not_found_error(&self) -> &IntCounter { &self.metrics.canister_not_found_error } @@ -674,6 +682,8 @@ impl ExecutionEnvironment { round_limits, subnet_cycles_config, &self.metrics.failed_subnet_message_charge, + &self.log, + &self.metrics.charging_from_balance_error, ); self.process_canister_manager_result(Err(err), state, msg, current_round) } @@ -1067,6 +1077,8 @@ impl ExecutionEnvironment { induction_cost, subnet_cycles_config, false, // we ignore the error anyway => no need to reveal top up balance + &self.log, + &self.metrics.charging_from_balance_error, ); } } diff --git a/rs/execution_environment/src/lib.rs b/rs/execution_environment/src/lib.rs index ed29ac0c7ea7..92fb8655b394 100644 --- a/rs/execution_environment/src/lib.rs +++ b/rs/execution_environment/src/lib.rs @@ -60,6 +60,11 @@ pub use scheduler::{ use std::{path::Path, sync::Arc}; use tokio::sync::mpsc::Sender; +/// Critical error for charges by the canister manager that exceed the +/// canister's cycles balance. +const CRITICAL_ERROR_CANISTER_MANAGER_CHARGING_FROM_BALANCE: &str = + "canister_manager_charging_from_balance"; + /// When executing a wasm method of query type, this enum indicates if we are /// running in an replicated or non-replicated context. This information is /// needed for various purposes and in particular to support the CoW memory @@ -385,6 +390,7 @@ fn setup_execution_helper( let canister_manager = Arc::new(CanisterManager::new( Arc::clone(&hypervisor), logger.clone(), + metrics_registry.error_counter(CRITICAL_ERROR_CANISTER_MANAGER_CHARGING_FROM_BALANCE), canister_manager_config, Arc::clone(&cycles_account_manager), Arc::clone(&fd_factory), 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 a69028a98cd5..0645d037c1ac 100644 --- a/rs/execution_environment/src/query_handler/query_cache/tests.rs +++ b/rs/execution_environment/src/query_handler/query_cache/tests.rs @@ -9,6 +9,7 @@ use ic_base_types::CanisterId; use ic_error_types::ErrorCode; use ic_heap_bytes::{DeterministicHeapBytes, HeapBytes, total_bytes}; use ic_interfaces::execution_environment::{SystemApiCallCounters, SystemApiCallId}; +use ic_logger::replica_logger::no_op_logger; use ic_management_canister_types_private::{ CanisterIdRecord, CanisterStatusResultV2, CanisterStatusType, Payload, }; @@ -27,6 +28,7 @@ use ic_types::{ }; use ic_types_cycles::{CanisterCyclesCostSchedule, CompoundCycles, Memory}; use ic_universal_canister::call_args; +use prometheus::IntCounter; use std::{collections::BTreeMap, sync::Arc, time::Duration}; const MAX_EXPIRY_TIME: Duration = Duration::from_secs(10); @@ -613,8 +615,10 @@ fn query_cache_ignores_balance_changes_when_query_does_not_read_balance() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + test.canister_state_mut(b_id).system_state.consume_cycles( CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ); // Run the same query for the second time. @@ -643,8 +647,10 @@ fn query_cache_ignores_balance_and_time_changes_when_query_is_static() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + test.canister_state_mut(b_id).system_state.consume_cycles( CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ); // Change the time. test.state_mut().metadata.batch_time += Duration::from_secs(1); @@ -796,8 +802,10 @@ fn query_cache_returns_different_results_for_different_canister_balances() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + test.canister_state_mut(b_id).system_state.consume_cycles( CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ); let res_2 = test.non_replicated_query(a_id, method, q); @@ -823,8 +831,10 @@ fn query_cache_returns_different_results_for_different_canister_balance128s() { assert_eq!(res_1, Ok(WasmResult::Reply(vec![42]))); // Change the canister balance. - let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + test.canister_state_mut(b_id).system_state.consume_cycles( CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ); let res_2 = test.non_replicated_query(a_id, method, q); @@ -861,8 +871,10 @@ fn query_cache_returns_different_results_on_combined_invalidation() { test.canister_state_mut(b_id) .system_state .bump_canister_version(); - let _uncharged = test.canister_state_mut(b_id).system_state.consume_cycles( + test.canister_state_mut(b_id).system_state.consume_cycles( CompoundCycles::::new(1_u64.into(), CanisterCyclesCostSchedule::Normal), + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ); let res_2 = test.non_replicated_query(a_id, method, q); @@ -909,13 +921,14 @@ fn query_cache_frees_memory_after_invalidated_entries() { assert_gt!(heap_bytes, BIG_RESPONSE_SIZE); // Set the canister balance to 42, so the second reply will have just 42 bytes. - let _uncharged = test - .canister_state_mut(id) - .system_state - .consume_cycles(CompoundCycles::::new( + test.canister_state_mut(id).system_state.consume_cycles( + CompoundCycles::::new( ((BIG_RESPONSE_SIZE - SMALL_RESPONSE_SIZE) as u64).into(), CanisterCyclesCostSchedule::Normal, - )); + ), + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); // The new 42 reply must invalidate and replace the previous 1MB reply in the cache. let res = test diff --git a/rs/execution_environment/src/scheduler.rs b/rs/execution_environment/src/scheduler.rs index c63b673ffdcf..94e04d9d6f2d 100644 --- a/rs/execution_environment/src/scheduler.rs +++ b/rs/execution_environment/src/scheduler.rs @@ -871,6 +871,7 @@ impl SchedulerImpl { .cycles_account_manager .charge_canister_for_resource_allocation_and_usage( &self.log, + self.exec_env.charging_from_balance_error(), canister, duration_since_last_charge, subnet_cycles_config, @@ -888,9 +889,11 @@ impl SchedulerImpl { canister.system_state.clear_canister_history(); canister.remove_log(); // Burn the remaining balance of the canister. - canister - .system_state - .burn_remaining_balance_for_uninstall(cost_schedule); + canister.system_state.burn_remaining_balance_for_uninstall( + cost_schedule, + &self.log, + self.exec_env.charging_from_balance_error(), + ); canister .canister_snapshots .delete_snapshots(&mut unflushed_checkpoint_ops); diff --git a/rs/execution_environment/src/scheduler/tests/metrics.rs b/rs/execution_environment/src/scheduler/tests/metrics.rs index 167ae1feee99..76c9a60f1b00 100644 --- a/rs/execution_environment/src/scheduler/tests/metrics.rs +++ b/rs/execution_environment/src/scheduler/tests/metrics.rs @@ -42,6 +42,7 @@ use ic_types_cycles::{ }; use ic_types_test_utils::ids::{canister_test_id, message_test_id, subnet_test_id, user_test_id}; use more_asserts::assert_ge; +use prometheus::IntCounter; use std::time::Duration; #[test] @@ -1431,10 +1432,13 @@ fn consumed_cycles_for_instructions_are_updated_from_valid_canisters() { let removed_cycles = CompoundCycles::::new(Cycles::from(1000_u128), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(removed_cycles); + .consume_cycles( + removed_cycles, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); test.state_metrics().observe( test.state().metadata.own_subnet_id, @@ -1547,10 +1551,13 @@ fn consumed_cycles_are_updated_from_deleted_canisters() { let removed_cycles = CompoundCycles::::new(Cycles::from(1000_u128), cost_schedule); - let _uncharged = test - .canister_state_mut(canister_id) + test.canister_state_mut(canister_id) .system_state - .consume_cycles(removed_cycles); + .consume_cycles( + removed_cycles, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), + ); test.inject_call_to_ic00( Method::DeleteCanister, diff --git a/rs/messaging/src/scheduling/valid_set_rule.rs b/rs/messaging/src/scheduling/valid_set_rule.rs index 0f092b1b8336..85e66002049f 100644 --- a/rs/messaging/src/scheduling/valid_set_rule.rs +++ b/rs/messaging/src/scheduling/valid_set_rule.rs @@ -25,7 +25,7 @@ use ic_types::{ }, time::expiry_time_from_now, }; -use prometheus::{Histogram, HistogramVec, IntCounterVec, IntGauge}; +use prometheus::{Histogram, HistogramVec, IntCounter, IntCounterVec, IntGauge}; use std::sync::Arc; struct VsrMetrics { @@ -40,6 +40,8 @@ struct VsrMetrics { /// Memory currently used by payloads of statuses in the ingress /// history. ingress_history_size: IntGauge, + /// Critical error for ingress induction costs exceeding the cycles balance. + charging_from_balance_error: IntCounter, } const METRIC_INDUCTED_INGRESS_MESSAGES: &str = "mr_inducted_ingress_message_count"; @@ -48,6 +50,8 @@ const METRIC_UNRELIABLE_INDUCT_INGRESS_MESSAGE_DURATION: &str = "mr_unreliable_induct_ingress_message_duration_seconds"; const METRIC_INGRESS_HISTORY_SIZE: &str = "mr_ingress_history_size_bytes"; +const CRITICAL_ERROR_CHARGING_FROM_BALANCE: &str = "mr_charging_from_balance"; + const LABEL_STATUS: &str = "status"; const LABEL_VALUE_SUCCESS: &str = "success"; @@ -76,6 +80,8 @@ impl VsrMetrics { METRIC_INGRESS_HISTORY_SIZE, "Memory currently used by payloads of statuses in the ingress history", ); + let charging_from_balance_error = + metrics_registry.error_counter(CRITICAL_ERROR_CHARGING_FROM_BALANCE); // Initialize all `inducted_ingress_messages` counters with zero, so they are // all exported from process start (`IntCounterVec` is really a map). @@ -98,6 +104,7 @@ impl VsrMetrics { inducted_ingress_payload_sizes, unreliable_induct_ingress_message_duration, ingress_history_size, + charging_from_balance_error, } } } @@ -310,6 +317,8 @@ impl> cost, subnet_cycles_config, reveal_top_up, + &self.log, + &self.metrics.charging_from_balance_error, ) { return Err(IngressInductionError::CanisterOutOfCycles(err)); } diff --git a/rs/replicated_state/src/canister_state/system_state.rs b/rs/replicated_state/src/canister_state/system_state.rs index 44cc1b0cc662..684e4b6c9729 100644 --- a/rs/replicated_state/src/canister_state/system_state.rs +++ b/rs/replicated_state/src/canister_state/system_state.rs @@ -1024,13 +1024,17 @@ impl SystemState { log: &ReplicaLogger, charging_from_balance_error: &IntCounter, ) { - // `consume_cycles()` charges only the part of the debit that the balance can - // cover and hands back the rest, which is neither charged nor reported as - // consumed. Dropping it here makes some of the postponed charges free. - let uncharged_debit = self.consume_cycles(CompoundCycles::::new( + let debit = CompoundCycles::::new( self.ingress_induction_cycles_debit, cost_schedule, - )); + ); + // Charge only the part of the debit that the balance can cover. Dropping the + // rest is legitimate here (making some of the postponed charges free), so it + // must be capped before `consume_cycles()`, which reports what it cannot + // charge as a critical error. + // + // We rely on saturating operations of `Cycles` here. + let uncharged_debit = debit.real() - self.cycles_balance; self.ingress_induction_cycles_debit = Cycles::zero(); if strict { debug_assert_eq!(uncharged_debit.get(), 0); @@ -1044,8 +1048,15 @@ impl SystemState { canister_id, uncharged_debit, ); + // Continue the execution by dropping the remaining debit, which makes + // some of the postponed charges free. } } + self.consume_cycles( + debit.minus_uncharged(uncharged_debit), + log, + charging_from_balance_error, + ); } /// This method is used for maintaining the backwards compatibility. @@ -2044,16 +2055,17 @@ impl SystemState { /// needs to be made (that will be refunded later with `refund_cycles`) or /// a direct charge happens without a prepayment (e.g. when paying for memory). /// - /// The balances are not required to cover the requested amount. Returns the - /// part that they could not cover, which is neither charged nor reported as - /// consumed. Getting back a non-zero amount is a bug in every caller that - /// guarantees a sufficient balance, so such callers should report it as a - /// critical error if they have a logger and an error counter at hand. - #[must_use] + /// The balances are required to cover the requested amount: the part that + /// they cannot cover is neither charged nor reported as consumed, and is + /// reported as a critical error instead. Callers that intend to charge only + /// what the balances can cover must cap the requested amount themselves, + /// e.g. with `CompoundCycles::minus_uncharged()`. pub fn consume_cycles( &mut self, requested_amount: CompoundCycles, - ) -> Cycles { + log: &ReplicaLogger, + charging_from_balance_error: &IntCounter, + ) { let requested_real = requested_amount.real(); let use_case = T::cycles_use_case(); let remaining_amount = match use_case { @@ -2076,10 +2088,23 @@ impl SystemState { }; // The balance may not cover the whole amount, in which case the subtraction // below saturates at zero and the uncovered part is never actually charged. - // Report only the part that the balance could cover as consumed, so that the + // Charge and report only the part that the balance could cover, so that the // consumed cycles metrics never exceed the cycles removed from the balance. let uncharged_amount = remaining_amount - self.cycles_balance; self.cycles_balance -= remaining_amount; + if !uncharged_amount.is_zero() { + // This case is unreachable and may happen only due to a bug: every caller + // is expected to either cover the requested amount or cap it beforehand. + charging_from_balance_error.inc(); + error!( + log, + "[EXC-BUG]: Charging {} for {} exceeds the cycles balance of {} by {}", + requested_real, + use_case.as_str(), + self.canister_id, + uncharged_amount, + ); + } let charged_amount = requested_amount.minus_uncharged(uncharged_amount); self.observe_consumed_cycles_with_use_case( charged_amount.nominal(), @@ -2087,7 +2112,6 @@ impl SystemState { use_case, ConsumingCycles::Prepayment, ); - uncharged_amount } /// Checks if the given amount of cycles from the main balance can be moved to the reserved balance. @@ -2133,12 +2157,16 @@ impl SystemState { pub fn burn_remaining_balance_for_uninstall( &mut self, cost_schedule: CanisterCyclesCostSchedule, + log: &ReplicaLogger, + charging_from_balance_error: &IntCounter, ) { - let balance = self.cycles_balance + self.reserved_balance; - let uncharged = - self.consume_cycles(CompoundCycles::::new(balance, cost_schedule)); // The balances cover the whole amount by construction. - debug_assert_eq!(uncharged, Cycles::zero()); + let balance = self.cycles_balance + self.reserved_balance; + self.consume_cycles( + CompoundCycles::::new(balance, cost_schedule), + log, + charging_from_balance_error, + ); } /// Observes the consumed cycles for HTTPS outcalls. This should only be diff --git a/rs/replicated_state/src/canister_state/tests.rs b/rs/replicated_state/src/canister_state/tests.rs index 734c87d44da4..af339b771792 100644 --- a/rs/replicated_state/src/canister_state/tests.rs +++ b/rs/replicated_state/src/canister_state/tests.rs @@ -910,7 +910,7 @@ fn update_balance_and_consumed_cycles_correctly() { let cost_schedule = CanisterCyclesCostSchedule::Normal; let prepaid_cycles = CompoundCycles::::new(initial_consumed_cycles, cost_schedule); - let _uncharged = system_state.consume_cycles(prepaid_cycles); + system_state.consume_cycles(prepaid_cycles, &no_op_logger(), &mock_metrics()); assert_eq!( system_state.balance(), INITIAL_CYCLES - initial_consumed_cycles @@ -938,7 +938,7 @@ fn update_balance_and_consumed_cycles_by_use_case_correctly() { let cycles_to_consume = Cycles::from(1000_u128); let cost_schedule = CanisterCyclesCostSchedule::Normal; let prepaid_cycles = CompoundCycles::::new(cycles_to_consume, cost_schedule); - let _uncharged = system_state.consume_cycles(prepaid_cycles); + system_state.consume_cycles(prepaid_cycles, &no_op_logger(), &mock_metrics()); let refund = CompoundCycles::::new(Cycles::from(100_u128), cost_schedule); system_state.refund_cycles(prepaid_cycles, refund); @@ -960,15 +960,20 @@ fn update_balance_and_consumed_cycles_by_use_case_correctly() { fn consume_cycles_exceeding_balance_reports_only_the_charged_amount() { let mut system_state = CanisterStateFixture::new().canister_state.system_state; let cost_schedule = CanisterCyclesCostSchedule::Normal; + let charging_from_balance_error = mock_metrics(); // Request more cycles than the balance can cover. - let uncovered_cycles = Cycles::new(1000); let requested_cycles = - CompoundCycles::::new(INITIAL_CYCLES + uncovered_cycles, cost_schedule); - let uncharged_cycles = system_state.consume_cycles(requested_cycles); + CompoundCycles::::new(INITIAL_CYCLES + Cycles::new(1000), cost_schedule); + system_state.consume_cycles( + requested_cycles, + &no_op_logger(), + &charging_from_balance_error, + ); // The balance is drained and only the drained amount is reported as consumed, - // i.e. the part of the request that the balance could not cover is not. - assert_eq!(uncovered_cycles, uncharged_cycles); + // i.e. the part of the request that the balance could not cover is not. That part + // is reported as a critical error instead. + assert_eq!(1, charging_from_balance_error.get()); assert_eq!(Cycles::zero(), system_state.balance()); assert_eq!( NominalCycles::new(INITIAL_CYCLES.get()), @@ -988,17 +993,22 @@ fn consume_cycles_exceeding_balance_reports_only_the_charged_amount() { fn consume_cycles_exceeding_balance_and_reserved_balance_reports_only_the_charged_amount() { let mut system_state = CanisterStateFixture::new().canister_state.system_state; let cost_schedule = CanisterCyclesCostSchedule::Normal; + let charging_from_balance_error = mock_metrics(); let reserved_cycles = Cycles::new(1000); system_state.reserve_cycles(reserved_cycles).unwrap(); // Request more cycles than the reserved balance and the balance together can cover. - let uncovered_cycles = Cycles::new(500); let requested_cycles = - CompoundCycles::::new(INITIAL_CYCLES + uncovered_cycles, cost_schedule); - let uncharged_cycles = system_state.consume_cycles(requested_cycles); + CompoundCycles::::new(INITIAL_CYCLES + Cycles::new(500), cost_schedule); + system_state.consume_cycles( + requested_cycles, + &no_op_logger(), + &charging_from_balance_error, + ); - // Both balances are drained and only the drained amount is reported as consumed. - assert_eq!(uncovered_cycles, uncharged_cycles); + // Both balances are drained, only the drained amount is reported as consumed and + // the part that they could not cover is reported as a critical error. + assert_eq!(1, charging_from_balance_error.get()); assert_eq!(Cycles::zero(), system_state.balance()); assert_eq!(Cycles::zero(), system_state.reserved_balance()); assert_eq!( diff --git a/rs/replicated_state/src/canister_states/tests.rs b/rs/replicated_state/src/canister_states/tests.rs index fbaf9d58bd6b..04d2df8dd387 100644 --- a/rs/replicated_state/src/canister_states/tests.rs +++ b/rs/replicated_state/src/canister_states/tests.rs @@ -9,7 +9,9 @@ use crate::{ ExportedFunctions, InputQueueType, Memory, SchedulerState, SystemState, }; use ic_base_types::NumSeconds; +use ic_logger::replica_logger::no_op_logger; use ic_management_canister_types_private::{CanisterChangeDetails, CanisterChangeOrigin}; +use ic_metrics::MetricsRegistry; use ic_registry_subnet_type::SubnetType; use ic_test_utilities_types::ids::canister_test_id; use ic_test_utilities_types::messages::RequestBuilder; @@ -864,12 +866,14 @@ fn total_consumed_cycles_combines_hot_and_cold() { }; fn consume(canister: &mut Arc, amount: u128) { - let _uncharged = Arc::make_mut(canister) - .system_state - .consume_cycles(CompoundCycles::::new( + Arc::make_mut(canister).system_state.consume_cycles( + CompoundCycles::::new( Cycles::new(amount), CanisterCyclesCostSchedule::Normal, - )); + ), + &no_op_logger(), + &MetricsRegistry::new().int_counter("error_counter", "Test error counter"), + ); } // Consuming cycles does not create any work, so the canister stays cold. diff --git a/rs/test_utilities/execution_environment/src/lib.rs b/rs/test_utilities/execution_environment/src/lib.rs index 08d96f86d5c6..9c114ecc1a45 100644 --- a/rs/test_utilities/execution_environment/src/lib.rs +++ b/rs/test_utilities/execution_environment/src/lib.rs @@ -2387,6 +2387,8 @@ impl ExecutionTest { CompoundCycles::::new(cycles, cost_schedule), Cycles::zero(), false, + &no_op_logger(), + &IntCounter::new("no_op", "no_op").unwrap(), ) .unwrap(); }