feat: track timing of sortitions and allowance for reorgs

* track sortition timing
* track proposal timing
* make proposal / sortition timing configurable

libsigner/src/events.rs

@@ -20,6 +20,7 @@ use std::net::{SocketAddr, TcpListener, TcpStream};
 use std::sync::atomic::{AtomicBool, Ordering};
 use std::sync::mpsc::Sender;
 use std::sync::Arc;
+use std::time::SystemTime;
 
 use blockstack_lib::chainstate::nakamoto::NakamotoBlock;
 use blockstack_lib::chainstate::stacks::boot::{MINERS_NAME, SIGNERS_NAME};
@@ -111,7 +112,14 @@ pub enum SignerEvent<T: SignerEventTrait> {
     /// Status endpoint request
     StatusCheck,
     /// A new burn block event was received with the given burnchain block height
-    NewBurnBlock(u64),
+    NewBurnBlock {
+        /// the burn height for the newly processed burn block
+        burn_height: u64,
+        /// the burn hash for the newly processed burn block
+        burn_header_hash: BurnchainHeaderHash,
+        /// the time at which this event was received by the signer's event processor
+        received_time: SystemTime,
+    },
 }
 
 /// Trait to implement a stop-signaler for the event receiver thread.
@@ -516,7 +524,19 @@ fn process_new_burn_block_event<T: SignerEventTrait>(
     }
     let temp: TempBurnBlockEvent = serde_json::from_slice(body.as_bytes())
         .map_err(|e| EventError::Deserialize(format!("Could not decode body to JSON: {:?}", &e)))?;
-    let event = SignerEvent::NewBurnBlock(temp.burn_block_height);
+    let burn_header_hash = temp
+        .burn_block_hash
+        .get(2..)
+        .ok_or_else(|| EventError::Deserialize("Hex string should be 0x prefixed".into()))
+        .and_then(|hex| {
+            BurnchainHeaderHash::from_hex(hex)
+                .map_err(|e| EventError::Deserialize(format!("Invalid hex string: {e}")))
+        })?;
+    let event = SignerEvent::NewBurnBlock {
+        burn_height: temp.burn_block_height,
+        received_time: SystemTime::now(),
+        burn_header_hash,
+    };
     if let Err(e) = request.respond(HttpResponse::empty(200u16)) {
         error!("Failed to respond to request: {:?}", &e);
     }

stacks-signer/src/chainstate.rs

@@ -13,17 +13,45 @@
 // 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 blockstack_lib::chainstate::nakamoto::NakamotoBlock;
 use blockstack_lib::chainstate::stacks::TenureChangePayload;
 use blockstack_lib::net::api::getsortition::SortitionInfo;
+use blockstack_lib::util_lib::db::Error as DBError;
+use clarity::types::chainstate::BurnchainHeaderHash;
 use slog::{slog_info, slog_warn};
 use stacks_common::types::chainstate::{ConsensusHash, StacksPublicKey};
 use stacks_common::util::hash::Hash160;
 use stacks_common::{info, warn};
 
 use crate::client::{ClientError, StacksClient};
+use crate::config::SignerConfig;
 use crate::signerdb::SignerDb;
 
