Improve error handling in approval voting block import (#5283)

* Print out original the runtime API error

* Improved error handling in approval voting block import

* Fix test

* Update comment

polkadot/Cargo.lock

@@ -6627,6 +6627,7 @@ dependencies = [
  "sp-keyring",
  "sp-keystore",
  "sp-runtime",
+ "thiserror",
  "tracing-gum",
 ]
 

polkadot/node/core/approval-voting/Cargo.toml

@@ -15,6 +15,7 @@ merlin = "2.0"
 schnorrkel = "0.9.1"
 kvdb = "0.11.0"
 derive_more = "0.99.17"
+thiserror = "1.0.30"
 
 polkadot-node-subsystem = { path = "../../subsystem" }
 polkadot-node-subsystem-util = { path = "../../subsystem-util" }

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

@@ -38,7 +38,7 @@ use polkadot_node_subsystem::{
 		ApprovalDistributionMessage, ChainApiMessage, ChainSelectionMessage, RuntimeApiMessage,
 		RuntimeApiRequest,
 	},
-	overseer, SubsystemContext, SubsystemError, SubsystemResult,
+	overseer, RuntimeApiError, SubsystemContext, SubsystemError, SubsystemResult,
 };
 use polkadot_node_subsystem_util::{
 	determine_new_blocks,
@@ -66,6 +66,7 @@ use crate::{
 
 use super::{State, LOG_TARGET};
 
+#[derive(Debug)]
 struct ImportedBlockInfo {
 	included_candidates: Vec<(CandidateHash, CandidateReceipt, CoreIndex, GroupIndex)>,
 	session_index: SessionIndex,
@@ -82,14 +83,36 @@ struct ImportedBlockInfoEnv<'a> {
 	keystore: &'a LocalKeystore,
 }
 
-// Computes information about the imported block. Returns `None` if the info couldn't be extracted -
+#[derive(Debug, thiserror::Error)]
-// failure to communicate with overseer,
+enum ImportedBlockInfoError {
+	// NOTE: The `RuntimeApiError` already prints out which request it was,
+	//       so it's not necessary to include that here.
+	#[error(transparent)]
+	RuntimeError(RuntimeApiError),
+
+	#[error("future cancalled while requesting {0}")]
+	FutureCancelled(&'static str, futures::channel::oneshot::Canceled),
+
+	#[error(transparent)]
+	ApprovalError(approval_types::ApprovalError),
+
+	#[error("block is from an ancient session")]
+	BlockFromAncientSession,
+
+	#[error("session info unavailable")]
+	SessionInfoUnavailable,
+
+	#[error("VRF info unavailable")]
+	VrfInfoUnavailable,
+}
+
+/// Computes information about the imported block. Returns an error if the info couldn't be extracted.
 async fn imported_block_info(
 	ctx: &mut (impl SubsystemContext + overseer::SubsystemContext),
 	env: ImportedBlockInfoEnv<'_>,
 	block_hash: Hash,
 	block_header: &Header,
-) -> SubsystemResult<Option<ImportedBlockInfo>> {
+) -> Result<ImportedBlockInfo, ImportedBlockInfoError> {
 	// Ignore any runtime API errors - that means these blocks are old and finalized.
 	// Only unfinalized blocks factor into the approval voting process.
 
@@ -104,8 +127,9 @@ async fn imported_block_info(
 
 		let events: Vec<CandidateEvent> = match c_rx.await {
 			Ok(Ok(events)) => events,
-			Ok(Err(_)) => return Ok(None),
+			Ok(Err(error)) => return Err(ImportedBlockInfoError::RuntimeError(error)),
-			Err(_) => return Ok(None),
+			Err(error) =>
+				return Err(ImportedBlockInfoError::FutureCancelled("CandidateEvents", error)),
 		};
 
 		events
@@ -130,8 +154,9 @@ async fn imported_block_info(
 
 		let session_index = match s_rx.await {
 			Ok(Ok(s)) => s,
-			Ok(Err(_)) => return Ok(None),
+			Ok(Err(error)) => return Err(ImportedBlockInfoError::RuntimeError(error)),
-			Err(_) => return Ok(None),
+			Err(error) =>
+				return Err(ImportedBlockInfoError::FutureCancelled("SessionIndexForChild", error)),
 		};
 
 		if env
@@ -146,7 +171,7 @@ async fn imported_block_info(
 				session_index
 			);
 
-			return Ok(None)
+			return Err(ImportedBlockInfoError::BlockFromAncientSession)
 		}
 
 		session_index
@@ -180,8 +205,9 @@ async fn imported_block_info(
 
 		match s_rx.await {
 			Ok(Ok(s)) => s,
-			Ok(Err(_)) => return Ok(None),
+			Ok(Err(error)) => return Err(ImportedBlockInfoError::RuntimeError(error)),
-			Err(_) => return Ok(None),
+			Err(error) =>
+				return Err(ImportedBlockInfoError::FutureCancelled("CurrentBabeEpoch", error)),
 		}
 	};
 
@@ -191,7 +217,7 @@ async fn imported_block_info(
 		None => {
 			gum::debug!(target: LOG_TARGET, "Session info unavailable for block {}", block_hash,);
 
-			return Ok(None)
+			return Err(ImportedBlockInfoError::SessionInfoUnavailable)
 		},
 	};
 
@@ -220,7 +246,7 @@ async fn imported_block_info(
 
 						(assignments, slot, relay_vrf)
 					},
-					Err(_) => return Ok(None),
+					Err(error) => return Err(ImportedBlockInfoError::ApprovalError(error)),
 				}
 			},
 			None => {
@@ -230,7 +256,7 @@ async fn imported_block_info(
 					block_hash,
 				);
 
-				return Ok(None)
+				return Err(ImportedBlockInfoError::VrfInfoUnavailable)
 			},
 		}
 	};
@@ -264,7 +290,7 @@ async fn imported_block_info(
 			},
 		});
 
