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 <rphmeier@gmail.com>

Co-authored-by: asynchronous rob <rphmeier@gmail.com>

polkadot/node/core/approval-voting/src/import.rs

@@ -560,9 +560,15 @@ pub(crate) async fn handle_new_head<Context, B: Backend>(
 		// 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 {

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<Vec<Hash>> {
+	#[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)
 }