feat(ui): Add a terminal-based progress bar to Zebra

[teor2345]

Motivation

Some users just want to see how Zebra's sync is progressing, without detailed logs.

You can see the progress bar by compiling Zebra with the progress-bar feature:

cargo run --features progress-bar --bin zebrad

This automatically redirects your logs to a file in the standard log path.

Closes #6245

Complex Code or Requirements

There are some shutdown delays, but they seem to be about the same as without the progress bar.

Solution

Terminal Display:

• Add a progress-bar feature to zebrad
• Add the progress bar writer to the tracing component
  • Redirect the logs to a file when the progress bar is on
  • Create missing directories for the log file
• Shut down the progress bar when there is an interrupt like Ctrl-C

Block Progress:

• Add a block progress bar transmitter
• Add checkpoint progress bar transmitters

Network Connections:

• Add inbound and outbound connection count transmitter
• Add address book peer status transmitters

Mempool:

• Add progress bars for transaction queue, transaction count, transaction memory, and rejected transactions

Related changes:

• Add a Display/to_string() implementation for NetworkUpgrade
• Add an optional limit and label to connection counters
• Improve CheckpointList API and CheckpointVerifier debugging
• Fix progress log formatting
• Add file security docs for running Zebra with elevated permissions

Review

This is a low priority change.

Reviewer Checklist

• Will the PR name make sense to users?
  • Does it need extra CHANGELOG info? (new features, breaking changes, large changes)
• Are the PR labels correct?
• Does the code do what the ticket and PR says?
  • Does it change concurrent code, unsafe code, or consensus rules?
• How do you know it works? Does it have tests?

Follow Up Work

Write a blog post.
Tweak progress bars display.

[codecov]

Codecov Report

Merging #6235 (08a8c64) into main (d1990ca) will increase coverage by 0.00%.
The diff coverage is 66.73%.

Additional details and impacted files

@@           Coverage Diff            @@
##             main    #6235    +/-   ##
========================================
  Coverage   77.72%   77.73%            
========================================
  Files         304      304            
  Lines       39665    40087   +422     
========================================
+ Hits        30830    31162   +332     
- Misses       8835     8925    +90     

[teor2345]

Initial progress on Monday:

[teor2345]

Tuesday progress:

Mainnet near the tip (no checkpoint display, the checkpoints are finished):

Testnet near genesis, with checkpoint display:

[teor2345]

This is bug #5366, let's track it for the next few weeks and see if it happens again:

ERROR: (gcloud.compute.ssh) Could not fetch resource:

• The resource 'projects/zealous-zebra/zones/us-central1-a/instances/sync-past-checkpoint-6235-merge-01d71d9' was not found

https://github.com/ZcashFoundation/zebra/actions/runs/4290568966/jobs/7475609940#step:8:88

[teor2345]

Thursday progress:

Mainnet near the tip, with chain forks display:

There's a bug in the chain fork display, because of how we clone chains. I think I can fix it by moving all the chain progress bars into the non-finalized state.

I'm not sure if I'll get a chance to do the mempool transaction count and transaction bytes.

[teor2345]

New screenshots from the latest version of this PR:

[teor2345]

Synced mainnet screenshot without the extra build and launch text:

[oxarbitrage]

This is not a code review so i have no idea how easy will be to fix some or all o this issues. I think is a good idea but do not look good yet from a UX perspective in my opinion.

Consider the following 2-3 minutes output with the progress bar feature enabled of a release build. I separated it into parts.

Before the any progress bar is shown:

