diff --git a/.github/workflows/bitcoin-tests.yml b/.github/workflows/bitcoin-tests.yml index 04e74f94e8..fd2d5606a2 100644 --- a/.github/workflows/bitcoin-tests.yml +++ b/.github/workflows/bitcoin-tests.yml @@ -122,6 +122,8 @@ jobs: - tests::signer::v0::signer_set_rollover - tests::signer::v0::signing_in_0th_tenure_of_reward_cycle - tests::signer::v0::continue_after_tenure_extend + - tests::signer::v0::tenure_extend_after_idle + - tests::signer::v0::stx_transfers_dont_effect_idle_timeout - tests::signer::v0::multiple_miners_with_custom_chain_id - tests::signer::v0::block_commit_delay - tests::signer::v0::continue_after_fast_block_no_sortition diff --git a/stackslib/src/net/api/postblock_proposal.rs b/stackslib/src/net/api/postblock_proposal.rs index 5648c578b3..b2abc56dd6 100644 --- a/stackslib/src/net/api/postblock_proposal.rs +++ b/stackslib/src/net/api/postblock_proposal.rs @@ -16,6 +16,8 @@ use std::io::{Read, Write}; use std::thread::{self, JoinHandle, Thread}; +#[cfg(any(test, feature = "testing"))] +use std::time::Duration; use clarity::vm::ast::ASTRules; use clarity::vm::costs::ExecutionCost; @@ -65,6 +67,10 @@ use crate::util_lib::db::Error as DBError; #[cfg(any(test, feature = "testing"))] pub static TEST_VALIDATE_STALL: std::sync::Mutex> = std::sync::Mutex::new(None); +#[cfg(any(test, feature = "testing"))] +/// Artificial delay to add to block validation. +pub static TEST_VALIDATE_DELAY_DURATION_SECS: std::sync::Mutex> = + std::sync::Mutex::new(None); // This enum is used to supply a `reason_code` for validation // rejection responses. This is serialized as an enum with string @@ -364,6 +370,14 @@ impl NakamotoBlockProposal { .unwrap_or(u64::MAX) }; + #[cfg(any(test, feature = "testing"))] + { + if let Some(delay) = *TEST_VALIDATE_DELAY_DURATION_SECS.lock().unwrap() { + warn!("Sleeping for {} seconds to simulate slow processing", delay); + thread::sleep(Duration::from_secs(delay)); + } + } + let mainnet = self.chain_id == CHAIN_ID_MAINNET; if self.chain_id != chainstate.chain_id || mainnet != chainstate.mainnet { warn!( diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index 0051902852..b27cd1c1fa 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -39,11 +39,13 @@ use stacks::codec::StacksMessageCodec; use stacks::core::{StacksEpochId, CHAIN_ID_TESTNET}; use stacks::libstackerdb::StackerDBChunkData; use stacks::net::api::getsigner::GetSignerResponse; -use stacks::net::api::postblock_proposal::{ValidateRejectCode, TEST_VALIDATE_STALL}; +use stacks::net::api::postblock_proposal::{ + ValidateRejectCode, TEST_VALIDATE_DELAY_DURATION_SECS, TEST_VALIDATE_STALL, +}; use stacks::net::relay::fault_injection::set_ignore_block; use stacks::types::chainstate::{StacksAddress, StacksBlockId, StacksPrivateKey, StacksPublicKey}; use stacks::types::PublicKey; -use stacks::util::hash::{hex_bytes, Hash160, MerkleHashFunc}; +use stacks::util::hash::{hex_bytes, Hash160, MerkleHashFunc, Sha512Trunc256Sum}; use stacks::util::secp256k1::{Secp256k1PrivateKey, Secp256k1PublicKey}; use stacks::util_lib::boot::boot_code_id; use stacks::util_lib::signed_structured_data::pox4::{ @@ -2562,6 +2564,255 @@ fn signers_broadcast_signed_blocks() { signer_test.shutdown(); } +#[test] +#[ignore] +/// This test verifies that a miner will produce a TenureExtend transaction after the idle timeout is reached. +fn tenure_extend_after_idle() { + if env::var("BITCOIND_TEST") != Ok("1".into()) { + return; + } + + tracing_subscriber::registry() + .with(fmt::layer()) + .with(EnvFilter::from_default_env()) + .init(); + + info!("------------------------- Test Setup -------------------------"); + let num_signers = 5; + let sender_sk = Secp256k1PrivateKey::new(); + let sender_addr = tests::to_addr(&sender_sk); + let send_amt = 100; + let send_fee = 180; + let _recipient = PrincipalData::from(StacksAddress::burn_address(false)); + let idle_timeout = Duration::from_secs(30); + let mut signer_test: SignerTest = SignerTest::new_with_config_modifications( + num_signers, + vec![(sender_addr, send_amt + send_fee)], + |config| { + // make the duration long enough that the miner will be marked as malicious + config.tenure_idle_timeout = idle_timeout; + }, + |_| {}, + None, + None, + ); + let _http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind); + + signer_test.boot_to_epoch_3(); + + info!("---- Nakamoto booted, starting test ----"); + let info_before = get_chain_info(&signer_test.running_nodes.conf); + let blocks_before = signer_test + .running_nodes + .nakamoto_blocks_mined + .load(Ordering::SeqCst); + signer_test.mine_nakamoto_block(Duration::from_secs(30)); + + // Verify that the block was mined + wait_for(30, || { + let blocks_mined = signer_test + .running_nodes + .nakamoto_blocks_mined + .load(Ordering::SeqCst); + let info = get_chain_info(&signer_test.running_nodes.conf); + Ok(blocks_mined > blocks_before && info.stacks_tip_height > info_before.stacks_tip_height) + }) + .expect("Timed out waiting for first nakamoto block to be mined"); + + info!("---- Waiting for a tenure extend ----"); + + // Now, wait for a block with a tenure extend + wait_for(idle_timeout.as_secs() + 10, || { + Ok(last_block_contains_tenure_change_tx( + TenureChangeCause::Extended, + )) + }) + .expect("Timed out waiting for a block with a tenure extend"); + + signer_test.shutdown(); +} + +#[test] +#[ignore] +/// Verify that Nakamoto blocks that don't modify the tenure's execution cost +/// don't modify the idle timeout. +fn stx_transfers_dont_effect_idle_timeout() { + if env::var("BITCOIND_TEST") != Ok("1".into()) { + return; + } + + tracing_subscriber::registry() + .with(fmt::layer()) + .with(EnvFilter::from_default_env()) + .init(); + + info!("------------------------- Test Setup -------------------------"); + let num_signers = 5; + let sender_sk = Secp256k1PrivateKey::new(); + let sender_addr = tests::to_addr(&sender_sk); + let send_amt = 100; + let send_fee = 180; + let num_txs = 5; + let recipient = PrincipalData::from(StacksAddress::burn_address(false)); + let idle_timeout = Duration::from_secs(60); + let mut signer_test: SignerTest = SignerTest::new_with_config_modifications( + num_signers, + vec![(sender_addr, (send_amt + send_fee) * num_txs)], + |config| { + // make the duration long enough that the miner will be marked as malicious + config.tenure_idle_timeout = idle_timeout; + }, + |_| {}, + None, + None, + ); + let naka_conf = signer_test.running_nodes.conf.clone(); + let http_origin = format!("http://{}", &naka_conf.node.rpc_bind); + + signer_test.boot_to_epoch_3(); + + // Add a delay to the block validation process + TEST_VALIDATE_DELAY_DURATION_SECS.lock().unwrap().replace(5); + + let info_before = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info"); + let blocks_before = signer_test + .running_nodes + .nakamoto_blocks_mined + .load(Ordering::SeqCst); + info!("---- Nakamoto booted, starting test ----"; + "info_height" => info_before.stacks_tip_height, + "blocks_before" => blocks_before, + ); + signer_test.mine_nakamoto_block(Duration::from_secs(30)); + + info!("---- Verifying that the block was mined ----"); + // Verify that the block was mined + wait_for(30, || { + let blocks_mined = signer_test + .running_nodes + .nakamoto_blocks_mined + .load(Ordering::SeqCst); + let info = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info"); + Ok(blocks_mined > blocks_before && info.stacks_tip_height > info_before.stacks_tip_height) + }) + .expect("Timed out waiting for first nakamoto block to be mined"); + + info!("---- Getting current idle timeout ----"); + + let reward_cycle = signer_test.get_current_reward_cycle(); + + let signer_slot_ids: Vec<_> = signer_test + .get_signer_indices(reward_cycle) + .iter() + .map(|id| id.0) + .collect(); + assert_eq!(signer_slot_ids.len(), num_signers); + + let get_last_block_hash = || { + let blocks = test_observer::get_blocks(); + let last_block = blocks.last().unwrap(); + let block_hash = + hex_bytes(&last_block.get("block_hash").unwrap().as_str().unwrap()[2..]).unwrap(); + Sha512Trunc256Sum::from_vec(&block_hash).unwrap() + }; + + let last_block_hash = get_last_block_hash(); + + let slot_id = 0_u32; + + let get_last_block_response = |slot_id: u32| { + let mut stackerdb = StackerDB::new( + &naka_conf.node.rpc_bind, + StacksPrivateKey::new(), // We are just reading so don't care what the key is + false, + reward_cycle, + SignerSlotID(0), // We are just reading so again, don't care about index. + ); + let latest_msgs = StackerDB::get_messages( + stackerdb + .get_session_mut(&MessageSlotID::BlockResponse) + .expect("Failed to get BlockResponse stackerdb session"), + &[slot_id], + ) + .expect("Failed to get message from stackerdb"); + let latest_msg = latest_msgs.last().unwrap(); + let SignerMessage::BlockResponse(BlockResponse::Accepted(accepted)) = latest_msg else { + panic!("Latest message from slot #{slot_id} isn't a block acceptance"); + }; + accepted.clone() + }; + + let initial_acceptance = get_last_block_response(slot_id); + assert_eq!(initial_acceptance.signer_signature_hash, last_block_hash); + + info!( + "---- Last idle timeout: {} ----", + initial_acceptance.response_data.tenure_extend_timestamp + ); + + // Now, mine a few nakamoto blocks with just transfers + + let mut sender_nonce = 0; + + // Note that this response was BEFORE the block was globally accepted. it will report a guestimated idle time + let initial_acceptance = initial_acceptance; + let mut first_global_acceptance = None; + for i in 0..num_txs { + info!("---- Mining interim block {} ----", i + 1); + let transfer_tx = make_stacks_transfer( + &sender_sk, + sender_nonce, + send_fee, + naka_conf.burnchain.chain_id, + &recipient, + send_amt, + ); + submit_tx(&http_origin, &transfer_tx); + sender_nonce += 1; + let info_before = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info"); + wait_for(30, || { + let info = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info"); + Ok(info.stacks_tip_height > info_before.stacks_tip_height) + }) + .expect("Timed out waiting for nakamoto block to be mined"); + + let latest_acceptance = get_last_block_response(slot_id); + let last_block_hash = get_last_block_hash(); + + assert_eq!(latest_acceptance.signer_signature_hash, last_block_hash); + + if first_global_acceptance.is_none() { + assert!(latest_acceptance.response_data.tenure_extend_timestamp < initial_acceptance.response_data.tenure_extend_timestamp, "First global acceptance should be less than initial guesstimated acceptance as its based on block proposal time rather than epoch time at time of response."); + first_global_acceptance = Some(latest_acceptance); + } else { + // Because the block only contains transfers, the idle timeout should not have changed between blocks post the tenure change + assert_eq!( + latest_acceptance.response_data.tenure_extend_timestamp, + first_global_acceptance + .as_ref() + .map(|acceptance| acceptance.response_data.tenure_extend_timestamp) + .unwrap() + ); + }; + } + + info!("---- Waiting for a tenure extend ----"); + + signer_test.shutdown(); +} + #[test] #[ignore] /// This test checks the behaviour of signers when a sortition is empty. Specifically: