diff --git a/prdoc/pr_7554.prdoc b/prdoc/pr_7554.prdoc new file mode 100644 index 0000000000000..4978d01d4060f --- /dev/null +++ b/prdoc/pr_7554.prdoc @@ -0,0 +1,8 @@ +title: 'sc-informant: Print full hash when debug logging is enabled' +doc: +- audience: Node Dev + description: |- + When debugging stuff, it is useful to see the full hashes and not only the "short form". This makes it easier to read logs and follow blocks. +crates: +- name: sc-informant + bump: patch diff --git a/substrate/client/informant/src/display.rs b/substrate/client/informant/src/display.rs index 2decd76747827..8b3e2730584ff 100644 --- a/substrate/client/informant/src/display.rs +++ b/substrate/client/informant/src/display.rs @@ -24,6 +24,8 @@ use sc_network_sync::{SyncState, SyncStatus, WarpSyncPhase, WarpSyncProgress}; use sp_runtime::traits::{Block as BlockT, CheckedDiv, NumberFor, Saturating, Zero}; use std::{fmt, time::Instant}; +use crate::PrintFullHashOnDebugLogging; + /// State of the informant display system. /// /// This is the system that handles the line that gets regularly printed and that looks something @@ -138,9 +140,9 @@ impl InformantDisplay { target, style(num_connected_peers).white().bold(), style(best_number).white().bold(), - best_hash, + PrintFullHashOnDebugLogging(&best_hash), style(finalized_number).white().bold(), - info.chain.finalized_hash, + PrintFullHashOnDebugLogging(&info.chain.finalized_hash), style(TransferRateFormat(avg_bytes_per_sec_inbound)).green(), style(TransferRateFormat(avg_bytes_per_sec_outbound)).red(), ) diff --git a/substrate/client/informant/src/lib.rs b/substrate/client/informant/src/lib.rs index 0b0e13dc08bbb..88da105edac72 100644 --- a/substrate/client/informant/src/lib.rs +++ b/substrate/client/informant/src/lib.rs @@ -21,13 +21,18 @@ use console::style; use futures::prelude::*; use futures_timer::Delay; -use log::{debug, info, trace}; +use log::{debug, info, log_enabled, trace}; use sc_client_api::{BlockchainEvents, UsageProvider}; use sc_network::NetworkStatusProvider; use sc_network_sync::{SyncStatusProvider, SyncingService}; use sp_blockchain::HeaderMetadata; use sp_runtime::traits::{Block as BlockT, Header}; -use std::{collections::VecDeque, fmt::Display, sync::Arc, time::Duration}; +use std::{ + collections::VecDeque, + fmt::{Debug, Display}, + sync::Arc, + time::Duration, +}; mod display; @@ -78,7 +83,20 @@ where }; } -fn display_block_import(client: Arc) -> impl Future +/// Print the full hash when debug logging is enabled. +struct PrintFullHashOnDebugLogging<'a, H>(&'a H); + +impl Display for PrintFullHashOnDebugLogging<'_, H> { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + if log_enabled!(log::Level::Debug) { + Debug::fmt(&self.0, f) + } else { + Display::fmt(&self.0, f) + } + } +} + +async fn display_block_import(client: Arc) where C: UsageProvider + HeaderMetadata + BlockchainEvents, >::Error: Display, @@ -91,8 +109,9 @@ where // Hashes of the last blocks we have seen at import. let mut last_blocks = VecDeque::new(); let max_blocks_to_track = 100; + let mut notifications = client.import_notification_stream(); - client.import_notification_stream().for_each(move |n| { + while let Some(n) = notifications.next().await { // detect and log reorganizations. if let Some((ref last_num, ref last_hash)) = last_best { if n.header.parent_hash() != last_hash && n.is_new_best { @@ -103,9 +122,9 @@ where Ok(ref ancestor) if ancestor.hash != *last_hash => info!( "♻️ Reorg on #{},{} to #{},{}, common ancestor #{},{}", style(last_num).red().bold(), - last_hash, + PrintFullHashOnDebugLogging(&last_hash), style(n.header.number()).green().bold(), - n.hash, + PrintFullHashOnDebugLogging(&n.hash), style(ancestor.number).white().bold(), ancestor.hash, ), @@ -133,11 +152,9 @@ where target: "substrate", "{best_indicator} Imported #{} ({} → {})", style(n.header.number()).white().bold(), - n.header.parent_hash(), - n.hash, + PrintFullHashOnDebugLogging(n.header.parent_hash()), + PrintFullHashOnDebugLogging(&n.hash), ); } - - future::ready(()) - }) + } }