Merge branch 'develop' into feat/allow-pretty-print-tests

Author: hstove

stacks-signer/src/v0/signer.rs

@@ -348,7 +348,7 @@ impl Signer {
                     crate::monitoring::increment_block_responses_sent(accepted);
                 }
                 Err(e) => {
-                    warn!("{self}: Failed to send block rejection to stacker-db: {e:?}",);
+                    warn!("{self}: Failed to send block response to stacker-db: {e:?}",);
                 }
             }
             return;
@@ -434,30 +434,8 @@ impl Signer {
         };
 
         #[cfg(any(test, feature = "testing"))]
-        let block_response = match &*TEST_REJECT_ALL_BLOCK_PROPOSAL.lock().unwrap() {
-            Some(public_keys) => {
-                if public_keys.contains(
-                    &stacks_common::types::chainstate::StacksPublicKey::from_private(
-                        &self.private_key,
-                    ),
-                ) {
-                    warn!("{self}: Rejecting block proposal automatically due to testing directive";
-                        "block_id" => %block_proposal.block.block_id(),
-                        "height" => block_proposal.block.header.chain_length,
-                        "consensus_hash" => %block_proposal.block.header.consensus_hash
-                    );
-                    Some(BlockResponse::rejected(
-                        block_proposal.block.header.signer_signature_hash(),
-                        RejectCode::TestingDirective,
-                        &self.private_key,
-                        self.mainnet,
-                    ))
-                } else {
-                    None
-                }
-            }
-            None => block_response,
-        };
+        let block_response =
+            self.test_reject_block_proposal(block_proposal, &mut block_info, block_response);
 
         if let Some(block_response) = block_response {
             // We know proposal is invalid. Send rejection message, do not do further validation
@@ -526,9 +504,8 @@ impl Signer {
                 {
                     debug!("{self}: Received block validation for a block that is already marked as {}. Ignoring...", block_info.state);
                     return None;
-                } else {
-                    block_info
                 }
+                block_info
             }
             Ok(None) => {
                 // We have not seen this block before. Why are we getting a response for it?
@@ -569,7 +546,15 @@ impl Signer {
             .signer_db
             .block_lookup(self.reward_cycle, &signer_signature_hash)
         {
-            Ok(Some(block_info)) => block_info,
+            Ok(Some(block_info)) => {
+                if block_info.state == BlockState::GloballyRejected
+                    || block_info.state == BlockState::GloballyAccepted
+                {
+                    debug!("{self}: Received block validation for a block that is already marked as {}. Ignoring...", block_info.state);
+                    return None;
+                }
+                block_info
+            }
             Ok(None) => {
                 // We have not seen this block before. Why are we getting a response for it?
                 debug!("{self}: Received a block validate response for a block we have not seen before. Ignoring...");
@@ -941,6 +926,44 @@ impl Signer {
         false
     }
 
+    #[cfg(any(test, feature = "testing"))]
+    fn test_reject_block_proposal(
+        &mut self,
+        block_proposal: &BlockProposal,
+        block_info: &mut BlockInfo,
+        block_response: Option<BlockResponse>,
+    ) -> Option<BlockResponse> {
+        let Some(public_keys) = &*TEST_REJECT_ALL_BLOCK_PROPOSAL.lock().unwrap() else {
+            return block_response;
+        };
+        if public_keys.contains(
+            &stacks_common::types::chainstate::StacksPublicKey::from_private(&self.private_key),
+        ) {
+            warn!("{self}: Rejecting block proposal automatically due to testing directive";
+                "block_id" => %block_proposal.block.block_id(),
+                "height" => block_proposal.block.header.chain_length,
+                "consensus_hash" => %block_proposal.block.header.consensus_hash
+            );
+            if let Err(e) = block_info.mark_locally_rejected() {
+                warn!("{self}: Failed to mark block as locally rejected: {e:?}",);
+            };
+            // We must insert the block into the DB to prevent subsequent repeat proposals being accepted (should reject
+            // as invalid since we rejected in a prior round if this crops up again)
+            // in case this is the first time we saw this block. Safe to do since this is testing case only.
+            self.signer_db
+                .insert_block(block_info)
+                .unwrap_or_else(|_| panic!("{self}: Failed to insert block in DB"));
+            Some(BlockResponse::rejected(
+                block_proposal.block.header.signer_signature_hash(),
+                RejectCode::TestingDirective,
+                &self.private_key,
+                self.mainnet,
+            ))
+        } else {
+            None
+        }
+    }
+
     /// Send a mock signature to stackerdb to prove we are still alive
     fn mock_sign(&mut self, mock_proposal: MockProposal) {
         info!("{self}: Mock signing mock proposal: {mock_proposal:?}");

testnet/stacks-node/src/config.rs

@@ -86,7 +86,9 @@ pub const OP_TX_ANY_ESTIM_SIZE: u64 = fmax!(
 const DEFAULT_MAX_RBF_RATE: u64 = 150; // 1.5x
 const DEFAULT_RBF_FEE_RATE_INCREMENT: u64 = 5;
 const INV_REWARD_CYCLES_TESTNET: u64 = 6;
-const DEFAULT_MIN_TIME_BETWEEN_BLOCKS_MS: u64 = 1000;
+const DEFAULT_MIN_TIME_BETWEEN_BLOCKS_MS: u64 = 1_000;
+const DEFAULT_FIRST_REJECTION_PAUSE_MS: u64 = 5_000;
+const DEFAULT_SUBSEQUENT_REJECTION_PAUSE_MS: u64 = 10_000;
 
 #[derive(Clone, Deserialize, Default, Debug)]
 #[serde(deny_unknown_fields)]
@@ -2183,6 +2185,10 @@ pub struct MinerConfig {
     /// The minimum time to wait between mining blocks in milliseconds. The value must be greater than or equal to 1000 ms because if a block is mined
     /// within the same second as its parent, it will be rejected by the signers.
     pub min_time_between_blocks_ms: u64,
+    /// Time in milliseconds to pause after receiving the first threshold rejection, before proposing a new block.
+    pub first_rejection_pause_ms: u64,
+    /// Time in milliseconds to pause after receiving subsequent threshold rejections, before proposing a new block.
+    pub subsequent_rejection_pause_ms: u64,
 }
 
 impl Default for MinerConfig {
@@ -2213,6 +2219,8 @@ impl Default for MinerConfig {
             max_reorg_depth: 3,
             pre_nakamoto_mock_signing: false, // Should only default true if mining key is set
             min_time_between_blocks_ms: DEFAULT_MIN_TIME_BETWEEN_BLOCKS_MS,
+            first_rejection_pause_ms: DEFAULT_FIRST_REJECTION_PAUSE_MS,
+            subsequent_rejection_pause_ms: DEFAULT_SUBSEQUENT_REJECTION_PAUSE_MS,
         }
     }
 }
@@ -2575,6 +2583,8 @@ pub struct MinerConfigFile {
     pub max_reorg_depth: Option<u64>,
     pub pre_nakamoto_mock_signing: Option<bool>,
     pub min_time_between_blocks_ms: Option<u64>,
+    pub first_rejection_pause_ms: Option<u64>,
+    pub subsequent_rejection_pause_ms: Option<u64>,
 }
 
 impl MinerConfigFile {
@@ -2688,6 +2698,8 @@ impl MinerConfigFile {
             } else {
                 ms
             }).unwrap_or(miner_default_config.min_time_between_blocks_ms),
+            first_rejection_pause_ms: self.first_rejection_pause_ms.unwrap_or(miner_default_config.first_rejection_pause_ms),
+            subsequent_rejection_pause_ms: self.subsequent_rejection_pause_ms.unwrap_or(miner_default_config.subsequent_rejection_pause_ms),
         })
     }
 }

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

@@ -283,6 +283,7 @@ impl BlockMinerThread {
         }
         let mut stackerdbs = StackerDBs::connect(&self.config.get_stacker_db_file_path(), true)
             .map_err(|e| NakamotoNodeError::MiningFailure(ChainstateError::NetError(e)))?;
+        let mut last_block_rejected = false;
 
         // now, actually run this tenure
         loop {
@@ -386,15 +387,25 @@ impl BlockMinerThread {
                             return Err(e);
                         }
                         _ => {
-                            error!("Error while gathering signatures: {e:?}. Will try mining again.";
+                            // Sleep for a bit to allow signers to catch up
+                            let pause_ms = if last_block_rejected {
+                                self.config.miner.subsequent_rejection_pause_ms
+                            } else {
+                                self.config.miner.first_rejection_pause_ms
+                            };
+
+                            error!("Error while gathering signatures: {e:?}. Will try mining again in {pause_ms}.";
                                 "signer_sighash" => %new_block.header.signer_signature_hash(),
                                 "block_height" => new_block.header.chain_length,
                                 "consensus_hash" => %new_block.header.consensus_hash,
                             );
+                            thread::sleep(Duration::from_millis(pause_ms));
+                            last_block_rejected = true;
                             continue;
                         }
                     },
                 };
+                last_block_rejected = false;
 
                 new_block.header.signer_signature = signer_signature;
                 if let Err(e) = self.broadcast(new_block.clone(), reward_set, &stackerdbs) {

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

@@ -4246,6 +4246,8 @@ fn locally_accepted_blocks_overriden_by_global_rejection() {
         .unwrap()
         .replace(rejecting_signers.clone());
     test_observer::clear();
+    // Make a new stacks transaction to create a different block signature, but make sure to propose it
+    // AFTER the signers are unfrozen so they don't inadvertently prevent the new block being accepted
     let transfer_tx = make_stacks_transfer(
         &sender_sk,
         sender_nonce,
@@ -4841,7 +4843,13 @@ fn miner_recovers_when_broadcast_block_delay_across_tenures_occurs() {
 
     // a tenure has begun, so wait until we mine a block
     wait_for(30, || {
-        Ok(mined_blocks.load(Ordering::SeqCst) > blocks_before)
+        let new_height = signer_test
+            .stacks_client
+            .get_peer_info()
+            .expect("Failed to get peer info")
+            .stacks_tip_height;
+        Ok(mined_blocks.load(Ordering::SeqCst) > blocks_before
+            && new_height > info_before.stacks_tip_height)
     })
     .expect("Timed out waiting for block to be mined and processed");