diff --git a/.github/workflows/bitcoin-tests.yml b/.github/workflows/bitcoin-tests.yml index 21ad473af8..9ae218e00f 100644 --- a/.github/workflows/bitcoin-tests.yml +++ b/.github/workflows/bitcoin-tests.yml @@ -147,7 +147,8 @@ jobs: - tests::signer::v0::single_miner_empty_sortition - tests::signer::v0::multiple_miners_empty_sortition - tests::signer::v0::block_proposal_timeout - - tests::signer::v0::rejected_blocks_count_towards_miner_validity + - tests::signer::v0::reorg_attempts_count_towards_miner_validity + - tests::signer::v0::reorg_attempts_activity_timeout_exceeded - tests::signer::v0::allow_reorg_within_first_proposal_burn_block_timing_secs - tests::nakamoto_integrations::burn_ops_integration_test - tests::nakamoto_integrations::check_block_heights diff --git a/stacks-signer/CHANGELOG.md b/stacks-signer/CHANGELOG.md index 2697d93508..83ac34c784 100644 --- a/stacks-signer/CHANGELOG.md +++ b/stacks-signer/CHANGELOG.md @@ -5,6 +5,16 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to the versioning scheme outlined in the [README.md](README.md). +## [Unreleased] + +## Added + +- Introduced the `reorg_attempts_activity_timeout_ms` configuration option for signers which is used to determine the length of time after the last block of a tenure is confirmed that an incoming miner's attempts to reorg it are considered valid miner activity. + +### Changed + +- Signers no longer view any block proposal by a miner in their DB as indicative of valid miner activity. + ## [3.1.0.0.4.0] ## Added diff --git a/stacks-signer/src/chainstate.rs b/stacks-signer/src/chainstate.rs index 3e59e58850..0fd81022e5 100644 --- a/stacks-signer/src/chainstate.rs +++ b/stacks-signer/src/chainstate.rs @@ -89,9 +89,9 @@ impl SortitionState { if self.miner_status != SortitionMinerStatus::Valid { return Ok(false); } - // if we've already seen a proposed block from this miner. It cannot have timed out. - let has_blocks = signer_db.has_proposed_block_in_tenure(&self.consensus_hash)?; - if has_blocks { + // if we've already signed a block in this tenure, the miner can't have timed out. + let has_block = signer_db.has_signed_block_in_tenure(&self.consensus_hash)?; + if has_block { return Ok(false); } let Some(received_ts) = signer_db.get_burn_block_receive_time(&self.burn_block_hash)? @@ -99,13 +99,15 @@ impl SortitionState { return Ok(false); }; let received_time = UNIX_EPOCH + Duration::from_secs(received_ts); - let Ok(elapsed) = std::time::SystemTime::now().duration_since(received_time) else { + let last_activity = signer_db + .get_last_activity_time(&self.consensus_hash)? + .map(|time| UNIX_EPOCH + Duration::from_secs(time)) + .unwrap_or(received_time); + + let Ok(elapsed) = std::time::SystemTime::now().duration_since(last_activity) else { return Ok(false); }; - if elapsed > timeout { - return Ok(true); - } - Ok(false) + Ok(elapsed > timeout) } } @@ -122,6 +124,9 @@ pub struct ProposalEvalConfig { pub tenure_last_block_proposal_timeout: Duration, /// How much idle time must pass before allowing a tenure extend pub tenure_idle_timeout: Duration, + /// Time following the last block of the previous tenure's global acceptance that a signer will consider an attempt by + /// the new miner to reorg it as valid towards miner activity + pub reorg_attempts_activity_timeout: Duration, } impl From<&SignerConfig> for ProposalEvalConfig { @@ -131,6 +136,7 @@ impl From<&SignerConfig> for ProposalEvalConfig { block_proposal_timeout: value.block_proposal_timeout, tenure_last_block_proposal_timeout: value.tenure_last_block_proposal_timeout, tenure_idle_timeout: value.tenure_idle_timeout, + reorg_attempts_activity_timeout: value.reorg_attempts_activity_timeout, } } } @@ -545,8 +551,10 @@ impl SortitionsView { signer_db: &mut SignerDb, client: &StacksClient, tenure_last_block_proposal_timeout: Duration, + reorg_attempts_activity_timeout: Duration, ) -> Result { // If the tenure change block confirms the expected parent block, it should confirm at least one more block than the last accepted block in the parent tenure. + // NOTE: returns the locally accepted block if it is not timed out, otherwise it will return the last globally accepted block. let last_block_info = Self::get_tenure_last_block_info( &tenure_change.prev_tenure_consensus_hash, signer_db, @@ -566,6 +574,21 @@ impl SortitionsView { "proposed_chain_length" => block.header.chain_length, "expected_at_least" => info.block.header.chain_length + 1, ); + if info.signed_group.map_or(true, |signed_time| { + signed_time + reorg_attempts_activity_timeout.as_secs() > get_epoch_time_secs() + }) { + // Note if there is no signed_group time, this is a locally accepted block (i.e. tenure_last_block_proposal_timeout has not been exceeded). + // Treat any attempt to reorg a locally accepted block as valid miner activity. + // If the call returns a globally accepted block, check its globally accepted time against a quarter of the block_proposal_timeout + // to give the miner some extra buffer time to wait for its chain tip to advance + // The miner may just be slow, so count this invalid block proposal towards valid miner activity. + if let Err(e) = signer_db.update_last_activity_time( + &tenure_change.tenure_consensus_hash, + get_epoch_time_secs(), + ) { + warn!("Failed to update last activity time: {e}"); + } + } return Ok(false); } } @@ -631,6 +654,7 @@ impl SortitionsView { signer_db, client, self.config.tenure_last_block_proposal_timeout, + self.config.reorg_attempts_activity_timeout, )?; if !confirms_expected_parent { return Ok(false); diff --git a/stacks-signer/src/client/mod.rs b/stacks-signer/src/client/mod.rs index 8e163ac319..b006c1fdfc 100644 --- a/stacks-signer/src/client/mod.rs +++ b/stacks-signer/src/client/mod.rs @@ -417,6 +417,7 @@ pub(crate) mod tests { block_proposal_validation_timeout: config.block_proposal_validation_timeout, tenure_idle_timeout: config.tenure_idle_timeout, block_proposal_max_age_secs: config.block_proposal_max_age_secs, + reorg_attempts_activity_timeout: config.reorg_attempts_activity_timeout, } } diff --git a/stacks-signer/src/config.rs b/stacks-signer/src/config.rs index 29ee35c961..f6d1cb6097 100644 --- a/stacks-signer/src/config.rs +++ b/stacks-signer/src/config.rs @@ -41,6 +41,7 @@ const DEFAULT_FIRST_PROPOSAL_BURN_BLOCK_TIMING_SECS: u64 = 60; const DEFAULT_TENURE_LAST_BLOCK_PROPOSAL_TIMEOUT_SECS: u64 = 30; const DEFAULT_DRY_RUN: bool = false; const TENURE_IDLE_TIMEOUT_SECS: u64 = 120; +const DEFAULT_REORG_ATTEMPTS_ACTIVITY_TIMEOUT_MS: u64 = 200_000; #[derive(thiserror::Error, Debug)] /// An error occurred parsing the provided configuration @@ -163,6 +164,9 @@ pub struct SignerConfig { pub tenure_idle_timeout: Duration, /// The maximum age of a block proposal in seconds that will be processed by the signer pub block_proposal_max_age_secs: u64, + /// Time following the last block of the previous tenure's global acceptance that a signer will consider an attempt by + /// the new miner to reorg it as valid towards miner activity + pub reorg_attempts_activity_timeout: Duration, /// The running mode for the signer (dry-run or normal) pub signer_mode: SignerConfigMode, } @@ -205,6 +209,9 @@ pub struct GlobalConfig { pub tenure_idle_timeout: Duration, /// The maximum age of a block proposal that will be processed by the signer pub block_proposal_max_age_secs: u64, + /// Time following the last block of the previous tenure's global acceptance that a signer will consider an attempt by + /// the new miner to reorg it as valid towards miner activity + pub reorg_attempts_activity_timeout: Duration, /// Is this signer binary going to be running in dry-run mode? pub dry_run: bool, } @@ -246,6 +253,9 @@ struct RawConfigFile { pub tenure_idle_timeout_secs: Option, /// The maximum age of a block proposal (in secs) that will be processed by the signer. pub block_proposal_max_age_secs: Option, + /// Time (in millisecs) following a block's global acceptance that a signer will consider an attempt by a miner + /// to reorg the block as valid towards miner activity + pub reorg_attempts_activity_timeout_ms: Option, /// Is this signer binary going to be running in dry-run mode? pub dry_run: Option, } @@ -349,6 +359,12 @@ impl TryFrom for GlobalConfig { .block_proposal_max_age_secs .unwrap_or(DEFAULT_BLOCK_PROPOSAL_MAX_AGE_SECS); + let reorg_attempts_activity_timeout = Duration::from_millis( + raw_data + .reorg_attempts_activity_timeout_ms + .unwrap_or(DEFAULT_REORG_ATTEMPTS_ACTIVITY_TIMEOUT_MS), + ); + let dry_run = raw_data.dry_run.unwrap_or(DEFAULT_DRY_RUN); Ok(Self { @@ -368,6 +384,7 @@ impl TryFrom for GlobalConfig { block_proposal_validation_timeout, tenure_idle_timeout, block_proposal_max_age_secs, + reorg_attempts_activity_timeout, dry_run, }) } diff --git a/stacks-signer/src/runloop.rs b/stacks-signer/src/runloop.rs index 96223b39a0..ad95dfc8e3 100644 --- a/stacks-signer/src/runloop.rs +++ b/stacks-signer/src/runloop.rs @@ -315,6 +315,7 @@ impl, T: StacksMessageCodec + Clone + Send + Debug> RunLo block_proposal_validation_timeout: self.config.block_proposal_validation_timeout, tenure_idle_timeout: self.config.tenure_idle_timeout, block_proposal_max_age_secs: self.config.block_proposal_max_age_secs, + reorg_attempts_activity_timeout: self.config.reorg_attempts_activity_timeout, })) } diff --git a/stacks-signer/src/signerdb.rs b/stacks-signer/src/signerdb.rs index 79325d1d13..8cd4f93ed6 100644 --- a/stacks-signer/src/signerdb.rs +++ b/stacks-signer/src/signerdb.rs @@ -480,6 +480,12 @@ CREATE TABLE IF NOT EXISTS block_validations_pending ( PRIMARY KEY (signer_signature_hash) ) STRICT;"#; +static CREATE_TENURE_ACTIVTY_TABLE: &str = r#" +CREATE TABLE IF NOT EXISTS tenure_activity ( + consensus_hash TEXT NOT NULL PRIMARY KEY, + last_activity_time INTEGER NOT NULL +) STRICT;"#; + static SCHEMA_1: &[&str] = &[ DROP_SCHEMA_0, CREATE_DB_CONFIG, @@ -534,9 +540,14 @@ static SCHEMA_6: &[&str] = &[ "INSERT OR REPLACE INTO db_config (version) VALUES (6);", ]; +static SCHEMA_7: &[&str] = &[ + CREATE_TENURE_ACTIVTY_TABLE, + "INSERT OR REPLACE INTO db_config (version) VALUES (7);", +]; + impl SignerDb { /// The current schema version used in this build of the signer binary. - pub const SCHEMA_VERSION: u32 = 6; + pub const SCHEMA_VERSION: u32 = 7; /// Create a new `SignerState` instance. /// This will create a new SQLite database at the given path @@ -650,6 +661,20 @@ impl SignerDb { Ok(()) } + /// Migrate from schema 6 to schema 7 + fn schema_7_migration(tx: &Transaction) -> Result<(), DBError> { + if Self::get_schema_version(tx)? >= 7 { + // no migration necessary + return Ok(()); + } + + for statement in SCHEMA_7.iter() { + tx.execute_batch(statement)?; + } + + Ok(()) + } + /// Register custom scalar functions used by the database fn register_scalar_functions(&self) -> Result<(), DBError> { // Register helper function for determining if a block is a tenure change transaction @@ -689,7 +714,8 @@ impl SignerDb { 3 => Self::schema_4_migration(&sql_tx)?, 4 => Self::schema_5_migration(&sql_tx)?, 5 => Self::schema_6_migration(&sql_tx)?, - 6 => break, + 6 => Self::schema_7_migration(&sql_tx)?, + 7 => break, x => return Err(DBError::Other(format!( "Database schema is newer than supported by this binary. Expected version = {}, Database version = {x}", Self::SCHEMA_VERSION, @@ -746,10 +772,10 @@ impl SignerDb { try_deserialize(result) } - /// Return whether a block proposal has been stored for a tenure (identified by its consensus hash) - /// Does not consider the block's state. - pub fn has_proposed_block_in_tenure(&self, tenure: &ConsensusHash) -> Result { - let query = "SELECT block_info FROM blocks WHERE consensus_hash = ? LIMIT 1"; + /// Return whether there was signed block in a tenure (identified by its consensus hash) + pub fn has_signed_block_in_tenure(&self, tenure: &ConsensusHash) -> Result { + let query = + "SELECT block_info FROM blocks WHERE consensus_hash = ? AND signed_over = 1 LIMIT 1"; let result: Option = query_row(&self.db, query, [tenure])?; Ok(result.is_some()) @@ -1112,6 +1138,30 @@ impl SignerDb { self.remove_pending_block_validation(&block_info.signer_signature_hash())?; Ok(()) } + /// Update the tenure (identified by consensus_hash) last activity timestamp + pub fn update_last_activity_time( + &mut self, + tenure: &ConsensusHash, + last_activity_time: u64, + ) -> Result<(), DBError> { + debug!("Updating last activity for tenure"; "consensus_hash" => %tenure, "last_activity_time" => last_activity_time); + self.db.execute("INSERT OR REPLACE INTO tenure_activity (consensus_hash, last_activity_time) VALUES (?1, ?2)", params![tenure, u64_to_sql(last_activity_time)?])?; + Ok(()) + } + + /// Get the last activity timestamp for a tenure (identified by consensus_hash) + pub fn get_last_activity_time(&self, tenure: &ConsensusHash) -> Result, DBError> { + let query = + "SELECT last_activity_time FROM tenure_activity WHERE consensus_hash = ? LIMIT 1"; + let Some(last_activity_time_i64) = query_row::(&self.db, query, &[tenure])? else { + return Ok(None); + }; + let last_activity_time = u64::try_from(last_activity_time_i64).map_err(|e| { + error!("Failed to parse db last_activity_time as u64: {e}"); + DBError::Corruption + })?; + Ok(Some(last_activity_time)) + } } fn try_deserialize(s: Option) -> Result, DBError> @@ -1903,7 +1953,7 @@ mod tests { } #[test] - fn has_proposed_block() { + fn has_signed_block() { let db_path = tmp_db_path(); let consensus_hash_1 = ConsensusHash([0x01; 20]); let consensus_hash_2 = ConsensusHash([0x02; 20]); @@ -1913,16 +1963,59 @@ mod tests { b.block.header.chain_length = 1; }); - assert!(!db.has_proposed_block_in_tenure(&consensus_hash_1).unwrap()); - assert!(!db.has_proposed_block_in_tenure(&consensus_hash_2).unwrap()); + assert!(!db.has_signed_block_in_tenure(&consensus_hash_1).unwrap()); + assert!(!db.has_signed_block_in_tenure(&consensus_hash_2).unwrap()); + block_info.signed_over = true; db.insert_block(&block_info).unwrap(); + assert!(db.has_signed_block_in_tenure(&consensus_hash_1).unwrap()); + assert!(!db.has_signed_block_in_tenure(&consensus_hash_2).unwrap()); + + block_info.block.header.consensus_hash = consensus_hash_2; block_info.block.header.chain_length = 2; + block_info.signed_over = false; db.insert_block(&block_info).unwrap(); - assert!(db.has_proposed_block_in_tenure(&consensus_hash_1).unwrap()); - assert!(!db.has_proposed_block_in_tenure(&consensus_hash_2).unwrap()); + assert!(db.has_signed_block_in_tenure(&consensus_hash_1).unwrap()); + assert!(!db.has_signed_block_in_tenure(&consensus_hash_2).unwrap()); + + block_info.signed_over = true; + + db.insert_block(&block_info).unwrap(); + + assert!(db.has_signed_block_in_tenure(&consensus_hash_1).unwrap()); + assert!(db.has_signed_block_in_tenure(&consensus_hash_2).unwrap()); + } + + #[test] + fn update_last_activity() { + let db_path = tmp_db_path(); + let consensus_hash_1 = ConsensusHash([0x01; 20]); + let consensus_hash_2 = ConsensusHash([0x02; 20]); + let mut db = SignerDb::new(db_path).expect("Failed to create signer db"); + + assert!(db + .get_last_activity_time(&consensus_hash_1) + .unwrap() + .is_none()); + assert!(db + .get_last_activity_time(&consensus_hash_2) + .unwrap() + .is_none()); + + let time = get_epoch_time_secs(); + db.update_last_activity_time(&consensus_hash_1, time) + .unwrap(); + let retrieved_time = db + .get_last_activity_time(&consensus_hash_1) + .unwrap() + .unwrap(); + assert_eq!(time, retrieved_time); + assert!(db + .get_last_activity_time(&consensus_hash_2) + .unwrap() + .is_none()); } } diff --git a/stacks-signer/src/tests/chainstate.rs b/stacks-signer/src/tests/chainstate.rs index 19f0d843c8..aa24cff7ab 100644 --- a/stacks-signer/src/tests/chainstate.rs +++ b/stacks-signer/src/tests/chainstate.rs @@ -91,6 +91,7 @@ fn setup_test_environment( block_proposal_timeout: Duration::from_secs(5), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(3), }, }; diff --git a/stacks-signer/src/v0/signer.rs b/stacks-signer/src/v0/signer.rs index 4cabbe7da1..e1d5662732 100644 --- a/stacks-signer/src/v0/signer.rs +++ b/stacks-signer/src/v0/signer.rs @@ -639,6 +639,7 @@ impl Signer { &mut self.signer_db, stacks_client, self.proposal_config.tenure_last_block_proposal_timeout, + self.proposal_config.reorg_attempts_activity_timeout, ) { Ok(true) => {} Ok(false) => { diff --git a/testnet/stacks-node/src/tests/nakamoto_integrations.rs b/testnet/stacks-node/src/tests/nakamoto_integrations.rs index f3659d5957..26c68bff35 100644 --- a/testnet/stacks-node/src/tests/nakamoto_integrations.rs +++ b/testnet/stacks-node/src/tests/nakamoto_integrations.rs @@ -6474,6 +6474,7 @@ fn signer_chainstate() { block_proposal_timeout: Duration::from_secs(100), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let mut sortitions_view = SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap(); @@ -6605,6 +6606,7 @@ fn signer_chainstate() { block_proposal_timeout: Duration::from_secs(100), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let burn_block_height = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()) .unwrap() @@ -6684,6 +6686,7 @@ fn signer_chainstate() { block_proposal_timeout: Duration::from_secs(100), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let mut sortitions_view = SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap(); assert!( diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index feb870143f..b0852398bb 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -493,6 +493,7 @@ fn block_proposal_rejection() { block_proposal_timeout: Duration::from_secs(100), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let mut block = NakamotoBlock { header: NakamotoBlockHeader::empty(), @@ -7797,6 +7798,7 @@ fn block_validation_response_timeout() { tenure_last_block_proposal_timeout: Duration::from_secs(30), block_proposal_timeout: Duration::from_secs(100), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let mut block = NakamotoBlock { header: NakamotoBlockHeader::empty(), @@ -7966,6 +7968,7 @@ fn block_validation_pending_table() { block_proposal_timeout: Duration::from_secs(100), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let mut block = NakamotoBlock { header: NakamotoBlockHeader::empty(), @@ -10658,6 +10661,7 @@ fn incoming_signers_ignore_block_proposals() { block_proposal_timeout: Duration::from_secs(100), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let mut block = NakamotoBlock { header: NakamotoBlockHeader::empty(), @@ -10833,6 +10837,7 @@ fn outgoing_signers_ignore_block_proposals() { block_proposal_timeout: Duration::from_secs(100), tenure_last_block_proposal_timeout: Duration::from_secs(30), tenure_idle_timeout: Duration::from_secs(300), + reorg_attempts_activity_timeout: Duration::from_secs(30), }; let mut block = NakamotoBlock { header: NakamotoBlockHeader::empty(), @@ -11276,7 +11281,8 @@ fn injected_signatures_are_ignored_across_boundaries() { #[test] #[ignore] -/// Test that signers count any block for a given tenure in its database towards a miner tenure activity. +/// Test that signers count a block proposal that was rejected due to a reorg towards miner activity since it showed up BEFORE +/// the reorg_attempts_activity_timeout /// /// Test Setup: /// The test spins up five stacks signers, one miner Nakamoto node, and a corresponding bitcoind. @@ -11296,7 +11302,7 @@ fn injected_signatures_are_ignored_across_boundaries() { /// /// Test Assertion: /// Stacks tip advances to N+1 -fn rejected_blocks_count_towards_miner_validity() { +fn reorg_attempts_count_towards_miner_validity() { if env::var("BITCOIND_TEST") != Ok("1".into()) { return; } @@ -11313,12 +11319,14 @@ fn rejected_blocks_count_towards_miner_validity() { let send_amt = 100; let send_fee = 180; let recipient = PrincipalData::from(StacksAddress::burn_address(false)); - let block_proposal_timeout = Duration::from_secs(20); + let block_proposal_timeout = Duration::from_secs(30); + let reorg_attempts_activity_timeout = Duration::from_secs(20); let mut signer_test: SignerTest = SignerTest::new_with_config_modifications( num_signers, vec![(sender_addr, send_amt + send_fee)], |config| { config.block_proposal_timeout = block_proposal_timeout; + config.reorg_attempts_activity_timeout = reorg_attempts_activity_timeout; }, |_| {}, None, @@ -11460,6 +11468,226 @@ fn rejected_blocks_count_towards_miner_validity() { signer_test.shutdown(); } +#[test] +#[ignore] +/// Test that signers do not count a block proposal that was rejected due to a reorg towards miner activity since it showed up AFTER +/// the reorg_attempts_activity_timeout +/// +/// Test Setup: +/// The test spins up five stacks signers, one miner Nakamoto node, and a corresponding bitcoind. +/// The stacks node is then advanced to Epoch 3.0 boundary to allow block signing. The block proposal timeout is set to 20 seconds. +/// +/// Test Execution: +/// Test validation endpoint is stalled. +/// The miner proposes a block N. +/// Block proposals are stalled. +/// A new tenure is started. +/// The test waits for reorg_attempts_activity_timeout + 1 second. +/// The miner proposes a block N'. +/// The test waits for block proposal timeout + 1 second. +/// The validation endpoint is resumed. +/// The signers accept block N. +/// The signers reject block N'. +/// The miner proposes block N+1. +/// The signers reject block N+1. +/// +/// Test Assertion: +/// Stacks tip advances to N. +fn reorg_attempts_activity_timeout_exceeded() { + 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::random(); + 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 block_proposal_timeout = Duration::from_secs(30); + let reorg_attempts_activity_timeout = Duration::from_secs(20); + let mut signer_test: SignerTest = SignerTest::new_with_config_modifications( + num_signers, + vec![(sender_addr, send_amt + send_fee)], + |config| { + config.block_proposal_timeout = block_proposal_timeout; + config.reorg_attempts_activity_timeout = reorg_attempts_activity_timeout; + }, + |_| {}, + None, + None, + ); + let http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind); + + signer_test.boot_to_epoch_3(); + + let wait_for_block_proposal = || { + let mut block_proposal = None; + let _ = wait_for(30, || { + block_proposal = test_observer::get_stackerdb_chunks() + .into_iter() + .flat_map(|chunk| chunk.modified_slots) + .find_map(|chunk| { + let message = SignerMessage::consensus_deserialize(&mut chunk.data.as_slice()) + .expect("Failed to deserialize SignerMessage"); + if let SignerMessage::BlockProposal(proposal) = message { + return Some(proposal); + } + None + }); + Ok(block_proposal.is_some()) + }); + block_proposal + }; + + let wait_for_block_rejections = |hash: Sha512Trunc256Sum| { + wait_for(30, || { + let stackerdb_events = test_observer::get_stackerdb_chunks(); + let block_rejections = stackerdb_events + .into_iter() + .flat_map(|chunk| chunk.modified_slots) + .filter_map(|chunk| { + let message = SignerMessage::consensus_deserialize(&mut chunk.data.as_slice()) + .expect("Failed to deserialize SignerMessage"); + match message { + SignerMessage::BlockResponse(BlockResponse::Rejected(rejection)) => { + if rejection.signer_signature_hash == hash { + assert_eq!( + rejection.reason_code, + RejectCode::SortitionViewMismatch + ); + Some(rejection) + } else { + None + } + } + _ => None, + } + }) + .collect::>(); + Ok(block_rejections.len() >= num_signers * 3 / 10) + }) + }; + + info!("------------------------- Test Mine Block N -------------------------"); + let chain_before = get_chain_info(&signer_test.running_nodes.conf); + // Stall validation so signers will be unable to process the tenure change block for Tenure B. + // And so the incoming miner proposes a block N' (the reorging block). + TEST_VALIDATE_STALL.set(true); + test_observer::clear(); + // submit a tx so that the miner will mine an extra block + let sender_nonce = 0; + let transfer_tx = make_stacks_transfer( + &sender_sk, + sender_nonce, + send_fee, + signer_test.running_nodes.conf.burnchain.chain_id, + &recipient, + send_amt, + ); + submit_tx(&http_origin, &transfer_tx); + + let block_proposal_n = wait_for_block_proposal().expect("Failed to get block proposal N"); + let chain_after = get_chain_info(&signer_test.running_nodes.conf); + assert_eq!(chain_after, chain_before); + TEST_BROADCAST_STALL.set(true); + + info!("------------------------- Start Tenure B -------------------------"); + let commits_before = signer_test + .running_nodes + .commits_submitted + .load(Ordering::SeqCst); + let chain_before = get_chain_info(&signer_test.running_nodes.conf); + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 60, + || { + let commits_count = signer_test + .running_nodes + .commits_submitted + .load(Ordering::SeqCst); + let chain_info = get_chain_info(&signer_test.running_nodes.conf); + Ok(commits_count > commits_before + && chain_info.burn_block_height > chain_before.burn_block_height) + }, + ) + .unwrap(); + + info!("------------------------- Wait for block N' to arrive late -------------------------"); + test_observer::clear(); + // Allow block N validation to finish. + TEST_VALIDATE_STALL.set(false); + wait_for(30, || { + let chain_info = get_chain_info(&signer_test.running_nodes.conf); + Ok(chain_info.stacks_tip_height > chain_before.stacks_tip_height) + }) + .expect("Tiemd out waiting for stacks tip to advance to block N"); + let chain_after = get_chain_info(&signer_test.running_nodes.conf); + TEST_VALIDATE_STALL.set(true); + // Allow incoming mine to propose block N' + // Make sure to wait the reorg_attempts_activity_timeout AFTER the block is globally signed over + // as this is the point where signers start considering from. + std::thread::sleep(reorg_attempts_activity_timeout.add(Duration::from_secs(1))); + TEST_BROADCAST_STALL.set(false); + let block_proposal_n_prime = + wait_for_block_proposal().expect("Failed to get block proposal N'"); + assert_eq!( + block_proposal_n_prime.block.header.chain_length, + chain_after.stacks_tip_height + ); + // Make sure that no subsequent proposal arrives before the block_proposal_timeout is exceeded + TEST_BROADCAST_STALL.set(true); + TEST_VALIDATE_STALL.set(false); + // We only need to wait the difference between the two timeouts now since we already slept for a min of reorg_attempts_activity_timeout + 1 + std::thread::sleep(block_proposal_timeout.saturating_sub(reorg_attempts_activity_timeout)); + assert_ne!(block_proposal_n, block_proposal_n_prime); + assert_eq!( + chain_after.stacks_tip_height, + block_proposal_n.block.header.chain_length + ); + let chain_before = chain_after; + + info!("------------------------- Wait for Block N' Rejection -------------------------"); + wait_for_block_rejections(block_proposal_n_prime.block.header.signer_signature_hash()) + .expect("FAIL: Timed out waiting for block proposal rejections of N'"); + + info!("------------------------- Wait for Block N+1 Proposal -------------------------"); + test_observer::clear(); + TEST_BROADCAST_STALL.set(false); + wait_for(30, || { + let block_proposal_n_1 = + wait_for_block_proposal().expect("Failed to get block proposal N+1"); + Ok(block_proposal_n_1.block.header.chain_length + == block_proposal_n.block.header.chain_length + 1) + }) + .expect("Timed out waiting for block N+1 to be proposed"); + + info!("------------------------- Wait for Block N+1 Rejection -------------------------"); + // The miner will automatically reattempt to mine a block N+1 once it sees the stacks tip advance to block N. + // N+1 will still be rejected however as the signers will have already marked the miner as invalid since the reorg + // block N' arrived AFTER the reorg_attempts_activity_timeout and the subsequent block N+1 arrived AFTER the + // block_proposal_timeout. + let block_proposal_n_1 = wait_for_block_proposal().expect("Failed to get block proposal N+1'"); + wait_for_block_rejections(block_proposal_n_1.block.header.signer_signature_hash()) + .expect("FAIL: Timed out waiting for block proposal rejections of N+1'"); + + info!("------------------------- Ensure chain halts -------------------------"); + // Just in case, wait again and ensure that the chain is still halted (once marked invalid, the miner can do nothing to satisfy the signers) + assert!(wait_for(reorg_attempts_activity_timeout.as_secs(), || { + let chain_info = get_chain_info(&signer_test.running_nodes.conf); + assert_eq!(chain_info.stacks_tip_height, chain_before.stacks_tip_height); + Ok(false) + }) + .is_err()); + signer_test.shutdown(); +} + #[test] #[ignore] fn fast_sortition() {