+#[derive(thiserror::Error, Debug)]
+/// Error type for the signer chainstate module
+pub enum SignerChainstateError {
+    /// Error resulting from database interactions
+    #[error("Database error: {0}")]
+    DBError(DBError),
+    /// Error resulting from crate::client interactions
+    #[error("Client error: {0}")]
+    ClientError(ClientError),
+}
+
+impl From<ClientError> for SignerChainstateError {
+    fn from(value: ClientError) -> Self {
+        Self::ClientError(value)
+    }
+}
+
+impl From<DBError> for SignerChainstateError {
+    fn from(value: DBError) -> Self {
+        Self::DBError(value)
+    }
+}
+
 /// Captures this signer's current view of a sortition's miner.
 #[derive(PartialEq, Eq, Debug)]
 pub enum SortitionMinerStatus {
@@ -56,6 +84,26 @@ pub struct SortitionState {
     pub consensus_hash: ConsensusHash,
     /// what is this signer's view of the this sortition's miner? did they misbehave?
     pub miner_status: SortitionMinerStatus,
+    /// the timestamp in the burn block that performed this sortition
+    pub burn_header_timestamp: u64,
+    /// the burn header hash of the burn block that performed this sortition
+    pub burn_block_hash: BurnchainHeaderHash,
+}
+
+/// Captures the configuration settings used by the signer when evaluating block proposals.
+#[derive(Debug, Clone)]
+pub struct ProposalEvalConfig {
+    /// How much time between the first block proposal in a tenure and the next bitcoin block
+    ///  must pass before a subsequent miner isn't allowed to reorg the tenure
+    pub first_proposal_burn_block_timing: Duration,
+}
+
+impl From<&SignerConfig> for ProposalEvalConfig {
+    fn from(value: &SignerConfig) -> Self {
+        Self {
+            first_proposal_burn_block_timing: value.first_proposal_burn_block_timing.clone(),
+        }
+    }
 }
 
 /// The signer's current view of the stacks chain's sortition
@@ -68,6 +116,8 @@ pub struct SortitionsView {
     pub cur_sortition: SortitionState,
     /// the hash at which the sortitions view was fetched
     pub latest_consensus_hash: ConsensusHash,
+    /// configuration settings for evaluating proposals
+    pub config: ProposalEvalConfig,
 }
 
 impl TryFrom<SortitionInfo> for SortitionState {
@@ -85,6 +135,8 @@ impl TryFrom<SortitionInfo> for SortitionState {
             parent_tenure_id: value
                 .stacks_parent_ch
                 .ok_or_else(|| ClientError::UnexpectedSortitionInfo)?,
+            burn_header_timestamp: value.burn_header_timestamp,
+            burn_block_hash: value.burn_block_hash,
             miner_status: SortitionMinerStatus::Valid,
         })
     }