$ ./target/release/zebrad 
2023-04-10T12:59:40.839277Z  INFO zebrad::components::tracing::component: started tracing component filter="info" TRACING_STATIC_MAX_LEVEL=LevelFilter::INFO LOG_STATIC_MAX_LEVEL=Info
2023-04-10T12:59:40.839317Z  INFO zebrad::components::tracing::component: activated progress bar
2023-04-10T12:59:40.839320Z  INFO zebrad::application: Diagnostic Metadata:
version: 1.0.0-rc.6+73.gb455bcf
Zcash network: Mainnet
state version: 25
branch: progress-bar
git commit: b455bcf
commit timestamp: 2023-04-04T01:22:44Z
target triple: x86_64-unknown-linux-gnu
build profile: release
2023-04-10T12:59:40.839327Z  INFO zebrad::application: loaded zebrad config config_path=None config=ZebradConfig { consensus: Config { checkpoint_sync: true, debug_skip_parameter_preload: false }, metrics: Config { endpoint_addr: None }, network: Config { listen_addr: 0.0.0.0:8233, network: Mainnet, initial_mainnet_peers: {"dnsseed.z.cash:8233", "dnsseed.str4d.xyz:8233", "mainnet.seeder.zfnd.org:8233", "mainnet.is.yolo.money:8233"}, initial_testnet_peers: {"dnsseed.testnet.z.cash:18233", "testnet.seeder.zfnd.org:18233", "testnet.is.yolo.money:18233"}, peerset_initial_target_size: 25, crawl_new_peer_interval: 61s }, state: Config { cache_dir: "/home/oxarbitrage/.cache/zebra", ephemeral: false, debug_stop_at_height: None, delete_old_database: true }, tracing: Config { use_color: true, force_use_color: false, filter: None, buffer_limit: 128000, endpoint_addr: None, flamegraph: None, log_file: None, use_journald: false }, sync: Config { download_concurrency_limit: 50, checkpoint_verify_concurrency_limit: 1000, full_verify_concurrency_limit: 20, parallel_cpu_threads: 0 }, mempool: Config { tx_cost_limit: 80000000, eviction_memory_time: 3600s, debug_enable_at_height: None }, rpc: Config { listen_addr: None, parallel_cpu_threads: 1, debug_force_finished_sync: false } }
2023-04-10T12:59:40.839380Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::application: initialized rayon thread pool for CPU-bound tasks num_threads=12
2023-04-10T12:59:40.839736Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: Starting zebrad
2023-04-10T12:59:40.839764Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: initializing node state
2023-04-10T12:59:40.843046Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: opening database, this may take a few minutes
2023-04-10T12:59:40.843140Z  INFO zebra_state::service::finalized_state::disk_db: the open file limit is high enough for Zebra current_limit=1024 min_limit=512 ideal_limit=1024
2023-04-10T12:59:45.262417Z  INFO zebra_state::service::finalized_state::disk_db: Opened Zebra state cache at /home/oxarbitrage/.cache/zebra/state/v25/mainnet
2023-04-10T12:59:45.263132Z  INFO zebra_state::service::finalized_state: loaded Zebra state cache tip=Some((Height(119273), block::Hash("00000000033a030a004d6c300a9af83c02a667b3ee16c0d1a118529f77942ebe")))
2023-04-10T12:59:45.263258Z  INFO zebra_state::service: starting legacy chain check
2023-04-10T12:59:45.263292Z  INFO zebra_state::service: cached state consensus branch is valid: no legacy chain found
2023-04-10T12:59:45.263369Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: initializing network
2023-04-10T12:59:45.263382Z  INFO {zebrad="b455bcf" net="Main"}:open_listener{addr=0.0.0.0:8233}: zebra_network::peer_set::initialize: Trying to open Zcash protocol endpoint at 0.0.0.0:8233...
2023-04-10T12:59:45.263433Z  INFO {zebrad="b455bcf" net="Main"}:open_listener{addr=0.0.0.0:8233}: zebra_network::peer_set::initialize: Opened Zcash protocol endpoint at 0.0.0.0:8233
2023-04-10T12:59:45.263700Z  INFO {zebrad="b455bcf" net="Main"}: zebra_network::address_book_updater: starting the address book updater
2023-04-10T12:59:45.264809Z  INFO {zebrad="b455bcf" net="Main"}:add_initial_peers: zebra_network::config: resolved seed peer IP addresses seed="dnsseed.str4d.xyz:8233" remote_ip_count=25
2023-04-10T12:59:45.264886Z  INFO {zebrad="b455bcf" net="Main"}:add_initial_peers: zebra_network::config: resolved seed peer IP addresses seed="dnsseed.z.cash:8233" remote_ip_count=25
2023-04-10T12:59:45.468261Z  INFO {zebrad="b455bcf" net="Main"}:add_initial_peers: zebra_network::config: resolved seed peer IP addresses seed="mainnet.is.yolo.money:8233" remote_ip_count=4

• I think all this should be hidden and only show the progress bars. If we want to keep some info messages we should make sure they are all the top.

