diff --git a/mining/src/lib.rs b/mining/src/lib.rs index d5eb767df..90affba84 100644 --- a/mining/src/lib.rs +++ b/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, } } } diff --git a/mining/src/manager.rs b/mining/src/manager.rs index bc140e933..65e089de2 100644 --- a/mining/src/manager.rs +++ b/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::>(); - 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 { diff --git a/mining/src/mempool/handle_new_block_transactions.rs b/mining/src/mempool/handle_new_block_transactions.rs index c234fcc7e..21295ae1e 100644 --- a/mining/src/mempool/handle_new_block_transactions.rs +++ b/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) } diff --git a/mining/src/mempool/mod.rs b/mining/src/mempool/mod.rs index 87bc0c01b..4849c3c83 100644 --- a/mining/src/mempool/mod.rs +++ b/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, } @@ -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 { diff --git a/mining/src/monitor.rs b/mining/src/monitor.rs index b71bb345c..b748ff09e 100644 --- a/mining/src/monitor.rs +++ b/mining/src/monitor.rs @@ -61,10 +61,10 @@ 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, @@ -72,6 +72,13 @@ impl MiningMonitor { 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;