@@ -112,7 +164,7 @@ impl SortitionsView {
         signer_db: &SignerDb,
         block: &NakamotoBlock,
         block_pk: &StacksPublicKey,
-    ) -> Result<bool, ClientError> {
+    ) -> Result<bool, SignerChainstateError> {
         let bitvec_all_1s = block.header.pox_treatment.iter().all(|entry| entry);
         if !bitvec_all_1s {
             warn!(
@@ -203,8 +255,13 @@ impl SortitionsView {
                 return Ok(false);
             }
             // now, we have to check if the parent tenure was a valid choice.
-            let is_valid_parent_tenure =
-                Self::check_parent_tenure_choice(proposed_by.state(), block, client)?;
+            let is_valid_parent_tenure = Self::check_parent_tenure_choice(
+                proposed_by.state(),
+                block,
+                signer_db,
+                client,
+                &self.config.first_proposal_burn_block_timing,
+            )?;
             if !is_valid_parent_tenure {
                 return Ok(false);
             }
@@ -251,8 +308,10 @@ impl SortitionsView {
     fn check_parent_tenure_choice(
         sortition_state: &SortitionState,
         block: &NakamotoBlock,
+        signer_db: &SignerDb,
         client: &StacksClient,
-    ) -> Result<bool, ClientError> {
+        first_proposal_burn_block_timing: &Duration,
+    ) -> Result<bool, SignerChainstateError> {
         // if the parent tenure is the last sortition, it is a valid choice.
         // if the parent tenure is a reorg, then all of the reorged sortitions
         //  must either have produced zero blocks _or_ produced their first block
@@ -277,9 +336,61 @@ impl SortitionsView {
             );
             return Ok(false);
         }
+
+        // this value *should* always be some, but try to do the best we can if it isn't
+        let sortition_state_received_time =
+            signer_db.get_burn_block_receive_time(&sortition_state.burn_block_hash)?;
+
         for tenure in tenures_reorged.iter() {
+            if tenure.consensus_hash == sortition_state.parent_tenure_id {
+                // this was a built-upon tenure, no need to check this tenure as part of the reorg.
+                continue;
+            }
+
             if tenure.first_block_mined.is_some() {
-                // TODO: must check if the first block was poorly timed.
+                let Some(local_block_info) =
+                    signer_db.get_first_signed_block_in_tenure(&tenure.consensus_hash)?
+                else {
+                    warn!(
+                        "Miner is not building off of most recent tenure, but a tenure they attempted to reorg has already mined blocks, and there is no local knowledge for that tenure's block timing.";
+                        "proposed_block_consensus_hash" => %block.header.consensus_hash,
+                        "proposed_block_signer_sighash" => %block.header.signer_signature_hash(),
+                        "parent_tenure" => %sortition_state.parent_tenure_id,
+                        "last_sortition" => %sortition_state.prior_sortition,
+                        "violating_tenure_id" => %tenure.consensus_hash,
+                        "violating_tenure_first_block_id" => ?tenure.first_block_mined,
+                    );
+                    return Ok(false);
+                };
+
+                let checked_proposal_timing = if let Some(sortition_state_received_time) =
+                    sortition_state_received_time
+                {
+                    // how long was there between when the proposal was received and the next sortition started?
+                    let proposal_to_sortition = sortition_state_received_time
+                        .saturating_sub(local_block_info.proposed_time);
+                    if Duration::from_secs(proposal_to_sortition)
+                        <= *first_proposal_burn_block_timing
+                    {
+                        info!(
+                            "Miner is not building off of most recent tenure. A tenure they reorg has already mined blocks, but the block was poorly timed, allowing the reorg.";
+                            "proposed_block_consensus_hash" => %block.header.consensus_hash,
+                            "proposed_block_signer_sighash" => %block.header.signer_signature_hash(),
+                            "parent_tenure" => %sortition_state.parent_tenure_id,
+                            "last_sortition" => %sortition_state.prior_sortition,
+                            "violating_tenure_id" => %tenure.consensus_hash,
+                            "violating_tenure_first_block_id" => ?tenure.first_block_mined,
+                            "violating_tenure_proposed_time" => local_block_info.proposed_time,
+                            "new_tenure_received_time" => sortition_state_received_time,
+                            "new_tenure_burn_timestamp" => sortition_state.burn_header_timestamp,
+                        );
+                        continue;
+                    }
+                    true
+                } else {
+                    false
+                };
+
                 warn!(
                     "Miner is not building off of most recent tenure, but a tenure they attempted to reorg has already mined blocks.";
                     "proposed_block_consensus_hash" => %block.header.consensus_hash,
@@ -288,6 +399,7 @@ impl SortitionsView {
                     "last_sortition" => %sortition_state.prior_sortition,
                     "violating_tenure_id" => %tenure.consensus_hash,
                     "violating_tenure_first_block_id" => ?tenure.first_block_mined,
+                    "checked_proposal_timing" => checked_proposal_timing,
                 );
                 return Ok(false);
             }
@@ -346,7 +458,10 @@ impl SortitionsView {
     }
 
     /// Fetch a new view of the recent sortitions
-    pub fn fetch_view(client: &StacksClient) -> Result<Self, ClientError> {
+    pub fn fetch_view(
+        config: ProposalEvalConfig,
+        client: &StacksClient,
+    ) -> Result<Self, ClientError> {
         let latest_state = client.get_latest_sortition()?;
         let latest_ch = latest_state.consensus_hash;
 
@@ -383,6 +498,7 @@ impl SortitionsView {
             cur_sortition,
             last_sortition,
             latest_consensus_hash,
+            config,
         })
     }
 }

stacks-signer/src/client/mod.rs

@@ -565,6 +565,7 @@ pub(crate) mod tests {
             tx_fee_ustx: config.tx_fee_ustx,
             max_tx_fee_ustx: config.max_tx_fee_ustx,
             db_path: config.db_path.clone(),
+            first_proposal_burn_block_timing: Duration::from_secs(30),
         }
     }
 

stacks-signer/src/config.rs

@@ -151,6 +151,9 @@ pub struct SignerConfig {
     pub max_tx_fee_ustx: Option<u64>,
     /// The path to the signer's database file
     pub db_path: PathBuf,
+    /// How much time between the first block proposal in a tenure and the next bitcoin block
+    ///  must pass before a subsequent miner isn't allowed to reorg the tenure
+    pub first_proposal_burn_block_timing: Duration,
 }
 
 /// The parsed configuration for the signer
@@ -190,6 +193,9 @@ pub struct GlobalConfig {
     pub db_path: PathBuf,
     /// Metrics endpoint
     pub metrics_endpoint: Option<SocketAddr>,
+    /// How much time between the first block proposal in a tenure and the next bitcoin block
+    ///  must pass before a subsequent miner isn't allowed to reorg the tenure
+    pub first_proposal_burn_block_timing: Duration,
 }
 
 /// Internal struct for loading up the config file
@@ -227,6 +233,9 @@ struct RawConfigFile {
     pub db_path: String,
     /// Metrics endpoint
     pub metrics_endpoint: Option<String>,
+    /// How much time between the first block proposal in a tenure and the next bitcoin block
+    ///  must pass before a subsequent miner isn't allowed to reorg the tenure
+    pub first_proposal_burn_block_timing_secs: Option<u64>,
 }
 
 impl RawConfigFile {
@@ -298,6 +307,8 @@ impl TryFrom<RawConfigFile> for GlobalConfig {
         let dkg_private_timeout = raw_data.dkg_private_timeout_ms.map(Duration::from_millis);
         let nonce_timeout = raw_data.nonce_timeout_ms.map(Duration::from_millis);
         let sign_timeout = raw_data.sign_timeout_ms.map(Duration::from_millis);
+        let first_proposal_burn_block_timing =
+            Duration::from_secs(raw_data.first_proposal_burn_block_timing_secs.unwrap_or(30));
         let db_path = raw_data.db_path.into();
 
         let metrics_endpoint = match raw_data.metrics_endpoint {
@@ -331,6 +342,7 @@ impl TryFrom<RawConfigFile> for GlobalConfig {
             auth_password: raw_data.auth_password,
             db_path,
             metrics_endpoint,
+            first_proposal_burn_block_timing,
         })
     }
 }

stacks-signer/src/runloop.rs

@@ -248,6 +248,7 @@ impl<Signer: SignerTrait<T>, T: StacksMessageCodec + Clone + Send + Debug> RunLo
             key_ids,
             signer_entries,
             signer_slot_ids: signer_slot_ids.into_values().collect(),
+            first_proposal_burn_block_timing: self.config.first_proposal_burn_block_timing,
             ecdsa_private_key: self.config.ecdsa_private_key,
             stacks_private_key: self.config.stacks_private_key,
             node_host: self.config.node_host.to_string(),
@@ -419,8 +420,8 @@ impl<Signer: SignerTrait<T>, T: StacksMessageCodec + Clone + Send + Debug>
                 }
                 return None;
             }
-        } else if let Some(SignerEvent::NewBurnBlock(current_burn_block_height)) = event {
-            if let Err(e) = self.refresh_runloop(current_burn_block_height) {
+        } else if let Some(SignerEvent::NewBurnBlock { burn_height, .. }) = event {
+            if let Err(e) = self.refresh_runloop(burn_height) {
                 error!("Failed to refresh signer runloop: {e}.");
                 warn!("Signer may have an outdated view of the network.");
             }