Improve Warp Sync Logging

prdoc/pr_10196.prdoc

@@ -0,0 +1,14 @@
+title: Improve Warp Sync Logging
+doc:
+- audience: Node Operator
+  description: |-
+    This update makes warp sync logs more useful. it shows a clear count of synced eras and removes
+    unnecessary block details during the proof phase, giving a better view of progress.
+
+crates:
+- name: sc-consensus-grandpa
+  bump: minor
+- name: sc-informant
+  bump: minor
+- name: sc-network-sync
+  bump: major

substrate/client/consensus/grandpa/src/warp_proof.rs

@@ -291,6 +291,7 @@ struct VerifierState<Block: BlockT> {
 struct GrandpaVerifier<Block: BlockT> {
 	state: VerifierState<Block>,
 	hard_forks: HashMap<(Block::Hash, NumberFor<Block>), (SetId, AuthorityList)>,
+	eras_synced: u64,
 }
 
 impl<Block: BlockT> Verifier<Block> for GrandpaVerifier<Block>
@@ -323,6 +324,9 @@ where
 			next_proof_context: last_header.hash(),
 		};
 
+		// Track eras synced
+		self.eras_synced += proof.proofs.len() as u64;
+
 		let justifications = proof
 			.proofs
 			.into_iter()
@@ -343,6 +347,10 @@ where
 	fn next_proof_context(&self) -> Block::Hash {
 		self.state.next_proof_context
 	}
+
+	fn status(&self) -> Option<String> {
+		Some(format!("{} eras synced", self.eras_synced))
+	}
 }
 
 impl<Block: BlockT, Backend: ClientBackend<Block>> WarpSyncProvider<Block>
@@ -373,6 +381,7 @@ where
 				next_proof_context: genesis_hash,
 			},
 			hard_forks: self.hard_forks.clone(),
+			eras_synced: 0,
 		})
 	}
 }

substrate/client/informant/src/display.rs

@@ -92,7 +92,7 @@ impl<B: BlockT> InformantDisplay<B> {
 		};
 
 		let (level, status, target) =
