Move block proposal timeout check to check_proposal and add unit tests

jferrant · jferrant · commit cf2566560c38 · 2024-07-24T13:06:22.000-04:00
Signed-off-by: Jacinta Ferrant &lt;jacinta@trustmachines.co&gt;
diff --git a/stacks-signer/src/chainstate.rs b/stacks-signer/src/chainstate.rs
@@ -13,7 +13,7 @@
 // You should have received a copy of the GNU General Public License
 // along with this program.  If not, see <http://www.gnu.org/licenses/>.
 
-use std::time::Duration;
+use std::time::{Duration, UNIX_EPOCH};
 
 use blockstack_lib::chainstate::nakamoto::NakamotoBlock;
 use blockstack_lib::chainstate::stacks::TenureChangePayload;
@@ -91,8 +91,8 @@ pub struct ProposalEvalConfig {
 impl From<&SignerConfig> for ProposalEvalConfig {
     fn from(value: &SignerConfig) -> Self {
         Self {
-            first_proposal_burn_block_timing: value.first_proposal_burn_block_timing.clone(),
-            block_proposal_timeout: value.block_proposal_timeout.clone(),
+            first_proposal_burn_block_timing: value.first_proposal_burn_block_timing,
+            block_proposal_timeout: value.block_proposal_timeout,
         }
     }
 }
@@ -150,12 +150,40 @@ impl<'a> ProposedBy<'a> {
 impl SortitionsView {
     /// Apply checks from the SortitionsView on the block proposal.
     pub fn check_proposal(
-        &self,
+        &mut self,
         client: &StacksClient,
         signer_db: &SignerDb,
         block: &NakamotoBlock,
         block_pk: &StacksPublicKey,
     ) -> Result<bool, SignerChainstateError> {
+        // If this is the first block in the tenure, check if it was proposed after the timeout
+        if signer_db
+            .get_last_signed_block_in_tenure(&block.header.consensus_hash)?
+            .is_none()
+        {
+            if let Some(received_ts) =
+                signer_db.get_burn_block_receive_time(&self.cur_sortition.burn_block_hash)?
+            {
+                let received_time = UNIX_EPOCH + Duration::from_secs(received_ts);
+                let elapsed = std::time::SystemTime::now()
+                    .duration_since(received_time)
+                    .unwrap_or_else(|_| {
+                        panic!("Failed to calculate time since burn block received")
+                    });
+                if elapsed >= self.config.block_proposal_timeout {
+                    warn!(
+                        "Miner proposed first block after block proposal timeout.";
+                        "proposed_block_consensus_hash" => %block.header.consensus_hash,
+                        "proposed_block_signer_sighash" => %block.header.signer_signature_hash(),
+                        "current_sortition_consensus_hash" => ?self.cur_sortition.consensus_hash,
+                        "last_sortition_consensus_hash" => ?self.last_sortition.as_ref().map(|x| x.consensus_hash),
+                        "burn_block_received_time" => ?received_time,
+                    );
+                    self.cur_sortition.miner_status =
+                        SortitionMinerStatus::InvalidatedBeforeFirstBlock;
+                }
+            }
+        }
         let bitvec_all_1s = block.header.pox_treatment.iter().all(|entry| entry);
         if !bitvec_all_1s {
             warn!(
diff --git a/stacks-signer/src/signerdb.rs b/stacks-signer/src/signerdb.rs
@@ -189,7 +189,7 @@ impl SignerDb {
             })
             .optional();
         match result {
-            Ok(x) => Ok(x.unwrap_or_else(|| 0)),
+            Ok(x) => Ok(x.unwrap_or(0)),
             Err(e) => Err(DBError::from(e)),
         }
     }
@@ -294,7 +294,7 @@ impl SignerDb {
         tenure: &ConsensusHash,
     ) -> Result<Option<BlockInfo>, DBError> {
         let query = "SELECT block_info FROM blocks WHERE consensus_hash = ? AND signed_over = 1 ORDER BY stacks_height ASC LIMIT 1";
-        let result: Option<String> = query_row(&self.db, query, &[tenure])?;
+        let result: Option<String> = query_row(&self.db, query, [tenure])?;
 
         try_deserialize(result)
     }
diff --git a/stacks-signer/src/tests/chainstate.rs b/stacks-signer/src/tests/chainstate.rs
@@ -86,7 +86,7 @@ fn setup_test_environment(
         last_sortition,
         config: ProposalEvalConfig {
             first_proposal_burn_block_timing: Duration::from_secs(30),
-            block_proposal_timeout: Duration::from_secs(30),
+            block_proposal_timeout: Duration::from_secs(5),
         },
     };
 
@@ -111,7 +111,7 @@ fn setup_test_environment(
             parent_block_id: StacksBlockId([0; 32]),
             tx_merkle_root: Sha512Trunc256Sum([0; 32]),
             state_index_root: TrieHash([0; 32]),
-            timestamp: 11,
+            timestamp: 3,
             miner_signature: MessageSignature::empty(),
             signer_signature: vec![],
             pox_treatment: BitVec::ones(1).unwrap(),
@@ -140,7 +140,7 @@ fn check_proposal_units() {
 
 #[test]
 fn check_proposal_miner_pkh_mismatch() {
-    let (stacks_client, signer_db, _block_pk, view, mut block) =
+    let (stacks_client, signer_db, _block_pk, mut view, mut block) =
         setup_test_environment("miner_pkh_mismatch");
     block.header.consensus_hash = view.cur_sortition.consensus_hash;
     let different_block_pk = StacksPublicKey::from_private(&StacksPrivateKey::from_seed(&[2, 3]));
@@ -328,7 +328,7 @@ fn make_tenure_change_tx(payload: TenureChangePayload) -> StacksTransaction {
 
 #[test]
 fn check_proposal_tenure_extend_invalid_conditions() {
-    let (stacks_client, signer_db, block_pk, view, mut block) =
+    let (stacks_client, signer_db, block_pk, mut view, mut block) =
         setup_test_environment("tenure_extend");
     block.header.consensus_hash = view.cur_sortition.consensus_hash;
     let mut extend_payload = make_tenure_change_payload();
@@ -351,3 +351,39 @@ fn check_proposal_tenure_extend_invalid_conditions() {
         .check_proposal(&stacks_client, &signer_db, &block, &block_pk)
         .unwrap());
 }
+
+#[test]
+fn check_block_proposal_timeout() {
+    let (stacks_client, mut signer_db, block_pk, mut view, mut curr_sortition_block) =
+        setup_test_environment("block_proposal_timeout");
+    curr_sortition_block.header.consensus_hash = view.cur_sortition.consensus_hash;
+    let mut last_sortition_block = curr_sortition_block.clone();
+    last_sortition_block.header.consensus_hash =
+        view.last_sortition.as_ref().unwrap().consensus_hash;
+
+    // Ensure we have a burn height to compare against
+    let burn_hash = view.cur_sortition.burn_block_hash;
+    let burn_height = 1;
+    let received_time = SystemTime::now();
+    signer_db
+        .insert_burn_block(&burn_hash, burn_height, &received_time)
+        .unwrap();
+
+    assert!(view
+        .check_proposal(&stacks_client, &signer_db, &curr_sortition_block, &block_pk)
+        .unwrap());
+
+    assert!(!view
+        .check_proposal(&stacks_client, &signer_db, &last_sortition_block, &block_pk)
+        .unwrap());
+
+    // Sleep a bit to time out the block proposal
+    std::thread::sleep(Duration::from_secs(5));
+    assert!(!view
+        .check_proposal(&stacks_client, &signer_db, &curr_sortition_block, &block_pk)
+        .unwrap());
+
+    assert!(view
+        .check_proposal(&stacks_client, &signer_db, &last_sortition_block, &block_pk)
+        .unwrap());
+}
diff --git a/stacks-signer/src/v0/signer.rs b/stacks-signer/src/v0/signer.rs
@@ -14,7 +14,6 @@
 // along with this program.  If not, see <http://www.gnu.org/licenses/>.
 use std::fmt::Debug;
 use std::sync::mpsc::Sender;
-use std::time::{Duration, UNIX_EPOCH};
 
 use blockstack_lib::net::api::postblock_proposal::BlockValidateResponse;
 use clarity::types::chainstate::StacksPrivateKey;
@@ -27,7 +26,7 @@ use slog::{slog_debug, slog_error, slog_info, slog_warn};
 use stacks_common::types::chainstate::StacksAddress;
 use stacks_common::{debug, error, info, warn};
 
-use crate::chainstate::{ProposalEvalConfig, SortitionMinerStatus, SortitionsView};
+use crate::chainstate::{ProposalEvalConfig, SortitionsView};
 use crate::client::{SignerSlotID, StackerDB, StacksClient};
 use crate::config::SignerConfig;
 use crate::runloop::{RunLoopCommand, SignerResult};
@@ -312,33 +311,6 @@ impl Signer {
 
         // Check if proposal can be rejected now if not valid against sortition view
         let block_response = if let Some(sortition_state) = sortition_state {
-            // If this is the first block in the tenure, check if it was proposed after the timeout
-            if let Ok(None) = self
-                .signer_db
-                .get_last_signed_block_in_tenure(&block_proposal.block.header.consensus_hash)
-            {
-                if let Ok(Some(received_ts)) = self
-                    .signer_db
-                    .get_burn_block_receive_time(&sortition_state.cur_sortition.burn_block_hash)
-                {
-                    let received_time = UNIX_EPOCH + Duration::from_secs(received_ts);
-                    let elapsed = std::time::SystemTime::now()
-                        .duration_since(received_time)
-                        .unwrap_or_else(|_| {
-                            panic!("{self}: Failed to calculate time since burn block received")
-                        });
-                    if elapsed >= self.proposal_config.block_proposal_timeout {
-                        warn!(
-                            "{self}: miner proposed block after timeout.";
-                            "signer_sighash" => %signer_signature_hash,
-                            "block_id" => %block_proposal.block.block_id(),
-                        );
-                        sortition_state.cur_sortition.miner_status =
-                            SortitionMinerStatus::InvalidatedBeforeFirstBlock;
-                    }
-                }
-            }
-
             match sortition_state.check_proposal(
                 stacks_client,
                 &self.signer_db,
diff --git a/testnet/stacks-node/src/tests/nakamoto_integrations.rs b/testnet/stacks-node/src/tests/nakamoto_integrations.rs
@@ -4655,7 +4655,8 @@ fn signer_chainstate() {
             first_proposal_burn_block_timing: Duration::from_secs(0),
             block_proposal_timeout: Duration::from_secs(100),
         };
-        let sortitions_view = SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap();
+        let mut sortitions_view =
+            SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap();
 
         // check the prior tenure's proposals again, confirming that the sortitions_view
         //  will reject them.
@@ -4769,7 +4770,8 @@ fn signer_chainstate() {
             first_proposal_burn_block_timing: Duration::from_secs(0),
             block_proposal_timeout: Duration::from_secs(100),
         };
-        let sortitions_view = SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap();
+        let mut sortitions_view =
+            SortitionsView::fetch_view(proposal_conf, &signer_client).unwrap();
         let valid = sortitions_view
             .check_proposal(
                 &signer_client,

Original file line number	Diff line number	Diff line change
`@@ -189,7 +189,7 @@ impl SignerDb {`
`189`	`189`	`})`
`190`	`190`	`.optional();`
`191`	`191`	`match result {`
`192`		`- Ok(x) => Ok(x.unwrap_or_else(\|\| 0)),`
	`192`	`+ Ok(x) => Ok(x.unwrap_or(0)),`
`193`	`193`	`Err(e) => Err(DBError::from(e)),`
`194`	`194`	`}`
`195`	`195`	`}`
`@@ -294,7 +294,7 @@ impl SignerDb {`
`294`	`294`	`tenure: &ConsensusHash,`
`295`	`295`	`) -> Result<Option<BlockInfo>, DBError> {`
`296`	`296`	`let query = "SELECT block_info FROM blocks WHERE consensus_hash = ? AND signed_over = 1 ORDER BY stacks_height ASC LIMIT 1";`
`297`		`- let result: Option<String> = query_row(&self.db, query, &[tenure])?;`
	`297`	`+ let result: Option<String> = query_row(&self.db, query, [tenure])?;`
`298`	`298`
`299`	`299`	`try_deserialize(result)`
`300`	`300`	`}`