First batch of progress bars is displayed

 | Known Peers: 0                                                                                                                                                                                                                             
 | Failed Peers: 0                                                                                                                                                                                                                            
 | Inbound Connections: 0                                                                                                                                                                                                                     
 | Known Peers: 0                                                                                                                                                                                                                             
 | Failed Peers: 0                                                                                                                                                                                                                            
 | Inbound Connections: 0                                                                                                                                                                                                                     
 | Never Attempted Peers: 0                                                                                                                                                                                                                   2023-04-10T12:59:55.266775Z  INFO {zebrad="b455bcf" net="Main"}:add_initial_peers: zebra_network::peer_set::initialize: limiting the initial peers list from 49 to 25
 \ Known Peers: 0                                                                                                                                                                                                                             
 \ Failed Peers: 0                                                                                                                                                                                                                            
 \ Inbound Connections: 0                                                                                                                                                                                                                     
 \ Never Attempted Peers: 0                                                                                                                                                                                                                   2023-04-10T12:59:55.817864Z  INFO {zebrad="b455bcf" net="Main"}:add_initial_peers: zebra_network::peer_set::initialize: an initial peer connection failed successes=6 errors=1 addr=[2a01:4f8:140:2393::2]:8233 e=Network is unreachable (os e / Known Peers: 0                                                                                                                                                                                                                             
 / Failed Peers: 0                                                                                                                                                                                                                            
 / Inbound Connections: 0                                                                                                                                                                                                                     
 / Never Attempted Peers: 0                                                                                                                                                                                                                    / Known Peers: 0                                                                                                                                                                                                                             
 / Failed Peers: 0                                                                                                                                                                                                                            
 / Known Peers: 0                                                                                                                                                                                                                             
 / Failed Peers: 0                                                                                                                                                                                                                            
 / Known Peers: 0                                                                                                                                                                                                                             
 / Failed Peers: 0                                                                                                                                                                                                                            
 / Known Peers: 0                                                                                                                                                                                                                             
 / Failed Peers: 0                                                                                                                                                                                                                            
 / Inbound Connections: 0                                                                                                                                                                                                                     
 / Known Peers: 0                                                                                                                                                                                                                             
 / Failed Peers: 0                                                                                                                                                                                                                            
 / Inbound Connections: 0                                                                                                                                                                                                                     
 - Known Peers (15m)
 [>                             ]   1% (51/4000)                                                                                                                                                                                              
 - Failed Peers (0s)
 [                              ]   0% (0/4000)                                                                                                                                                                                               
 - Inbound Connections: 0                                                                                                                                                                                                                     
 / Outbound Connections: 23                                                                                                                                                                                                                   
 - Never Attempted Peers (25m)
 [>                             ]   1% (30/4000)               

• Info messages are shown between the different progress bars.
• We should consider making a “panel” instead of a progress bar for each item. For example 1% (52/4000) is more than enough information for Known Peers, nobody is expecting this bar to get up to 100%. The only progress bars that makes sense to me are the ones i am expecting to finish (blocks. maybe checkpoints).

Progress bars then show up again

2023-04-10T12:59:58.527979Z  INFO {zebrad="b455bcf" net="Main"}:init{config=Config { checkpoint_sync: true, debug_skip_parameter_preload: false } network=Mainnet debug_skip_parameter_preload=false}: zebra_consensus::chain: initializing chain verifier tip=Some((Height(119273), block::Hash("00000000033a030a004d6c300a9af83c02a667b3ee16c0d1a118529f77942ebe"))) max_checkpoint_height=Height(2024043)
2023-04-10T12:59:58.528053Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: initializing syncer
2023-04-10T12:59:58.528061Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: initializing mempool
2023-04-10T12:59:58.528079Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::components::sync::gossip: initializing block gossip task
2023-04-10T12:59:58.528095Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::components::mempool::crawler: initializing mempool crawler task
2023-04-10T12:59:58.528102Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: spawned initial Zebra tasks
2023-04-10T12:59:58.528102Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::components::mempool::queue_checker: initializing mempool queue checker task
2023-04-10T12:59:58.528107Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::components::mempool::gossip: initializing transaction gossip task
2023-04-10T12:59:58.528135Z  INFO {zebrad="b455bcf" net="Main"}: zebra_state::config: checking for old database versions
2023-04-10T12:59:58.528168Z  INFO {zebrad="b455bcf" net="Main"}:sync:try_to_sync: zebrad::components::sync: starting sync, obtaining new tips state_tip=Some(Height(119273))
 / Known Peers (15m)
 [>                             ]   1% (51/4000)                                                                                                                                                                                              
 / Failed Peers (0s)
 | Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 / Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 / Failed Peers (2h)
 \ Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 \ Failed Peers (12h)
 \ Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 \ Failed Peers (12h)
 - Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 | Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 | Failed Peers (12h)
 [>                             ]   0% (10/4000)                                                                                                                                                                                              
 / Inbound Connections: 0                                                                                                                                                                                                                     
 | Outbound Connections (0s)
 [================>             ]  56% (42/75)                                                                                                                                                                                                
 \ Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 \ Failed Peers (19h)
 | Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 \ Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 \ Failed Peers (19h)
 - Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 - Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 \ Failed Peers (19h)
 | Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 - Known Peers (81m)
 [>                             ]   1% (52/4000)                                                                                                                                                                                              
 - Failed Peers (19h)
 - Known Peers (81m)
 \ Failed Peers (19h)
 [>                             ]   0% (12/4000)                                                                                                                                                                                              
 \ Inbound Connections: 0                                                                                                                                                                                                                     
 - Outbound Connections (0s)
 \ Failed Peers (19h)
 [>                             ]   0% (12/4000)                                                                                                                                                                                              
2023-04-10T13:02:11.154689Z  INFO zebra_state::service: waiting for the block write task to finish
^C^[    ^C^C2023-04-10T13:02:30.960944Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::components::tokio: shutting down Zebra
2023-04-10T13:02:30.960962Z  INFO {zebrad="b455bcf" net="Main"}: zebrad::commands::start: stopping zebrad

• After some more info messages progress bars show up again.

While zebra is running:

• Progress bars like Known Peers start to repeat themselves and get stacked. There should be only 1 progress bar per item in the entire output.
• Info messages appear and disappear fast (but not enough to don’t see them) at the bottom of the console making the refresh to look weird, refresh should be imperceptible and only progress bars and numbers should change when happens.
• You can’t copy paste a progress bar while is running. For example i cant copy and paste from the console the blocks progress bar.

At exit:

• A lot of progress bars disappear when exiting zebra like the blocks, verified checkpoints, etc.

[teor2345]

This is not a code review so i have no idea how easy will be to fix some or all o this issues. I think is a good idea but do not look good yet from a UX perspective in my opinion.

This is an experimental feature which is not on by default. We can make the UX better after we merge it, if it's a priority for the Zebra project. (Or if a volunteer contributor wants to do it.)

Consider the following 2-3 minutes output with the progress bar feature enabled of a release build. I separated it into parts.
…

• Info messages are shown between the different progress bars.

Please configure a separate log file so you don't see the logs. The instructions are at the top of this PR, and in the code comments as part of the list of Zebra features:
https://github.com/ZcashFoundation/zebra/pull/6235/files#diff-8388fb4abd443e134f601d5fc09f5d5750fbb9748bc6a3a81f0f95f0b6e34bfbR65

• We should consider making a “panel” instead of a progress bar for each item. For example 1% (52/4000) is more than enough information for Known Peers, nobody is expecting this bar to get up to 100%. The only progress bars that makes sense to me are the ones i am expecting to finish (blocks. maybe checkpoints).

Sure, we can switch some of these progress bars so they have no limit.

I'd like to get user feedback on which progress bars and limits are useful before we make these kinds of changes. Then if this feature becomes a priority, we can do that in a future PR.

Progress bars then show up again

• After some more info messages progress bars show up again.
• Info messages appear and disappear fast (but not enough to don’t see them) at the bottom of the console making the refresh to look weird, refresh should be imperceptible and only progress bars and numbers should change when happens.

These are all the same configuration issue, please configure the logs to go to a file.

While zebra is running:

• Progress bars like Known Peers start to repeat themselves and get stacked. There should be only 1 progress bar per item in the entire output.

I'm not sure what is happening here, it could be a bug in the underlying library, your terminal application, or your shell. You could try a different shell?

I'm using Linux, bash, tmux, mosh, and macOS Terminal.app, so I'm not sure I can reproduce those errors.

It might also go away if we remove the chain fork progress bars, because it adds or removes bars for each chain.

I can do a bug report if we find some simple way to reproduce it. But I don't think it's a blocker for this PR, because the feature is off by default.

• You can’t copy paste a progress bar while is running. For example i cant copy and paste from the console the blocks progress bar.

This is a missing feature in your terminal, try a different terminal application or shell.
Is copying and pasting progress bars is an important feature for Zebra to support?

At exit:

• A lot of progress bars disappear when exiting zebra like the blocks, verified checkpoints, etc.

When Zebra shuts down, it needs to stop its progress monitoring thread. This also stops the progress bars.

I don't think we need to show progress after Zebra exits.

[oxarbitrage]

My apologies for not following the instructions correctly. By removing the logs as instructed almost all the issues i reported are gone. There are still a few but i agree they are minor and it looks a lot better overall.

I think the no logs should be the default behavior when the feature is active.

I still think most of the bars are not needed but i understand that we can't invest time now to discuss what we want to show and how.

Ill review the code and probably approve soon.

[arya2]

This looks absolutely marvelous, great work, thank you!!!

I'd love to see this become a default feature once it works with tracing logs being written to the terminal.

(Config options for which progress bars show up would also be nice)

[teor2345]

I think the no logs should be the default behavior when the feature is active.

I made this change in the PR, here's how it looks now:

$ cargo run --features progress-bar --bin zebrad
Compiling zebrad v1.0.0-rc.6 (/home/dev/zebra/zebrad)
Finished release [optimized + debuginfo] target(s) in 47.07s
running zebra
directory for log file "/home/dev/.local/state/zebrad.log" does not exist, trying to create it...
sending logs to "/home/dev/.local/state/zebrad.log"...
waiting for initial progress reports...

And then the progress bars show up (with no logs in the terminal).