Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

chore: do not use time of next round in tests #2455

Merged
merged 2 commits into from
Nov 7, 2024
+136 −81
Merged

chore: do not use time of next round in tests #2455

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
0cb8e03
chore: do not use time of next round in tests
mraszyk Nov 6, 2024
245658b
drop StateMachine::get_time_of_next_round
mraszyk Nov 6, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 4 additions & 4 deletions rs/ethereum/cketh/minter/tests/cketh.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,7 @@ use icrc_ledger_types::icrc3::transactions::{Burn, Mint};
use num_traits::cast::ToPrimitive;
use serde_json::json;
use std::str::FromStr;
use std::time::Duration;

#[test]
fn should_deposit_and_withdraw() {
Expand Down Expand Up @@ -436,10 +437,9 @@ fn should_reimburse() {
let balance_before_withdrawal = cketh.balance_of(caller);
assert_eq!(balance_before_withdrawal, withdrawal_amount);

let time_at_withdrawal = cketh
.env
.get_time_of_next_round()
.as_nanos_since_unix_epoch();
// advance time so that time does not grow implicitly when executing a round
cketh.env.advance_time(Duration::from_secs(1));
let time_at_withdrawal = cketh.env.get_time().as_nanos_since_unix_epoch();

let cketh = cketh
.call_minter_withdraw_eth(caller, withdrawal_amount.clone(), destination.clone())
Expand Down
16 changes: 6 additions & 10 deletions rs/execution_environment/src/execution_environment/tests/canister_task.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -226,12 +226,10 @@ fn global_timer_can_be_cancelled() {
.install_canister(UNIVERSAL_CANISTER_WASM.to_vec(), vec![], None)
.unwrap();

// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
// Setup global timer to increase a global counter
let now_nanos = env
.time_of_next_round()
.duration_since(UNIX_EPOCH)
.unwrap()
.as_nanos() as u64;
let now_nanos = env.time().duration_since(UNIX_EPOCH).unwrap().as_nanos() as u64;
let set_global_timer = wasm()
.set_global_timer_method(wasm().inc_global_counter())
.api_global_timer_set(now_nanos + 3) // set the deadline in three rounds from now
Expand Down Expand Up @@ -309,12 +307,10 @@ fn global_timer_is_one_off() {
.install_canister(UNIVERSAL_CANISTER_WASM.to_vec(), vec![], None)
.unwrap();

// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
// Setup global timer to increase a global counter
let now_nanos = env
.time_of_next_round()
.duration_since(UNIX_EPOCH)
.unwrap()
.as_nanos() as u64;
let now_nanos = env.time().duration_since(UNIX_EPOCH).unwrap().as_nanos() as u64;
let set_global_timer = wasm()
.set_global_timer_method(wasm().inc_global_counter())
.api_global_timer_set(now_nanos + 2) // set the deadline in two rounds from now
Expand Down
96 changes: 62 additions & 34 deletions rs/execution_environment/tests/canister_logging.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -317,7 +317,9 @@ fn test_appending_logs_in_replied_update_call(#[strategy("\\PC*")] message: Stri
.update("test", wat_fn().debug_print(message.as_bytes()))
.build_wasm(),
);
let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand All @@ -334,7 +336,9 @@ fn test_appending_logs_in_trapped_update_call(#[strategy("\\PC*")] message: Stri
.update("test", wat_fn().debug_print(message.as_bytes()).trap())
.build_wasm(),
);
let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand All @@ -354,7 +358,9 @@ fn test_appending_logs_in_replied_replicated_query_call(#[strategy("\\PC*")] mes
.query("test", wat_fn().debug_print(message.as_bytes()))
.build_wasm(),
);
let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand All @@ -371,7 +377,9 @@ fn test_appending_logs_in_trapped_replicated_query_call(#[strategy("\\PC*")] mes
.query("test", wat_fn().debug_print(message.as_bytes()).trap())
.build_wasm(),
);
let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand Down Expand Up @@ -400,13 +408,15 @@ fn test_canister_log_record_index_increment_for_different_calls() {
.build_wasm(),
);

// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
// First call.
let timestamp_01 = system_time_to_nanos(env.time_of_next_round());
let timestamp_01 = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test1", vec![]);

// Second call.
env.advance_time(Duration::from_nanos(123_456));
let timestamp_23 = system_time_to_nanos(env.time_of_next_round());
let timestamp_23 = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test2", vec![]);

let result = fetch_canister_logs(&env, controller, canister_id);
Expand Down Expand Up @@ -439,16 +449,18 @@ fn test_canister_log_record_index_increment_after_node_restart() {
);
env.set_checkpoints_enabled(true);

// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
// First call.
let timestamp_01 = system_time_to_nanos(env.time_of_next_round());
let timestamp_01 = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test1", vec![]);

// Node restart.
let env = restart_node(env);
env.advance_time(Duration::from_nanos(123_456));

// Second call.
let timestamp_23 = system_time_to_nanos(env.time_of_next_round());
let timestamp_23 = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test2", vec![]);

let result = fetch_canister_logs(&env, controller, canister_id);
Expand All @@ -470,8 +482,10 @@ fn test_logging_in_trapped_wasm_execution() {
.update("test", wat_fn().stable_grow(1).stable_read(0, 70_000))
.build_wasm(),
);
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
// Grow stable memory by 1 page (64kb), reading outside of the page should trap.
let timestamp = system_time_to_nanos(env.time_of_next_round());
let timestamp = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand All @@ -488,7 +502,9 @@ fn test_logging_in_trapped_wasm_execution() {
fn test_logging_explicit_canister_trap_without_message() {
let (env, canister_id, controller) =
setup_with_controller(wat_canister().update("test", wat_fn().trap()).build_wasm());
let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand All @@ -504,7 +520,9 @@ fn test_logging_explicit_canister_trap_with_message() {
.update("test", wat_fn().trap_with_blob(b"some text"))
.build_wasm(),
);
let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand Down Expand Up @@ -626,7 +644,7 @@ fn test_deleting_logs_on_reinstall() {
env.advance_time(TIME_STEP);

// Prepopulate log.
let timestamp_1_update = system_time_to_nanos(env.time_of_next_round());
let timestamp_1_update = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test_1", vec![]);
env.advance_time(TIME_STEP);

Expand Down Expand Up @@ -656,7 +674,7 @@ fn test_deleting_logs_on_reinstall() {
env.advance_time(TIME_STEP);

// Populate log after reinstall.
let timestamp_2_update = system_time_to_nanos(env.time_of_next_round());
let timestamp_2_update = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test_2", vec![]);
env.advance_time(TIME_STEP);

Expand All @@ -682,7 +700,7 @@ fn test_deleting_logs_on_uninstall() {
env.advance_time(TIME_STEP);

// Prepopulate log.
let timestamp_1_update = system_time_to_nanos(env.time_of_next_round());
let timestamp_1_update = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test_1", vec![]);
env.advance_time(TIME_STEP);

Expand Down Expand Up @@ -732,12 +750,12 @@ fn test_logging_debug_print_persists_over_upgrade() {
env.advance_time(TIME_STEP);

// Pre-populate log.
let timestamp_before_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_before_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

// Upgrade canister.
let timestamp_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_upgrade = system_time_to_nanos(env.time());
let _ = env.upgrade_canister(
canister_id,
wat_canister()
Expand All @@ -751,7 +769,7 @@ fn test_logging_debug_print_persists_over_upgrade() {
);
env.advance_time(TIME_STEP);

let timestamp_after_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_after_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

Expand Down Expand Up @@ -781,7 +799,7 @@ fn test_logging_trap_at_install_start() {
env.advance_time(TIME_STEP);

// Install canister with a trap in the start function.
let timestamp_install = system_time_to_nanos(env.time_of_next_round());
let timestamp_install = system_time_to_nanos(env.time());
let result = env.install_wasm_in_mode(
canister_id,
CanisterInstallMode::Install,
Expand Down Expand Up @@ -814,7 +832,7 @@ fn test_logging_trap_at_install_init() {
env.advance_time(TIME_STEP);

// Install canister with a trap in the init function.
let timestamp_install = system_time_to_nanos(env.time_of_next_round());
let timestamp_install = system_time_to_nanos(env.time());
let result = env.install_wasm_in_mode(
canister_id,
CanisterInstallMode::Install,
Expand Down Expand Up @@ -857,12 +875,12 @@ fn test_logging_trap_in_pre_upgrade() {
env.advance_time(TIME_STEP);

// Pre-populate log.
let timestamp_before_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_before_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

// Upgrade canister.
let timestamp_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_upgrade = system_time_to_nanos(env.time());
let result = env.upgrade_canister(
canister_id,
wat_canister()
Expand All @@ -879,7 +897,7 @@ fn test_logging_trap_in_pre_upgrade() {
env.advance_time(TIME_STEP);

// Populate log after failed upgrade.
let timestamp_after_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_after_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

Expand Down Expand Up @@ -914,12 +932,12 @@ fn test_logging_trap_after_upgrade_in_start() {
env.advance_time(TIME_STEP);

// Pre-populate log.
let timestamp_before_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_before_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

// Upgrade canister.
let timestamp_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_upgrade = system_time_to_nanos(env.time());
let result = env.upgrade_canister(
canister_id,
wat_canister()
Expand All @@ -936,7 +954,7 @@ fn test_logging_trap_after_upgrade_in_start() {
env.advance_time(TIME_STEP);

// Populate log after failed upgrade.
let timestamp_after_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_after_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

Expand Down Expand Up @@ -972,12 +990,12 @@ fn test_logging_trap_after_upgrade_in_post_upgrade() {
env.advance_time(TIME_STEP);

// Pre-populate log.
let timestamp_before_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_before_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

// Upgrade canister.
let timestamp_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_upgrade = system_time_to_nanos(env.time());
let result = env.upgrade_canister(
canister_id,
wat_canister()
Expand All @@ -998,7 +1016,7 @@ fn test_logging_trap_after_upgrade_in_post_upgrade() {
env.advance_time(TIME_STEP);

// Populate log after failed upgrade.
let timestamp_after_upgrade = system_time_to_nanos(env.time_of_next_round());
let timestamp_after_upgrade = system_time_to_nanos(env.time());
let _ = env.execute_ingress(canister_id, "test", vec![]);
env.advance_time(TIME_STEP);

Expand Down Expand Up @@ -1042,7 +1060,9 @@ fn test_logging_debug_print_over_dts() {
.build_wasm(),
);

let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
// Slice #0 is processed inside `send_ingress` in round #0.
let _msg_id = env.send_ingress(PrincipalId::new_anonymous(), canister_id, "test", vec![]);
// Since one slice was processed in `send_ingress` iterate over one slice less.
Expand Down Expand Up @@ -1093,7 +1113,9 @@ fn test_logging_trap_over_dts() {
.build_wasm(),
);

let timestamp = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp = system_time_to_nanos(env.time());
// Slice #0 is processed inside `send_ingress` in round #0.
let _msg_id = env.send_ingress(PrincipalId::new_anonymous(), canister_id, "test", vec![]);
// Since one slice was processed in `send_ingress` iterate over one slice less.
Expand Down Expand Up @@ -1186,8 +1208,10 @@ fn test_logging_of_long_running_dts_over_checkpoint() {
canister_log_response(vec![])
);

// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
// Rounds #B0 and further: Afther the checkpoint process the message again through all the slices.
let timestamp_after_checkpoint = system_time_to_nanos(env.time_of_next_round());
let timestamp_after_checkpoint = system_time_to_nanos(env.time());
for i in 0..number_of_slices {
let result = fetch_canister_logs(&env, controller, canister_id);
assert_eq!(
Expand All @@ -1200,7 +1224,7 @@ fn test_logging_of_long_running_dts_over_checkpoint() {
env.advance_time(TIME_STEP);
}
// Round to process short message.
let timestamp_short = system_time_to_nanos(env.time_of_next_round());
let timestamp_short = system_time_to_nanos(env.time());
env.tick();
env.advance_time(TIME_STEP);

Expand Down Expand Up @@ -1248,7 +1272,9 @@ fn test_canister_log_on_reply() {
let (env, canister_id, controller) = setup_with_controller(UNIVERSAL_CANISTER_WASM.to_vec());

let instructions_per_slice = MAX_INSTRUCTIONS_PER_SLICE.get();
let timestamp_init = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp_init = system_time_to_nanos(env.time());
let _ = env.execute_ingress(
canister_id,
"update",
Expand Down Expand Up @@ -1302,7 +1328,9 @@ fn test_canister_log_on_cleanup() {
// Test that the log is recorded inside cleanup callback.
let (env, canister_id, controller) = setup_with_controller(UNIVERSAL_CANISTER_WASM.to_vec());

let timestamp_init = system_time_to_nanos(env.time_of_next_round());
// advance time so that time does not grow implicitly when executing a round
env.advance_time(Duration::from_secs(1));
let timestamp_init = system_time_to_nanos(env.time());
let instructions_per_slice = MAX_INSTRUCTIONS_PER_SLICE.get();
let _ = env.execute_ingress(
canister_id,
Expand Down
Loading
Loading