feat: integration test for retry pending block validations

Author: hstove

.github/workflows/bitcoin-tests.yml

@@ -131,6 +131,7 @@ jobs:
           - tests::signer::v0::block_commit_delay
           - tests::signer::v0::continue_after_fast_block_no_sortition
           - tests::signer::v0::block_validation_response_timeout
+          - tests::signer::v0::block_validation_pending_table
           - tests::signer::v0::tenure_extend_after_bad_commit
           - tests::signer::v0::block_proposal_max_age_rejections
           - tests::nakamoto_integrations::burn_ops_integration_test

stacks-signer/src/signerdb.rs

@@ -24,6 +24,8 @@ use blockstack_lib::util_lib::db::{
     query_row, query_rows, sqlite_open, table_exists, tx_begin_immediate, u64_to_sql,
     Error as DBError,
 };
+#[cfg(any(test, feature = "testing"))]
+use blockstack_lib::util_lib::db::{FromColumn, FromRow};
 use clarity::types::chainstate::{BurnchainHeaderHash, StacksAddress};
 use libsigner::BlockProposal;
 use rusqlite::functions::FunctionFlags;
@@ -1060,6 +1062,16 @@ impl SignerDb {
         Ok(())
     }
 
+    /// For tests, fetch all pending block validations
+    #[cfg(any(test, feature = "testing"))]
+    pub fn get_all_pending_block_validations(
+        &self,
+    ) -> Result<Vec<PendingBlockValidation>, DBError> {
+        let qry = "SELECT signer_signature_hash, added_time FROM block_validations_pending";
+        let args = params![];
+        query_rows(&self.db, qry, args)
+    }
+
     /// Return the start time (epoch time in seconds) and the processing time in milliseconds of the tenure (idenfitied by consensus_hash).
     fn get_tenure_times(&self, tenure: &ConsensusHash) -> Result<(u64, u64), DBError> {
         let query = "SELECT tenure_change, proposed_time, validation_time_ms FROM blocks WHERE consensus_hash = ?1 AND state = ?2 ORDER BY stacks_height DESC";
@@ -1134,6 +1146,27 @@ where
         .map_err(DBError::SerializationError)
 }
 
+/// For tests, a struct to represent a pending block validation
+#[cfg(any(test, feature = "testing"))]
+pub struct PendingBlockValidation {
+    /// The signer signature hash of the block
+    pub signer_signature_hash: Sha512Trunc256Sum,
+    /// The time at which the block was added to the pending table
+    pub added_time: u64,
+}
+
+#[cfg(any(test, feature = "testing"))]
+impl FromRow<PendingBlockValidation> for PendingBlockValidation {
+    fn from_row(row: &rusqlite::Row) -> Result<Self, DBError> {
+        let signer_signature_hash = Sha512Trunc256Sum::from_column(row, "signer_signature_hash")?;
+        let added_time = row.get_unwrap(1);
+        Ok(PendingBlockValidation {
+            signer_signature_hash,
+            added_time,
+        })
+    }
+}
+
 #[cfg(test)]
 mod tests {
     use std::fs;

stackslib/src/net/api/postblock_proposal.rs

@@ -175,6 +175,16 @@ impl From<Result<BlockValidateOk, BlockValidateReject>> for BlockValidateRespons
     }
 }
 
+impl BlockValidateResponse {
+    /// Get the signer signature hash from the response
+    pub fn signer_signature_hash(&self) -> Sha512Trunc256Sum {
+        match self {
+            BlockValidateResponse::Ok(o) => o.signer_signature_hash,
+            BlockValidateResponse::Reject(r) => r.signer_signature_hash,
+        }
+    }
+}
+
 /// Represents a block proposed to the `v3/block_proposal` endpoint for validation
 #[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
 pub struct NakamotoBlockProposal {

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

@@ -39,7 +39,7 @@ use clarity::vm::types::PrincipalData;
 use libsigner::v0::messages::{
     BlockAccepted, BlockResponse, MessageSlotID, PeerInfo, SignerMessage,
 };
-use libsigner::{SignerEntries, SignerEventTrait};
+use libsigner::{BlockProposal, SignerEntries, SignerEventTrait};
 use stacks::chainstate::coordinator::comm::CoordinatorChannels;
 use stacks::chainstate::nakamoto::signer_set::NakamotoSigners;
 use stacks::chainstate::stacks::boot::{NakamotoSignerEntry, SIGNERS_NAME};
@@ -678,6 +678,25 @@ impl<S: Signer<T> + Send + 'static, T: SignerEventTrait + 'static> SignerTest<Sp
         }
     }
 
