WIP: broken test initial braindump

Signed-off-by: Jacinta Ferrant <[email protected]>

Author: jferrant

.github/workflows/bitcoin-tests.yml

@@ -120,6 +120,7 @@ jobs:
           - tests::signer::v0::signing_in_0th_tenure_of_reward_cycle
           - tests::signer::v0::continue_after_tenure_extend
           - tests::signer::v0::multiple_miners_with_custom_chain_id
+          - tests::signer::v0::block_validation_response_timeout
           - tests::nakamoto_integrations::burn_ops_integration_test
           - tests::nakamoto_integrations::check_block_heights
           - tests::nakamoto_integrations::clarity_burn_state

stacks-signer/src/chainstate.rs

@@ -119,16 +119,13 @@ pub struct ProposalEvalConfig {
     pub first_proposal_burn_block_timing: Duration,
     /// Time between processing a sortition and proposing a block before the block is considered invalid
     pub block_proposal_timeout: Duration,
-    /// How long to wait for a block proposal validation response
-    pub block_proposal_validation_timeout: Duration,
 }
 
 impl From<&SignerConfig> for ProposalEvalConfig {
     fn from(value: &SignerConfig) -> Self {
         Self {
             first_proposal_burn_block_timing: value.first_proposal_burn_block_timing,
             block_proposal_timeout: value.block_proposal_timeout,
-            block_proposal_validation_timeout: value.block_proposal_validation_timeout,
         }
     }
 }

stacks-signer/src/tests/chainstate.rs

@@ -89,7 +89,6 @@ fn setup_test_environment(
         config: ProposalEvalConfig {
             first_proposal_burn_block_timing: Duration::from_secs(30),
             block_proposal_timeout: Duration::from_secs(5),
-            block_proposal_validation_timeout: Duration::from_secs(60),
         },
     };
 

stacks-signer/src/v0/signer.rs

@@ -15,7 +15,7 @@
 use std::collections::HashMap;
 use std::fmt::Debug;
 use std::sync::mpsc::Sender;
-use std::time::Instant;
+use std::time::{Duration, Instant};
 
 use blockstack_lib::chainstate::nakamoto::{NakamotoBlock, NakamotoBlockHeader};
 use blockstack_lib::net::api::postblock_proposal::{
@@ -86,6 +86,9 @@ pub struct Signer {
     pub signer_db: SignerDb,
     /// Configuration for proposal evaluation
     pub proposal_config: ProposalEvalConfig,
+    /// How long to wait for a block proposal validation response to arrive before
+    /// marking a submitted block as invalid
+    pub block_proposal_validation_timeout: Duration,
     /// The current submitted block proposal and its submission time
     pub submitted_block_proposal: Option<(BlockProposal, Instant)>,
 }
@@ -279,6 +282,7 @@ impl From<SignerConfig> for Signer {
             signer_db,
             proposal_config,
             submitted_block_proposal: None,
+            block_proposal_validation_timeout: signer_config.block_proposal_validation_timeout,
         }
     }
 }
@@ -670,7 +674,7 @@ impl Signer {
             // Nothing to check.
             return;
         };
-        if block_submission.elapsed() < self.proposal_config.block_proposal_validation_timeout {
+        if block_submission.elapsed() < self.block_proposal_validation_timeout {
             // Not expired yet.
             return;
         }
@@ -710,7 +714,7 @@ impl Signer {
             }
         };
         warn!(
-            "{self}: Failed to receive block validation response within {} ms. Rejecting block.", self.proposal_config.block_proposal_validation_timeout.as_millis();
+            "{self}: Failed to receive block validation response within {} ms. Rejecting block.", self.block_proposal_validation_timeout.as_millis();
             "signer_sighash" => %signature_sighash,
             "block_id" => %block_proposal.block.block_id(),
         );

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

