From 13900dfeea6c3b7273b6775c5ac78fd57c7b7b2d Mon Sep 17 00:00:00 2001 From: Vsevolod Stakhov Date: Fri, 27 May 2022 10:32:24 +0100 Subject: [PATCH] Improve forceApprove logging (#5595) * Add some meaningful logging to the force approval to understand why it fails * Add original block into the log to simplify logs lurking * Update node/core/approval-voting/src/import.rs Co-authored-by: asynchronous rob Co-authored-by: asynchronous rob --- .../node/core/approval-voting/src/import.rs | 8 +++++- polkadot/node/core/approval-voting/src/ops.rs | 27 +++++++++++++++++-- 2 files changed, 32 insertions(+), 3 deletions(-) diff --git a/polkadot/node/core/approval-voting/src/import.rs b/polkadot/node/core/approval-voting/src/import.rs index 202e44464f..d43bf40546 100644 --- a/polkadot/node/core/approval-voting/src/import.rs +++ b/polkadot/node/core/approval-voting/src/import.rs @@ -560,9 +560,15 @@ pub(crate) async fn handle_new_head( // ancestors. this can only be done after writing the block entry above. if let Some(up_to) = force_approve { gum::debug!(target: LOG_TARGET, ?block_hash, up_to, "Enacting force-approve"); - let approved_hashes = crate::ops::force_approve(db, block_hash, up_to) .map_err(|e| SubsystemError::with_origin("approval-voting", e))?; + gum::debug!( + target: LOG_TARGET, + ?block_hash, + up_to, + "Force-approving {} blocks", + approved_hashes.len() + ); // Notify chain-selection of all approved hashes. for hash in approved_hashes { diff --git a/polkadot/node/core/approval-voting/src/ops.rs b/polkadot/node/core/approval-voting/src/ops.rs index c4c64aeaf4..0491009b07 100644 --- a/polkadot/node/core/approval-voting/src/ops.rs +++ b/polkadot/node/core/approval-voting/src/ops.rs @@ -28,6 +28,7 @@ use super::{ approval_db::v1::{OurAssignment, StoredBlockRange}, backend::{Backend, OverlayedBackend}, persisted_entries::{ApprovalEntry, BlockEntry, CandidateEntry}, + LOG_TARGET, }; /// Information about a new candidate necessary to instantiate the requisite @@ -280,20 +281,31 @@ pub fn force_approve( chain_head: Hash, up_to: BlockNumber, ) -> SubsystemResult> { + #[derive(PartialEq, Eq)] enum State { WalkTo, Approving, } - let mut approved_hashes = Vec::new(); let mut cur_hash = chain_head; let mut state = State::WalkTo; + let mut cur_block_number: BlockNumber = 0; // iterate back to the `up_to` block, and then iterate backwards until all blocks // are updated. while let Some(mut entry) = store.load_block_entry(&cur_hash)? { - if entry.block_number() <= up_to { + cur_block_number = entry.block_number(); + if cur_block_number <= up_to { + if state == State::WalkTo { + gum::debug!( + target: LOG_TARGET, + block_hash = ?chain_head, + ?cur_hash, + ?cur_block_number, + "Start forced approval from block", + ); + } state = State::Approving; } @@ -309,6 +321,17 @@ pub fn force_approve( } } + if state == State::WalkTo { + gum::warn!( + target: LOG_TARGET, + ?chain_head, + ?cur_hash, + ?cur_block_number, + ?up_to, + "Missing block in the chain, cannot start force approval" + ); + } + Ok(approved_hashes) }