From a52bdc03580a5700f9d7f2dd376df93411533937 Mon Sep 17 00:00:00 2001 From: Martin Raszyk Date: Wed, 5 Aug 2026 14:06:01 +0000 Subject: [PATCH] fix: check the cycles balance and charge executed instructions on DTS resume `InstallCodeHelper` records the cycles balance of the clean canister state it was built from and compares it when resuming a paused `install_code` execution, analogously to `ResponseHelper` and `CallOrTaskHelper`. Moreover, if resuming a paused execution fails, then the instructions already executed by the paused Wasm execution are charged now: those instructions consumed round instructions, but the instruction limits are only updated when the Wasm execution finishes and hence such instructions used to be free. For `install_code`, only the instructions of the steps preceding the paused Wasm execution (e.g., compilation) used to be charged; for update calls, replicated queries, canister tasks, and response callbacks, no instructions used to be charged at all; for cleanup callbacks, the instructions of the preceding response callback used to be charged, but not those of the cleanup callback itself. Finally, `dts_replicated_execution_resume_fails_due_to_cycles_change` moves to the general execution tests as `dts_resume_fails_due_to_cycles_decrease`, decreases the cycles balance using `remove_cycles`, and covers response and cleanup callbacks and the heartbeat in addition to update calls and replicated queries; the new test `dts_install_code_resume_fails_due_to_cycles_decrease` covers `install_code`. The tests assert that the instructions reported by the failed execution match the round instructions consumed by its slices and that the canister is charged exactly the cost of those instructions, for which `ExecutionTest` tracks the round instructions consumed per canister. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/execution/call_or_task.rs | 37 ++- .../src/execution/call_or_task/tests.rs | 67 ----- .../src/execution/install.rs | 8 +- .../src/execution/install_code.rs | 55 +++- .../src/execution/install_code/tests.rs | 56 ++++ .../src/execution/response.rs | 66 ++++- .../src/execution/upgrade.rs | 12 +- .../src/execution_environment/tests.rs | 265 +++++++++++++++++- .../execution_environment/src/lib.rs | 24 ++ 9 files changed, 485 insertions(+), 105 deletions(-) diff --git a/rs/execution_environment/src/execution/call_or_task.rs b/rs/execution_environment/src/execution/call_or_task.rs index e7b3a4bce6b8..fecb9d812a8a 100644 --- a/rs/execution_environment/src/execution/call_or_task.rs +++ b/rs/execution_environment/src/execution/call_or_task.rs @@ -228,7 +228,7 @@ pub fn execute_call_or_task( }; let paused_execution = Box::new(PausedCallOrTaskExecution { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), original, }); ExecuteMessageResult::Paused { @@ -322,6 +322,7 @@ struct OriginalContext { struct PausedCallOrTaskHelper { call_context_id: CallContextId, initial_cycles_balance: Cycles, + executed_wasm_instructions: NumInstructions, } /// A helper that implements and keeps track of update call steps. @@ -330,6 +331,12 @@ struct CallOrTaskHelper { canister: CanisterState, call_context_id: CallContextId, initial_cycles_balance: Cycles, + // Instructions already executed by a Wasm execution that has been paused and + // has not finished yet. Such instructions are not reflected in the + // instruction limits because those are updated only when the Wasm execution + // finishes, so they are tracked here in order to be charged if the execution + // fails before the Wasm execution finishes. + executed_wasm_instructions: NumInstructions, deallocation_sender: DeallocationSender, } @@ -412,17 +419,22 @@ impl CallOrTaskHelper { canister, call_context_id, initial_cycles_balance, + executed_wasm_instructions: NumInstructions::new(0), deallocation_sender: deallocation_sender.clone(), }) } /// Returns a struct with all the necessary information to replay the /// performed update call steps in subsequent rounds. - fn pause(self) -> PausedCallOrTaskHelper { + /// The given `executed_wasm_instructions` are the instructions executed by + /// the Wasm slice that is being paused. + fn pause(self, executed_wasm_instructions: NumInstructions) -> PausedCallOrTaskHelper { self.deallocation_sender.send(Box::new(self.canister)); PausedCallOrTaskHelper { call_context_id: self.call_context_id, initial_cycles_balance: self.initial_cycles_balance, + executed_wasm_instructions: self.executed_wasm_instructions + + executed_wasm_instructions, } } @@ -435,7 +447,8 @@ impl CallOrTaskHelper { paused: PausedCallOrTaskHelper, deallocation_sender: &DeallocationSender, ) -> Result { - let helper = Self::new(clean_canister, original, deallocation_sender)?; + let mut helper = Self::new(clean_canister, original, deallocation_sender)?; + helper.executed_wasm_instructions = paused.executed_wasm_instructions; if helper.initial_cycles_balance != paused.initial_cycles_balance { let msg = match original.call_or_task { CanisterCallOrTask::Update(_) => { @@ -717,6 +730,11 @@ impl PausedExecution for PausedCallOrTaskExecution { self.original.method, clean_canister.canister_id(), ); + // If resuming fails, then the instructions already executed by the paused + // Wasm execution are still charged: they have been executed and hence + // consumed round instructions, but the instruction limits are updated + // only when the Wasm execution finishes. + let executed_wasm_instructions = self.paused_helper.executed_wasm_instructions; let helper = match CallOrTaskHelper::resume( &clean_canister, &self.original, @@ -733,16 +751,15 @@ impl PausedExecution for PausedCallOrTaskExecution { err, ); self.paused_wasm_execution.abort(); - return finish_err( - clean_canister, + let instructions_left = NumInstructions::new( self.original .execution_parameters .instruction_limits - .message(), - err, - self.original, - round, + .message() + .get() + .saturating_sub(executed_wasm_instructions.get()), ); + return finish_err(clean_canister, instructions_left, err, self.original, round); } }; @@ -760,7 +777,7 @@ impl PausedExecution for PausedCallOrTaskExecution { update_round_limits(round_limits, &slice); let paused_execution = Box::new(PausedCallOrTaskExecution { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), original: self.original, }); ExecuteMessageResult::Paused { diff --git a/rs/execution_environment/src/execution/call_or_task/tests.rs b/rs/execution_environment/src/execution/call_or_task/tests.rs index fb5d8e0219f8..e75609376082 100644 --- a/rs/execution_environment/src/execution/call_or_task/tests.rs +++ b/rs/execution_environment/src/execution/call_or_task/tests.rs @@ -720,73 +720,6 @@ fn hitting_access_limit_fails_non_replicated_query() { ); } -#[test] -fn dts_replicated_execution_resume_fails_due_to_cycles_change() { - with_update_and_replicated_query(|method| { - // Test steps: - // 1. Canister A starts running the update|query method. - // 2. While canister A is paused, we change its cycles balance. - // 3. The update|query method resumes, detects the cycles balance mismatch, and - // fails. - let instruction_limit = 1_000_000; - let mut test = ExecutionTestBuilder::new() - .with_instruction_limit(instruction_limit) - .with_slice_instruction_limit(200_000) - .with_manual_execution() - .build(); - - let a_id = test.universal_canister().unwrap(); - - let a = wasm() - .stable64_grow(1) - .stable64_fill(0, 0, 50_000) - .stable64_fill(0, 0, 50_000) - .stable64_fill(0, 0, 50_000) - .stable64_fill(0, 0, 50_000) - .stable64_fill(0, 0, 50_000) - .stable64_fill(0, 0, 50_000) - .stable64_fill(0, 0, 50_000) - .stable64_fill(0, 0, 50_000) - .build(); - - let (ingress_id, _) = test.ingress_raw(a_id, method, a); - - test.execute_slice(a_id); - assert_eq!( - test.canister_state(a_id).next_execution(), - NextExecution::ContinueLong, - ); - - // Change the cycles balance of the clean canister. - let balance = test.canister_state(a_id).system_state.balance(); - test.canister_state_mut(a_id) - .system_state - .add_cycles(balance + Cycles::new(1)); - - test.execute_slice(a_id); - - assert_eq!( - test.canister_state(a_id).next_execution(), - NextExecution::None, - ); - - let err = check_ingress_status(test.ingress_status(&ingress_id)).unwrap_err(); - let message = if method == "update" { - "an update call" - } else { - "a replicated query" - }; - err.assert_contains( - ErrorCode::CanisterWasmEngineError, - &format!( - "Error from Canister {a_id}: Canister encountered a Wasm engine error: \ - Failed to apply system changes: Mismatch in cycles \ - balance when resuming {message}" - ), - ); - }); -} - #[test] fn dts_replicated_execution_resume_fails_due_to_call_context_change() { with_update_and_replicated_query(|method| { diff --git a/rs/execution_environment/src/execution/install.rs b/rs/execution_environment/src/execution/install.rs index 4570e8adaff1..fd7bcf3a94fd 100644 --- a/rs/execution_environment/src/execution/install.rs +++ b/rs/execution_environment/src/execution/install.rs @@ -204,7 +204,7 @@ pub(crate) fn execute_install( ingress_status_with_processing_state(&original.message, original.time); let paused_execution = Box::new(PausedStartExecutionDuringInstall { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), context_sender, context_arg: context.arg, original, @@ -322,7 +322,7 @@ fn install_stage_2b_continue_install_after_start( let ingress_status = ingress_status_with_processing_state(&original.message, original.time); let paused_execution = Box::new(PausedInitExecution { - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), paused_wasm_execution, original, }); @@ -440,7 +440,7 @@ impl PausedInstallCodeExecution for PausedInitExecution { update_round_limits(round_limits, &slice); let paused_execution = Box::new(PausedInitExecution { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), ..*self }); DtsInstallCodeResult::Paused { @@ -550,7 +550,7 @@ impl PausedInstallCodeExecution for PausedStartExecutionDuringInstall { ); let paused_execution = Box::new(PausedStartExecutionDuringInstall { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), ..*self }); DtsInstallCodeResult::Paused { diff --git a/rs/execution_environment/src/execution/install_code.rs b/rs/execution_environment/src/execution/install_code.rs index 81a006fa0e6f..46502312501d 100644 --- a/rs/execution_environment/src/execution/install_code.rs +++ b/rs/execution_environment/src/execution/install_code.rs @@ -27,6 +27,7 @@ use ic_types::{ CanisterLog, CanisterTimer, MemoryAllocation, NumInstructions, Time, messages::CanisterCall, }; use ic_types_cycles::{CompoundCycles, Cycles, CyclesUseCase, Instructions}; +use ic_wasm_types::WasmEngineError::FailedToApplySystemChanges; use ic_wasm_types::WasmHash; use crate::{ @@ -103,6 +104,8 @@ pub(crate) enum InstallCodeStep { pub(crate) struct PausedInstallCodeHelper { steps: Vec, instructions_left: NumInstructions, + initial_cycles_balance: Cycles, + executed_wasm_instructions: NumInstructions, } /// A helper that implements and keeps track of `install_code` steps. @@ -124,12 +127,21 @@ pub(crate) struct InstallCodeHelper { deallocated_wasm_custom_sections_bytes: NumBytes, // The total heap delta of all steps. total_heap_delta: NumBytes, + // The cycles balance of the clean canister state this helper was built from. + initial_cycles_balance: Cycles, + // Instructions already executed by a Wasm execution that has been paused and + // has not finished yet. Such instructions are not reflected in + // `execution_parameters` because the instruction limits are updated only + // when the Wasm execution finishes, so they are tracked here in order to be + // charged if the execution fails before the Wasm execution finishes. + executed_wasm_instructions: NumInstructions, } impl InstallCodeHelper { pub fn new(clean_canister: &CanisterState, original: &OriginalContext) -> Self { Self { steps: vec![], + initial_cycles_balance: clean_canister.system_state.balance(), canister: clean_canister.clone(), message_instruction_limit: original.execution_parameters.instruction_limits.message(), execution_parameters: original.execution_parameters.clone(), @@ -139,6 +151,7 @@ impl InstallCodeHelper { deallocated_bytes: NumBytes::new(0), deallocated_wasm_custom_sections_bytes: NumBytes::new(0), total_heap_delta: NumBytes::new(0), + executed_wasm_instructions: NumInstructions::new(0), } } @@ -233,16 +246,23 @@ impl InstallCodeHelper { /// Returns a struct with all the necessary information to replay the /// performed `install_code` steps in subsequent rounds. - pub fn pause(self) -> PausedInstallCodeHelper { + /// The given `executed_wasm_instructions` are the instructions executed by + /// the Wasm slice that is being paused. + pub fn pause(self, executed_wasm_instructions: NumInstructions) -> PausedInstallCodeHelper { PausedInstallCodeHelper { instructions_left: self.instructions_left(), steps: self.steps, + initial_cycles_balance: self.initial_cycles_balance, + executed_wasm_instructions: self.executed_wasm_instructions + + executed_wasm_instructions, } } /// Replays the previous `install_code` steps on the given clean canister. - /// Returns an error if any step fails. Otherwise, it returns an instance of - /// the helper that can be used to continue the `install_code` execution. + /// Returns an error if the cycles balance of the clean canister differs from + /// the cycles balance at the start of the DTS execution or if any step + /// fails. Otherwise, it returns an instance of the helper that can be used + /// to continue the `install_code` execution. #[allow(clippy::result_large_err)] pub fn resume( clean_canister: &CanisterState, @@ -259,12 +279,36 @@ impl InstallCodeHelper { > { let mut helper = Self::new(clean_canister, original); let paused_instructions_left = paused.instructions_left; + let executed_wasm_instructions = paused.executed_wasm_instructions; + // If resuming fails, then the instructions already executed by the paused + // Wasm execution are charged in addition to the instructions accounted + // for in `paused_instructions_left`: they have been executed and hence + // consumed round instructions, but the instruction limits of the helper + // are updated only when the Wasm execution finishes. + let instructions_left_on_error = NumInstructions::new( + paused_instructions_left + .get() + .saturating_sub(executed_wasm_instructions.get()), + ); + + // The cycles balance of the clean canister must not change during the + // DTS execution. + if helper.initial_cycles_balance != paused.initial_cycles_balance { + let msg = "Mismatch in cycles balance when resuming an install code".to_string(); + let err = HypervisorError::WasmEngineError(FailedToApplySystemChanges(msg)); + let err = (clean_canister.canister_id(), err).into(); + return Err((err, instructions_left_on_error, helper.take_canister_log())); + } + for state_change in paused.steps.into_iter() { helper .replay_step(state_change, original, round) - .map_err(|err| (err, paused_instructions_left, helper.take_canister_log()))?; + .map_err(|err| (err, instructions_left_on_error, helper.take_canister_log()))?; } debug_assert_eq!(paused_instructions_left, helper.instructions_left()); + // Replaying the steps of a Wasm execution that has already finished resets + // this counter, so it is restored after replaying all the steps. + helper.executed_wasm_instructions = executed_wasm_instructions; Ok(helper) } @@ -654,6 +698,9 @@ impl InstallCodeHelper { self.execution_parameters .instruction_limits .update(output.num_instructions_left); + // The instructions of all the slices of this Wasm execution are now + // reflected in the instruction limits above. + self.executed_wasm_instructions = NumInstructions::new(0); debug_assert!( output diff --git a/rs/execution_environment/src/execution/install_code/tests.rs b/rs/execution_environment/src/execution/install_code/tests.rs index 6d78ab13d4f0..a41b01ae641b 100644 --- a/rs/execution_environment/src/execution/install_code/tests.rs +++ b/rs/execution_environment/src/execution/install_code/tests.rs @@ -125,6 +125,62 @@ fn dts_resume_works_in_install_code() { assert_eq!(result, WasmResult::Reply(EmptyBlob.encode())); } +/// Analogously to `dts_resume_fails_due_to_cycles_decrease` for calls, +/// replicated queries, callbacks, and tasks, resuming a paused `install_code` +/// whose canister lost cycles while it was paused fails instead of replaying the +/// recorded steps on a balance that can no longer cover them. +#[test] +fn dts_install_code_resume_fails_due_to_cycles_decrease() { + const INSTRUCTION_LIMIT: u64 = 50_000_000; + let mut test = ExecutionTestBuilder::new() + .with_install_code_instruction_limit(INSTRUCTION_LIMIT) + .with_install_code_slice_instruction_limit(132_000) + .with_create_execution_state_base_cost(0) + .with_manual_execution() + .build(); + let canister_id = test.create_canister(Cycles::new(1_000_000_000_000_000)); + let payload = InstallCodeArgs { + mode: CanisterInstallMode::Install, + canister_id: canister_id.get(), + wasm_module: wat::parse_str(DTS_INSTALL_WAT).unwrap(), + arg: vec![], + sender_canister_version: None, + }; + let ingress_id = test.dts_install_code(payload); + + // The first slice has been executed and the execution is paused. + assert_eq!( + test.canister_state(canister_id).next_execution(), + NextExecution::ContinueInstallCode + ); + assert!(test.canister_state(canister_id).has_paused_install_code()); + + // Decrease the cycles balance of the clean canister. + test.canister_state_mut(canister_id) + .system_state + .remove_cycles(Cycles::new(1)); + + // The next slice detects the cycles balance mismatch and fails the execution. + test.execute_slice(canister_id); + assert_eq!( + test.canister_state(canister_id).next_execution(), + NextExecution::None + ); + + let err = check_ingress_status(test.ingress_status(&ingress_id)).unwrap_err(); + err.assert_contains( + ErrorCode::CanisterWasmEngineError, + &format!( + "Error from Canister {canister_id}: Canister encountered a Wasm engine error: \ + Failed to apply system changes: Mismatch in cycles \ + balance when resuming an install code" + ), + ); + + // The canister has no code installed. + assert!(test.canister_state(canister_id).execution_state.is_none()); +} + #[test] fn dts_abort_works_in_install_code() { const INSTRUCTION_LIMIT: u64 = 50_000_000; diff --git a/rs/execution_environment/src/execution/response.rs b/rs/execution_environment/src/execution/response.rs index 59ccfe6bc0da..b1eb249de445 100644 --- a/rs/execution_environment/src/execution/response.rs +++ b/rs/execution_environment/src/execution/response.rs @@ -114,6 +114,7 @@ struct PausedResponseHelper { refund_for_response_transmission: CompoundCycles, initial_cycles_balance: Cycles, response_sender: CanisterId, + executed_wasm_instructions: NumInstructions, } /// A helper that implements and keeps track of response execution steps. @@ -126,6 +127,12 @@ struct ResponseHelper { refund_for_response_transmission: CompoundCycles, initial_cycles_balance: Cycles, response_sender: CanisterId, + // Instructions already executed by a Wasm execution that has been paused and + // has not finished yet. Such instructions are not reflected in the + // instruction limits because those are updated only when the Wasm execution + // finishes, so they are tracked here in order to be charged if the execution + // fails before the Wasm execution finishes. + executed_wasm_instructions: NumInstructions, applied_subnet_memory_reservation: NumBytes, deallocation_sender: DeallocationSender, } @@ -193,6 +200,7 @@ impl ResponseHelper { refund_for_response_transmission, initial_cycles_balance, response_sender, + executed_wasm_instructions: NumInstructions::new(0), applied_subnet_memory_reservation: NumBytes::new(0), deallocation_sender: deallocation_sender.clone(), }; @@ -295,7 +303,13 @@ impl ResponseHelper { /// Returns a struct with all the necessary information to replay the /// initial steps in subsequent rounds. - fn pause(self, round_limits: &mut RoundLimits) -> PausedResponseHelper { + /// The given `executed_wasm_instructions` are the instructions executed by + /// the Wasm slice that is being paused. + fn pause( + self, + round_limits: &mut RoundLimits, + executed_wasm_instructions: NumInstructions, + ) -> PausedResponseHelper { self.revert_subnet_memory_reservation(round_limits); self.deallocation_sender.send(Box::new(self.canister)); PausedResponseHelper { @@ -305,9 +319,19 @@ impl ResponseHelper { refund_for_response_transmission: self.refund_for_response_transmission, initial_cycles_balance: self.initial_cycles_balance, response_sender: self.response_sender, + executed_wasm_instructions: self.executed_wasm_instructions + + executed_wasm_instructions, } } + /// Resets the instructions executed by a paused Wasm execution because a new + /// Wasm execution (the cleanup callback) is about to start and the + /// instructions of the previous one are already reflected in the instruction + /// limits of the new one. + fn start_new_wasm_execution(&mut self) { + self.executed_wasm_instructions = NumInstructions::new(0); + } + /// Replays validation and the initial steps on the given clean canister and /// returns the helper to continue the DTS execution. /// @@ -346,6 +370,7 @@ impl ResponseHelper { refund_for_response_transmission: paused.refund_for_response_transmission, initial_cycles_balance: clean_canister.system_state.balance(), response_sender: paused.response_sender, + executed_wasm_instructions: paused.executed_wasm_instructions, applied_subnet_memory_reservation: NumBytes::new(0), deallocation_sender: deallocation_sender.clone(), }; @@ -746,6 +771,11 @@ impl PausedExecution for PausedResponseExecution { // The height of the `clean_canister` state increases with every call of // `resume()`. We re-create the helper based on `clean_canister` so that // the Wasm state changes are applied to the up-to-date state. + // If resuming fails, then the instructions already executed by the paused + // Wasm execution are still charged: they have been executed and hence + // consumed round instructions, but the instruction limits are updated + // only when the Wasm execution finishes. + let executed_wasm_instructions = self.helper.executed_wasm_instructions; let (helper, result) = match ResponseHelper::resume( self.helper, &clean_canister, @@ -768,10 +798,14 @@ impl PausedExecution for PausedResponseExecution { err, ); self.paused_wasm_execution.abort(); - let result = wasm_execution_error( - err, - self.execution_parameters.instruction_limits.message(), + let instructions_left = NumInstructions::new( + self.execution_parameters + .instruction_limits + .message() + .get() + .saturating_sub(executed_wasm_instructions.get()), ); + let result = wasm_execution_error(err, instructions_left); (helper, result) } }; @@ -861,6 +895,11 @@ impl PausedExecution for PausedCleanupExecution { // // Note that we don't apply changes from the response callback execution // because the cleanup callback runs only if the response callback fails. + // If resuming fails, then the instructions already executed by the paused + // Wasm execution are still charged: they have been executed and hence + // consumed round instructions, but the instruction limits are updated + // only when the Wasm execution finishes. + let executed_wasm_instructions = self.helper.executed_wasm_instructions; let (helper, result) = match ResponseHelper::resume( self.helper, &clean_canister, @@ -883,10 +922,14 @@ impl PausedExecution for PausedCleanupExecution { err, ); self.paused_wasm_execution.abort(); - let result = wasm_execution_error( - err, - self.execution_parameters.instruction_limits.message(), + let instructions_left = NumInstructions::new( + self.execution_parameters + .instruction_limits + .message() + .get() + .saturating_sub(executed_wasm_instructions.get()), ); + let result = wasm_execution_error(err, instructions_left); (helper, result) } }; @@ -1091,7 +1134,7 @@ fn reserve_cleanup_instructions( #[allow(clippy::too_many_arguments)] fn execute_response_cleanup( clean_canister: CanisterState, - helper: ResponseHelper, + mut helper: ResponseHelper, cleanup_closure: WasmClosure, callback_err: HypervisorError, instructions_left: NumInstructions, @@ -1104,6 +1147,9 @@ fn execute_response_cleanup( execution_parameters .instruction_limits .update(instructions_left); + // The instructions executed by the response callback are reflected in the + // instruction limits updated above. + helper.start_new_wasm_execution(); let func_ref = match original.call_origin { CallOrigin::Ingress(..) | CallOrigin::CanisterUpdate(..) | CallOrigin::SystemTask => { FuncRef::UpdateClosure(cleanup_closure) @@ -1176,7 +1222,7 @@ fn process_response_result( update_round_limits(round_limits, &slice); let paused_execution = Box::new(PausedResponseExecution { paused_wasm_execution, - helper: helper.pause(round_limits), + helper: helper.pause(round_limits, slice.executed_instructions), execution_parameters, reserved_cleanup_instructions, original, @@ -1276,7 +1322,7 @@ fn process_cleanup_result( update_round_limits(round_limits, &slice); let paused_execution = Box::new(PausedCleanupExecution { paused_wasm_execution, - helper: helper.pause(round_limits), + helper: helper.pause(round_limits, slice.executed_instructions), execution_parameters, callback_err, original, diff --git a/rs/execution_environment/src/execution/upgrade.rs b/rs/execution_environment/src/execution/upgrade.rs index b84742d07dda..9c8139da21d5 100644 --- a/rs/execution_environment/src/execution/upgrade.rs +++ b/rs/execution_environment/src/execution/upgrade.rs @@ -193,7 +193,7 @@ pub(crate) fn execute_upgrade( ingress_status_with_processing_state(&original.message, original.time); let paused_execution = Box::new(PausedPreUpgradeExecution { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), context, original, }); @@ -393,7 +393,7 @@ fn upgrade_stage_2_and_3a_create_execution_state_and_call_start( ingress_status_with_processing_state(&original.message, original.time); let paused_execution = Box::new(PausedStartExecutionDuringUpgrade { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), context_sender, context_arg: context.arg, original, @@ -515,7 +515,7 @@ fn upgrade_stage_4a_call_post_upgrade( ingress_status_with_processing_state(&original.message, original.time); let paused_execution = Box::new(PausedPostUpgradeExecution { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), original, }); DtsInstallCodeResult::Paused { @@ -634,7 +634,7 @@ impl PausedInstallCodeExecution for PausedPreUpgradeExecution { update_round_limits(round_limits, &slice); let paused_execution = Box::new(PausedPreUpgradeExecution { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), ..*self }); DtsInstallCodeResult::Paused { @@ -746,7 +746,7 @@ impl PausedInstallCodeExecution for PausedStartExecutionDuringUpgrade { update_round_limits(round_limits, &slice); let paused_execution = Box::new(PausedStartExecutionDuringUpgrade { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), ..*self }); DtsInstallCodeResult::Paused { @@ -854,7 +854,7 @@ impl PausedInstallCodeExecution for PausedPostUpgradeExecution { update_round_limits(round_limits, &slice); let paused_execution = Box::new(PausedPostUpgradeExecution { paused_wasm_execution, - paused_helper: helper.pause(), + paused_helper: helper.pause(slice.executed_instructions), ..*self }); DtsInstallCodeResult::Paused { diff --git a/rs/execution_environment/src/execution_environment/tests.rs b/rs/execution_environment/src/execution_environment/tests.rs index 1b3abc0d8597..3cd04f23f751 100644 --- a/rs/execution_environment/src/execution_environment/tests.rs +++ b/rs/execution_environment/src/execution_environment/tests.rs @@ -17,8 +17,11 @@ use ic_management_canister_types_private::{ use ic_registry_routing_table::{CanisterIdRange, RoutingTable, canister_id_into_u64}; use ic_registry_subnet_type::SubnetType; use ic_replicated_state::{ - CanisterStatus, ReplicatedState, SystemState, - canister_state::{DEFAULT_QUEUE_CAPACITY, WASM_PAGE_SIZE_IN_BYTES}, + CanisterStatus, ExecutionTask, ReplicatedState, SystemState, + canister_state::{ + DEFAULT_QUEUE_CAPACITY, NextExecution, WASM_PAGE_SIZE_IN_BYTES, + execution_state::WasmExecutionMode, + }, metadata_state::subnet_call_context_manager::PreSignatureStash, metadata_state::testing::{NetworkTopologyTesting, SystemMetadataTesting}, testing::{CanisterQueuesTesting, SystemStateTesting}, @@ -31,7 +34,7 @@ use ic_test_utilities_execution_environment::{ }; use ic_test_utilities_metrics::{fetch_histogram_vec_count, metric_vec}; use ic_types::{ - CanisterId, CountBytes, PrincipalId, RegistryVersion, + CanisterId, CountBytes, NumInstructions, PrincipalId, RegistryVersion, canister_http::{CanisterHttpMethod, PricingVersion, Replication, Transform}, consensus::idkg::{IDkgMasterPublicKeyId, PreSigId}, ingress::{IngressState, IngressStatus, WasmResult}, @@ -42,7 +45,8 @@ use ic_types::{ time::UNIX_EPOCH, }; use ic_types_cycles::{ - CanisterCyclesCostSchedule, Cycles, CyclesUseCase, NominalCycles, NominalCyclesTesting, + CanisterCyclesCostSchedule, CompoundCycles, Cycles, CyclesUseCase, Instructions, NominalCycles, + NominalCyclesTesting, }; use ic_types_test_utils::ids::{canister_test_id, node_test_id, subnet_test_id, user_test_id}; use ic_universal_canister::{CallArgs, UNIVERSAL_CANISTER_WASM, call_args, wasm}; @@ -6002,3 +6006,256 @@ fn list_canisters_via_ingress_fails_at_execution() { .contains("list_canisters cannot be called by a user") ); } + +/// Snapshot of the cycles and instruction counters of a canister that are needed +/// to check the accounting of a paused execution that fails to resume. +#[derive(Clone, Copy)] +struct ExecutionAccounting { + consumed_cycles: NominalCycles, + execution_cost: CompoundCycles, + round_instructions: NumInstructions, + executed_instructions: NumInstructions, +} + +impl ExecutionAccounting { + fn take(test: &ExecutionTest, canister_id: CanisterId) -> Self { + Self { + consumed_cycles: test + .canister_state(canister_id) + .system_state + .canister_metrics() + .consumed_cycles_by_use_cases() + .get(&CyclesUseCase::Instructions) + .cloned() + .unwrap_or_default(), + execution_cost: test.canister_execution_cost(canister_id), + round_instructions: test.round_instructions(canister_id), + executed_instructions: test.executed_instructions(), + } + } +} + +/// Decreases the cycles balance of the given canister, which must have a paused +/// execution, and resumes that execution, which must fail. +/// +/// Asserts that the failed execution is charged for exactly the instructions it +/// had already executed: the instructions it reports as used match the round +/// instructions consumed by its slices, and the cycles charged to the canister +/// match the cost of exactly those instructions. +/// +/// `before_execution` must be taken right before the first slice of the paused +/// execution. `before_message` must be taken before the execution cycles were +/// prepaid, which happens when the message execution starts, except for a +/// response callback, whose execution is prepaid already when the caller +/// performs the call; the two snapshots coincide in the former case. +fn resume_paused_execution_after_cycles_decrease( + test: &mut ExecutionTest, + canister_id: CanisterId, + before_message: ExecutionAccounting, + before_execution: ExecutionAccounting, +) { + assert_eq!( + test.canister_state(canister_id).next_execution(), + NextExecution::ContinueLong, + ); + + test.canister_state_mut(canister_id) + .system_state + .remove_cycles(Cycles::new(1)); + + test.execute_slice(canister_id); + assert_eq!( + test.canister_state(canister_id).next_execution(), + NextExecution::None, + ); + + let after = ExecutionAccounting::take(test, canister_id); + + // The failed execution reports exactly the instructions consumed by its + // slices: resuming failed before resuming the Wasm execution, so no further + // instructions were consumed after the last pause. + let executed_instructions = + after.executed_instructions - before_execution.executed_instructions; + assert_eq!( + executed_instructions, + after.round_instructions - before_execution.round_instructions + ); + + // The canister is charged exactly the cost of those instructions. + let expected_cost = test + .cycles_account_manager() + .execution_cost( + executed_instructions, + test.get_own_subnet_cycles_config(), + WasmExecutionMode::Wasm32, + ) + .nominal(); + assert_eq!( + (after.execution_cost - before_execution.execution_cost).nominal(), + expected_cost + ); + assert_eq!( + after.consumed_cycles - before_message.consumed_cycles, + (after.execution_cost - before_message.execution_cost).nominal() + ); +} + +/// Every kind of paused execution re-creates its helper from the current clean +/// canister state when it is resumed, so it relies on the cycles balance of that +/// state not changing while the execution is paused. This test covers all of +/// them: update calls, replicated queries, response callbacks, cleanup +/// callbacks, and canister tasks (heartbeat). The `install_code` case is covered +/// by `dts_install_code_resume_fails_due_to_cycles_decrease`. +#[test] +fn dts_resume_fails_due_to_cycles_decrease() { + // 1. Update calls and replicated queries. + for method in ["update", "query"] { + let mut test = ExecutionTestBuilder::new() + .with_instruction_limit(1_000_000) + .with_slice_instruction_limit(200_000) + .with_manual_execution() + .build(); + + let a_id = test.universal_canister().unwrap(); + + let a = wasm() + .instruction_counter_is_at_least(200_000) + .message_payload() + .append_and_reply() + .build(); + + let (ingress_id, _) = test.ingress_raw(a_id, method, a); + + let before = ExecutionAccounting::take(&test, a_id); + test.execute_slice(a_id); + resume_paused_execution_after_cycles_decrease(&mut test, a_id, before, before); + + let err = check_ingress_status(test.ingress_status(&ingress_id)).unwrap_err(); + let message = if method == "update" { + "an update call" + } else { + "a replicated query" + }; + err.assert_contains( + ErrorCode::CanisterWasmEngineError, + &format!( + "Error from Canister {a_id}: Canister encountered a Wasm engine error: \ + Failed to apply system changes: Mismatch in cycles \ + balance when resuming {message}" + ), + ); + } + + // 2. Response and cleanup callbacks. The response callback traps in the + // cleanup case, so that the long-running callback is the cleanup one. + for cleanup in [false, true] { + let mut test = ExecutionTestBuilder::new() + .with_instruction_limit(100_000_000) + .with_slice_instruction_limit(1_000_000) + .with_manual_execution() + .build(); + + let a_id = test.universal_canister().unwrap(); + let b_id = test.universal_canister().unwrap(); + + let b = wasm().message_payload().append_and_reply().build(); + + let long_execution = wasm() + .instruction_counter_is_at_least(1_000_000) + .message_payload() + .append_and_reply() + .build(); + let call_args = if cleanup { + call_args() + .other_side(b) + .on_reply(wasm().trap()) + .on_cleanup(long_execution) + } else { + call_args().other_side(b).on_reply(long_execution) + }; + let a = wasm().call_simple(b_id, "update", call_args).build(); + + let (ingress_id, _) = test.ingress_raw(a_id, "update", a); + + // The execution of the response callback is prepaid when canister A + // performs the call, so the snapshots are taken before that. + let before_message = ExecutionAccounting::take(&test, a_id); + + // Canister A calls canister B, which replies. + test.execute_message(a_id); + test.induct_messages(); + test.execute_message(b_id); + test.induct_messages(); + + // Start executing the response|cleanup callback. + let before_execution = ExecutionAccounting::take(&test, a_id); + test.execute_slice(a_id); + resume_paused_execution_after_cycles_decrease( + &mut test, + a_id, + before_message, + before_execution, + ); + + let err = check_ingress_status(test.ingress_status(&ingress_id)).unwrap_err(); + let code = if cleanup { + // The error of the trapping response callback takes precedence. + ErrorCode::CanisterCalledTrap + } else { + ErrorCode::CanisterWasmEngineError + }; + assert_eq!(err.code(), code); + assert!( + err.description().contains( + "Failed to apply system changes: Mismatch in cycles \ + balance when resuming a response call" + ), + "unexpected error: {err}" + ); + } + + // 3. Canister tasks, e.g. the heartbeat. + { + let mut test = ExecutionTestBuilder::new() + .with_instruction_limit(100_000_000) + .with_slice_instruction_limit(1_000_000) + .with_manual_execution() + .build(); + + let canister_id = test.universal_canister().unwrap(); + let (ingress_id, _) = test.ingress_raw( + canister_id, + "update", + wasm() + .set_heartbeat( + wasm() + .instruction_counter_is_at_least(1_000_000) + .stable_grow(1) + .build(), + ) + .reply() + .build(), + ); + test.execute_message(canister_id); + check_ingress_status(test.ingress_status(&ingress_id)).unwrap(); + let stable_memory_size = test.execution_state(canister_id).stable_memory.size; + + test.canister_state_mut(canister_id) + .system_state + .task_queue + .enqueue(ExecutionTask::Heartbeat); + + // Start executing the heartbeat. + let before = ExecutionAccounting::take(&test, canister_id); + test.execute_slice(canister_id); + resume_paused_execution_after_cycles_decrease(&mut test, canister_id, before, before); + + // A canister task has no ingress status and the failure is not recorded + // in the canister log, but the state changes of the heartbeat must have + // been dropped along with the failed execution. + assert_eq!( + test.execution_state(canister_id).stable_memory.size, + stable_memory_size + ); + } +} diff --git a/rs/test_utilities/execution_environment/src/lib.rs b/rs/test_utilities/execution_environment/src/lib.rs index 4fffd9477e91..d9d74095462d 100644 --- a/rs/test_utilities/execution_environment/src/lib.rs +++ b/rs/test_utilities/execution_environment/src/lib.rs @@ -292,6 +292,11 @@ pub struct ExecutionTest { subnet_available_callbacks: i64, // The number of instructions executed so far per canister. executed_instructions: HashMap, + // The number of round instructions consumed so far by executing slices of + // canister messages and tasks per canister. Unlike `executed_instructions`, + // this is accumulated for every executed slice and thus also accounts for + // slices of executions that were paused and did not finish (yet). + round_instructions: HashMap, // The total cost of execution so far per canister. execution_cost: HashMap>, // Tracks paused subnet message executions per canister. @@ -444,6 +449,16 @@ impl ExecutionTest { self.executed_instructions.values().sum() } + /// Returns the number of round instructions consumed so far by executing + /// slices of canister messages and tasks of the given canister, including + /// slices of executions that did not finish. + pub fn round_instructions(&self, canister_id: CanisterId) -> NumInstructions { + self.round_instructions + .get(&canister_id) + .copied() + .unwrap_or_else(|| NumInstructions::new(0)) + } + pub fn ingress_memory_capacity(&self) -> NumBytes { self.ingress_memory_capacity } @@ -1960,6 +1975,7 @@ impl ExecutionTest { compute_allocation_used, subnet_memory_reservation: self.subnet_memory_reservation, }; + let remaining_round_instructions_before = round_limits.instructions; let result = execute_canister( &self.exec_env, canister, @@ -1972,6 +1988,13 @@ impl ExecutionTest { state.get_own_subnet_cycles_config(), ); state.metadata.heap_delta_estimate += result.heap_delta; + let slice_instructions_used = + remaining_round_instructions_before - round_limits.instructions; + *self + .round_instructions + .entry(canister_id) + .or_insert_with(|| NumInstructions::new(0)) += + NumInstructions::from(slice_instructions_used.get() as u64); self.subnet_available_memory = round_limits.subnet_available_memory; self.subnet_available_callbacks = round_limits.subnet_available_callbacks; if let Some(instructions_used) = result.instructions_used { @@ -3088,6 +3111,7 @@ impl ExecutionTestBuilder { state: Some(state), message_id: 0, executed_instructions: HashMap::new(), + round_instructions: HashMap::new(), execution_cost: HashMap::new(), paused_subnet_messages: HashMap::new(), xnet_messages: vec![],