-			match (sync_status.state, sync_status.state_sync, sync_status.warp_sync) {
+			match (sync_status.state, sync_status.state_sync, sync_status.warp_sync.clone()) {
 				// Do not set status to "Block history" when we are doing a major sync.
 				//
 				// A node could for example have been warp synced to the tip of the chain and
@@ -106,15 +106,16 @@ impl<B: BlockT> InformantDisplay<B> {
 				// Handle all phases besides the two phases we already handle above.
 				(_, _, Some(warp))
 					if !matches!(warp.phase, WarpSyncPhase::DownloadingBlocks(_)) =>
-					(
-						"⏩",
-						"Warping".into(),
-						format!(
-							", {}, {:.2} Mib",
-							warp.phase,
-							(warp.total_bytes as f32) / (1024f32 * 1024f32)
-						),
-					),
+				{
+					let total_mib = (warp.total_bytes as f32) / (1024f32 * 1024f32);
+					let progress_text = if let Some(ref status) = warp.status {
+						format!(", {status}, {total_mib:.2} Mib")
+					} else {
+						format!(" {total_mib:.2} Mib")
+					};
+
+					("⏩", "Warping".into(), progress_text)
+				},
 				(_, Some(state), _) => (
 					"⚙️ ",
 					"State sync".into(),
@@ -132,20 +133,40 @@ impl<B: BlockT> InformantDisplay<B> {
 					("⚙️ ", format!("Preparing{}", speed), format!(", target=#{target}")),
 			};
 
-		info!(
-			target: "substrate",
-			"{} {}{} ({} peers), best: #{} ({}), finalized #{} ({}), ⬇ {} ⬆ {}",
-			level,
-			style(&status).white().bold(),
-			target,
-			style(num_connected_peers).white().bold(),
-			style(best_number).white().bold(),
-			PrintFullHashOnDebugLogging(&best_hash),
-			style(finalized_number).white().bold(),
-			PrintFullHashOnDebugLogging(&info.chain.finalized_hash),
-			style(TransferRateFormat(avg_bytes_per_sec_inbound)).green(),
-			style(TransferRateFormat(avg_bytes_per_sec_outbound)).red(),
-		)
+		let show_block_info = match sync_status.warp_sync {
+			Some(warp) => matches!(warp.phase, WarpSyncPhase::DownloadingBlocks(_)),
+			_ => true,
+		};
+
+		if show_block_info {
+			// Show full log with best/finalized blocks
+			info!(
+				target: "substrate",
+				"{} {}{} ({} peers), best: #{} ({}), finalized #{} ({}), ⬇ {} ⬆ {}",
+				level,
+				style(&status).white().bold(),
+				target,
+				style(num_connected_peers).white().bold(),
+				style(best_number).white().bold(),
+				PrintFullHashOnDebugLogging(&best_hash),
+				style(finalized_number).white().bold(),
+				PrintFullHashOnDebugLogging(&info.chain.finalized_hash),
+				style(TransferRateFormat(avg_bytes_per_sec_inbound)).green(),
+				style(TransferRateFormat(avg_bytes_per_sec_outbound)).red(),
+			)
+		} else {
+			// Simplified log for warp sync without best/finalized blocks
+			info!(
+				target: "substrate",
+				"{} {}{} ({} peers), ⬇ {} ⬆ {}",
+				level,
+				style(&status).white().bold(),
+				target,
+				style(num_connected_peers).white().bold(),
+				style(TransferRateFormat(avg_bytes_per_sec_inbound)).green(),
+				style(TransferRateFormat(avg_bytes_per_sec_outbound)).red(),
+			)
+		}
 	}
 }
 

substrate/client/network/sync/src/strategy/chain_sync.rs

@@ -839,6 +839,7 @@ where
 		let warp_sync_progress = self.gap_sync.as_ref().map(|gap_sync| WarpSyncProgress {
 			phase: WarpSyncPhase::DownloadingBlocks(gap_sync.best_queued_number),
 			total_bytes: 0,
+			status: None,
 		});
 
 		SyncStatus {

substrate/client/network/sync/src/strategy/warp.rs

@@ -68,6 +68,8 @@ pub trait Verifier<Block: BlockT>: Send + Sync {
 	) -> Result<VerificationResult<Block>, Box<dyn std::error::Error + Send + Sync>>;
 	/// Hash to be used as the starting point for the next proof request.
 	fn next_proof_context(&self) -> Block::Hash;
+	/// Get status text for progress reporting
+	fn status(&self) -> Option<String>;
 }
 
 /// Proof verification result.
@@ -153,6 +155,8 @@ pub struct WarpSyncProgress<Block: BlockT> {
 	pub phase: WarpSyncPhase<Block>,
 	/// Total bytes downloaded so far.
 	pub total_bytes: u64,
+	/// Optional status text from the verifier.
+	pub status: Option<String>,
 }
 
 /// Warp sync configuration as accepted by [`WarpSync`].
@@ -635,18 +639,22 @@ where
 					required_peers: self.min_peers_to_start_warp_sync,
 				},
 				total_bytes: self.total_proof_bytes,
+				status: None,
 			},
-			Phase::WarpProof { .. } => WarpSyncProgress {
+			Phase::WarpProof { verifier } => WarpSyncProgress {
 				phase: WarpSyncPhase::DownloadingWarpProofs,
 				total_bytes: self.total_proof_bytes,
+				status: verifier.status(),
 			},
 			Phase::TargetBlock(_) => WarpSyncProgress {
 				phase: WarpSyncPhase::DownloadingTargetBlock,
 				total_bytes: self.total_proof_bytes,
+				status: None,
 			},
 			Phase::Complete => WarpSyncProgress {
 				phase: WarpSyncPhase::Complete,
 				total_bytes: self.total_proof_bytes + self.total_state_bytes,
+				status: None,
 			},
 		}
 	}
@@ -808,6 +816,7 @@ mod test {
 				proof: &EncodedProof,
 			) -> Result<VerificationResult<B>, Box<dyn std::error::Error + Send + Sync>>;
 			fn next_proof_context(&self) -> B::Hash;
+			fn status(&self) -> Option<String>;
 		}
 	}
 

substrate/client/network/test/src/lib.rs

@@ -673,6 +673,10 @@ impl<B: BlockT> WarpVerifier<B> for TestVerifier<B> {
 	fn next_proof_context(&self) -> B::Hash {
 		self.genesis_hash
 	}
+
+	fn status(&self) -> Option<String> {
+		None
+	}
 }
 
 impl<B: BlockT> WarpSyncProvider<B> for TestWarpSyncProvider<B> {