-	Ok(Some(ImportedBlockInfo {
+	Ok(ImportedBlockInfo {
 		included_candidates,
 		session_index,
 		assignments,
@@ -272,7 +298,7 @@ async fn imported_block_info(
 		relay_vrf_story,
 		slot,
 		force_approve,
-	}))
+	})
 }
 
 /// Information about a block and imported candidates.
@@ -382,9 +408,9 @@ pub(crate) async fn handle_new_head(
 				keystore: &state.keystore,
 			};
 
-			match imported_block_info(ctx, env, block_hash, &block_header).await? {
+			match imported_block_info(ctx, env, block_hash, &block_header).await {
-				Some(i) => imported_blocks_and_info.push((block_hash, block_header, i)),
+				Ok(i) => imported_blocks_and_info.push((block_hash, block_header, i)),
-				None => {
+				Err(error) => {
 					// It's possible that we've lost a race with finality.
 					let (tx, rx) = oneshot::channel();
 					ctx.send_message(ChainApiMessage::FinalizedBlockHash(
@@ -403,8 +429,9 @@ pub(crate) async fn handle_new_head(
 						// in the approval-db.
 						gum::warn!(
 							target: LOG_TARGET,
-							"Unable to gather info about imported block {:?}. Skipping chain.",
+							"Skipping chain: unable to gather info about imported block {:?}: {}",
 							(block_hash, block_header.number),
+							error,
 						);
 					}
 
@@ -757,8 +784,7 @@ pub(crate) mod tests {
 					keystore: &LocalKeystore::in_memory(),
 				};
 
-				let info =
+				let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();
-					imported_block_info(&mut ctx, env, hash, &header).await.unwrap().unwrap();
 
 				assert_eq!(info.included_candidates, included_candidates);
 				assert_eq!(info.session_index, session);
@@ -866,9 +892,9 @@ pub(crate) mod tests {
 					keystore: &LocalKeystore::in_memory(),
 				};
 
-				let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();
+				let info = imported_block_info(&mut ctx, env, hash, &header).await;
 
-				assert!(info.is_none());
+				assert_matches!(info, Err(ImportedBlockInfoError::VrfInfoUnavailable));
 			})
 		};
 
@@ -964,9 +990,9 @@ pub(crate) mod tests {
 					keystore: &LocalKeystore::in_memory(),
 				};
 
-				let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();
+				let info = imported_block_info(&mut ctx, env, hash, &header).await;
 
-				assert!(info.is_none());
+				assert_matches!(info, Err(ImportedBlockInfoError::BlockFromAncientSession));
 			})
 		};
 
@@ -1063,8 +1089,7 @@ pub(crate) mod tests {
 					keystore: &LocalKeystore::in_memory(),
 				};
 
-				let info =
+				let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();
-					imported_block_info(&mut ctx, env, hash, &header).await.unwrap().unwrap();
 
 				assert_eq!(info.included_candidates, included_candidates);
 				assert_eq!(info.session_index, session);

polkadot/node/subsystem-types/src/errors.rs

@@ -21,8 +21,8 @@ use crate::JaegerError;
 /// A description of an error causing the runtime API request to be unservable.
 #[derive(thiserror::Error, Debug, Clone)]
 pub enum RuntimeApiError {
-	/// The runtime API cannot be executed due to a
+	/// The runtime API cannot be executed due to a runtime error.
-	#[error("The runtime API '{runtime_api_name}' cannot be executed")]
+	#[error("The runtime API '{runtime_api_name}' cannot be executed: {source}")]
 	Execution {
 		/// The runtime API being called
 		runtime_api_name: &'static str,