Merge branch 'fix/forked-tenure-okay-ci-test' into fix/5642

stacks-signer/src/v0/signer.rs

@@ -618,6 +618,11 @@ impl Signer {
                             "proposed_block_signer_sighash" => %signer_signature_hash,
                             "proposed_chain_length" => proposed_block.header.chain_length,
                             "expected_at_least" => last_block_info.block.header.chain_length + 1,
+                            "last_block_info.block.header.consensus_hash" => %last_block_info.block.header.consensus_hash,
+                            "proposed_block_consensus_hash" => %proposed_block_consensus_hash,
+                            "last_block_info.state" => %last_block_info.state,
+                            "non_reorgable_block" => non_reorgable_block,
+                            "reorg_timeout_exceeded" => reorg_timeout_exceeded
                         );
                         return Some(self.create_block_rejection(
                             RejectCode::SortitionViewMismatch,

stackslib/src/net/p2p.rs

@@ -5219,7 +5219,7 @@ impl PeerNetwork {
         poll_timeout: u64,
         handler_args: &RPCHandlerArgs,
     ) -> Result<NetworkResult, net_error> {
-        debug!(">>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for {}) >>>>>>>>>>>>>>>>>>>>>>>>>>>>", poll_timeout);
+        debug!(">>>>>>>>>>>>>>>>>>>>>>> Begin Network Dispatch (poll for {}, ibd={}) >>>>>>>>>>>>>>>>>>>>>>>>>>>>", poll_timeout, ibd);
         let mut poll_states = match self.network {
             None => {
                 debug!("{:?}: network not connected", &self.local_peer);

stackslib/src/net/relay.rs

@@ -75,6 +75,10 @@ pub mod fault_injection {
     use std::path::Path;
 
     static IGNORE_BLOCK: std::sync::Mutex<Option<(u64, String)>> = std::sync::Mutex::new(None);
+    pub static TEST_BLOCK_ANNOUNCE_STALL: std::sync::Mutex<Option<bool>> =
+        std::sync::Mutex::new(None);
+    pub static TEST_BLOCK_ANNOUNCE_SKIP: std::sync::Mutex<Option<bool>> =
+        std::sync::Mutex::new(None);
 
     pub fn ignore_block(height: u64, working_dir: &str) -> bool {
         if let Some((ignore_height, ignore_dir)) = &*IGNORE_BLOCK.lock().unwrap() {
@@ -102,6 +106,34 @@ pub mod fault_injection {
         warn!("Fault injection: clear ignore block");
         *IGNORE_BLOCK.lock().unwrap() = None;
     }
+
+    pub fn stacks_announce_is_blocked() -> bool {
+        *TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap() == Some(true)
+    }
+
+    pub fn stacks_announce_is_skipped() -> bool {
+        *TEST_BLOCK_ANNOUNCE_SKIP.lock().unwrap() == Some(true)
+    }
+
+    pub fn no_stacks_announce() -> bool {
+        stacks_announce_is_blocked() || stacks_announce_is_skipped()
+    }
+
+    pub fn block_stacks_announce() {
+        *TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap() = Some(true);
+    }
+
+    pub fn unblock_stacks_announce() {
+        *TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap() = None;
+    }
+
+    pub fn skip_stacks_announce() {
+        *TEST_BLOCK_ANNOUNCE_SKIP.lock().unwrap() = Some(true);
+    }
+
+    pub fn unskip_stacks_announce() {
+        *TEST_BLOCK_ANNOUNCE_SKIP.lock().unwrap() = None;
+    }
 }
 
 #[cfg(not(any(test, feature = "testing")))]
@@ -113,6 +145,10 @@ pub mod fault_injection {
     pub fn set_ignore_block(_height: u64, _working_dir: &str) {}
 
     pub fn clear_ignore_block() {}
+
+    pub fn no_stacks_announce() -> bool {
+        false
+    }
 }
 
 pub struct Relayer {
@@ -1085,7 +1121,9 @@ impl Relayer {
         if accepted {
             info!("{}", &accept_msg);
             if let Some(coord_comms) = coord_comms {
-                if !coord_comms.announce_new_stacks_block() {
+                if !fault_injection::no_stacks_announce()
+                    && !coord_comms.announce_new_stacks_block()
+                {
                     return Err(chainstate_error::NetError(net_error::CoordinatorClosed));
                 }
             }
@@ -2089,7 +2127,9 @@ impl Relayer {
                 new_confirmed_microblocks.len()
             );
             if let Some(coord_comms) = coord_comms {
-                if !coord_comms.announce_new_stacks_block() {
+                if !fault_injection::no_stacks_announce()
+                    && !coord_comms.announce_new_stacks_block()
+                {
                     return Err(net_error::CoordinatorClosed);
                 }
             }
@@ -2178,7 +2218,9 @@ impl Relayer {
         }
         if !http_uploaded_blocks.is_empty() {
             coord_comms.inspect(|comm| {
-                comm.announce_new_stacks_block();
+                if !fault_injection::no_stacks_announce() {
+                    comm.announce_new_stacks_block();
+                }
             });
         }
 

testnet/stacks-node/src/nakamoto_node.rs

@@ -309,14 +309,12 @@ impl StacksNode {
 
     /// Process a state coming from the burnchain, by extracting the validated KeyRegisterOp
     /// and inspecting if a sortition was won.
-    /// `ibd`: boolean indicating whether or not we are in the initial block download
     /// Called from the main thread.
     pub fn process_burnchain_state(
         &mut self,
         config: &Config,
         sortdb: &SortitionDB,
         sort_id: &SortitionId,
-        ibd: bool,
     ) -> Result<(), Error> {
         let ic = sortdb.index_conn();
 
@@ -370,7 +368,6 @@ impl StacksNode {
             "burn_height" => block_height,
             "leader_keys_count" => num_key_registers,
             "block_commits_count" => num_block_commits,
-            "in_initial_block_download?" => ibd,
         );
 
         self.globals.set_last_sortition(block_snapshot.clone());

testnet/stacks-node/src/nakamoto_node/miner.rs

@@ -39,7 +39,7 @@ use stacks::chainstate::stacks::{
 };
 use stacks::net::p2p::NetworkHandle;
 use stacks::net::stackerdb::StackerDBs;
-use stacks::net::{NakamotoBlocksData, StacksMessageType};
+use stacks::net::{relay, NakamotoBlocksData, StacksMessageType};
 use stacks::util::get_epoch_time_secs;
 use stacks::util::secp256k1::MessageSignature;
 use stacks_common::types::chainstate::{StacksAddress, StacksBlockId};
@@ -59,8 +59,6 @@ pub static TEST_MINE_STALL: std::sync::Mutex<Option<bool>> = std::sync::Mutex::n
 #[cfg(test)]
 pub static TEST_BROADCAST_STALL: std::sync::Mutex<Option<bool>> = std::sync::Mutex::new(None);
 #[cfg(test)]
-pub static TEST_BLOCK_ANNOUNCE_STALL: std::sync::Mutex<Option<bool>> = std::sync::Mutex::new(None);
-#[cfg(test)]
 pub static TEST_SKIP_P2P_BROADCAST: std::sync::Mutex<Option<bool>> = std::sync::Mutex::new(None);
 
 /// If the miner was interrupted while mining a block, how long should the
@@ -219,15 +217,15 @@ impl BlockMinerThread {
 
     #[cfg(test)]
     fn fault_injection_block_announce_stall(new_block: &NakamotoBlock) {
-        if *TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap() == Some(true) {
+        if relay::fault_injection::stacks_announce_is_blocked() {
             // Do an extra check just so we don't log EVERY time.
             warn!("Fault injection: Block announcement 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_BLOCK_ANNOUNCE_STALL.lock().unwrap() == Some(true) {
+            while relay::fault_injection::stacks_announce_is_blocked() {
                 std::thread::sleep(std::time::Duration::from_millis(10));
             }
             info!("Fault injection: Block announcement is no longer stalled due to testing directive.";
@@ -495,7 +493,11 @@ impl BlockMinerThread {
 
             // wake up chains coordinator
             Self::fault_injection_block_announce_stall(&new_block);
-            self.globals.coord().announce_new_stacks_block();
+            if !relay::fault_injection::stacks_announce_is_skipped() {
+                self.globals.coord().announce_new_stacks_block();
+            } else {
+                info!("Miner: skip block announce due to fault injection directive");
+            }
 
             self.last_block_mined = Some(new_block);
             self.mined_blocks += 1;

testnet/stacks-node/src/nakamoto_node/relayer.rs

@@ -43,7 +43,7 @@ use stacks::monitoring::increment_stx_blocks_mined_counter;
 use stacks::net::db::LocalPeer;
 use stacks::net::p2p::NetworkHandle;
 use stacks::net::relay::Relayer;
-use stacks::net::NetworkResult;
+use stacks::net::{relay, NetworkResult};
 use stacks_common::types::chainstate::{
     BlockHeaderHash, BurnchainHeaderHash, StacksBlockId, StacksPublicKey, VRFSeed,
 };
@@ -551,7 +551,9 @@ impl RelayerThread {
         self.globals.counters.bump_blocks_processed();
 
         // there may be a bufferred stacks block to process, so wake up the coordinator to check
-        self.globals.coord_comms.announce_new_stacks_block();
+        if !relay::fault_injection::no_stacks_announce() {
+            self.globals.coord_comms.announce_new_stacks_block();
+        }
 
         info!(
             "Relayer: Process sortition";

testnet/stacks-node/src/run_loop/nakamoto.rs

@@ -637,7 +637,6 @@ impl RunLoop {
                             self.config(),
                             burnchain.sortdb_mut(),
                             sortition_id,
-                            ibd,
                         ) {
                             // relayer errored, exit.
                             error!("Runloop: Block relayer and miner errored, exiting."; "err" => ?e);
@@ -714,6 +713,11 @@ impl RunLoop {
                         globals.raise_initiative("runloop-synced".to_string());
                     }
                 }
+            } else {
+                info!("Runloop: still synchronizing";
+                    "sortition_db_height" => sortition_db_height,
+                    "burnchain_height" => burnchain_height,
+                    "ibd" => ibd);
             }
         }
     }

testnet/stacks-node/src/syncctl.rs

@@ -195,7 +195,6 @@ impl PoxSyncWatchdog {
                 .max(burnchain_height)
         };
 
-        self.relayer_comms.set_ibd(ibbd);
         if !self.unconditionally_download {
             self.relayer_comms
                 .interruptable_sleep(self.steady_state_burnchain_sync_interval)?;

testnet/stacks-node/src/tests/nakamoto_integrations.rs

@@ -73,6 +73,7 @@ use stacks::net::api::getstackers::GetStackersResponse;
 use stacks::net::api::postblock_proposal::{
     BlockValidateReject, BlockValidateResponse, NakamotoBlockProposal, ValidateRejectCode,
 };
+use stacks::net::relay;
 use stacks::types::chainstate::{ConsensusHash, StacksBlockId};
 use stacks::util::hash::hex_bytes;
 use stacks::util_lib::boot::boot_code_id;
@@ -96,9 +97,7 @@ use stacks_signer::signerdb::{BlockInfo, BlockState, ExtraBlockInfo, SignerDb};
 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,
-};
+use crate::nakamoto_node::miner::{TEST_BROADCAST_STALL, TEST_MINE_STALL, TEST_SKIP_P2P_BROADCAST};
 use crate::neon::{Counters, RunLoopCounter};
 use crate::operations::BurnchainOpSigner;
 use crate::run_loop::boot_nakamoto;
@@ -4987,7 +4986,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.lock().unwrap().replace(true);
-    TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap().replace(true);
+    relay::fault_injection::block_stacks_announce();
     let blocks_before = mined_blocks.load(Ordering::SeqCst);
     let commits_before = commits_submitted.load(Ordering::SeqCst);
 
@@ -5057,7 +5056,7 @@ fn forked_tenure_is_ignored() {
         .get_stacks_blocks_processed();
     next_block_and(&mut btc_regtest_controller, 60, || {
         test_skip_commit_op.set(false);
-        TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap().replace(false);
+        relay::fault_injection::unblock_stacks_announce();
         let commits_count = commits_submitted.load(Ordering::SeqCst);
         let blocks_count = mined_blocks.load(Ordering::SeqCst);
         let blocks_processed = coord_channel

testnet/stacks-node/src/tests/signer/v0.rs

@@ -45,6 +45,7 @@ use stacks::net::api::postblock_proposal::{
     BlockValidateResponse, ValidateRejectCode, TEST_VALIDATE_DELAY_DURATION_SECS,
     TEST_VALIDATE_STALL,
 };
+use stacks::net::relay;
 use stacks::net::relay::fault_injection::set_ignore_block;
 use stacks::types::chainstate::{StacksAddress, StacksBlockId, StacksPrivateKey, StacksPublicKey};
 use stacks::types::PublicKey;
@@ -57,7 +58,7 @@ use stacks::util_lib::signed_structured_data::pox4::{
 };
 use stacks_common::bitvec::BitVec;
 use stacks_common::types::chainstate::TrieHash;
-use stacks_common::util::sleep_ms;
+use stacks_common::util::{get_epoch_time_ms, sleep_ms};
 use stacks_signer::chainstate::{ProposalEvalConfig, SortitionsView};
 use stacks_signer::client::{SignerSlotID, StackerDB};
 use stacks_signer::config::{build_signer_config_tomls, GlobalConfig as SignerConfig, Network};
@@ -71,9 +72,7 @@ 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,
-};
+use crate::nakamoto_node::miner::{TEST_BROADCAST_STALL, TEST_MINE_STALL};
 use crate::nakamoto_node::stackerdb_listener::TEST_IGNORE_SIGNERS;
 use crate::neon::Counters;
 use crate::run_loop::boot_nakamoto;
@@ -952,6 +951,8 @@ fn forked_tenure_testing(
         |config| {
             // make the duration long enough that the reorg attempt will definitely be accepted
             config.first_proposal_burn_block_timing = proposal_limit;
+            config.tenure_last_block_proposal_timeout = Duration::from_secs(0);
+
             // don't allow signers to post signed blocks (limits the amount of fault injection we
             // need)
             TEST_SKIP_BLOCK_BROADCAST.set(true);
@@ -1019,7 +1020,7 @@ fn forked_tenure_testing(
 
     // For the next tenure, submit the commit op but do not allow any stacks blocks to be broadcasted
     TEST_BROADCAST_STALL.lock().unwrap().replace(true);
-    TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap().replace(true);
+    relay::fault_injection::block_stacks_announce();
     let blocks_before = mined_blocks.load(Ordering::SeqCst);
     let commits_before = commits_submitted.load(Ordering::SeqCst);
 
@@ -1094,14 +1095,14 @@ fn forked_tenure_testing(
     );
     assert_ne!(tip_b, tip_a);
 
+    info!("Starting Tenure C.");
     if !expect_tenure_c {
+        info!("Process Tenure B");
         // allow B to process, so it'll be distinct from C
-        TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap().replace(false);
+        relay::fault_injection::unblock_stacks_announce();
         sleep_ms(1000);
     }
 
-    info!("Starting Tenure C.");
-
     // Submit a block commit op for tenure C
     let commits_before = commits_submitted.load(Ordering::SeqCst);
     let blocks_before = if expect_tenure_c {
@@ -1115,14 +1116,29 @@ fn forked_tenure_testing(
         .nakamoto_test_skip_commit_op
         .set(false);
 
+    let mut tenure_b_deadline = None;
+
+    // have the current miner thread just skip block-processing, so tenure C can start
+    relay::fault_injection::skip_stacks_announce();
+    relay::fault_injection::unblock_stacks_announce();
+
     next_block_and(
         &mut signer_test.running_nodes.btc_regtest_controller,
         60,
         || {
             let commits_count = commits_submitted.load(Ordering::SeqCst);
             if commits_count > commits_before {
-                // now allow block B to process if it hasn't already.
-                TEST_BLOCK_ANNOUNCE_STALL.lock().unwrap().replace(false);
+                // once the commit happens, give a grace period for tenure C to be mined and
+                // procesed
+                if let Some(dl) = tenure_b_deadline.as_mut() {
+                    if *dl < get_epoch_time_ms() {
+                        // unblock miner thread, but don't process tenure B just yet
+                        coord_channel.lock().unwrap().announce_new_stacks_block();
+                        *dl = get_epoch_time_ms() + 100_000_000_000;
+                    }
+                } else {
+                    tenure_b_deadline = Some(get_epoch_time_ms() + 10_000);
+                }
             }
             let rejected_count = rejected_blocks.load(Ordering::SeqCst);
             let (blocks_count, rbf_count, has_reject_count) = if expect_tenure_c {
@@ -1171,6 +1187,9 @@ fn forked_tenure_testing(
         panic!();
     });
 
+    relay::fault_injection::unskip_stacks_announce();
+    coord_channel.lock().unwrap().announce_new_stacks_block();
+
     // allow blocks B and C to be processed
     sleep_ms(1000);