From b21f156ac84cef3a63ef9db9cc6057e16304ac3c Mon Sep 17 00:00:00 2001 From: Brice Dobry Date: Tue, 4 Feb 2025 15:44:24 -0500 Subject: [PATCH 1/7] feat: stop waiting for signatures if the chain tip advances This could happen at the beginning of a tenure, if the miner for tenure T+1 proposes its first block before it sees the last block from tenure T, so the block it proposed is reorging that last block. Once it sees this block, it should immediately stop waiting for signatures and instead build a new block off of the new tip. Fixes: #5751 --- .github/workflows/bitcoin-tests.yml | 1 + stacks-signer/src/v0/signer.rs | 4 + .../stacks-node/src/nakamoto_node/miner.rs | 77 ++- .../src/nakamoto_node/signer_coordinator.rs | 13 + .../src/tests/nakamoto_integrations.rs | 11 +- testnet/stacks-node/src/tests/signer/v0.rs | 449 +++++++++++++++++- 6 files changed, 522 insertions(+), 33 deletions(-) diff --git a/.github/workflows/bitcoin-tests.yml b/.github/workflows/bitcoin-tests.yml index b07c0dc2e4..7b3d06f48c 100644 --- a/.github/workflows/bitcoin-tests.yml +++ b/.github/workflows/bitcoin-tests.yml @@ -151,6 +151,7 @@ jobs: - tests::signer::v0::block_proposal_timeout - tests::signer::v0::rejected_blocks_count_towards_miner_validity - tests::signer::v0::allow_reorg_within_first_proposal_burn_block_timing_secs + - tests::signer::v0::interrupt_miner_on_new_stacks_tip - tests::nakamoto_integrations::burn_ops_integration_test - tests::nakamoto_integrations::check_block_heights - tests::nakamoto_integrations::clarity_burn_state diff --git a/stacks-signer/src/v0/signer.rs b/stacks-signer/src/v0/signer.rs index 4cabbe7da1..6669b00d7c 100644 --- a/stacks-signer/src/v0/signer.rs +++ b/stacks-signer/src/v0/signer.rs @@ -207,6 +207,10 @@ impl SignerTrait for Signer { "block_height" => b.header.chain_length, "signer_sighash" => %b.header.signer_signature_hash(), ); + #[cfg(any(test, feature = "testing"))] + if self.test_skip_block_broadcast(b) { + return; + } stacks_client.post_block_until_ok(self, b); } SignerMessage::MockProposal(mock_proposal) => { diff --git a/testnet/stacks-node/src/nakamoto_node/miner.rs b/testnet/stacks-node/src/nakamoto_node/miner.rs index 16b33ead7a..4c5324411e 100644 --- a/testnet/stacks-node/src/nakamoto_node/miner.rs +++ b/testnet/stacks-node/src/nakamoto_node/miner.rs @@ -65,11 +65,20 @@ use crate::run_loop::RegisteredKey; pub static TEST_MINE_STALL: LazyLock> = LazyLock::new(TestFlag::default); #[cfg(test)] /// Test flag to stall block proposal broadcasting -pub static TEST_BROADCAST_STALL: LazyLock> = LazyLock::new(TestFlag::default); +pub static TEST_BROADCAST_PROPOSAL_STALL: LazyLock> = + LazyLock::new(TestFlag::default); #[cfg(test)] +// Test flag to stall the miner from announcing a block while this flag is true pub static TEST_BLOCK_ANNOUNCE_STALL: LazyLock> = LazyLock::new(TestFlag::default); #[cfg(test)] -pub static TEST_SKIP_P2P_BROADCAST: LazyLock> = LazyLock::new(TestFlag::default); +// Test flag to skip broadcasting blocks over the p2p network +pub static TEST_P2P_BROADCAST_SKIP: LazyLock> = LazyLock::new(TestFlag::default); +#[cfg(test)] +// Test flag to stall broadcasting blocks over the p2p network +pub static TEST_P2P_BROADCAST_STALL: LazyLock> = LazyLock::new(TestFlag::default); +#[cfg(test)] +// Test flag to skip pushing blocks to the signers +pub static TEST_BLOCK_PUSH_SKIP: LazyLock> = LazyLock::new(TestFlag::default); /// If the miner was interrupted while mining a block, how long should the /// miner thread sleep before trying again? @@ -252,19 +261,19 @@ impl BlockMinerThread { } #[cfg(test)] - fn fault_injection_block_broadcast_stall(new_block: &NakamotoBlock) { - if TEST_BROADCAST_STALL.get() { + fn fault_injection_block_proposal_stall(new_block: &NakamotoBlock) { + if TEST_BROADCAST_PROPOSAL_STALL.get() { // Do an extra check just so we don't log EVERY time. - warn!("Fault injection: Broadcasting is stalled due to testing directive."; + warn!("Fault injection: Block proposal broadcast is stalled due to testing directive."; "stacks_block_id" => %new_block.block_id(), "stacks_block_hash" => %new_block.header.block_hash(), "height" => new_block.header.chain_length, "consensus_hash" => %new_block.header.consensus_hash ); - while TEST_BROADCAST_STALL.get() { + while TEST_BROADCAST_PROPOSAL_STALL.get() { std::thread::sleep(std::time::Duration::from_millis(10)); } - info!("Fault injection: Broadcasting is no longer stalled due to testing directive."; + info!("Fault injection: Block proposal broadcast is no longer stalled due to testing directive."; "block_id" => %new_block.block_id(), "height" => new_block.header.chain_length, "consensus_hash" => %new_block.header.consensus_hash @@ -273,7 +282,7 @@ impl BlockMinerThread { } #[cfg(not(test))] - fn fault_injection_block_broadcast_stall(_ignored: &NakamotoBlock) {} + fn fault_injection_block_proposal_stall(_ignored: &NakamotoBlock) {} #[cfg(test)] fn fault_injection_block_announce_stall(new_block: &NakamotoBlock) { @@ -301,10 +310,7 @@ impl BlockMinerThread { #[cfg(test)] fn fault_injection_skip_block_broadcast() -> bool { - if TEST_SKIP_P2P_BROADCAST.get() { - return true; - } - false + TEST_P2P_BROADCAST_SKIP.get() } #[cfg(not(test))] @@ -312,6 +318,40 @@ impl BlockMinerThread { false } + #[cfg(test)] + fn fault_injection_block_broadcast_stall(new_block: &NakamotoBlock) { + if TEST_P2P_BROADCAST_STALL.get() { + // Do an extra check just so we don't log EVERY time. + warn!("Fault injection: P2P block broadcast is stalled due to testing directive."; + "stacks_block_id" => %new_block.block_id(), + "stacks_block_hash" => %new_block.header.block_hash(), + "height" => new_block.header.chain_length, + "consensus_hash" => %new_block.header.consensus_hash + ); + while TEST_P2P_BROADCAST_STALL.get() { + std::thread::sleep(std::time::Duration::from_millis(10)); + } + info!("Fault injection: P2P block broadcast is no longer stalled due to testing directive."; + "block_id" => %new_block.block_id(), + "height" => new_block.header.chain_length, + "consensus_hash" => %new_block.header.consensus_hash + ); + } + } + + #[cfg(not(test))] + fn fault_injection_block_broadcast_stall(_ignored: &NakamotoBlock) {} + + #[cfg(test)] + fn fault_injection_skip_block_push() -> bool { + TEST_BLOCK_PUSH_SKIP.get() + } + + #[cfg(not(test))] + fn fault_injection_skip_block_push() -> bool { + false + } + /// Stop a miner tenure by blocking the miner and then joining the tenure thread #[cfg(test)] fn fault_injection_stall_miner() { @@ -516,7 +556,7 @@ impl BlockMinerThread { }; if let Some(mut new_block) = new_block { - Self::fault_injection_block_broadcast_stall(&new_block); + Self::fault_injection_block_proposal_stall(&new_block); let signer_signature = match self.propose_block( coordinator, @@ -532,7 +572,7 @@ impl BlockMinerThread { "block_height" => new_block.header.chain_length, "consensus_hash" => %new_block.header.consensus_hash, ); - return Err(e); + return Ok(()); } NakamotoNodeError::BurnchainTipChanged => { info!("Burnchain tip changed while waiting for signatures"; @@ -739,6 +779,7 @@ impl BlockMinerThread { ); return Ok(()); } + Self::fault_injection_block_broadcast_stall(block); let parent_block_info = NakamotoChainState::get_block_header(chain_state.db(), &block.header.parent_block_id)? @@ -834,6 +875,14 @@ impl BlockMinerThread { let miners_contract_id = boot_code_id(MINERS_NAME, chain_state.mainnet); let mut miners_session = StackerDBSession::new(&rpc_socket.to_string(), miners_contract_id); + if Self::fault_injection_skip_block_push() { + warn!( + "Fault injection: Skipping block push for {}", + block.block_id() + ); + return Ok(()); + } + SignerCoordinator::send_miners_message( miner_privkey, &sort_db, diff --git a/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs b/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs index 2138b7e767..a607ee7f9e 100644 --- a/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs +++ b/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs @@ -288,6 +288,7 @@ impl SignerCoordinator { self.get_block_status( &block.header.signer_signature_hash(), &block.block_id(), + block.header.parent_block_id, chain_state, sortdb, counters, @@ -303,6 +304,7 @@ impl SignerCoordinator { &self, block_signer_sighash: &Sha512Trunc256Sum, block_id: &StacksBlockId, + parent_block_id: StacksBlockId, chain_state: &mut StacksChainState, sortdb: &SortitionDB, counters: &Counters, @@ -384,6 +386,17 @@ impl SignerCoordinator { )); } + // Check if a new Stacks block has arrived + let (canonical_stacks_tip_ch, canonical_stacks_tip_bh) = + SortitionDB::get_canonical_stacks_chain_tip_hash(sortdb.conn()).unwrap(); + let canonical_stacks_tip = + StacksBlockId::new(&canonical_stacks_tip_ch, &canonical_stacks_tip_bh); + info!("SignCoordinator: Current stacks tip: {canonical_stacks_tip}, parent: {parent_block_id}"); + if canonical_stacks_tip != parent_block_id { + debug!("SignCoordinator: Exiting due to new stacks tip"); + return Err(NakamotoNodeError::StacksTipChanged); + } + continue; } }; diff --git a/testnet/stacks-node/src/tests/nakamoto_integrations.rs b/testnet/stacks-node/src/tests/nakamoto_integrations.rs index 4099ce64f2..40de53d565 100644 --- a/testnet/stacks-node/src/tests/nakamoto_integrations.rs +++ b/testnet/stacks-node/src/tests/nakamoto_integrations.rs @@ -97,7 +97,8 @@ use stacks_signer::v0::SpawnedSigner; use super::bitcoin_regtest::BitcoinCoreController; use crate::nakamoto_node::miner::{ - TEST_BLOCK_ANNOUNCE_STALL, TEST_BROADCAST_STALL, TEST_MINE_STALL, TEST_SKIP_P2P_BROADCAST, + TEST_BLOCK_ANNOUNCE_STALL, TEST_BROADCAST_PROPOSAL_STALL, TEST_MINE_STALL, + TEST_P2P_BROADCAST_SKIP, }; use crate::nakamoto_node::relayer::{RelayerThread, TEST_MINER_THREAD_STALL}; use crate::neon::{Counters, RunLoopCounter}; @@ -5186,7 +5187,7 @@ fn forked_tenure_is_ignored() { // For the next tenure, submit the commit op but do not allow any stacks blocks to be broadcasted. // Stall the miner thread; only wait until the number of submitted commits increases. - TEST_BROADCAST_STALL.set(true); + TEST_BROADCAST_PROPOSAL_STALL.set(true); TEST_BLOCK_ANNOUNCE_STALL.set(true); let blocks_before = mined_blocks.load(Ordering::SeqCst); @@ -5205,7 +5206,7 @@ fn forked_tenure_is_ignored() { // Unpause the broadcast of Tenure B's block, do not submit commits, and do not allow blocks to // be processed test_skip_commit_op.set(true); - TEST_BROADCAST_STALL.set(false); + TEST_BROADCAST_PROPOSAL_STALL.set(false); // Wait for a stacks block to be broadcasted. // However, it will not be processed. @@ -9876,7 +9877,7 @@ fn skip_mining_long_tx() { }) .unwrap(); - TEST_SKIP_P2P_BROADCAST.set(true); + TEST_P2P_BROADCAST_SKIP.set(true); let tx = make_contract_publish( &sender_2_sk, 0, @@ -9903,7 +9904,7 @@ fn skip_mining_long_tx() { }) .unwrap(); - TEST_SKIP_P2P_BROADCAST.set(false); + TEST_P2P_BROADCAST_SKIP.set(false); } else { let transfer_tx = make_stacks_transfer( &sender_1_sk, diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index dfe5c34443..0760550f03 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -36,6 +36,7 @@ use stacks::chainstate::nakamoto::{NakamotoBlock, NakamotoBlockHeader, NakamotoC use stacks::chainstate::stacks::address::PoxAddress; use stacks::chainstate::stacks::boot::MINERS_NAME; use stacks::chainstate::stacks::db::{StacksBlockHeaderTypes, StacksChainState, StacksHeaderInfo}; +use stacks::chainstate::stacks::miner::{TransactionEvent, TransactionSuccessEvent}; use stacks::chainstate::stacks::{StacksTransaction, TenureChangeCause, TransactionPayload}; use stacks::codec::StacksMessageCodec; use stacks::config::{EventKeyType, EventObserverConfig}; @@ -74,7 +75,8 @@ use tracing_subscriber::{fmt, EnvFilter}; use super::SignerTest; use crate::event_dispatcher::{MinedNakamotoBlockEvent, TEST_SKIP_BLOCK_ANNOUNCEMENT}; use crate::nakamoto_node::miner::{ - TEST_BLOCK_ANNOUNCE_STALL, TEST_BROADCAST_STALL, TEST_MINE_STALL, + TEST_BLOCK_ANNOUNCE_STALL, TEST_BROADCAST_PROPOSAL_STALL, TEST_MINE_STALL, + TEST_P2P_BROADCAST_STALL, }; use crate::nakamoto_node::stackerdb_listener::TEST_IGNORE_SIGNERS; use crate::neon::Counters; @@ -588,7 +590,7 @@ fn miner_gather_signatures() { // Disable p2p broadcast of the nakamoto blocks, so that we rely // on the signer's using StackerDB to get pushed blocks - nakamoto_node::miner::TEST_SKIP_P2P_BROADCAST.set(true); + nakamoto_node::miner::TEST_P2P_BROADCAST_SKIP.set(true); info!("------------------------- Test Setup -------------------------"); let num_signers = 5; @@ -1019,7 +1021,7 @@ fn forked_tenure_testing( .unwrap(); // For the next tenure, submit the commit op but do not allow any stacks blocks to be broadcasted - TEST_BROADCAST_STALL.set(true); + TEST_BROADCAST_PROPOSAL_STALL.set(true); TEST_BLOCK_ANNOUNCE_STALL.set(true); let blocks_before = mined_blocks.load(Ordering::SeqCst); @@ -1044,7 +1046,7 @@ fn forked_tenure_testing( .running_nodes .nakamoto_test_skip_commit_op .set(true); - TEST_BROADCAST_STALL.set(false); + TEST_BROADCAST_PROPOSAL_STALL.set(false); // Wait for a stacks block to be broadcasted let start_time = Instant::now(); @@ -1964,7 +1966,7 @@ fn miner_forking() { info!("------------------------- RL1 Wins Sortition -------------------------"); info!("Pausing stacks block proposal to force an empty tenure commit from RL2"); - TEST_BROADCAST_STALL.set(true); + TEST_BROADCAST_PROPOSAL_STALL.set(true); let rl1_commits_before = commits_submitted_rl1.load(Ordering::SeqCst); let burn_height_before = get_burn_height(); @@ -2027,7 +2029,7 @@ fn miner_forking() { // unblock block mining let blocks_len = test_observer::get_blocks().len(); - TEST_BROADCAST_STALL.set(false); + TEST_BROADCAST_PROPOSAL_STALL.set(false); // Wait for the block to be broadcasted and processed wait_for(30, || Ok(test_observer::get_blocks().len() > blocks_len)) @@ -2114,7 +2116,7 @@ fn miner_forking() { info!("------------------------- RL1 RBFs its Own Commit -------------------------"); info!("Pausing stacks block proposal to test RBF capability"); - TEST_BROADCAST_STALL.set(true); + TEST_BROADCAST_PROPOSAL_STALL.set(true); let rl1_commits_before = commits_submitted_rl1.load(Ordering::SeqCst); info!("Unpausing commits from RL1"); @@ -2152,7 +2154,7 @@ fn miner_forking() { let rl1_commits_before = commits_submitted_rl1.load(Ordering::SeqCst); // unblock block mining let blocks_len = test_observer::get_blocks().len(); - TEST_BROADCAST_STALL.set(false); + TEST_BROADCAST_PROPOSAL_STALL.set(false); // Wait for the block to be broadcasted and processed wait_for(30, || Ok(test_observer::get_blocks().len() > blocks_len)) @@ -3349,7 +3351,7 @@ fn empty_sortition() { signer_test.boot_to_epoch_3(); - TEST_BROADCAST_STALL.set(true); + TEST_BROADCAST_PROPOSAL_STALL.set(true); info!("------------------------- Test Mine Regular Tenure A -------------------------"); let commits_before = signer_test @@ -3396,7 +3398,7 @@ fn empty_sortition() { .unwrap(); info!("Pausing stacks block proposal to force an empty tenure"); - TEST_BROADCAST_STALL.set(true); + TEST_BROADCAST_PROPOSAL_STALL.set(true); info!("Pausing commit op to prevent tenure C from starting..."); signer_test @@ -3429,7 +3431,7 @@ fn empty_sortition() { std::thread::sleep(block_proposal_timeout.add(Duration::from_secs(1))); - TEST_BROADCAST_STALL.set(false); + TEST_BROADCAST_PROPOSAL_STALL.set(false); info!("------------------------- Test Delayed Block is Rejected -------------------------"); let reward_cycle = signer_test.get_current_reward_cycle(); @@ -4561,7 +4563,7 @@ fn duplicate_signers() { // Disable p2p broadcast of the nakamoto blocks, so that we rely // on the signer's using StackerDB to get pushed blocks - nakamoto_node::miner::TEST_SKIP_P2P_BROADCAST.set(true); + nakamoto_node::miner::TEST_P2P_BROADCAST_SKIP.set(true); info!("------------------------- Test Setup -------------------------"); let num_signers = 5; @@ -12116,7 +12118,7 @@ fn block_proposal_timeout() { signer_test.boot_to_epoch_3(); // Pause the miner's block proposals - TEST_BROADCAST_STALL.set(true); + TEST_BROADCAST_PROPOSAL_STALL.set(true); let wait_for_block_proposal = || { let mut block_proposal = None; @@ -12161,7 +12163,7 @@ fn block_proposal_timeout() { test_observer::clear(); info!("------------------------- Attempt Mine Block N -------------------------"); - TEST_BROADCAST_STALL.set(false); + TEST_BROADCAST_PROPOSAL_STALL.set(false); let block_proposal_n = wait_for_block_proposal().expect("Failed to get block proposal N"); @@ -12835,3 +12837,422 @@ fn tenure_extend_cost_threshold() { signer_test.shutdown(); } + +#[test] +#[ignore] +/// Test that a miner that begins mining before seeing the last block of the +/// previous tenure can be interrupted when its tip advances to the last block, +/// then successfully mine a block on top of that block. +/// +/// 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. +/// +/// Test Execution: +/// The node mines 1 stacks block N (all signers sign it). The subsequent block N+1 is proposed, but <30% accept it. The remaining signers +/// do not make a decision on the block. A new tenure begins and the miner proposes a new block N+1' which all signers accept. +/// +/// Test Assertion: +/// Stacks tip advances to N+1' +fn interrupt_miner_on_new_stacks_tip() { + if env::var("BITCOIND_TEST") != Ok("1".into()) { + return; + } + + 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 btc_miner_1_seed = vec![1, 1, 1, 1]; + let btc_miner_2_seed = vec![2, 2, 2, 2]; + let btc_miner_1_pk = Keychain::default(btc_miner_1_seed.clone()).get_pub_key(); + let btc_miner_2_pk = Keychain::default(btc_miner_2_seed.clone()).get_pub_key(); + + let node_1_rpc = gen_random_port(); + let node_1_p2p = gen_random_port(); + let node_2_rpc = gen_random_port(); + let node_2_p2p = gen_random_port(); + + let localhost = "127.0.0.1"; + let node_1_rpc_bind = format!("{localhost}:{node_1_rpc}"); + let node_2_rpc_bind = format!("{localhost}:{node_2_rpc}"); + let mut node_2_listeners = Vec::new(); + + // partition the signer set so that ~half are listening and using node 1 for RPC and events, + // and the rest are using node 2 + + let mut signer_test: SignerTest = SignerTest::new_with_config_modifications( + num_signers, + vec![(sender_addr, (send_amt + send_fee) * 2)], + |signer_config| { + let node_host = if signer_config.endpoint.port() % 2 == 0 { + &node_1_rpc_bind + } else { + &node_2_rpc_bind + }; + signer_config.node_host = node_host.to_string(); + // we're deliberately stalling proposals: don't punish this in this test! + signer_config.block_proposal_timeout = Duration::from_secs(240); + // make sure that we don't allow forking due to burn block timing + signer_config.first_proposal_burn_block_timing = Duration::from_secs(60); + }, + |config| { + config.node.rpc_bind = format!("{localhost}:{node_1_rpc}"); + config.node.p2p_bind = format!("{localhost}:{node_1_p2p}"); + config.node.data_url = format!("http://{localhost}:{node_1_rpc}"); + config.node.p2p_address = format!("{localhost}:{node_1_p2p}"); + + config.node.seed = btc_miner_1_seed.clone(); + config.node.local_peer_seed = btc_miner_1_seed.clone(); + config.burnchain.local_mining_public_key = Some(btc_miner_1_pk.to_hex()); + config.miner.mining_key = Some(Secp256k1PrivateKey::from_seed(&[1])); + config.node.pox_sync_sample_secs = 30; + config.miner.block_commit_delay = Duration::from_secs(0); + config.miner.tenure_cost_limit_per_block_percentage = None; + + config.events_observers.retain(|listener| { + match std::net::SocketAddr::from_str(&listener.endpoint) { + Ok(addr) => { + if addr.port() % 2 == 0 && addr.port() != test_observer::EVENT_OBSERVER_PORT { + return true; + } + + node_2_listeners.push(listener.clone()); + addr.port() == test_observer::EVENT_OBSERVER_PORT + } + Err(_) => { + warn!( + "Cannot parse {} to a socket, assuming it isn't a signer-listener binding", + listener.endpoint + ); + true + } + } + }) + }, + Some(vec![btc_miner_1_pk, btc_miner_2_pk]), + None, + ); + let conf = signer_test.running_nodes.conf.clone(); + let mut conf_node_2 = conf.clone(); + conf_node_2.node.rpc_bind = node_2_rpc_bind; + conf_node_2.node.p2p_bind = format!("{localhost}:{node_2_p2p}"); + conf_node_2.node.data_url = format!("http://{localhost}:{node_2_rpc}"); + conf_node_2.node.p2p_address = format!("{localhost}:{node_2_p2p}"); + conf_node_2.node.seed = btc_miner_2_seed.clone(); + conf_node_2.burnchain.local_mining_public_key = Some(btc_miner_2_pk.to_hex()); + conf_node_2.node.local_peer_seed = btc_miner_2_seed; + conf_node_2.node.miner = true; + conf_node_2.events_observers.clear(); + conf_node_2.events_observers.extend(node_2_listeners); + conf_node_2.miner.mining_key = Some(Secp256k1PrivateKey::from_seed(&[2])); + assert!(!conf_node_2.events_observers.is_empty()); + + let node_1_sk = Secp256k1PrivateKey::from_seed(&conf.node.local_peer_seed); + let node_1_pk = StacksPublicKey::from_private(&node_1_sk); + + conf_node_2.node.working_dir = format!("{}-1", conf_node_2.node.working_dir); + + conf_node_2.node.set_bootstrap_nodes( + format!("{}@{}", &node_1_pk.to_hex(), conf.node.p2p_bind), + conf.burnchain.chain_id, + conf.burnchain.peer_version, + ); + + let mut run_loop_2 = boot_nakamoto::BootRunLoop::new(conf_node_2.clone()).unwrap(); + let Counters { + naka_skip_commit_op: skip_commit_op_rl2, + naka_submitted_commits: commits_submitted_rl2, + naka_submitted_commit_last_burn_height: commits_submitted_rl2_last_burn_height, + naka_proposed_blocks: proposed_blocks_rl2, + .. + } = run_loop_2.counters(); + let _run_loop_2_thread = thread::Builder::new() + .name("run_loop_2".into()) + .spawn(move || run_loop_2.start(None, 0)) + .unwrap(); + + let all_signers: Vec<_> = signer_test + .signer_stacks_private_keys + .iter() + .map(StacksPublicKey::from_private) + .collect(); + let http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind); + + signer_test.boot_to_epoch_3(); + + wait_for(120, || { + let Some(node_1_info) = get_chain_info_opt(&conf) else { + return Ok(false); + }; + let Some(node_2_info) = get_chain_info_opt(&conf_node_2) else { + return Ok(false); + }; + Ok(node_1_info.stacks_tip_height == node_2_info.stacks_tip_height) + }) + .expect("Timed out waiting for boostrapped node to catch up to the miner"); + + let commits_submitted_rl1 = signer_test.running_nodes.commits_submitted.clone(); + let commits_submitted_rl1_last_burn_height = + signer_test.running_nodes.last_commit_burn_height.clone(); + let skip_commit_op_rl1 = signer_test + .running_nodes + .nakamoto_test_skip_commit_op + .clone(); + + let mining_pk_1 = StacksPublicKey::from_private(&conf.miner.mining_key.unwrap()); + let mining_pk_2 = StacksPublicKey::from_private(&conf_node_2.miner.mining_key.unwrap()); + let mining_pkh_1 = Hash160::from_node_public_key(&mining_pk_1); + let mining_pkh_2 = Hash160::from_node_public_key(&mining_pk_2); + debug!("The mining key for miner 1 is {mining_pkh_1}"); + debug!("The mining key for miner 2 is {mining_pkh_2}"); + + let sortdb = conf.get_burnchain().open_sortition_db(true).unwrap(); + let get_burn_height = || { + SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()) + .unwrap() + .block_height + }; + + let wait_for_chains = || { + wait_for(30, || { + let Some(chain_info_1) = get_chain_info_opt(&conf) else { + return Ok(false); + }; + let Some(chain_info_2) = get_chain_info_opt(&conf_node_2) else { + return Ok(false); + }; + Ok(chain_info_1.burn_block_height == chain_info_2.burn_block_height) + }) + }; + info!("------------------------- Reached Epoch 3.0 -------------------------"); + + info!("Pausing both miners' block commit submissions"); + skip_commit_op_rl1.set(true); + skip_commit_op_rl2.set(true); + + info!("Flushing any pending commits to enable custom winner selection"); + let burn_height_before = get_burn_height(); + let blocks_before = test_observer::get_blocks().len(); + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 30, + || { + Ok(get_burn_height() > burn_height_before + && test_observer::get_blocks().len() > blocks_before) + }, + ) + .unwrap(); + + info!("------------------------- RL1 Wins Sortition -------------------------"); + let rl1_commits_before = commits_submitted_rl1.load(Ordering::SeqCst); + let burn_height_before = get_burn_height(); + + info!("Unpausing commits from RL1"); + skip_commit_op_rl1.set(false); + + info!("Waiting for commits from RL1"); + wait_for(30, || { + Ok( + commits_submitted_rl1.load(Ordering::SeqCst) > rl1_commits_before + && commits_submitted_rl1_last_burn_height.load(Ordering::SeqCst) + >= burn_height_before, + ) + }) + .expect("Timed out waiting for miner 1 to submit a commit op"); + + info!("Pausing commits from RL1"); + skip_commit_op_rl1.set(true); + + let burn_height_before = get_burn_height(); + info!("Mine RL1 Tenure"); + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 30, + || Ok(get_burn_height() > burn_height_before), + ) + .unwrap(); + let burn_height_after = get_burn_height(); + + wait_for_chains().expect("Timed out waiting for Rl1 and Rl2 chains to advance"); + let sortdb = conf.get_burnchain().open_sortition_db(true).unwrap(); + let tip = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()).unwrap(); + // make sure the tenure was won by RL1 + assert!(tip.sortition, "No sortition was won"); + assert_eq!( + tip.miner_pk_hash.unwrap(), + mining_pkh_1, + "RL1 did not win the sortition" + ); + + // Wait for RL1 to mine the tenure change block + wait_for(30, || { + Ok( + test_observer::get_blocks().last().unwrap()["burn_block_height"] + .as_u64() + .unwrap() + == burn_height_after, + ) + }) + .expect("Timed out waiting for RL1 to mine the tenure change block"); + + // Make the miner stall before broadcasting the block once it has been approved + TEST_P2P_BROADCAST_STALL.set(true); + // TEST_BLOCK_ANNOUNCE_STALL.set(true); + // Make the signers not broadcast the block once it has been approved + TEST_SKIP_BLOCK_BROADCAST.set(true); + + // submit a tx so that the miner will mine a stacks 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, + ); + let tx = submit_tx(&http_origin, &transfer_tx); + info!("Submitted tx {tx} in to mine block N"); + + // Wait for the block with this transfer to be accepted + wait_for(30, || { + Ok(test_observer::get_mined_nakamoto_blocks() + .last() + .unwrap() + .tx_events + .iter() + .any(|t| { + let TransactionEvent::Success(TransactionSuccessEvent { txid, .. }) = t else { + return false; + }; + txid.to_hex() == tx + })) + }) + .expect("Timed out waiting for the transfer tx to be mined"); + + let blocks = test_observer::get_mined_nakamoto_blocks(); + let block_n = blocks.last().expect("No blocks mined"); + signer_test + .wait_for_block_acceptance(30, &block_n.signer_signature_hash, &all_signers) + .expect("Timed out waiting for block acceptance of N"); + + info!("------------------------- RL2 Wins Sortition -------------------------"); + let rl2_commits_before = commits_submitted_rl2.load(Ordering::SeqCst); + let burn_height_before = get_burn_height(); + + info!("Unpausing commits from RL2"); + skip_commit_op_rl2.set(false); + + info!("Waiting for commits from RL2"); + wait_for(30, || { + Ok( + commits_submitted_rl2.load(Ordering::SeqCst) > rl2_commits_before + && commits_submitted_rl2_last_burn_height.load(Ordering::SeqCst) + >= burn_height_before, + ) + }) + .expect("Timed out waiting for miner 2 to submit a commit op"); + + info!("Pausing commits from RL2"); + skip_commit_op_rl2.set(true); + + info!("Make signers ignore all block proposals, so that they don't reject it quickly"); + TEST_IGNORE_ALL_BLOCK_PROPOSALS.set(all_signers.clone()); + + let burn_height_before = get_burn_height(); + let proposals_before = proposed_blocks_rl2.load(Ordering::SeqCst); + info!("Mine RL2 Tenure"); + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 30, + || Ok(get_burn_height() > burn_height_before), + ) + .unwrap(); + + wait_for_chains().expect("Timed out waiting for Rl1 and Rl2 chains to advance"); + let sortdb = conf.get_burnchain().open_sortition_db(true).unwrap(); + let tip = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()).unwrap(); + // make sure the tenure was won by RL2 + assert!(tip.sortition, "No sortition was won"); + assert_eq!( + tip.miner_pk_hash.unwrap(), + mining_pkh_2, + "RL2 did not win the sortition" + ); + + info!("------------------------- RL2 Proposes Block N' -------------------------"); + + wait_for(30, || { + Ok(proposed_blocks_rl2.load(Ordering::SeqCst) > proposals_before) + }) + .expect("Timed out waiting for the block proposal from RL2"); + + info!("------------------------- Block N is Announced -------------------------"); + + let proposals_before = proposed_blocks_rl2.load(Ordering::SeqCst); + TEST_P2P_BROADCAST_STALL.set(false); + + // Wait for RL2's tip to advance to the last block + wait_for(30, || { + let Some(chain_info_2) = get_chain_info_opt(&conf_node_2) else { + return Ok(false); + }; + Ok(chain_info_2.stacks_tip_height == block_n.stacks_height) + }) + .expect("Timed out waiting for RL2 to advance to block N"); + + info!("------------------------- RL2 Proposes Block N+1 -------------------------"); + // Miner 2 should be interrupted from waiting for N' to be accepted when it sees N + + info!("Stop signers from ignoring proposals"); + TEST_IGNORE_ALL_BLOCK_PROPOSALS.set(Vec::new()); + + wait_for(30, || { + Ok(proposed_blocks_rl2.load(Ordering::SeqCst) > proposals_before) + }) + .expect("Timed out waiting for the new block proposal from RL2"); + + info!("------------------------- Signers Accept Block N+1 -------------------------"); + + wait_for(30, || { + let Some(chain_info_2) = get_chain_info_opt(&conf_node_2) else { + return Ok(false); + }; + Ok(chain_info_2.stacks_tip_height == block_n.stacks_height + 1) + }) + .expect("Timed out waiting for RL2 to advance to block N"); + + info!("------------------------- Next Tenure Builds on N+1 -------------------------"); + + let rl1_commits_before = commits_submitted_rl1.load(Ordering::SeqCst); + let rl2_commits_before = commits_submitted_rl2.load(Ordering::SeqCst); + + skip_commit_op_rl1.set(false); + skip_commit_op_rl2.set(false); + + // Wait for both miners to submit block commits + wait_for(30, || { + Ok( + commits_submitted_rl1.load(Ordering::SeqCst) > rl1_commits_before + && commits_submitted_rl2.load(Ordering::SeqCst) > rl2_commits_before, + ) + }) + .expect("Timed out waiting for miners to submit block commits"); + + next_block_and_process_new_stacks_block( + &mut signer_test.running_nodes.btc_regtest_controller, + 30, + &signer_test.running_nodes.coord_channel, + ) + .expect("Timed out waiting for the next block to be mined"); + + wait_for_chains().expect("Timed out waiting for Rl1 and Rl2 chains to advance"); + + info!("------------------------- Shutdown -------------------------"); + signer_test.shutdown(); +} From 99b84136930f12be8f04cf5404fe2107b22fe4c4 Mon Sep 17 00:00:00 2001 From: Brice Dobry Date: Tue, 4 Feb 2025 15:48:51 -0500 Subject: [PATCH 2/7] docs: add changelog entry --- CHANGELOG.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 1f7fce479b..d3b7b6c796 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,6 +11,8 @@ and this project adheres to the versioning scheme outlined in the [README.md](RE ### Changed +- Miner will stop waiting for signatures on a block if the Stacks tip advances (causing the block it had proposed to be invalid). + ### Fixed ## [3.1.0.0.5] From 96bd346c7c6abb9344400bedf10f72435dad3f1a Mon Sep 17 00:00:00 2001 From: Brice Dobry Date: Tue, 4 Feb 2025 17:36:33 -0500 Subject: [PATCH 3/7] chore: remove log and clarify test logs --- testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs | 1 - testnet/stacks-node/src/tests/signer/v0.rs | 3 ++- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs b/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs index a607ee7f9e..e537dc90b0 100644 --- a/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs +++ b/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs @@ -391,7 +391,6 @@ impl SignerCoordinator { SortitionDB::get_canonical_stacks_chain_tip_hash(sortdb.conn()).unwrap(); let canonical_stacks_tip = StacksBlockId::new(&canonical_stacks_tip_ch, &canonical_stacks_tip_bh); - info!("SignCoordinator: Current stacks tip: {canonical_stacks_tip}, parent: {parent_block_id}"); if canonical_stacks_tip != parent_block_id { debug!("SignCoordinator: Exiting due to new stacks tip"); return Err(NakamotoNodeError::StacksTipChanged); diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index 0760550f03..a4bf07b2f0 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -13140,6 +13140,7 @@ fn interrupt_miner_on_new_stacks_tip() { signer_test .wait_for_block_acceptance(30, &block_n.signer_signature_hash, &all_signers) .expect("Timed out waiting for block acceptance of N"); + info!("Block N is {}", block_n.stacks_height); info!("------------------------- RL2 Wins Sortition -------------------------"); let rl2_commits_before = commits_submitted_rl2.load(Ordering::SeqCst); @@ -13225,7 +13226,7 @@ fn interrupt_miner_on_new_stacks_tip() { }; Ok(chain_info_2.stacks_tip_height == block_n.stacks_height + 1) }) - .expect("Timed out waiting for RL2 to advance to block N"); + .expect("Timed out waiting for RL2 to advance to block N+1"); info!("------------------------- Next Tenure Builds on N+1 -------------------------"); From 07b39fbdbfee4cd5aaa15585b53e6eee766831b7 Mon Sep 17 00:00:00 2001 From: Brice Dobry Date: Wed, 5 Feb 2025 10:13:56 -0500 Subject: [PATCH 4/7] fix: test flakiness, ensure proposal is emitted at the correct time --- testnet/stacks-node/src/tests/signer/v0.rs | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index a4bf07b2f0..f6c84594a8 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -13195,8 +13195,9 @@ fn interrupt_miner_on_new_stacks_tip() { info!("------------------------- Block N is Announced -------------------------"); - let proposals_before = proposed_blocks_rl2.load(Ordering::SeqCst); + TEST_BROADCAST_PROPOSAL_STALL.set(true); TEST_P2P_BROADCAST_STALL.set(false); + let proposals_before = proposed_blocks_rl2.load(Ordering::SeqCst); // Wait for RL2's tip to advance to the last block wait_for(30, || { @@ -13212,6 +13213,7 @@ fn interrupt_miner_on_new_stacks_tip() { info!("Stop signers from ignoring proposals"); TEST_IGNORE_ALL_BLOCK_PROPOSALS.set(Vec::new()); + TEST_BROADCAST_PROPOSAL_STALL.set(false); wait_for(30, || { Ok(proposed_blocks_rl2.load(Ordering::SeqCst) > proposals_before) From a420939f766230e4c47b1009e813b5a2a8f3e502 Mon Sep 17 00:00:00 2001 From: Brice Dobry Date: Wed, 5 Feb 2025 10:24:20 -0500 Subject: [PATCH 5/7] fix: Stacks tip check only checks parent tenure This is needed for the case where the miner is knowingly reorging the previous tenure, which is the canonical tip, but this reorg is allowed because of the bad timing of blocks. --- .../src/nakamoto_node/signer_coordinator.rs | 18 ++++++++++++------ 1 file changed, 12 insertions(+), 6 deletions(-) diff --git a/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs b/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs index e537dc90b0..0dcbfa04ad 100644 --- a/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs +++ b/testnet/stacks-node/src/nakamoto_node/signer_coordinator.rs @@ -321,6 +321,10 @@ impl SignerCoordinator { ) })?; + let parent_tenure_header = + NakamotoChainState::get_block_header(chain_state.db(), &parent_block_id)? + .ok_or(NakamotoNodeError::UnexpectedChainState)?; + // this is used to track the start of the waiting cycle let rejections_timer = Instant::now(); loop { @@ -386,12 +390,14 @@ impl SignerCoordinator { )); } - // Check if a new Stacks block has arrived - let (canonical_stacks_tip_ch, canonical_stacks_tip_bh) = - SortitionDB::get_canonical_stacks_chain_tip_hash(sortdb.conn()).unwrap(); - let canonical_stacks_tip = - StacksBlockId::new(&canonical_stacks_tip_ch, &canonical_stacks_tip_bh); - if canonical_stacks_tip != parent_block_id { + // Check if a new Stacks block has arrived in the parent tenure + let highest_in_tenure = + NakamotoChainState::get_highest_known_block_header_in_tenure( + &mut chain_state.index_conn(), + &parent_tenure_header.consensus_hash, + )? + .ok_or(NakamotoNodeError::UnexpectedChainState)?; + if highest_in_tenure.index_block_hash() != parent_block_id { debug!("SignCoordinator: Exiting due to new stacks tip"); return Err(NakamotoNodeError::StacksTipChanged); } From 2f99dde45b049941947fcda506700b1638dbda8d Mon Sep 17 00:00:00 2001 From: Brice Dobry Date: Wed, 5 Feb 2025 20:01:55 -0500 Subject: [PATCH 6/7] fix: resolve merge conflicts --- testnet/stacks-node/src/tests/signer/v0.rs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index dfe787f938..0bddceeaa2 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -11714,7 +11714,7 @@ fn reorg_attempts_activity_timeout_exceeded() { 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); + TEST_BROADCAST_PROPOSAL_STALL.set(true); info!("------------------------- Start Tenure B -------------------------"); let commits_before = signer_test @@ -11752,7 +11752,7 @@ fn reorg_attempts_activity_timeout_exceeded() { // 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); + TEST_BROADCAST_PROPOSAL_STALL.set(false); let block_proposal_n_prime = wait_for_block_proposal().expect("Failed to get block proposal N'"); assert_eq!( @@ -11760,7 +11760,7 @@ fn reorg_attempts_activity_timeout_exceeded() { 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_BROADCAST_PROPOSAL_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)); @@ -11777,7 +11777,7 @@ fn reorg_attempts_activity_timeout_exceeded() { info!("------------------------- Wait for Block N+1 Proposal -------------------------"); test_observer::clear(); - TEST_BROADCAST_STALL.set(false); + TEST_BROADCAST_PROPOSAL_STALL.set(false); wait_for(30, || { let block_proposal_n_1 = wait_for_block_proposal().expect("Failed to get block proposal N+1"); From 5308a99778e7b0155f74691abb9eb0abf63b8b93 Mon Sep 17 00:00:00 2001 From: Brice Dobry Date: Wed, 5 Feb 2025 20:14:27 -0500 Subject: [PATCH 7/7] test: improvements to `interrupt_miner_on_new_stacks_tip` --- testnet/stacks-node/src/tests/signer/v0.rs | 21 +++++++++++++++++---- 1 file changed, 17 insertions(+), 4 deletions(-) diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index 0bddceeaa2..7388349ca6 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -13077,8 +13077,13 @@ fn tenure_extend_cost_threshold() { /// The stacks node is then advanced to Epoch 3.0 boundary to allow block signing. /// /// Test Execution: -/// The node mines 1 stacks block N (all signers sign it). The subsequent block N+1 is proposed, but <30% accept it. The remaining signers -/// do not make a decision on the block. A new tenure begins and the miner proposes a new block N+1' which all signers accept. +/// Miner 1 mines a tenure change block, then mines a second block, block N, +/// but the signers will not broadcast it, and the miner will stall before +/// broadcasting. Miner 2 wins the next sortition and proposes a block N', +/// since it has not seen N, but signers are ignoring proposals so that it is +/// not rejected. Miner 1 then announces N. Miner 2 sees N, stops waiting +/// for signatures on N' and submits a new proposal, N+1, which is accepted. +/// Finally a new tenure arrives and N+2 is mined. /// /// Test Assertion: /// Stacks tip advances to N+1' @@ -13141,6 +13146,7 @@ fn interrupt_miner_on_new_stacks_tip() { config.node.pox_sync_sample_secs = 30; config.miner.block_commit_delay = Duration::from_secs(0); config.miner.tenure_cost_limit_per_block_percentage = None; + config.miner.block_rejection_timeout_steps = [(0, Duration::from_secs(1200))].into(); config.events_observers.retain(|listener| { match std::net::SocketAddr::from_str(&listener.endpoint) { @@ -13330,7 +13336,6 @@ fn interrupt_miner_on_new_stacks_tip() { // Make the miner stall before broadcasting the block once it has been approved TEST_P2P_BROADCAST_STALL.set(true); - // TEST_BLOCK_ANNOUNCE_STALL.set(true); // Make the signers not broadcast the block once it has been approved TEST_SKIP_BLOCK_BROADCAST.set(true); @@ -13482,7 +13487,15 @@ fn interrupt_miner_on_new_stacks_tip() { ) .expect("Timed out waiting for the next block to be mined"); - wait_for_chains().expect("Timed out waiting for Rl1 and Rl2 chains to advance"); + wait_for(30, || { + let Some(chain_info) = get_chain_info_opt(&conf) else { + return Ok(false); + }; + Ok(chain_info.stacks_tip_height == block_n.stacks_height + 2) + }) + .expect("Timed out waiting for height to advance to block N+2"); + + wait_for_chains().expect("Timed out waiting for Rl2 to reach N+2"); info!("------------------------- Shutdown -------------------------"); signer_test.shutdown();