Skip to content

Commit

Permalink
cleanup perf logs
Browse files Browse the repository at this point in the history
  • Loading branch information
chenyukang committed Mar 14, 2024
1 parent 8463d72 commit 96ccb0d
Show file tree
Hide file tree
Showing 4 changed files with 7 additions and 49 deletions.
11 changes: 2 additions & 9 deletions tx-pool/src/component/pool_map.rs
Original file line number Diff line number Diff line change
Expand Up @@ -19,8 +19,6 @@ use ckb_types::{
};
use multi_index_map::MultiIndexMap;
use std::collections::HashSet;
use std::time::Instant;

type ConflictEntry = (TxEntry, Reject);

#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash)]
Expand Down Expand Up @@ -131,16 +129,11 @@ impl PoolMap {
}

pub(crate) fn get_max_update_time(&self) -> u64 {
let instant = Instant::now();
let res = self
.entries
self.entries
.iter()
.map(|(_, entry)| entry.inner.timestamp)
.max()
.unwrap_or(0);
let duration = instant.elapsed();
debug!("[Perf] get_max_update_time duration: {:?}", duration);
res
.unwrap_or(0)
}

pub(crate) fn get_by_id(&self, id: &ProposalShortId) -> Option<&PoolEntry> {
Expand Down
7 changes: 0 additions & 7 deletions tx-pool/src/pool.rs
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,6 @@ use ckb_types::{
use lru::LruCache;
use std::collections::{HashMap, HashSet};
use std::sync::Arc;
use std::time::Instant;

const COMMITTED_HASH_CACHE_SIZE: usize = 100_000;
const CONFLICTES_CACHE_SIZE: usize = 10_000;
Expand Down Expand Up @@ -246,7 +245,6 @@ impl TxPool {
// Expire all transaction (and their dependencies) in the pool.
pub(crate) fn remove_expired(&mut self, callbacks: &Callbacks) {
let now_ms = ckb_systemtime::unix_time_as_millis();
let instant = Instant::now();

let removed: Vec<_> = self
.pool_map
Expand All @@ -262,13 +260,10 @@ impl TxPool {
let reject = Reject::Expiry(entry.timestamp);
callbacks.call_reject(self, &entry, reject);
}
let duration = instant.elapsed();
debug!("[Perf] remove_expired duration: {:?}", duration);
}

// Remove transactions from the pool until total size <= size_limit.
pub(crate) fn limit_size(&mut self, callbacks: &Callbacks) {
let instant = Instant::now();
while self.pool_map.total_tx_size > self.config.max_tx_pool_size {
let next_evict_entry = || {
self.pool_map
Expand All @@ -294,8 +289,6 @@ impl TxPool {
}
}
self.pool_map.entries.shrink_to_fit();
let duration = instant.elapsed();
debug!("[Perf] limit_size duration: {:?}", duration);
}

// remove transaction with detached proposal from gap and proposed
Expand Down
26 changes: 1 addition & 25 deletions tx-pool/src/process.rs
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ use ckb_verification::{
use std::collections::HashSet;
use std::collections::{HashMap, VecDeque};
use std::sync::Arc;
use std::time::{Duration, Instant};
use std::time::Duration;
use tokio::task::block_in_place;

const DELAY_LIMIT: usize = 1_500 * 21; // 1_500 per block, 21 blocks
Expand Down Expand Up @@ -103,7 +103,6 @@ impl TxPoolService {
entry: TxEntry,
mut status: TxStatus,
) -> (Result<(), Reject>, Arc<Snapshot>) {
let instant = Instant::now();
let (ret, snapshot) = self
.with_tx_pool_write_lock(move |tx_pool, snapshot| {
// check_rbf must be invoked in `write` lock to avoid concurrent issues.
Expand Down Expand Up @@ -171,8 +170,6 @@ impl TxPoolService {
})
.await;

let duration = instant.elapsed();
debug!("[Perf] submit_entry: {:?}", duration);
(ret, snapshot)
}

Expand Down Expand Up @@ -241,7 +238,6 @@ impl TxPoolService {
tx: &TransactionView,
) -> (Result<PreCheckedTx, Reject>, Arc<Snapshot>) {
// Acquire read lock for cheap check
let instant = Instant::now();
let tx_size = tx.data().serialized_size_in_block();

let (ret, snapshot) = self
Expand Down Expand Up @@ -283,8 +279,6 @@ impl TxPoolService {
}
})
.await;
let duration = instant.elapsed();
debug!("[Perf] pre-check: {:?}", duration);
(ret, snapshot)
}

Expand Down Expand Up @@ -1131,7 +1125,6 @@ fn _submit_entry(
) -> Result<HashSet<TxEntry>, Reject> {
let tx_hash = entry.transaction().hash();
debug!("submit_entry {:?} {}", status, tx_hash);
let start = Instant::now();
let (succ, evicts) = match status {
TxStatus::Fresh => tx_pool.add_pending(entry.clone())?,
TxStatus::Gap => tx_pool.add_gap(entry.clone())?,
Expand All @@ -1144,8 +1137,6 @@ fn _submit_entry(
TxStatus::Proposed => callbacks.call_proposed(&entry),
}
}
let duration = start.elapsed();
debug!("[Perf] Time elapsed in _submit_entry is: {:?}", duration);
Ok(evicts)
}

Expand All @@ -1158,7 +1149,6 @@ fn _update_tx_pool_for_reorg(
callbacks: &Callbacks,
mine_mode: bool,
) {
let instant = Instant::now();
tx_pool.snapshot = Arc::clone(&snapshot);

// NOTE: `remove_by_detached_proposal` will try to re-put the given expired/detached proposals into
Expand All @@ -1176,7 +1166,6 @@ fn _update_tx_pool_for_reorg(
let mut proposals = Vec::new();
let mut gaps = Vec::new();

let instant = Instant::now();
for entry in tx_pool.pool_map.entries.get_by_status(&Status::Gap) {
let short_id = entry.inner.proposal_short_id();
if snapshot.proposals().contains_proposed(&short_id) {
Expand All @@ -1193,16 +1182,7 @@ fn _update_tx_pool_for_reorg(
gaps.push(elem);
}
}
let duration = instant.elapsed();
debug!("[Perf] reorg duration: {:?}", duration);
debug!(
"[Perf] reorg size: tx_pool size {:?} snapshot gap: {:?}, proposed: {:?}",
tx_pool.pool_map.entries.len(),
snapshot.proposals().gap().len(),
snapshot.proposals().set().len(),
);

let instant = Instant::now();
for (id, entry) in proposals {
debug!("begin to proposed: {:x}", id);
if let Err(e) = tx_pool.proposed_rtx(&id) {
Expand All @@ -1228,17 +1208,13 @@ fn _update_tx_pool_for_reorg(
callbacks.call_reject(tx_pool, &entry, e.clone());
}
}
let duration = instant.elapsed();
debug!("[Perf] reorg setting: {:?}", duration);
}

// Remove expired transaction from pending
tx_pool.remove_expired(callbacks);

// Remove transactions from the pool until its size <= size_limit.
tx_pool.limit_size(callbacks);
let duration = instant.elapsed();
debug!("[Perf] reorg _update_tx_pool_for_reorg: {:?}", duration);
}

pub fn all_inputs_is_unknown(snapshot: &Snapshot, tx: &TransactionView) -> bool {
Expand Down
12 changes: 4 additions & 8 deletions tx-pool/src/service.rs
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@ use ckb_chain_spec::consensus::Consensus;
use ckb_channel::oneshot;
use ckb_error::AnyError;
use ckb_jsonrpc_types::BlockTemplate;
use ckb_logger::{debug, error, info};
use ckb_logger::{error, info};
use ckb_network::{NetworkController, PeerIndex};
use ckb_snapshot::Snapshot;
use ckb_stop_handler::new_tokio_exit_rx;
Expand All @@ -33,7 +33,7 @@ use std::sync::{
atomic::{AtomicBool, Ordering},
Arc,
};
use std::time::{Duration, Instant};
use std::time::Duration;
use tokio::sync::watch;
use tokio::sync::{mpsc, RwLock};
use tokio::task::block_in_place;
Expand Down Expand Up @@ -920,8 +920,7 @@ impl TxPoolService {
let tx_pool = self.tx_pool.read().await;
let orphan = self.orphan.read().await;
let tip_header = tx_pool.snapshot.tip_header();
let instant = Instant::now();
let res = TxPoolInfo {
TxPoolInfo {
tip_hash: tip_header.hash(),
tip_number: tip_header.number(),
pending_size: tx_pool.pool_map.pending_size(),
Expand All @@ -934,10 +933,7 @@ impl TxPoolService {
last_txs_updated_at: tx_pool.pool_map.get_max_update_time(),
tx_size_limit: TRANSACTION_SIZE_LIMIT,
max_tx_pool_size: self.tx_pool_config.max_tx_pool_size as u64,
};
let duration = instant.elapsed();
debug!("[Perf] tx_pool info: {:?}", duration);
res
}
}

pub fn should_notify_block_assembler(&self) -> bool {
Expand Down

0 comments on commit 96ccb0d

Please sign in to comment.