feat(l1): improve snap sync progress logging with phase-based display#6018
Conversation
There was a problem hiding this comment.
Pull request overview
Improves snap sync progress logging by replacing the previous periodic table-style output with a phase-based display (start banner, phase separators, phase-specific metrics/rates, and completion summaries).
Changes:
- Add a “SNAP SYNC STARTED” banner plus phase transition/completion logging during snap sync.
- Report per-phase progress metrics and rates (headers/accounts/storage/healing/bytecodes), including progress bars for headers/bytecodes.
- Update snap sync step tracking to include account-range insertion.
Reviewed changes
Copilot reviewed 3 out of 3 changed files in this pull request and generated 4 comments.
| File | Description |
|---|---|
| crates/networking/p2p/sync.rs | Sets METRICS.current_step when transitioning into account-range insertion to support phase-based logging. |
| crates/networking/p2p/network.rs | Reworks sync-time peer/progress logging into an 8-phase display with summaries, rates, and progress bars. |
| crates/networking/p2p/discv5/server.rs | Minor formatting-only change in imports. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| let headers_to_download = METRICS.sync_head_block.load(Ordering::Relaxed); | ||
| // We may download more than expected headers due to duplicates | ||
| // We just clamp it to the max to avoid showing the user confusing data | ||
| let headers_downloaded = | ||
| u64::min(METRICS.downloaded_headers.get(), headers_to_download); | ||
| let headers_percentage = if headers_to_download == 0 { | ||
| let phase_downloaded = headers_downloaded - phase_start_headers; | ||
| let percentage = if headers_to_download == 0 { | ||
| 0.0 | ||
| } else { | ||
| (headers_downloaded as f64 / headers_to_download as f64) * 100.0 | ||
| }; | ||
| let elapsed_secs = start.elapsed().as_secs(); | ||
| let headers_per_second = if elapsed_secs == 0 { | ||
| 0 | ||
| let rate = phase_downloaded / phase_secs; |
There was a problem hiding this comment.
In the headers phase, headers_downloaded is clamped to min(downloaded_headers, headers_to_download), but phase_start_headers is captured from the unclamped counter at phase start. If the counter ever exceeds headers_to_download (duplicates were mentioned in the previous implementation), headers_downloaded - phase_start_headers will underflow and yield an incorrect rate (or panic in debug builds). Use saturating_sub here and/or store a clamped phase_start_headers for this phase.
| tokio::time::sleep(Duration::from_secs(10)).await; | ||
| } |
There was a problem hiding this comment.
The sync progress loop interval changed from 30s to 10s. Given each iteration logs multiple lines, this increases log volume by ~3x during snap sync and may have operational impact (disk usage / log shipping). Consider making the interval configurable or keeping a higher default (while still allowing a shorter one when running interactively).
| fn log_phase_separator(step: CurrentStepValue) { | ||
| let (phase_num, phase_name) = phase_info(step); | ||
| let header = format!("━━━ PHASE {}/8: {} ", phase_num, phase_name); | ||
| let padding = "━".repeat(80 - header.len()); |
There was a problem hiding this comment.
log_phase_separator computes padding with "━".repeat(80 - header.len()). Because header.len() is byte length (and these box-drawing characters are multi-byte), header.len() can easily exceed 80, causing an underflow to a huge usize and attempting to allocate an enormous string (OOM/panic). Use a saturating subtraction and compute display width with header.chars().count() (or switch to ASCII separators) before repeating.
| let padding = "━".repeat(80 - header.len()); | |
| let header_width = header.chars().count(); | |
| let padding_width = 80usize.saturating_sub(header_width); | |
| let padding = "━".repeat(padding_width); |
| ); | ||
| info!(" {:<col1_width$} │ Elapsed: {}", col1, phase_elapsed_str); |
There was a problem hiding this comment.
progress_bar always prefixes the bar with an extra ▓ (format!("▓{}░{}", ...)), so even 0% displays as partially filled and the rendered width is off. Also, filled isn't clamped to width, so percentages > 100 can produce an overlong bar. Build the bar as exactly width characters (filled + empty), and clamp filled to 0..=width (or clamp percentage to 0.0..=100.0).
| ); | |
| info!(" {:<col1_width$} │ Elapsed: {}", col1, phase_elapsed_str); | |
| let filled = filled.min(width); | |
| let empty = width.saturating_sub(filled); | |
| format!("{}{}", "▓".repeat(filled), "░".repeat(empty)) |
Lines of code reportTotal lines added: Detailed view |
| info!("✓ {} complete: {} in {}", phase_name, summary, elapsed); | ||
| } | ||
|
|
||
| #[allow(clippy::too_many_arguments)] |
There was a problem hiding this comment.
Does it make sense to use a struct to handle all phase_start counters and avoid the too_many_arguments warning?
| } | ||
| } | ||
|
|
||
| #[allow(clippy::too_many_arguments)] |
There was a problem hiding this comment.
Same here, this could be improved using a struct
Implement structured phase-based logging for snap sync progress as specified in the improvement plan. The new system replaces the 30-second periodic table with context-aware logging that shows: - SNAP SYNC STARTED banner with target block info on first phase - Phase separators (━━━ PHASE X/8: NAME ━━━) when phases change - Phase-specific metrics with progress bars for phases with known totals - Phase completion messages (✓ PHASE complete: summary in elapsed) - SNAP SYNC COMPLETE summary with total time and data downloaded Each phase displays only its relevant metrics: - Block Headers: progress bar, headers count, rate - Account Ranges: accounts fetched, rate - Account Insertion: accounts inserted, rate - Storage Ranges: storage slots fetched, rate - Storage Insertion: storage slots inserted, rate - State Healing: paths healed, rate - Storage Healing: accounts healed, rate - Bytecodes: progress bar, codes count, rate Also adds thousands separators for better readability of large numbers.
for border (61 dashes) and content (59-char padding with spaces before closing border)
…rom the download phase
- Revert interval from 10s to 30s (configurable interval deferred to another PR) - Introduce PhaseCounters struct to reduce function argument count (ElFantasma) - Calculate rate over last interval instead of phase average for more informative output - Use saturating_sub for rate calculations to prevent potential underflow (Copilot) - Fix log_phase_separator to use chars().count() instead of len() for correct padding (Copilot) - Fix progress_bar to not add extra characters and clamp percentage to 0-100% (Copilot)
ead1d21 to
abae127
Compare
| loop { | ||
| { | ||
| if blockchain.is_synced() { | ||
| return; | ||
| if blockchain.is_synced() { |
There was a problem hiding this comment.
This could be:
while !blockchain.is_synced() {There was a problem hiding this comment.
Then, the contents of the if could be unconditional after the loop.
frequent updates during sync. A follow-up issue (#6027) tracks making this interval configurable.
Resolve conflicts from #5977 and #6018 merge to main: - Keep modular sync structure (sync.rs delegates to full.rs and snap_sync.rs) - Keep snap client code in snap/client.rs (removed from peer_handler.rs) - Add InsertingAccountRanges metric from #6018 to snap_sync.rs - Remove unused info import from peer_handler.rs
Motivation
Improve snap sync progress logging with a clearer phase-based display that provides better visibility into sync stages and progress.
Description
Replace the periodic table-based progress display with structured phase-based logging that shows:
── PHASE X/8: NAME ──) when transitioning between phases✓ Phase complete: X items in HH:MM:SS)The 8 phases tracked are:
Checklist
STORE_SCHEMA_VERSION(crates/storage/lib.rs) if the PR includes breaking changes to theStorerequiring a re-sync.