+    /// Get miner stackerDB messages
+    pub fn get_miner_proposal_messages(&self) -> Vec<BlockProposal> {
+        let proposals: Vec<_> = test_observer::get_stackerdb_chunks()
+            .into_iter()
+            .flat_map(|chunk| chunk.modified_slots)
+            .filter_map(|chunk| {
+                let Ok(message) = SignerMessage::consensus_deserialize(&mut chunk.data.as_slice())
+                else {
+                    return None;
+                };
+                match message {
+                    SignerMessage::BlockProposal(proposal) => Some(proposal),
+                    _ => None,
+                }
+            })
+            .collect();
+        proposals
+    }
+
     /// Get /v2/info from the node
     pub fn get_peer_info(&self) -> PeerInfo {
         self.stacks_client

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

@@ -60,6 +60,7 @@ use stacks_common::util::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};
+use stacks_signer::signerdb::SignerDb;
 use stacks_signer::v0::signer::{
     TEST_IGNORE_ALL_BLOCK_PROPOSALS, TEST_PAUSE_BLOCK_BROADCAST, TEST_REJECT_ALL_BLOCK_PROPOSAL,
     TEST_SKIP_BLOCK_BROADCAST,
@@ -7767,6 +7768,178 @@ fn block_validation_response_timeout() {
     );
 }
 
