Log mempool sampled instead of exact lengths

mining/src/lib.rs

@@ -19,13 +19,20 @@ pub mod testutils;
 
 pub struct MiningCounters {
     pub creation_time: Instant,
+
+    // Counters
     pub high_priority_tx_counts: AtomicU64,
     pub low_priority_tx_counts: AtomicU64,
     pub block_tx_counts: AtomicU64,
     pub tx_accepted_counts: AtomicU64,
     pub input_counts: AtomicU64,
     pub output_counts: AtomicU64,
+
+    // Samples
     pub ready_txs_sample: AtomicU64,
+    pub txs_sample: AtomicU64,
+    pub orphans_sample: AtomicU64,
+    pub accepted_sample: AtomicU64,
 }
 
 impl Default for MiningCounters {
@@ -39,6 +46,9 @@ impl Default for MiningCounters {
             input_counts: Default::default(),
             output_counts: Default::default(),
             ready_txs_sample: Default::default(),
+            txs_sample: Default::default(),
+            orphans_sample: Default::default(),
+            accepted_sample: Default::default(),
         }
     }
 }
@@ -54,6 +64,9 @@ impl MiningCounters {
             input_counts: self.input_counts.load(Ordering::Relaxed),
             output_counts: self.output_counts.load(Ordering::Relaxed),
             ready_txs_sample: self.ready_txs_sample.load(Ordering::Relaxed),
+            txs_sample: self.txs_sample.load(Ordering::Relaxed),
+            orphans_sample: self.orphans_sample.load(Ordering::Relaxed),
+            accepted_sample: self.accepted_sample.load(Ordering::Relaxed),
         }
     }
 
@@ -79,6 +92,9 @@ pub struct MempoolCountersSnapshot {
     pub input_counts: u64,
     pub output_counts: u64,
     pub ready_txs_sample: u64,
+    pub txs_sample: u64,
+    pub orphans_sample: u64,
+    pub accepted_sample: u64,
 }
 
 impl MempoolCountersSnapshot {
@@ -119,6 +135,9 @@ impl core::ops::Sub for &MempoolCountersSnapshot {
             input_counts: self.input_counts.checked_sub(rhs.input_counts).unwrap_or_default(),
             output_counts: self.output_counts.checked_sub(rhs.output_counts).unwrap_or_default(),
             ready_txs_sample: (self.ready_txs_sample + rhs.ready_txs_sample) / 2,
+            txs_sample: (self.txs_sample + rhs.txs_sample) / 2,
+            orphans_sample: (self.orphans_sample + rhs.orphans_sample) / 2,
+            accepted_sample: (self.accepted_sample + rhs.accepted_sample) / 2,
         }
     }
 }

mining/src/manager.rs

@@ -225,7 +225,6 @@ impl MiningManager {
             mempool.post_validate_and_insert_transaction(consensus, validation_result, transaction, priority, orphan)?
         {
             let unorphaned_transactions = mempool.get_unorphaned_transactions_after_accepted_transaction(&accepted_transaction);
-            mempool.log_stats();
             drop(mempool);
 
             // The capacity used here may be exceeded since accepted unorphaned transaction may themselves unorphan other transactions.
@@ -296,7 +295,6 @@ impl MiningManager {
                     }
                 })
                 .collect::<Vec<_>>();
-            mempool.log_stats();
             drop(mempool);
         }
         accepted_transactions
@@ -388,7 +386,6 @@ impl MiningManager {
                 }
             });
             unorphaned_transactions.extend(txs);
-            mempool.log_stats();
         }
 
         accepted_transactions.extend(self.validate_and_insert_unorphaned_transactions(consensus, unorphaned_transactions));
@@ -523,8 +520,6 @@ impl MiningManager {
             1 => debug!("Removed transaction ({}) {}", TxRemovalReason::Expired, expired_low_priority_transactions[0]),
             n => debug!("Removed {} transactions ({}): {}...", n, TxRemovalReason::Expired, expired_low_priority_transactions[0]),
         }
