diff --git a/chain/src/chain.rs b/chain/src/chain.rs index d1ee15f7fda..aec614756f6 100644 --- a/chain/src/chain.rs +++ b/chain/src/chain.rs @@ -476,7 +476,7 @@ impl ChainService { for leader_hash in self.orphan_blocks_broker().clone_leaders() { if !db_txn.get_block_epoch_index(&leader_hash).is_some() { - debug!("block {}'s block_epoch_index not stored", leader_hash); + trace!("a orphan leader: {} not stored", leader_hash); continue; } diff --git a/sync/src/relayer/mod.rs b/sync/src/relayer/mod.rs index a873ef02d7b..ad9a5455d51 100644 --- a/sync/src/relayer/mod.rs +++ b/sync/src/relayer/mod.rs @@ -27,7 +27,7 @@ use crate::{ }; use ckb_chain::chain::ChainController; use ckb_constant::sync::BAD_MESSAGE_BAN_TIME; -use ckb_logger::{debug_target, error_target, info, info_target, trace_target, warn_target}; +use ckb_logger::{debug, debug_target, error_target, info, info_target, trace_target, warn_target}; use ckb_network::{ async_trait, bytes::Bytes, tokio, CKBProtocolContext, CKBProtocolHandler, PeerIndex, SupportProtocols, TargetSession, diff --git a/sync/src/synchronizer/block_fetcher.rs b/sync/src/synchronizer/block_fetcher.rs index 6e96c26a99b..f087883ba05 100644 --- a/sync/src/synchronizer/block_fetcher.rs +++ b/sync/src/synchronizer/block_fetcher.rs @@ -8,7 +8,6 @@ use ckb_shared::{BlockStatus, HeaderView}; use ckb_systemtime::unix_time_as_millis; use ckb_types::{core, packed}; use std::cmp::min; -use std::time::Duration; pub struct BlockFetcher<'a> { synchronizer: &'a Synchronizer, @@ -190,10 +189,11 @@ impl<'a> BlockFetcher<'a> { && inflight.insert(self.peer, (header.number(), hash).into()) { debug!( - "request peer-{} for {}-{}", + "request peer-{} for {}-{}, tip: {}", self.peer, header.number(), - header.hash() + header.hash(), + self.active_chain.tip_number(), ); fetch.push(header) } @@ -237,6 +237,21 @@ impl<'a> BlockFetcher<'a> { inflight.total_inflight_count(), *inflight ) + } else { + let fetch_head = fetch.first().map_or(0_u64.into(), |v| v.number()); + let fetch_last = fetch.last().map_or(0_u64.into(), |v| v.number()); + let inflight_peer_count = inflight.peer_inflight_count(self.peer); + let inflight_total_count = inflight.total_inflight_count(); + debug!( + "request peer-{} for batch blocks: [{}-{}], batch len:{} , tip_header: {}, [peer / total inflight count]: [{} / {}]", + self.peer, + fetch_head, + fetch_last, + fetch.len(), + self.active_chain.tip_number(), + inflight_peer_count, + inflight_total_count, + ); } Some( diff --git a/sync/src/synchronizer/mod.rs b/sync/src/synchronizer/mod.rs index 488b51866a6..ef46678f872 100644 --- a/sync/src/synchronizer/mod.rs +++ b/sync/src/synchronizer/mod.rs @@ -578,7 +578,9 @@ impl Synchronizer { continue; } if let Err(err) = nc.disconnect(*peer, "sync disconnect") { - debug!("synchronizer disconnect error: {:?}", err); + debug!("synchronizer disconnect peer-{}, error: {:?}", *peer, err); + } else { + debug!("synchronizer disconnect peer-{}", *peer); } } diff --git a/sync/src/types/mod.rs b/sync/src/types/mod.rs index c67ca59c4a5..f48dd6211b7 100644 --- a/sync/src/types/mod.rs +++ b/sync/src/types/mod.rs @@ -12,7 +12,7 @@ use ckb_constant::sync::{ RETRY_ASK_TX_TIMEOUT_INCREASE, SUSPEND_SYNC_TIME, }; use ckb_error::{is_internal_db_error, Error as CKBError}; -use ckb_logger::{debug, error, trace}; +use ckb_logger::{debug, error, info, trace}; use ckb_network::{CKBProtocolContext, PeerIndex, SupportProtocols}; use ckb_shared::{shared::Shared, Snapshot}; use ckb_shared::{BlockStatus, HeaderView}; @@ -263,6 +263,11 @@ impl HeadersSyncController { } } +#[derive(Clone, Default, Debug)] +pub struct PeerTrace { + connected_at: u64, +} + #[derive(Clone, Default, Debug)] pub struct PeerState { pub headers_sync_controller: Option, @@ -275,10 +280,12 @@ pub struct PeerState { // use on ibd concurrent block download // save `get_headers` locator hashes here pub unknown_header_list: Vec, + + pub trace: PeerTrace, } impl PeerState { - pub fn new(peer_flags: PeerFlags) -> PeerState { + pub fn new(peer_flags: PeerFlags, connected_at: u64) -> PeerState { PeerState { headers_sync_controller: None, peer_flags, @@ -286,6 +293,7 @@ impl PeerState { best_known_header: None, last_common_header: None, unknown_header_list: Vec::new(), + trace: PeerTrace { connected_at }, } } @@ -850,7 +858,7 @@ impl Peers { state.sync_connected(); }) .or_insert_with(|| { - let mut state = PeerState::new(peer_flags); + let mut state = PeerState::new(peer_flags, unix_time_as_millis()); state.sync_connected(); state }); @@ -859,7 +867,7 @@ impl Peers { pub fn relay_connected(&self, peer: PeerIndex) { self.state .entry(peer) - .or_insert_with(|| PeerState::new(PeerFlags::default())); + .or_insert_with(|| PeerState::new(PeerFlags::default(), unix_time_as_millis())); } pub fn get_best_known_header(&self, pi: PeerIndex) -> Option { @@ -909,6 +917,12 @@ impl Peers { ); } + info!( + "disconnected peer: {}, connection_duration: {}", + peer, + unix_time_as_millis() - peer_state.trace.connected_at + ); + // Protection node disconnected if peer_state.peer_flags.is_protect { assert_ne!( diff --git a/util/app-config/src/lib.rs b/util/app-config/src/lib.rs index a8fbbab64da..d66b338a83c 100644 --- a/util/app-config/src/lib.rs +++ b/util/app-config/src/lib.rs @@ -31,7 +31,7 @@ use clap::ArgMatches; use std::{path::PathBuf, str::FromStr}; // 500_000 total difficulty -const MIN_CHAIN_WORK_500K: U256 = u256!("0x3314412053c82802a7"); +const MIN_CHAIN_WORK_500K: U256 = u256!("0x331"); /// A struct including all the information to start the ckb process. pub struct Setup {