+/// Test that, when a signer submit a block validation request and
+/// gets a 429 the signer stores the pending request and submits
+/// it again after the current block validation request finishes.
+#[test]
+#[ignore]
+fn block_validation_pending_table() {
+    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 timeout = Duration::from_secs(30);
+    let sender_sk = Secp256k1PrivateKey::new();
+    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 short_timeout = Duration::from_secs(20);
+
+    let mut signer_test: SignerTest<SpawnedSigner> = SignerTest::new_with_config_modifications(
+        num_signers,
+        vec![(sender_addr, send_amt + send_fee)],
+        |config| {
+            config.block_proposal_validation_timeout = timeout;
+        },
+        |_| {},
+        None,
+        None,
+    );
+    let db_path = signer_test.signer_configs[0].db_path.clone();
+    let http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind);
+    signer_test.boot_to_epoch_3();
+
+    info!("----- Starting test -----";
+        "db_path" => db_path.clone().to_str(),
+    );
+    signer_test.mine_and_verify_confirmed_naka_block(timeout, num_signers, true);
+    TEST_VALIDATE_DELAY_DURATION_SECS
+        .lock()
+        .unwrap()
+        .replace(30);
+
+    let signer_db = SignerDb::new(db_path).unwrap();
+
+    let proposals_before = signer_test.get_miner_proposal_messages().len();
+
+    let peer_info = signer_test.get_peer_info();
+
+    // submit a tx so that the miner will attempt to mine an extra block
+    let sender_nonce = 0;
+    let transfer_tx = make_stacks_transfer(
+        &sender_sk,
+        sender_nonce,
+        send_fee,
+        signer_test.running_nodes.conf.burnchain.chain_id,
+        &recipient,
+        send_amt,
+    );
+    submit_tx(&http_origin, &transfer_tx);
+
+    info!("----- Waiting for miner to propose a block -----");
+
+    // Wait for the miner to propose a block
+    wait_for(30, || {
+        Ok(signer_test.get_miner_proposal_messages().len() > proposals_before)
+    })
+    .expect("Timed out waiting for miner to propose a block");
+
+    info!("----- Proposing a concurrent block -----");
+    let proposal_conf = ProposalEvalConfig {
+        first_proposal_burn_block_timing: Duration::from_secs(0),
+        block_proposal_timeout: Duration::from_secs(100),
+        tenure_last_block_proposal_timeout: Duration::from_secs(30),
+        tenure_idle_timeout: Duration::from_secs(300),
+    };
+    let mut block = NakamotoBlock {
+        header: NakamotoBlockHeader::empty(),
+        txs: vec![],
+    };
+    block.header.timestamp = get_epoch_time_secs();
+
+    let view = SortitionsView::fetch_view(proposal_conf, &signer_test.stacks_client).unwrap();
+    block.header.pox_treatment = BitVec::ones(1).unwrap();
+    block.header.consensus_hash = view.cur_sortition.consensus_hash;
+    block.header.chain_length = peer_info.stacks_tip_height + 1;
+    let block_signer_signature_hash = block.header.signer_signature_hash();
+    signer_test.propose_block(block.clone(), short_timeout);
+
+    info!(
+        "----- Waiting for a pending block proposal in SignerDb -----";
+        "signer_signature_hash" => block_signer_signature_hash.to_hex(),
+    );
+    let mut last_log = Instant::now();
+    last_log -= Duration::from_secs(5);
+    wait_for(120, || {
+        let sighash = match signer_db.get_pending_block_validation() {
+            Ok(Some(sighash)) => sighash,
+            Err(e) => {
+                error!("Failed to get pending block validation: {e}");
+                panic!("Failed to get pending block validation");
+            }
+            Ok(None) => {
+                if last_log.elapsed() > Duration::from_secs(5) {
+                    info!("----- No pending block validations found -----");
+                    last_log = Instant::now();
+                }
+                return Ok(false);
+            }
+        };
+        if last_log.elapsed() > Duration::from_secs(5) && sighash != block_signer_signature_hash {
+            let pending_block_validations = signer_db
+                .get_all_pending_block_validations()
+                .expect("Failed to get pending block validations");
+            info!(
+                "----- Received a different pending block proposal -----";
+                "db_signer_signature_hash" => sighash.to_hex(),
+                "proposed_signer_signature_hash" => block_signer_signature_hash.to_hex(),
+                "pending_block_validations" => pending_block_validations.iter()
+                    .map(|p| p.signer_signature_hash.to_hex())
+                    .collect::<Vec<String>>()
+                    .join(", "),
+            );
+            last_log = Instant::now();
+        }
+        Ok(sighash == block_signer_signature_hash)
+    })
+    .expect("Timed out waiting for pending block proposal");
+
+    // Set the delay to 0 so that the block validation finishes quickly
+    TEST_VALIDATE_DELAY_DURATION_SECS.lock().unwrap().take();
+
+    info!("----- Waiting for pending block validation to be submitted -----");
+
+    wait_for(30, || {
+        let proposal_responses = test_observer::get_proposal_responses();
+        let found_proposal = proposal_responses
+            .iter()
+            .any(|p| p.signer_signature_hash() == block_signer_signature_hash);
+        Ok(found_proposal)
+    })
+    .expect("Timed out waiting for pending block validation to be submitted");
+
+    info!("----- Waiting for pending block validation to be removed -----");
+    wait_for(30, || {
+        let Ok(Some(sighash)) = signer_db.get_pending_block_validation() else {
+            // There are no pending block validations
+            return Ok(true);
+        };
+        Ok(sighash != block_signer_signature_hash)
+    })
+    .expect("Timed out waiting for pending block validation to be removed");
+
+    // for test cleanup we need to wait for block rejections
+    let signer_keys = signer_test
+        .signer_configs
+        .iter()
+        .map(|c| StacksPublicKey::from_private(&c.stacks_private_key))
+        .collect::<Vec<_>>();
+    signer_test
+        .wait_for_block_rejections(30, &signer_keys)
+        .expect("Timed out waiting for block rejections");
+
+    info!("------------------------- Shutdown -------------------------");
+    signer_test.shutdown();
+}
+
 #[test]
 #[ignore]
 /// Test that a miner will extend its tenure after the succeding miner fails to mine a block.