-
-        self.mempool.write().log_stats();
     }
 
     pub fn revalidate_high_priority_transactions(
@@ -696,7 +691,6 @@ impl MiningManager {
                 let _ = transaction_ids_sender.send(valid_ids);
             }
             drop(_swo);
-            mempool.log_stats();
             drop(mempool);
         }
         match accepted + missing_outpoint + invalid {

mining/src/mempool/handle_new_block_transactions.rs

@@ -47,7 +47,9 @@ impl Mempool {
         self.counters.input_counts.fetch_add(input_counts as u64, Ordering::Relaxed);
         self.counters.output_counts.fetch_add(output_counts as u64, Ordering::Relaxed);
         self.counters.ready_txs_sample.store(self.transaction_pool.ready_transaction_count() as u64, Ordering::Relaxed);
-        self.log_stats();
+        self.counters.txs_sample.store(self.transaction_pool.len() as u64, Ordering::Relaxed);
+        self.counters.orphans_sample.store(self.orphan_pool.len() as u64, Ordering::Relaxed);
+        self.counters.accepted_sample.store(self.accepted_transactions.len() as u64, Ordering::Relaxed);
 
         Ok(unorphaned_transactions)
     }

mining/src/mempool/mod.rs

@@ -12,10 +12,7 @@ use self::{
     tx::Priority,
 };
 use kaspa_consensus_core::tx::{MutableTransaction, TransactionId};
-use kaspa_core::{
-    info,
-    time::{unix_now, Stopwatch},
-};
+use kaspa_core::time::Stopwatch;
 use std::{collections::hash_map::Entry, sync::Arc};
 
 pub(crate) mod check_transaction_standard;
@@ -48,7 +45,6 @@ pub(crate) struct Mempool {
     transaction_pool: TransactionsPool,
     orphan_pool: OrphanPool,
     accepted_transactions: AcceptedTransactions,
-    last_stat_report_time: u64,
     counters: Arc<MiningCounters>,
 }
 
@@ -57,7 +53,7 @@ impl Mempool {
         let transaction_pool = TransactionsPool::new(config.clone());
         let orphan_pool = OrphanPool::new(config.clone());
         let accepted_transactions = AcceptedTransactions::new(config.clone());
-        Self { config, transaction_pool, orphan_pool, accepted_transactions, last_stat_report_time: unix_now(), counters }
+        Self { config, transaction_pool, orphan_pool, accepted_transactions, counters }
     }
 
     pub(crate) fn get_transaction(
@@ -166,20 +162,6 @@ impl Mempool {
             .filter(|transaction_id| !(self.transaction_pool.has(transaction_id) || self.orphan_pool.has(transaction_id)));
         self.accepted_transactions.unaccepted(&mut not_in_pools_txs)
     }
-
-    pub(crate) fn log_stats(&mut self) {
-        const LOG_STATS_REPORT_INTERVAL_MILLISECONDS: u64 = 2000;
-        let now = unix_now();
-        if now >= self.last_stat_report_time + LOG_STATS_REPORT_INTERVAL_MILLISECONDS {
-            info!(
-                "Mempool stats: {} txs, {} orphans, {} accepted",
-                self.transaction_pool.len(),
-                self.orphan_pool.len(),
-                self.accepted_transactions.len()
-            );
-            self.last_stat_report_time = now;
-        }
-    }
 }
 
 pub mod tx {

mining/src/monitor.rs

@@ -61,17 +61,24 @@ impl MiningMonitor {
                 delta.low_priority_tx_counts,
                 delta.tx_accepted_counts,
             );
-            // FIXME: (wip) decide if the log level should be debug and what info should be kept or formulated differently
+            // FIXME: (wip) change the log level to debug and decide what info should be kept or formulated differently
             if tx_script_cache_snapshot != last_tx_script_cache_snapshot {
                 info!(
-                    "UTXOs stats: {} spent, {} created ({} signatures validated, {} cache hits, {:.2} hit ratio)",
+                    "UTXO set stats: {} spent, {} created ({} signatures validated, {} cache hits, {:.2} hit ratio)",
                     delta.input_counts,
                     delta.output_counts,
                     tx_script_cache_delta.insert_counts,
                     tx_script_cache_delta.get_counts,
                     tx_script_cache_delta.hit_ratio()
                 );
             }
+            // FIXME: change to debug
+            if delta.txs_sample + delta.orphans_sample > 0 {
+                info!(
+                    "Mempool sample: {} ready out of {} txs, {} orphans, {} cached as accepted",
+                    delta.ready_txs_sample, delta.txs_sample, delta.orphans_sample, delta.accepted_sample
+                );
+            }
 
             last_snapshot = snapshot;
             last_tx_script_cache_snapshot = tx_script_cache_snapshot;