@@ -6450,7 +6450,6 @@ fn signer_chainstate() {
         let proposal_conf = ProposalEvalConfig {
             first_proposal_burn_block_timing: Duration::from_secs(0),
             block_proposal_timeout: Duration::from_secs(100),
-            block_proposal_validation_timeout: Duration::from_secs(100),
         };
         let mut sortitions_view =
             SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap();
@@ -6589,7 +6588,6 @@ fn signer_chainstate() {
         let proposal_conf = ProposalEvalConfig {
             first_proposal_burn_block_timing: Duration::from_secs(0),
             block_proposal_timeout: Duration::from_secs(100),
-            block_proposal_validation_timeout: Duration::from_secs(100),
         };
         let burn_block_height = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn())
             .unwrap()
@@ -6667,7 +6665,6 @@ fn signer_chainstate() {
     let proposal_conf = ProposalEvalConfig {
         first_proposal_burn_block_timing: Duration::from_secs(0),
         block_proposal_timeout: Duration::from_secs(100),
-        block_proposal_validation_timeout: Duration::from_secs(100),
     };
     let mut sortitions_view = SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap();
     let burn_block_height = SortitionDB::get_canonical_burn_chain_tip(sortdb.conn())

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

@@ -456,7 +456,6 @@ fn block_proposal_rejection() {
     let proposal_conf = ProposalEvalConfig {
         first_proposal_burn_block_timing: Duration::from_secs(0),
         block_proposal_timeout: Duration::from_secs(100),
-        block_proposal_validation_timeout: Duration::from_secs(100),
     };
     let mut block = NakamotoBlock {
         header: NakamotoBlockHeader::empty(),
@@ -5608,3 +5607,152 @@ fn multiple_miners_with_custom_chain_id() {
     run_loop_2_thread.join().unwrap();
     signer_test.shutdown();
 }
+
+// Teimout a block validation response
+#[test]
+#[ignore]
+fn block_validation_response_timeout() {
+    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(60);
+    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 mut signer_test: SignerTest<SpawnedSigner> = SignerTest::new_with_config_modifications(
+        num_signers,
+        vec![(sender_addr.clone(), send_amt + send_fee)],
+        |config| {
+            config.block_proposal_validation_timeout = timeout;
+        },
+        |_| {},
+        None,
+        None,
+    );
+    let http_origin = format!("http://{}", &signer_test.running_nodes.conf.node.rpc_bind);
+    signer_test.boot_to_epoch_3();
+
+    info!("------------------------- Test Mine and Verify Confirmed Nakamoto Block -------------------------");
+    signer_test.mine_and_verify_confirmed_naka_block(timeout, num_signers);
+    info!("------------------------- Test Block Validation Stalled -------------------------");
+    TEST_VALIDATE_STALL.lock().unwrap().replace(true);
+    let validation_stall_start = Instant::now();
+
+    let proposals_before = signer_test
+        .running_nodes
+        .nakamoto_blocks_proposed
+        .load(Ordering::SeqCst);
+
+    // 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!("Submitted transfer tx and waiting for block proposal");
+    wait_for(30, || {
+        Ok(signer_test
+            .running_nodes
+            .nakamoto_blocks_proposed
+            .load(Ordering::SeqCst)
+            > proposals_before)
+    })
+    .expect("Timed out waiting for block proposal");
+
+    info!("------------------------- Propose Another Block -------------------------");
+    let proposal_conf = ProposalEvalConfig {
+        first_proposal_burn_block_timing: Duration::from_secs(0),
+        block_proposal_timeout: Duration::from_secs(100),
+    };
+    let mut block = NakamotoBlock {
+        header: NakamotoBlockHeader::empty(),
+        txs: vec![],
+    };
+
+    // Propose a block to the signers that passes initial checks but will not be submitted to the stacks node due to the submission stall
+    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 = 1; // We have mined 1 block so far
+
+    let block_signer_signature_hash_1 = block.header.signer_signature_hash();
+    let info_before = get_chain_info(&signer_test.running_nodes.conf);
+    signer_test.propose_block(block, Duration::from_secs(30));
+
+    info!("------------------------- Waiting for Timeout -------------------------");
+    // Sleep the necessary timeout to make sure the validation times out.
+    let elapsed = validation_stall_start.elapsed();
+    std::thread::sleep(timeout.saturating_sub(elapsed));
+
+    info!("------------------------- Wait for Block Rejection Due to Timeout -------------------------");
+    // Verify the signers rejected the first block due to timeout
+    let start = Instant::now();
+    let mut rejected_signers = vec![];
+    let mut saw_connectivity_complaint = false;
+    while rejected_signers.len() < num_signers {
+        std::thread::sleep(Duration::from_secs(1));
+        let chunks = test_observer::get_stackerdb_chunks();
+        for chunk in chunks.into_iter().flat_map(|chunk| chunk.modified_slots) {
+            let Ok(message) = SignerMessage::consensus_deserialize(&mut chunk.data.as_slice())
+            else {
+                continue;
+            };
+            if let SignerMessage::BlockResponse(BlockResponse::Rejected(BlockRejection {
+                reason: _reason,
+                reason_code,
+                signer_signature_hash,
+                signature,
+                ..
+            })) = message
+            {
+                if signer_signature_hash == block_signer_signature_hash_1 {
+                    rejected_signers.push(signature);
+                    if matches!(reason_code, RejectCode::ConnectivityIssues) {
+                        saw_connectivity_complaint = true;
+                    }
+                }
+            }
+        }
+        assert!(
+            start.elapsed() <= Duration::from_secs(10),
+            "Timed out after waiting for response from signer"
+        );
+    }
+
+    assert!(
+        saw_connectivity_complaint,
+        "We did not see the expected connectity rejection reason"
+    );
+    // Make sure our chain has still not advanced
+    let info_after = get_chain_info(&signer_test.running_nodes.conf);
+    assert_eq!(info_before, info_after);
+
+    info!("Unpausing block validation");
+    // Disable the stall and wait for the block to be processed
+    TEST_VALIDATE_STALL.lock().unwrap().replace(false);
+
+    info!("------------------------- Test Mine and Verify Confirmed Nakamoto Block -------------------------");
+    signer_test.mine_and_verify_confirmed_naka_block(timeout, num_signers);
+
+    assert_eq!(
+        get_chain_info(&signer_test.running_nodes.conf).stacks_tip_height,
+        info_before.stacks_tip_height + 1,
+    );
+}