Merge pull request #6203 from obycode/feat/miner-metrics

Miner metrics and mock miner improvements

Author: obycode

CHANGELOG.md

@@ -10,6 +10,9 @@ and this project adheres to the versioning scheme outlined in the [README.md](RE
 ### Added
 
 - Added a new RPC endpoint `/v3/health` to query the node's health status. The endpoint returns a 200 status code with relevant synchronization information (including the node's current Stacks tip height, the maximum Stacks tip height among its neighbors, and the difference between these two). A user can use the `difference_from_max_peer` value to decide what is a good threshold for them before considering the node out of sync. The endpoint returns a 500 status code if the query cannot retrieve viable data.
+- Improve prometheus metrics to gain more insights into the current state of the mempool
+  - `stacks_node_miner_stop_reason_total`: Counts the number of times the miner stopped mining due to various reasons.
+  - Always report the number of transactions mined in the last attempt, even if there were 0
 
 - Added a new option `--postcondition-mode [allow, deny]` to `blockstack-cli publish` command, to set the post-condition mode to allow or deny on the transaction (default is deny)
 
@@ -20,6 +23,7 @@ and this project adheres to the versioning scheme outlined in the [README.md](RE
 ### Fixed
 
 - Fixed an issue that prevented the correct usage of anchor mode options (`--microblock-only`, `--block-only`) when using `blockstack-cli publish` command.
+- Fix several bugs in the mock-miner that caused it to fail to mine blocks in certain conditions
 
 ## [3.1.0.0.12]
 

stackslib/src/chainstate/nakamoto/miner.rs

@@ -602,6 +602,7 @@ impl NakamotoBlockBuilder {
         }
 
         if builder.txs.is_empty() {
+            set_last_mined_block_transaction_count(0);
             return Err(Error::NoTransactionsToMine);
         }
 

stackslib/src/chainstate/stacks/miner.rs

@@ -54,7 +54,8 @@ use crate::clarity_vm::clarity::{ClarityInstance, Error as clarity_error};
 use crate::core::mempool::*;
 use crate::core::*;
 use crate::monitoring::{
-    set_last_mined_block_transaction_count, set_last_mined_execution_cost_observed,
+    increment_miner_stop_reason, set_last_mined_block_transaction_count,
+    set_last_mined_execution_cost_observed, MinerStopReason,
 };
 use crate::net::relay::Relayer;
 
@@ -2801,6 +2802,7 @@ fn select_and_apply_transactions_from_mempool<B: BlockBuilder>(
                     (*settings.miner_status.lock().expect("FATAL: mutex poisoned")).is_blocked();
                 if blocked {
                     info!("Miner stopping due to preemption");
+                    increment_miner_stop_reason(MinerStopReason::Preempted);
                     return Ok(None);
                 }
 
@@ -2809,6 +2811,7 @@ fn select_and_apply_transactions_from_mempool<B: BlockBuilder>(
 
                 if block_limit_hit == BlockLimitFunction::LIMIT_REACHED {
                     info!("Miner stopping due to limit reached");
+                    increment_miner_stop_reason(MinerStopReason::LimitReached);
                     return Ok(None);
                 }
                 let time_now = get_epoch_time_ms();
@@ -2817,6 +2820,7 @@ fn select_and_apply_transactions_from_mempool<B: BlockBuilder>(
                         "Miner stopping due to mining time exceeded ({} ms)",
                         max_miner_time_ms
                     );
+                    increment_miner_stop_reason(MinerStopReason::DeadlineReached);
                     return Ok(None);
                 }
                 if let Some(time_estimate) = txinfo.metadata.time_estimate_ms {
@@ -2926,6 +2930,7 @@ fn select_and_apply_transactions_from_mempool<B: BlockBuilder>(
                                 {
                                     info!("Miner stopping due to limit reached");
                                     block_limit_hit = BlockLimitFunction::LIMIT_REACHED;
+                                    increment_miner_stop_reason(MinerStopReason::LimitReached);
                                     return Ok(None);
                                 }
                             }

stackslib/src/core/mempool.rs

@@ -1695,7 +1695,7 @@ impl MemPoolDB {
                     break MempoolIterationStopReason::DeadlineReached;
                 }
 
-                // First, try to read from the retry list
+                // Get the next candidate transaction.
                 let (candidate, update_estimate) = match settings.strategy {
                     MemPoolWalkStrategy::GlobalFeeRate => {
                         // First, try to read from the retry list
@@ -1733,6 +1733,9 @@ impl MemPoolDB {
                                                 !start_with_no_estimate,
                                             ),
                                             None => {
+                                                monitoring::increment_miner_stop_reason(
+                                                    monitoring::MinerStopReason::NoTransactions,
+                                                );
                                                 break MempoolIterationStopReason::NoMoreCandidates;
                                             }
                                         }
@@ -1749,6 +1752,9 @@ impl MemPoolDB {
                                 (tx, update_estimate)
                             }
                             None => {
+                                monitoring::increment_miner_stop_reason(
+                                    monitoring::MinerStopReason::NoTransactions,
+                                );
                                 break MempoolIterationStopReason::NoMoreCandidates;
                             }
                         }

stackslib/src/monitoring/mod.rs

@@ -462,6 +462,22 @@ pub fn get_burnchain_signer() -> Option<BurnchainSigner> {
     None
 }
 
+define_named_enum!(MinerStopReason {
+    NoTransactions("no_transactions"),
+    Preempted("preempted"),
+    LimitReached("limit_reached"),
+    DeadlineReached("deadline_reached"),
+});
+
+// Increment the counter for the given miner stop reason.
+#[allow(unused_variables)]
+pub fn increment_miner_stop_reason(reason: MinerStopReason) {
+    #[cfg(feature = "monitoring_prom")]
+    prometheus::MINER_STOP_REASON_TOTAL
+        .with_label_values(&[reason.get_name_str()])
+        .inc();
+}
+
 #[derive(Debug)]
 pub struct SetGlobalBurnchainSignerError;
 

stackslib/src/monitoring/prometheus.rs

@@ -254,6 +254,12 @@ lazy_static! {
         "stacks_node_miner_current_median_commitment_low",
         "Low 64 bits of a miner's median commitment over the mining commitment window."
     )).unwrap();
+
+    pub static ref MINER_STOP_REASON_TOTAL: IntCounterVec = register_int_counter_vec!(
+        "stacks_node_miner_stop_reason_total",
+        "Total number of times the miner stopped for each reason",
+        &["reason"]
+    ).unwrap();
 }
 
 pub fn new_rpc_call_timer(path: &str) -> HistogramTimer {

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

@@ -528,16 +528,21 @@ impl BlockMinerThread {
             thread::sleep(Duration::from_millis(ABORT_TRY_AGAIN_MS));
             return Ok(());
         }
+
+        // Reset the mempool caches if needed. When mock-mining, we always
+        // reset the caches, because the blocks we mine are not actually
+        // processed, so the mempool caches are not valid.
         if self.reset_mempool_caches
             || self.config.miner.mempool_walk_strategy
                 == MemPoolWalkStrategy::NextNonceWithHighestFeeRate
+            || self.config.node.mock_mining
         {
             let mut mem_pool = self
                 .config
                 .connect_mempool_db()
                 .expect("Database failure opening mempool");
 
-            if self.reset_mempool_caches {
+            if self.reset_mempool_caches || self.config.node.mock_mining {
                 mem_pool.reset_mempool_caches()?;
             } else {
                 // Even if the nonce cache is still valid, NextNonceWithHighestFeeRate strategy
@@ -1400,20 +1405,15 @@ impl BlockMinerThread {
             .make_vrf_proof()
             .ok_or_else(|| NakamotoNodeError::BadVrfConstruction)?;
 
-        if self.last_block_mined.is_none() && parent_block_info.parent_tenure.is_none() {
-            warn!("Miner should be starting a new tenure, but failed to load parent tenure info");
-            return Err(NakamotoNodeError::ParentNotFound);
-        };
-
-        // If we're mock mining, we need to manipulate the `last_block_mined`
-        // to match what it should be based on the actual chainstate.
         if self.config.node.mock_mining {
             if let Some((last_block_consensus_hash, _)) = &self.last_block_mined {
-                // If the parent block is in the same tenure, then we should
-                // pretend that we mined it.
+                // If we're mock mining, we need to manipulate the `last_block_mined`
+                // to match what it should be based on the actual chainstate.
                 if last_block_consensus_hash
                     == &parent_block_info.stacks_parent_header.consensus_hash
                 {
+                    // If the parent block is in the same tenure, then we should
+                    // pretend that we mined it.
                     self.last_block_mined = Some((
                         parent_block_info.stacks_parent_header.consensus_hash,
                         parent_block_info
@@ -1429,6 +1429,11 @@ impl BlockMinerThread {
             }
         }
 
+        if self.last_block_mined.is_none() && parent_block_info.parent_tenure.is_none() {
+            warn!("Miner should be starting a new tenure, but failed to load parent tenure info");
+            return Err(NakamotoNodeError::ParentNotFound);
+        };
+
         // create our coinbase if this is the first block we've mined this tenure
         let tenure_start_info = self.make_tenure_start_info(
             &chain_state,

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

@@ -1298,9 +1298,14 @@ impl RelayerThread {
         debug!("Relayer: starting new tenure thread");
 
         let rand_id = thread_rng().gen::<u32>();
+        let is_mock = if self.config.node.mock_mining {
+            "mock-"
+        } else {
+            ""
+        };
 
         let new_miner_handle = std::thread::Builder::new()
-            .name(format!("miner.{parent_tenure_start}.{rand_id}",))
+            .name(format!("{is_mock}miner.{parent_tenure_start}.{rand_id}",))
             .stack_size(BLOCK_PROCESSOR_STACK_SIZE)
             .spawn(move || {
                 debug!(