octo
/
Zebra
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

fix(log): Remove redundant startup logs, fix progress bar number, order, and wording (#7087) 

* Remove duplicate "running" message, send log file opening logs to stderr

* Add missing block progress bar desc, make them consistent

* Put progress bars in a specific order in each section

* Actually make block progress bar desc consistent

* Make progress bar order even more consistent

* Fix fork blocks plural for 1 block

* Use the correct number of chain fork bars

* Disable confusing partial work display

* Add struct field category comments

* Silence a verbose inventory log
This commit is contained in:
teor 2023-07-05 17:08:59 +10:00 committed by GitHub
parent 5598d1a72b
commit f2a2a403a8
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 81 additions and 54 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

5
zebra-consensus/src/checkpoint.rs
View File

@ -265,10 +265,11 @@ where
let (sender, receiver) = mpsc::channel();
#[cfg(feature = "progress-bar")]
let queued_blocks_bar = howudoin::new().label("Queued Checkpoint Blocks");
let queued_blocks_bar = howudoin::new_root().label("Checkpoint Queue Height");
#[cfg(feature = "progress-bar")]
let verified_checkpoint_bar = howudoin::new().label("Verified Checkpoints");
let verified_checkpoint_bar =
howudoin::new_with_parent(queued_blocks_bar.id()).label("Verified Checkpoints");
let verifier = CheckpointVerifier {
checkpoint_list,

12
zebra-network/src/address_book_updater.rs
View File

@ -58,14 +58,12 @@ impl AddressBookUpdater {
#[cfg(feature = "progress-bar")]
let (mut address_info, address_bar, never_bar, failed_bar) = {
let address_bar = howudoin::new().label("Known Peers");
let address_bar = howudoin::new_root().label("Known Peers");
let never_bar =
howudoin::new_with_parent(address_bar.id()).label("Never Attempted Peers");
let failed_bar = howudoin::new_with_parent(never_bar.id()).label("Failed Peers");
(
address_metrics.clone(),
address_bar,
howudoin::new_with_parent(address_bar.id()).label("Never Attempted Peers"),
howudoin::new_with_parent(address_bar.id()).label("Failed Peers"),
)
(address_metrics.clone(), address_bar, never_bar, failed_bar)
};
let worker_address_book = address_book.clone();

2
zebra-network/src/peer_set/limit.rs
View File

@ -66,7 +66,7 @@ impl ActiveConnectionCounter {
let label = label.to_string();
#[cfg(feature = "progress-bar")]
let connection_bar = howudoin::new().label(label.clone());
let connection_bar = howudoin::new_root().label(label.clone());
Self {
count: 0,

4
zebra-network/src/peer_set/set.rs
View File

@ -783,11 +783,11 @@ where
return fut.map_err(Into::into).boxed();
}
// TODO: reduce this log level after testing #2156 and #2726
tracing::info!(
tracing::debug!(
?hash,
"all ready peers are missing inventory, failing request"
);
async move {
// Let other tasks run, so a retry request might get different ready peers.
tokio::task::yield_now().await;

29
zebra-state/src/service/non_finalized_state.rs
View File

@ -36,6 +36,8 @@ pub(crate) use chain::Chain;
///
/// Most chain data is clone-on-write using [`Arc`].
pub struct NonFinalizedState {
// Chain Data
//
/// Verified, non-finalized chains, in ascending work order.
///
/// The best chain is [`NonFinalizedState::best_chain()`], or `chain_iter().next()`.
@ -43,6 +45,8 @@ pub struct NonFinalizedState {
/// callers should migrate to `chain_iter().next()`.
chain_set: BTreeSet<Arc<Chain>>,
// Configuration
//
/// The configured Zcash network.
pub network: Network,
@ -653,7 +657,7 @@ impl NonFinalizedState {
// Update the chain count bar
if self.chain_count_bar.is_none() {
self.chain_count_bar = Some(howudoin::new().label("Chain Forks"));
self.chain_count_bar = Some(howudoin::new_root().label("Chain Forks"));
}
let chain_count_bar = self
@ -677,9 +681,11 @@ impl NonFinalizedState {
match self.chain_count().cmp(&prev_length_bars) {
Greater => self
.chain_fork_length_bars
.resize_with(self.chain_count(), howudoin::new),
.resize_with(self.chain_count(), || {
howudoin::new_with_parent(chain_count_bar.id())
}),
Less => {
let redundant_bars = self.chain_fork_length_bars.split_off(prev_length_bars);
let redundant_bars = self.chain_fork_length_bars.split_off(self.chain_count());
for bar in redundant_bars {
bar.close();
}
@ -708,19 +714,24 @@ impl NonFinalizedState {
// zebra_chain::transparent::MIN_TRANSPARENT_COINBASE_MATURITY,
// ));
// display work as bits
let mut desc = format!(
"Work {:.1} bits",
chain.partial_cumulative_work.difficulty_bits_for_display(),
);
// TODO: store work in the finalized state for each height (#7109),
// and show the full chain work here, like `zcashd` (#7110)
//
// For now, we don't show any work here, see the deleted code in PR #7087.
let mut desc = String::new();
if let Some(recent_fork_height) = chain.recent_fork_height() {
let recent_fork_length = chain
.recent_fork_length()
.expect("just checked recent fork height");
let mut plural = "s";
if recent_fork_length == 1 {
plural = "";
}
desc.push_str(&format!(
" at {recent_fork_height:?} + {recent_fork_length} blocks"
" at {recent_fork_height:?} + {recent_fork_length} block{plural}"
));
}

39
zebrad/src/components/mempool.rs
View File

@ -414,26 +414,35 @@ impl Mempool {
let _max_transaction_count = self.config.tx_cost_limit
/ zebra_chain::transaction::MEMPOOL_TRANSACTION_COST_THRESHOLD;
self.queued_count_bar = Some(*howudoin::new().label("Mempool Queue").set_pos(0u64));
let transaction_count_bar = *howudoin::new_root()
.label("Mempool Transactions")
.set_pos(0u64);
// .set_len(max_transaction_count);
let transaction_cost_bar = howudoin::new_with_parent(transaction_count_bar.id())
.label("Mempool Cost")
.set_pos(0u64)
// .set_len(self.config.tx_cost_limit)
.fmt_as_bytes(true);
let queued_count_bar = *howudoin::new_with_parent(transaction_cost_bar.id())
.label("Mempool Queue")
.set_pos(0u64);
// .set_len(
// u64::try_from(downloads::MAX_INBOUND_CONCURRENCY).expect("fits in u64"),
// ),
// );
self.transaction_count_bar = Some(*howudoin::new().label("Mempool Txs").set_pos(0u64));
// .set_len(max_transaction_count),
self.transaction_cost_bar = Some(
howudoin::new()
.label("Mempool Cost")
.set_pos(0u64)
// .set_len(self.config.tx_cost_limit)
.fmt_as_bytes(true),
);
self.rejected_count_bar = Some(*howudoin::new().label("Mempool Rejects").set_pos(0u64));
let rejected_count_bar = *howudoin::new_with_parent(queued_count_bar.id())
.label("Mempool Rejects")
.set_pos(0u64);
// .set_len(
// u64::try_from(storage::MAX_EVICTION_MEMORY_ENTRIES).expect("fits in u64"),
// ),
// );
self.transaction_count_bar = Some(transaction_count_bar);
self.transaction_cost_bar = Some(transaction_cost_bar);
self.queued_count_bar = Some(queued_count_bar);
self.rejected_count_bar = Some(rejected_count_bar);
}
// Update if the mempool has ever been active

28
zebrad/src/components/sync/progress.rs
View File

@ -152,8 +152,7 @@ pub async fn show_block_chain_progress(
} else {
block_bar
.set_pos(current_height.0)
.set_len(u64::from(estimated_height.0))
.desc(network_upgrade.to_string());
.set_len(u64::from(estimated_height.0));
}
// Skip logging and status updates if it isn't time for them yet.
@ -217,7 +216,7 @@ pub async fn show_block_chain_progress(
// TODO: use add_warn(), but only add each warning once
#[cfg(feature = "progress-bar")]
block_bar.desc("chain updates have stalled");
block_bar.desc(format!("{}: sync has stalled", network_upgrade));
} else if is_syncer_stopped && remaining_sync_blocks > MIN_SYNC_WARNING_BLOCKS {
// We've stopped syncing blocks, but we estimate we're a long way from the tip.
//
@ -235,7 +234,10 @@ pub async fn show_block_chain_progress(
);
#[cfg(feature = "progress-bar")]
block_bar.desc("sync is very slow, or estimated tip is wrong");
block_bar.desc(format!(
"{}: sync is very slow, or estimated tip is wrong",
network_upgrade
));
} else if is_syncer_stopped && current_height <= after_checkpoint_height {
// We've stopped syncing blocks,
// but we're below the minimum height estimated from our checkpoints.
@ -259,7 +261,7 @@ pub async fn show_block_chain_progress(
);
#[cfg(feature = "progress-bar")]
block_bar.desc("sync is very slow");
block_bar.desc(format!("{}: sync is very slow", network_upgrade));
} else if is_syncer_stopped {
// We've stayed near the tip for a while, and we've stopped syncing lots of blocks.
// So we're mostly using gossiped blocks now.
@ -273,7 +275,7 @@ pub async fn show_block_chain_progress(
);
#[cfg(feature = "progress-bar")]
block_bar.desc(format!("{}: initial sync finished", network_upgrade));
block_bar.desc(format!("{}: waiting for next block", network_upgrade));
} else if remaining_sync_blocks <= MAX_CLOSE_TO_TIP_BLOCKS {
// We estimate we're near the tip, but we have been syncing lots of blocks recently.
// We might also be using some gossiped blocks.
@ -288,7 +290,7 @@ pub async fn show_block_chain_progress(
);
#[cfg(feature = "progress-bar")]
block_bar.desc(format!("{}: initial sync almost finished", network_upgrade));
block_bar.desc(format!("{}: finishing initial sync", network_upgrade));
} else {
// We estimate we're far from the tip, and we've been syncing lots of blocks.
info!(
@ -299,9 +301,14 @@ pub async fn show_block_chain_progress(
%time_since_last_state_block,
"estimated progress to chain tip",
);
#[cfg(feature = "progress-bar")]
block_bar.desc(format!("{}: syncing blocks", network_upgrade));
}
} else {
let sync_percent = format!("{:.SYNC_PERCENT_FRAC_DIGITS$} %", 0.0f64,);
#[cfg(feature = "progress-bar")]
let network_upgrade = NetworkUpgrade::Genesis;
if is_syncer_stopped {
// We've stopped syncing blocks,
@ -315,7 +322,7 @@ pub async fn show_block_chain_progress(
);
#[cfg(feature = "progress-bar")]
block_bar.desc("can't download genesis block");
block_bar.desc(format!("{}: can't download genesis block", network_upgrade));
} else {
// We're waiting for the genesis block to be committed to the state,
// before we can estimate the best chain tip.
@ -326,7 +333,10 @@ pub async fn show_block_chain_progress(
);
#[cfg(feature = "progress-bar")]
block_bar.desc("waiting to download genesis block");
block_bar.desc(format!(
"{}: waiting to download genesis block",
network_upgrade
));
}
}

16
zebrad/src/components/tracing/component.rs
View File

@ -77,7 +77,9 @@ impl Tracing {
///
/// If `uses_intro` is true, show a welcome message, the `network`,
/// and the Zebra logo on startup. (If the terminal supports it.)
#[allow(clippy::print_stdout, clippy::print_stderr, clippy::unwrap_in_result)]
//
// This method should only print to stderr, because stdout is for tracing logs.
#[allow(clippy::print_stderr, clippy::unwrap_in_result)]
pub fn new(network: Network, config: Config, uses_intro: bool) -> Result<Self, FrameworkError> {
// Only use color if tracing output is being sent to a terminal or if it was explicitly
// forced to.
@ -113,10 +115,6 @@ impl Tracing {
}
let writer = if let Some(log_file) = config.log_file.as_ref() {
if uses_intro {
println!("running zebra");
}
// Make sure the directory for the log file exists.
// If the log is configured in the current directory, it won't have a parent directory.
//
@ -131,17 +129,17 @@ impl Tracing {
let log_file_dir = log_file.parent();
if let Some(log_file_dir) = log_file_dir {
if !log_file_dir.exists() {
println!("directory for log file {log_file:?} does not exist, trying to create it...");
eprintln!("Directory for log file {log_file:?} does not exist, trying to create it...");
if let Err(create_dir_error) = fs::create_dir_all(log_file_dir) {
println!("failed to create directory for log file: {create_dir_error}");
println!("trying log file anyway...");
eprintln!("Failed to create directory for log file: {create_dir_error}");
eprintln!("Trying log file anyway...");
}
}
}
if uses_intro {
println!("sending logs to {log_file:?}...");
eprintln!("Sending logs to {log_file:?}...");
}
let log_file = File::options().append(true).create(true).open(log_file)?;
Box::new(log_file) as BoxWrite