From 559b1d676a8204952c7244e030b76b23b0e11cc6 Mon Sep 17 00:00:00 2001 From: Hank Stoever Date: Thu, 31 Oct 2024 09:43:29 -0700 Subject: [PATCH 1/6] dx: add set/get helper to TestFlag --- .../stacks-node/src/nakamoto_node/relayer.rs | 8 +----- testnet/stacks-node/src/run_loop/neon.rs | 15 ++++++++++- .../src/tests/nakamoto_integrations.rs | 8 +++--- testnet/stacks-node/src/tests/signer/v0.rs | 26 +++++-------------- 4 files changed, 26 insertions(+), 31 deletions(-) diff --git a/testnet/stacks-node/src/nakamoto_node/relayer.rs b/testnet/stacks-node/src/nakamoto_node/relayer.rs index ef01f67f4b..bb03222502 100644 --- a/testnet/stacks-node/src/nakamoto_node/relayer.rs +++ b/testnet/stacks-node/src/nakamoto_node/relayer.rs @@ -1003,13 +1003,7 @@ impl RelayerThread { #[cfg(test)] fn fault_injection_skip_block_commit(&self) -> bool { - self.globals - .counters - .naka_skip_commit_op - .0 - .lock() - .unwrap() - .unwrap_or(false) + self.globals.counters.naka_skip_commit_op.get() } #[cfg(not(test))] diff --git a/testnet/stacks-node/src/run_loop/neon.rs b/testnet/stacks-node/src/run_loop/neon.rs index a18a61988b..887c79b9ba 100644 --- a/testnet/stacks-node/src/run_loop/neon.rs +++ b/testnet/stacks-node/src/run_loop/neon.rs @@ -93,6 +93,19 @@ impl Default for TestFlag { } } +#[cfg(test)] +impl TestFlag { + /// Set the test flag to the given value + pub fn set(&self, value: bool) { + *self.0.lock().unwrap() = Some(value); + } + + /// Get the test flag value. Defaults to false if the flag is not set. + pub fn get(&self) -> bool { + self.0.lock().unwrap().unwrap_or(false) + } +} + #[derive(Clone, Default)] pub struct Counters { pub blocks_processed: RunLoopCounter, @@ -1034,7 +1047,7 @@ impl RunLoop { /// This function will block by looping infinitely. /// It will start the burnchain (separate thread), set-up a channel in /// charge of coordinating the new blocks coming from the burnchain and - /// the nodes, taking turns on tenures. + /// the nodes, taking turns on tenures. /// /// Returns `Option` so that data can be passed to `NakamotoNode` pub fn start( diff --git a/testnet/stacks-node/src/tests/nakamoto_integrations.rs b/testnet/stacks-node/src/tests/nakamoto_integrations.rs index b5140a06ee..adca6411de 100644 --- a/testnet/stacks-node/src/tests/nakamoto_integrations.rs +++ b/testnet/stacks-node/src/tests/nakamoto_integrations.rs @@ -5051,7 +5051,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.0.lock().unwrap().replace(true); + test_skip_commit_op.set(true); TEST_BROADCAST_STALL.lock().unwrap().replace(false); // Wait for a stacks block to be broadcasted. @@ -5104,7 +5104,7 @@ fn forked_tenure_is_ignored() { .expect("Mutex poisoned") .get_stacks_blocks_processed(); next_block_and(&mut btc_regtest_controller, 60, || { - test_skip_commit_op.0.lock().unwrap().replace(false); + test_skip_commit_op.set(false); TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap().replace(false); let commits_count = commits_submitted.load(Ordering::SeqCst); let blocks_count = mined_blocks.load(Ordering::SeqCst); @@ -7054,7 +7054,7 @@ fn continue_tenure_extend() { .get_stacks_blocks_processed(); info!("Pausing commit ops to trigger a tenure extend."); - test_skip_commit_op.0.lock().unwrap().replace(true); + test_skip_commit_op.set(true); next_block_and(&mut btc_regtest_controller, 60, || Ok(true)).unwrap(); @@ -7153,7 +7153,7 @@ fn continue_tenure_extend() { } info!("Resuming commit ops to mine regular tenures."); - test_skip_commit_op.0.lock().unwrap().replace(false); + test_skip_commit_op.set(false); // Mine 15 more regular nakamoto tenures for _i in 0..15 { diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index 234b73684a..e4a4deea37 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -1003,10 +1003,7 @@ fn forked_tenure_testing( signer_test .running_nodes .nakamoto_test_skip_commit_op - .0 - .lock() - .unwrap() - .replace(true); + .set(true); TEST_BROADCAST_STALL.lock().unwrap().replace(false); // Wait for a stacks block to be broadcasted @@ -1083,10 +1080,7 @@ fn forked_tenure_testing( signer_test .running_nodes .nakamoto_test_skip_commit_op - .0 - .lock() - .unwrap() - .replace(false); + .set(false); let commits_count = commits_submitted.load(Ordering::SeqCst); if commits_count > commits_before { @@ -1850,7 +1844,7 @@ fn miner_forking() { let pre_nakamoto_peer_1_height = get_chain_info(&conf).stacks_tip_height; - naka_skip_commit_op.0.lock().unwrap().replace(false); + naka_skip_commit_op.set(true); info!("------------------------- Reached Epoch 3.0 -------------------------"); let mut sortitions_seen = Vec::new(); @@ -1868,7 +1862,7 @@ fn miner_forking() { .running_nodes .btc_regtest_controller .build_next_block(1); - naka_skip_commit_op.0.lock().unwrap().replace(false); + naka_skip_commit_op.set(false); // wait until a commit is submitted by run_loop_2 wait_for(60, || { @@ -1892,7 +1886,7 @@ fn miner_forking() { // block commits from RL2 -- this will block until the start of the next iteration // in this loop. - naka_skip_commit_op.0.lock().unwrap().replace(true); + naka_skip_commit_op.set(true); // ensure RL1 performs an RBF after unblock block broadcast let rl1_commits_before = signer_test .running_nodes @@ -2499,10 +2493,7 @@ fn empty_sortition() { signer_test .running_nodes .nakamoto_test_skip_commit_op - .0 - .lock() - .unwrap() - .replace(true); + .set(true); let blocks_after = signer_test .running_nodes @@ -5120,10 +5111,7 @@ fn continue_after_tenure_extend() { signer_test .running_nodes .nakamoto_test_skip_commit_op - .0 - .lock() - .unwrap() - .replace(true); + .set(true); // It's possible that we have a pending block commit already. // Mine two BTC blocks to "flush" this commit. From f5c8b03e2005c949218fe93a711bc964240f8f66 Mon Sep 17 00:00:00 2001 From: Hank Stoever Date: Thu, 31 Oct 2024 11:23:50 -0700 Subject: [PATCH 2/6] feat: setup test to repro #5400 --- testnet/stacks-node/src/tests/signer/v0.rs | 195 +++++++++++++++++++++ 1 file changed, 195 insertions(+) diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index e4a4deea37..ecb3ac46bd 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -5074,6 +5074,201 @@ fn miner_recovers_when_broadcast_block_delay_across_tenures_occurs() { assert_ne!(block_n_2, block_n); } +/// Test a scenario where: +/// We have one miner. During block A, there is a sortition and a TenureChange. +/// Block B is mined, but it does not contain a TenureChange (ie because a +/// new burn block was mined too quickly). +/// Then block C occurs, which does not have a sortition. +#[test] +#[ignore] +fn continue_after_fast_block_no_sortition() { + 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 _recipient = PrincipalData::from(StacksAddress::burn_address(false)); + let send_amt = 100; + let send_fee = 180; + let mut signer_test: SignerTest = SignerTest::new( + num_signers, + vec![(sender_addr.clone(), (send_amt + send_fee) * 5)], + ); + let timeout = Duration::from_secs(200); + let _coord_channel = signer_test.running_nodes.coord_channel.clone(); + let _http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind); + + signer_test.boot_to_epoch_3(); + + let burnchain = signer_test.running_nodes.conf.get_burnchain(); + let sortdb = burnchain.open_sortition_db(true).unwrap(); + + let get_burn_height = || { + SortitionDB::get_canonical_burn_chain_tip(&sortdb.conn()) + .unwrap() + .block_height + }; + + let all_signers = signer_test + .signer_stacks_private_keys + .iter() + .map(StacksPublicKey::from_private) + .collect::>(); + + let commits_before = signer_test + .running_nodes + .commits_submitted + .load(Ordering::SeqCst); + + info!("------------------------- Mine Normal Tenure -------------------------"); + signer_test.mine_and_verify_confirmed_naka_block(timeout, num_signers); + + let stacks_height_before = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info") + .stacks_tip_height; + + // Wait for a new block commit + wait_for(20, || { + let commits = signer_test + .running_nodes + .commits_submitted + .load(Ordering::SeqCst); + // 2 because we mined one block in the normal tenure + Ok(commits - commits_before >= 2) + }) + .expect("Timed out waiting for a new block commit"); + + // Make all signers ignore block proposals + let ignoring_signers: Vec<_> = all_signers.iter().cloned().collect(); + TEST_REJECT_ALL_BLOCK_PROPOSAL + .lock() + .unwrap() + .replace(ignoring_signers.clone()); + + // Don't make future block commits + signer_test + .running_nodes + .nakamoto_test_skip_commit_op + .set(true); + + let burn_height_before = get_burn_height(); + + let rejections_before = signer_test + .running_nodes + .nakamoto_blocks_rejected + .load(Ordering::SeqCst); + + // Mine a new burn block + info!("------------------------- Starting Tenure B -------------------------"; + "burn_height_before" => burn_height_before, + "rejections_before" => rejections_before, + ); + + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 60, + || Ok(get_burn_height() > burn_height_before), + ) + .unwrap(); + + // assure we have a sortition + let tip = SortitionDB::get_canonical_burn_chain_tip(&sortdb.conn()).unwrap(); + assert!(tip.sortition); + + let burn_height_before = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info") + .burn_block_height; + + info!("----- Waiting for block rejections -----"); + let min_rejections = (num_signers as u64) * 4 / 10; + // Wait until we have some block rejections + wait_for(30, || { + let rejections = signer_test + .running_nodes + .nakamoto_blocks_rejected + .load(Ordering::SeqCst); + let rejections_diff = rejections - rejections_before; + Ok(rejections_diff >= min_rejections) + }) + .expect("Timed out waiting for block rejections"); + + // Miner another block and ensure there is _no_ sortition + info!("------------------------- Mine another block -------------------------"); + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 60, + || { + let burn_height = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info") + .burn_block_height; + Ok(burn_height > burn_height_before) + }, + ) + .unwrap(); + + // Verify that no Stacks blocks have been mined (signers are ignoring) + let stacks_height = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info") + .stacks_tip_height; + assert_eq!(stacks_height, stacks_height_before); + + let stacks_height_before = stacks_height; + + info!("----- Enabling signers to approve proposals -----"; + "stacks_height" => stacks_height_before, + ); + + // Allow signers to respond to proposals again + TEST_REJECT_ALL_BLOCK_PROPOSAL + .lock() + .unwrap() + .replace(Vec::new()); + + wait_for(30, || { + let stacks_height = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info") + .stacks_tip_height; + Ok(stacks_height > stacks_height_before) + }) + .expect("Expected a new Stacks block to be mined"); + + let blocks = test_observer::get_blocks(); + // Debug the last 4 blocks + let blocks = blocks.iter().rev().take(4).rev().collect::>(); + for block in blocks { + println!("\n\n"); + info!("Block: {}", serde_json::to_string_pretty(&block).unwrap()); + let transactions = block.get("transactions").unwrap().as_array().unwrap(); + for tx in transactions.iter().rev() { + let raw_tx = tx.get("raw_tx").unwrap().as_str().unwrap(); + if raw_tx != "0x00" { + let tx_bytes = hex_bytes(&raw_tx[2..]).unwrap(); + let parsed = + StacksTransaction::consensus_deserialize(&mut tx_bytes.as_slice()).unwrap(); + info!("Tx: {}", serde_json::to_string_pretty(&parsed).unwrap()); + } + } + } +} + #[test] #[ignore] /// Test that we can mine a tenure extend and then continue mining afterwards. From 1aa67938803013cd6d635dfd0e6794920aa8921c Mon Sep 17 00:00:00 2001 From: Jacinta Ferrant Date: Tue, 5 Nov 2024 10:56:25 -0800 Subject: [PATCH 3/6] Apply clippy Signed-off-by: Jacinta Ferrant --- 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 ea24d24a5b..c41dd110e9 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -5044,7 +5044,7 @@ fn continue_after_fast_block_no_sortition() { let send_fee = 180; let mut signer_test: SignerTest = SignerTest::new( num_signers, - vec![(sender_addr.clone(), (send_amt + send_fee) * 5)], + vec![(sender_addr, (send_amt + send_fee) * 5)], ); let timeout = Duration::from_secs(200); let _coord_channel = signer_test.running_nodes.coord_channel.clone(); @@ -5056,7 +5056,7 @@ fn continue_after_fast_block_no_sortition() { let sortdb = burnchain.open_sortition_db(true).unwrap(); let get_burn_height = || { - SortitionDB::get_canonical_burn_chain_tip(&sortdb.conn()) + SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()) .unwrap() .block_height }; @@ -5093,7 +5093,7 @@ fn continue_after_fast_block_no_sortition() { .expect("Timed out waiting for a new block commit"); // Make all signers ignore block proposals - let ignoring_signers: Vec<_> = all_signers.iter().cloned().collect(); + let ignoring_signers = all_signers.to_vec(); TEST_REJECT_ALL_BLOCK_PROPOSAL .lock() .unwrap() @@ -5126,7 +5126,7 @@ fn continue_after_fast_block_no_sortition() { .unwrap(); // assure we have a sortition - let tip = SortitionDB::get_canonical_burn_chain_tip(&sortdb.conn()).unwrap(); + let tip = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()).unwrap(); assert!(tip.sortition); let burn_height_before = signer_test From d0355cb1a9f6e6024647e15f98585b39ed8c3370 Mon Sep 17 00:00:00 2001 From: Jacinta Ferrant Date: Tue, 5 Nov 2024 12:18:53 -0800 Subject: [PATCH 4/6] Use multiple miners to trigger weird chain stall Signed-off-by: Jacinta Ferrant --- testnet/stacks-node/src/tests/signer/v0.rs | 309 ++++++++++++++++----- 1 file changed, 239 insertions(+), 70 deletions(-) diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index c41dd110e9..24647910f4 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -5030,50 +5030,178 @@ fn continue_after_fast_block_no_sortition() { 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 _recipient = PrincipalData::from(StacksAddress::burn_address(false)); let send_amt = 100; let send_fee = 180; - let mut signer_test: SignerTest = SignerTest::new( + let num_txs = 5; + + 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(); + + let max_nakamoto_tenures = 30; + + info!("------------------------- Test Setup -------------------------"); + // 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) * 5)], + vec![(sender_addr, (send_amt + send_fee) * num_txs)], + |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(); + }, + |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.miner.wait_on_interim_blocks = Duration::from_secs(5); + config.node.pox_sync_sample_secs = 30; + config.burnchain.pox_reward_length = Some(max_nakamoto_tenures); + + 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.events_observers.retain(|listener| { + let Ok(addr) = std::net::SocketAddr::from_str(&listener.endpoint) else { + warn!( + "Cannot parse {} to a socket, assuming it isn't a signer-listener binding", + listener.endpoint + ); + return true; + }; + if addr.port() % 2 == 0 || addr.port() == test_observer::EVENT_OBSERVER_PORT { + return true; + } + node_2_listeners.push(listener.clone()); + false + }) + }, + Some(vec![btc_miner_1_pk, btc_miner_2_pk]), + None, ); - let timeout = Duration::from_secs(200); - let _coord_channel = signer_test.running_nodes.coord_channel.clone(); - let _http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind); + let conf = signer_test.running_nodes.conf.clone(); + let mut conf_node_2 = conf.clone(); + conf_node_2.node.rpc_bind = format!("{localhost}:{node_2_rpc}"); + 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.clone(); + conf_node_2.miner.mining_key = Some(Secp256k1PrivateKey::from_seed(&[2])); + conf_node_2.node.miner = true; + conf_node_2.events_observers.clear(); + conf_node_2.events_observers.extend(node_2_listeners); + 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 run_loop_stopper_2 = run_loop_2.get_termination_switch(); + let rl2_coord_channels = run_loop_2.coordinator_channels(); + let Counters { + naka_submitted_commits: rl2_commits, + naka_skip_commit_op: rl2_skip_commit_op, + naka_mined_blocks: blocks_mined2, + .. + } = run_loop_2.counters(); + + let rl1_commits = signer_test.running_nodes.commits_submitted.clone(); + let blocks_mined1 = signer_test.running_nodes.nakamoto_blocks_mined.clone(); + + info!("------------------------- Pause Miner 2's Block Commits -------------------------"); + + rl2_skip_commit_op.set(true); + let run_loop_2_thread = thread::Builder::new() + .name("run_loop_2".into()) + .spawn(move || run_loop_2.start(None, 0)) + .unwrap(); 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"); + + info!("------------------------- Reached Epoch 3.0 -------------------------"); + let burnchain = signer_test.running_nodes.conf.get_burnchain(); let sortdb = burnchain.open_sortition_db(true).unwrap(); + let all_signers = signer_test + .signer_stacks_private_keys + .iter() + .map(StacksPublicKey::from_private) + .collect::>(); let get_burn_height = || { SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()) .unwrap() .block_height }; + let starting_peer_height = get_chain_info(&conf).stacks_tip_height; + let starting_burn_height = get_burn_height(); + let mut btc_blocks_mined = 0; - let all_signers = signer_test - .signer_stacks_private_keys - .iter() - .map(StacksPublicKey::from_private) - .collect::>(); + info!("------------------------- Miner 1 Mines a Normal Tenure A -------------------------"); + let blocks_processed_before_1 = blocks_mined1.load(Ordering::SeqCst); + let commits_before_1 = rl1_commits.load(Ordering::SeqCst); - let commits_before = signer_test - .running_nodes - .commits_submitted - .load(Ordering::SeqCst); + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 60, + || Ok(rl1_commits.load(Ordering::SeqCst) > commits_before_1), + ) + .unwrap(); + btc_blocks_mined += 1; - info!("------------------------- Mine Normal Tenure -------------------------"); - signer_test.mine_and_verify_confirmed_naka_block(timeout, num_signers); + // wait for the new block to be processed + wait_for(60, || { + Ok(blocks_mined1.load(Ordering::SeqCst) > blocks_processed_before_1) + }) + .unwrap(); + + info!( + "Nakamoto blocks mined: {}", + blocks_mined1.load(Ordering::SeqCst) + ); let stacks_height_before = signer_test .stacks_client @@ -5081,17 +5209,6 @@ fn continue_after_fast_block_no_sortition() { .expect("Failed to get peer info") .stacks_tip_height; - // Wait for a new block commit - wait_for(20, || { - let commits = signer_test - .running_nodes - .commits_submitted - .load(Ordering::SeqCst); - // 2 because we mined one block in the normal tenure - Ok(commits - commits_before >= 2) - }) - .expect("Timed out waiting for a new block commit"); - // Make all signers ignore block proposals let ignoring_signers = all_signers.to_vec(); TEST_REJECT_ALL_BLOCK_PROPOSAL @@ -5099,21 +5216,23 @@ fn continue_after_fast_block_no_sortition() { .unwrap() .replace(ignoring_signers.clone()); - // Don't make future block commits + // Make sure miner 1 doesn't submit a block commit for the next tenure signer_test .running_nodes .nakamoto_test_skip_commit_op .set(true); - let burn_height_before = get_burn_height(); - let rejections_before = signer_test .running_nodes .nakamoto_blocks_rejected .load(Ordering::SeqCst); + // Unpause miner 2's block commits + rl2_skip_commit_op.set(false); + // Mine a new burn block - info!("------------------------- Starting Tenure B -------------------------"; + let burn_height_before = get_burn_height(); + info!("------------------------- Miner 2 Mines an Empty Tenure B -------------------------"; "burn_height_before" => burn_height_before, "rejections_before" => rejections_before, ); @@ -5124,17 +5243,12 @@ fn continue_after_fast_block_no_sortition() { || Ok(get_burn_height() > burn_height_before), ) .unwrap(); + btc_blocks_mined += 1; // assure we have a sortition let tip = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()).unwrap(); assert!(tip.sortition); - let burn_height_before = signer_test - .stacks_client - .get_peer_info() - .expect("Failed to get peer info") - .burn_block_height; - info!("----- Waiting for block rejections -----"); let min_rejections = (num_signers as u64) * 4 / 10; // Wait until we have some block rejections @@ -5148,52 +5262,76 @@ fn continue_after_fast_block_no_sortition() { }) .expect("Timed out waiting for block rejections"); + // Make miner 2 also fail to submit commits + rl2_skip_commit_op.set(true); // Miner another block and ensure there is _no_ sortition - info!("------------------------- Mine another block -------------------------"); - next_block_and( - &mut signer_test.running_nodes.btc_regtest_controller, - 60, - || { - let burn_height = signer_test - .stacks_client - .get_peer_info() - .expect("Failed to get peer info") - .burn_block_height; - Ok(burn_height > burn_height_before) - }, - ) - .unwrap(); + info!("------------------------- Mine Burn Block with No Sortition -------------------------"); + let blocks_processed_before_1 = blocks_mined1.load(Ordering::SeqCst); + let blocks_processed_before_2 = blocks_mined2.load(Ordering::SeqCst); + let burn_height_before = get_burn_height(); + let commits_before_1 = rl1_commits.load(Ordering::SeqCst); + let commits_before_2 = rl2_commits.load(Ordering::SeqCst); - // Verify that no Stacks blocks have been mined (signers are ignoring) + signer_test + .running_nodes + .btc_regtest_controller + .build_next_block(1); + btc_blocks_mined += 1; + + wait_for(30, || Ok(get_burn_height() > burn_height_before)).unwrap(); + + assert_eq!(rl1_commits.load(Ordering::SeqCst), commits_before_1); + assert_eq!(rl2_commits.load(Ordering::SeqCst), commits_before_2); + assert_eq!( + blocks_mined1.load(Ordering::SeqCst), + blocks_processed_before_1 + ); + assert_eq!( + blocks_mined2.load(Ordering::SeqCst), + blocks_processed_before_2 + ); + + // Verify that no Stacks blocks have been mined (signers are ignoring) and no commits have been submitted by either miner let stacks_height = signer_test .stacks_client .get_peer_info() .expect("Failed to get peer info") .stacks_tip_height; assert_eq!(stacks_height, stacks_height_before); - let stacks_height_before = stacks_height; + info!( + "------------------------- Miner 2 Attempts to Mine a Tenure C -------------------------" + ); + + let blocks_processed_before_2 = blocks_mined2.load(Ordering::SeqCst); + let burn_height_before = get_burn_height(); + let commits_before_2 = rl2_commits.load(Ordering::SeqCst); + info!("----- Enabling signers to approve proposals -----"; "stacks_height" => stacks_height_before, ); - // Allow signers to respond to proposals again TEST_REJECT_ALL_BLOCK_PROPOSAL .lock() .unwrap() .replace(Vec::new()); - wait_for(30, || { - let stacks_height = signer_test - .stacks_client - .get_peer_info() - .expect("Failed to get peer info") - .stacks_tip_height; - Ok(stacks_height > stacks_height_before) - }) - .expect("Expected a new Stacks block to be mined"); + // Unpause miner 2's block commits + rl2_skip_commit_op.set(false); + // TODO: can combine the following three wait_for and also the next_block_and once fixed + next_block_and( + &mut signer_test.running_nodes.btc_regtest_controller, + 60, + || Ok(rl2_commits.load(Ordering::SeqCst) > commits_before_2), + ) + .unwrap(); + btc_blocks_mined += 1; + + wait_for(30, || Ok(get_burn_height() > burn_height_before)).unwrap(); + + // TODO DELETE THIS let blocks = test_observer::get_blocks(); // Debug the last 4 blocks let blocks = blocks.iter().rev().take(4).rev().collect::>(); @@ -5211,6 +5349,37 @@ fn continue_after_fast_block_no_sortition() { } } } + + wait_for(30, || { + Ok(blocks_mined2.load(Ordering::SeqCst) > blocks_processed_before_2) + }) + .expect("Timed out waiting for block to be mined and processed"); + + wait_for(30, || { + let stacks_height = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info") + .stacks_tip_height; + Ok(stacks_height > stacks_height_before) + }) + .expect("Expected a new Stacks block to be mined"); + + let peer_info = signer_test + .stacks_client + .get_peer_info() + .expect("Failed to get peer info"); + + assert_eq!(get_burn_height(), starting_burn_height + btc_blocks_mined); + // We only successfully mine 2 stacks block in this test + assert_eq!(peer_info.stacks_tip_height, starting_peer_height + 2); + rl2_coord_channels + .lock() + .expect("Mutex poisoned") + .stop_chains_coordinator(); + run_loop_stopper_2.store(false, Ordering::SeqCst); + run_loop_2_thread.join().unwrap(); + signer_test.shutdown(); } #[test] From e459b8cf2f51b05d1e26b4fe612534fe09f4ed0c Mon Sep 17 00:00:00 2001 From: Jacinta Ferrant Date: Tue, 5 Nov 2024 12:28:04 -0800 Subject: [PATCH 5/6] Update test description Signed-off-by: Jacinta Ferrant --- testnet/stacks-node/src/tests/signer/v0.rs | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index 24647910f4..bad6bc6db7 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -5019,10 +5019,13 @@ fn miner_recovers_when_broadcast_block_delay_across_tenures_occurs() { } /// Test a scenario where: -/// We have one miner. During block A, there is a sortition and a TenureChange. -/// Block B is mined, but it does not contain a TenureChange (ie because a -/// new burn block was mined too quickly). -/// Then block C occurs, which does not have a sortition. +/// Two miners boot to Nakamoto. +/// Miner 1 wins the first Nakamoto tenure A. Miner 1 mines a regular stacks block N. +/// Miner 2 wins the second Nakamoto tenure B and proposes block N+1, but it is rejected by the signers. +/// An empty burn block is mined +/// Miner 2 wins the third Nakamoto tenure C. Miner 2 proposes a block N+1' which all signers accept. +/// Asserts: +/// - The stacks tip advances to N+1' #[test] #[ignore] fn continue_after_fast_block_no_sortition() { From 25cd9d986d942d0ce0688ade209d204246984c6d Mon Sep 17 00:00:00 2001 From: Jacinta Ferrant Date: Tue, 5 Nov 2024 14:22:26 -0800 Subject: [PATCH 6/6] Update test to be more streamlined and ensure no extra commits make it in Signed-off-by: Jacinta Ferrant --- testnet/stacks-node/src/tests/signer/v0.rs | 164 ++++++++++++--------- 1 file changed, 98 insertions(+), 66 deletions(-) diff --git a/testnet/stacks-node/src/tests/signer/v0.rs b/testnet/stacks-node/src/tests/signer/v0.rs index bad6bc6db7..80aca7291e 100644 --- a/testnet/stacks-node/src/tests/signer/v0.rs +++ b/testnet/stacks-node/src/tests/signer/v0.rs @@ -5023,7 +5023,9 @@ fn miner_recovers_when_broadcast_block_delay_across_tenures_occurs() { /// Miner 1 wins the first Nakamoto tenure A. Miner 1 mines a regular stacks block N. /// Miner 2 wins the second Nakamoto tenure B and proposes block N+1, but it is rejected by the signers. /// An empty burn block is mined -/// Miner 2 wins the third Nakamoto tenure C. Miner 2 proposes a block N+1' which all signers accept. +/// TODO: which behaviour do we want to enforce? Should we allow both? If so, we should force both explicitly +/// Miner 1 should issue a tenure extend and propose block N+1' which is accepted by the signers OR +/// Miner 2 should issue a new TenureChangePayload followed by a TenureExtend. /// Asserts: /// - The stacks tip advances to N+1' #[test] @@ -5034,11 +5036,13 @@ fn continue_after_fast_block_no_sortition() { } let num_signers = 5; + let recipient = PrincipalData::from(StacksAddress::burn_address(false)); 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 num_txs = 1; + let sender_nonce = 0; let btc_miner_1_seed = vec![1, 1, 1, 1]; let btc_miner_2_seed = vec![2, 2, 2, 2]; @@ -5129,6 +5133,7 @@ fn continue_after_fast_block_no_sortition() { conf.burnchain.chain_id, conf.burnchain.peer_version, ); + let http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind); let mut run_loop_2 = boot_nakamoto::BootRunLoop::new(conf_node_2.clone()).unwrap(); let run_loop_stopper_2 = run_loop_2.get_termination_switch(); @@ -5145,6 +5150,7 @@ fn continue_after_fast_block_no_sortition() { info!("------------------------- Pause Miner 2's Block Commits -------------------------"); + // Make sure Miner 2 cannot win a sortition at first. rl2_skip_commit_op.set(true); let run_loop_2_thread = thread::Builder::new() .name("run_loop_2".into()) @@ -5185,16 +5191,23 @@ fn continue_after_fast_block_no_sortition() { info!("------------------------- Miner 1 Mines a Normal Tenure A -------------------------"); let blocks_processed_before_1 = blocks_mined1.load(Ordering::SeqCst); - let commits_before_1 = rl1_commits.load(Ordering::SeqCst); + info!("------------------------- Pause Miner 1's Block Commit -------------------------"); + // Make sure miner 1 doesn't submit a block commit for the next tenure BEFORE mining the bitcoin block + signer_test + .running_nodes + .nakamoto_test_skip_commit_op + .set(true); - next_block_and( - &mut signer_test.running_nodes.btc_regtest_controller, - 60, - || Ok(rl1_commits.load(Ordering::SeqCst) > commits_before_1), - ) - .unwrap(); + signer_test + .running_nodes + .btc_regtest_controller + .build_next_block(1); btc_blocks_mined += 1; + // assure we have a sortition + let tip = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()).unwrap(); + assert!(tip.sortition); + // wait for the new block to be processed wait_for(60, || { Ok(blocks_mined1.load(Ordering::SeqCst) > blocks_processed_before_1) @@ -5212,6 +5225,7 @@ fn continue_after_fast_block_no_sortition() { .expect("Failed to get peer info") .stacks_tip_height; + info!("------------------------- Make Signers Reject All Subsequent Proposals -------------------------"); // Make all signers ignore block proposals let ignoring_signers = all_signers.to_vec(); TEST_REJECT_ALL_BLOCK_PROPOSAL @@ -5219,21 +5233,27 @@ fn continue_after_fast_block_no_sortition() { .unwrap() .replace(ignoring_signers.clone()); - // Make sure miner 1 doesn't submit a block commit for the next tenure - signer_test - .running_nodes - .nakamoto_test_skip_commit_op - .set(true); - + info!("------------------------- Unpause Miner 2's Block Commits -------------------------"); let rejections_before = signer_test .running_nodes .nakamoto_blocks_rejected .load(Ordering::SeqCst); + let rl2_commits_before = rl2_commits.load(Ordering::SeqCst); // Unpause miner 2's block commits rl2_skip_commit_op.set(false); - // Mine a new burn block + info!("------------------------- Wait for Miner 2's Block Commit Submission -------------------------"); + // Ensure the miner 2 submits a block commit before mining the bitcoin block + wait_for(30, || { + Ok(rl2_commits.load(Ordering::SeqCst) > rl2_commits_before) + }) + .unwrap(); + + // Make miner 2 also fail to submit any FURTHER block commits + info!("------------------------- Pause Miner 2's Block Commits -------------------------"); + rl2_skip_commit_op.set(true); + let burn_height_before = get_burn_height(); info!("------------------------- Miner 2 Mines an Empty Tenure B -------------------------"; "burn_height_before" => burn_height_before, @@ -5253,20 +5273,29 @@ fn continue_after_fast_block_no_sortition() { assert!(tip.sortition); info!("----- Waiting for block rejections -----"); - let min_rejections = (num_signers as u64) * 4 / 10; + let min_rejections = num_signers * 4 / 10; // Wait until we have some block rejections wait_for(30, || { - let rejections = signer_test - .running_nodes - .nakamoto_blocks_rejected - .load(Ordering::SeqCst); - let rejections_diff = rejections - rejections_before; - Ok(rejections_diff >= min_rejections) + std::thread::sleep(Duration::from_secs(1)); + let chunks = test_observer::get_stackerdb_chunks(); + let rejections: Vec<_> = chunks + .into_iter() + .flat_map(|chunk| chunk.modified_slots) + .filter(|chunk| { + let Ok(message) = SignerMessage::consensus_deserialize(&mut chunk.data.as_slice()) + else { + return false; + }; + matches!( + message, + SignerMessage::BlockResponse(BlockResponse::Rejected(_)) + ) + }) + .collect(); + Ok(rejections.len() >= min_rejections) }) .expect("Timed out waiting for block rejections"); - // Make miner 2 also fail to submit commits - rl2_skip_commit_op.set(true); // Miner another block and ensure there is _no_ sortition info!("------------------------- Mine Burn Block with No Sortition -------------------------"); let blocks_processed_before_1 = blocks_mined1.load(Ordering::SeqCst); @@ -5294,6 +5323,10 @@ fn continue_after_fast_block_no_sortition() { blocks_processed_before_2 ); + // assure we have NO sortition + let tip = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn()).unwrap(); + assert!(!tip.sortition); + // Verify that no Stacks blocks have been mined (signers are ignoring) and no commits have been submitted by either miner let stacks_height = signer_test .stacks_client @@ -5303,56 +5336,32 @@ fn continue_after_fast_block_no_sortition() { assert_eq!(stacks_height, stacks_height_before); let stacks_height_before = stacks_height; - info!( - "------------------------- Miner 2 Attempts to Mine a Tenure C -------------------------" - ); - let blocks_processed_before_2 = blocks_mined2.load(Ordering::SeqCst); - let burn_height_before = get_burn_height(); - let commits_before_2 = rl2_commits.load(Ordering::SeqCst); - info!("----- Enabling signers to approve proposals -----"; "stacks_height" => stacks_height_before, ); + + let nmb_old_blocks = test_observer::get_blocks().len(); // Allow signers to respond to proposals again TEST_REJECT_ALL_BLOCK_PROPOSAL .lock() .unwrap() .replace(Vec::new()); - // Unpause miner 2's block commits - rl2_skip_commit_op.set(false); - - // TODO: can combine the following three wait_for and also the next_block_and once fixed - next_block_and( - &mut signer_test.running_nodes.btc_regtest_controller, - 60, - || Ok(rl2_commits.load(Ordering::SeqCst) > commits_before_2), - ) - .unwrap(); - btc_blocks_mined += 1; - - wait_for(30, || Ok(get_burn_height() > burn_height_before)).unwrap(); - - // TODO DELETE THIS - let blocks = test_observer::get_blocks(); - // Debug the last 4 blocks - let blocks = blocks.iter().rev().take(4).rev().collect::>(); - for block in blocks { - println!("\n\n"); - info!("Block: {}", serde_json::to_string_pretty(&block).unwrap()); - let transactions = block.get("transactions").unwrap().as_array().unwrap(); - for tx in transactions.iter().rev() { - let raw_tx = tx.get("raw_tx").unwrap().as_str().unwrap(); - if raw_tx != "0x00" { - let tx_bytes = hex_bytes(&raw_tx[2..]).unwrap(); - let parsed = - StacksTransaction::consensus_deserialize(&mut tx_bytes.as_slice()).unwrap(); - info!("Tx: {}", serde_json::to_string_pretty(&parsed).unwrap()); - } - } - } + // submit a tx so that the miner will mine an extra block just in case due to timing constraints, the first block with the tenure extend was + // rejected already by the signers + 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); + // TODO: combine these wait fors once fixed code + // wait for the new block to be processed wait_for(30, || { Ok(blocks_mined2.load(Ordering::SeqCst) > blocks_processed_before_2) }) @@ -5368,14 +5377,37 @@ fn continue_after_fast_block_no_sortition() { }) .expect("Expected a new Stacks block to be mined"); + wait_for( + 30, + || Ok(test_observer::get_blocks().len() > nmb_old_blocks), + ) + .expect("Timed out waiting for test observer to see new block"); + + let blocks = test_observer::get_blocks(); + let tenure_extend_block = if nmb_old_blocks + 1 == test_observer::get_blocks().len() { + blocks.last().unwrap() + } else { + &blocks[blocks.len() - 2] + }; + let transactions = tenure_extend_block["transactions"].as_array().unwrap(); + let tx = transactions.first().expect("No transactions in block"); + let raw_tx = tx["raw_tx"].as_str().unwrap(); + let tx_bytes = hex_bytes(&raw_tx[2..]).unwrap(); + let parsed = StacksTransaction::consensus_deserialize(&mut &tx_bytes[..]).unwrap(); + match &parsed.payload { + TransactionPayload::TenureChange(payload) + if payload.cause == TenureChangeCause::Extended => {} + _ => panic!("Expected tenure extend transaction, got {parsed:?}"), + }; + let peer_info = signer_test .stacks_client .get_peer_info() .expect("Failed to get peer info"); assert_eq!(get_burn_height(), starting_burn_height + btc_blocks_mined); - // We only successfully mine 2 stacks block in this test - assert_eq!(peer_info.stacks_tip_height, starting_peer_height + 2); + // We successfully mine at least 2 stacks block in this test + assert!(peer_info.stacks_tip_height >= starting_peer_height + 2); rl2_coord_channels .lock() .expect("Mutex poisoned")