approval votes checking logs (#3233)

* approval-voting: logs for invalid votes

* proper errors for assignment checks

* proper errors for approval checks

node/core/approval-voting/src/lib.rs

@@ -23,9 +23,10 @@
 
 use polkadot_node_subsystem::{
 	messages::{
-		AssignmentCheckResult, ApprovalCheckResult, ApprovalVotingMessage,
-		RuntimeApiMessage, RuntimeApiRequest, ChainApiMessage, ApprovalDistributionMessage,
-		ValidationFailed, CandidateValidationMessage, AvailabilityRecoveryMessage,
+		AssignmentCheckError, AssignmentCheckResult, ApprovalCheckError, ApprovalCheckResult,
+		ApprovalVotingMessage, RuntimeApiMessage, RuntimeApiRequest, ChainApiMessage,
+		ApprovalDistributionMessage, ValidationFailed, CandidateValidationMessage,
+		AvailabilityRecoveryMessage,
 	},
 	errors::RecoveryError,
 	Subsystem, SubsystemContext, SubsystemError, SubsystemResult, SpawnedSubsystem,
@@ -1334,14 +1335,17 @@ fn check_and_import_assignment(
 	let tick_now = state.clock.tick_now();
 	let block_entry = match state.db.load_block_entry(&assignment.block_hash)? {
 		Some(b) => b,
-		None => return Ok((AssignmentCheckResult::Bad, Vec::new())),
+		None => return Ok((AssignmentCheckResult::Bad(
+			AssignmentCheckError::UnknownBlock(assignment.block_hash),
+		), Vec::new())),
 	};
 
 	let session_info = match state.session_info(block_entry.session()) {
 		Some(s) => s,
 		None => {
-			tracing::warn!(target: LOG_TARGET, "Unknown session info for {}", block_entry.session());
-			return Ok((AssignmentCheckResult::Bad, Vec::new()));
+			return Ok((AssignmentCheckResult::Bad(
+				AssignmentCheckError::UnknownSessionIndex(block_entry.session()),
+			), Vec::new()));
 		}
 	};
 
@@ -1349,20 +1353,17 @@ fn check_and_import_assignment(
 		= match block_entry.candidate(candidate_index as usize)
 	{
 		Some((c, h)) => (*c, *h),
-		None => return Ok((AssignmentCheckResult::Bad, Vec::new())), // no candidate at core.
+		None => return Ok((AssignmentCheckResult::Bad(
+			AssignmentCheckError::InvalidCandidateIndex(candidate_index),
+		), Vec::new())), // no candidate at core.
 	};
 
 	let mut candidate_entry = match state.db.load_candidate_entry(&assigned_candidate_hash)? {
 		Some(c) => c,
 		None => {
-			tracing::warn!(
-				target: LOG_TARGET,
-				"Missing candidate entry {} referenced in live block {}",
-				assigned_candidate_hash,
-				assignment.block_hash,
-			);
-
-			return Ok((AssignmentCheckResult::Bad, Vec::new()));
+			return Ok((AssignmentCheckResult::Bad(
+				AssignmentCheckError::InvalidCandidate(candidate_index, assigned_candidate_hash),
+			), Vec::new()));
 		}
 	};
 
@@ -1372,7 +1373,9 @@ fn check_and_import_assignment(
 			candidate_entry.approval_entry_mut(&assignment.block_hash)
 		{
 			Some(a) => a,
-			None => return Ok((AssignmentCheckResult::Bad, Vec::new())),
+			None => return Ok((AssignmentCheckResult::Bad(
+				AssignmentCheckError::Internal(assignment.block_hash, assigned_candidate_hash),
+			), Vec::new())),
 		};
 
 		let res = state.assignment_criteria.check_assignment_cert(
@@ -1385,7 +1388,9 @@ fn check_and_import_assignment(
 		);
 
 		let tranche = match res {
-			Err(crate::criteria::InvalidAssignment) => return Ok((AssignmentCheckResult::Bad, Vec::new())),
+			Err(crate::criteria::InvalidAssignment) => return Ok((AssignmentCheckResult::Bad(
+				AssignmentCheckError::InvalidCert(assignment.validator),
+			), Vec::new())),
 			Ok(tranche) => {
 				let current_tranche = state.clock.tranche_now(
 					state.slot_duration_millis,
@@ -1455,20 +1460,27 @@ fn check_and_import_approval<T>(
 
 	let block_entry = match state.db.load_block_entry(&approval.block_hash)? {
 		Some(b) => b,
-		None => respond_early!(ApprovalCheckResult::Bad)
+		None => {
+			respond_early!(ApprovalCheckResult::Bad(
+				ApprovalCheckError::UnknownBlock(approval.block_hash),
+			))
+		}
 	};
 
 	let session_info = match state.session_info(block_entry.session()) {
 		Some(s) => s,
 		None => {
-			tracing::warn!(target: LOG_TARGET, "Unknown session info for {}", block_entry.session());
-			respond_early!(ApprovalCheckResult::Bad)
+			respond_early!(ApprovalCheckResult::Bad(
+				ApprovalCheckError::UnknownSessionIndex(block_entry.session()),
+			))
 		}
 	};
 
 	let approved_candidate_hash = match block_entry.candidate(approval.candidate_index as usize) {
 		Some((_, h)) => *h,
-		None => respond_early!(ApprovalCheckResult::Bad)
+		None => respond_early!(ApprovalCheckResult::Bad(
+			ApprovalCheckError::InvalidCandidateIndex(approval.candidate_index),
+		))
 	};
 
 	let approval_payload = ApprovalVote(approved_candidate_hash)
@@ -1476,33 +1488,41 @@ fn check_and_import_approval<T>(
 
 	let pubkey = match session_info.validators.get(approval.validator.0 as usize) {
 		Some(k) => k,
-		None => respond_early!(ApprovalCheckResult::Bad)
+		None => respond_early!(ApprovalCheckResult::Bad(
+			ApprovalCheckError::InvalidValidatorIndex(approval.validator),
+		))
 	};
 
 	let approval_sig_valid = approval.signature.verify(approval_payload.as_slice(), pubkey);
 
 	if !approval_sig_valid {
-		respond_early!(ApprovalCheckResult::Bad)
+		respond_early!(ApprovalCheckResult::Bad(
+			ApprovalCheckError::InvalidSignature(approval.validator),
+		))
 	}
 
 	let candidate_entry = match state.db.load_candidate_entry(&approved_candidate_hash)? {
 		Some(c) => c,
 		None => {
-			tracing::warn!(
-				target: LOG_TARGET,
-				"Unknown candidate entry for {}",
-				approved_candidate_hash,
-			);
-
-			respond_early!(ApprovalCheckResult::Bad)
+			respond_early!(ApprovalCheckResult::Bad(
+				ApprovalCheckError::InvalidCandidate(approval.candidate_index, approved_candidate_hash),
+			))
 		}
 	};
 
 	// Don't accept approvals until assignment.
-	if candidate_entry.approval_entry(&approval.block_hash)
-		.map_or(true, |e| !e.is_assigned(approval.validator))
-	{
-		respond_early!(ApprovalCheckResult::Bad)
+	match candidate_entry.approval_entry(&approval.block_hash) {
+		None => {
+			respond_early!(ApprovalCheckResult::Bad(
+				ApprovalCheckError::Internal(approval.block_hash, approved_candidate_hash),
+			))
+		}
+		Some(e) if !e.is_assigned(approval.validator) => {
+			respond_early!(ApprovalCheckResult::Bad(
+				ApprovalCheckError::NoAssignment(approval.validator),
+			))
+		}
+		_ => {},
 	}
 
 	// importing the approval can be heavy as it may trigger acceptance for a series of blocks.

node/core/approval-voting/src/tests.rs

@@ -397,8 +397,9 @@ fn rejects_bad_assignment() {
 	assert!(res.1.iter().any(|action| matches!(action, Action::WriteCandidateEntry(..))));
 
 	// unknown hash
+	let unknown_hash = Hash::repeat_byte(0x02);
 	let assignment = IndirectAssignmentCert {
-		block_hash: Hash::repeat_byte(0x02),
+		block_hash: unknown_hash,
 		validator: ValidatorIndex(0),
 		cert: garbage_assignment_cert(
 			AssignmentCertKind::RelayVRFModulo {
@@ -412,7 +413,7 @@ fn rejects_bad_assignment() {
 		assignment,
 		candidate_index,
 	).unwrap();
-	assert_eq!(res.0, AssignmentCheckResult::Bad);
+	assert_eq!(res.0, AssignmentCheckResult::Bad(AssignmentCheckError::UnknownBlock(unknown_hash)));
 
 	let mut state = State {
 		assignment_criteria: Box::new(MockAssignmentCriteria::check_only(|| {
@@ -427,7 +428,7 @@ fn rejects_bad_assignment() {
 		assignment_good,
 		candidate_index,
 	).unwrap();
-	assert_eq!(res.0, AssignmentCheckResult::Bad);
+	assert_eq!(res.0, AssignmentCheckResult::Bad(AssignmentCheckError::InvalidCert(ValidatorIndex(0))));
 }
 
 #[test]
@@ -495,7 +496,7 @@ fn rejects_assignment_with_unknown_candidate() {
 		assignment.clone(),
 		candidate_index,
 	).unwrap();
-	assert_eq!(res.0, AssignmentCheckResult::Bad);
+	assert_eq!(res.0, AssignmentCheckResult::Bad(AssignmentCheckError::InvalidCandidateIndex(candidate_index)));
 }
 
 #[test]
@@ -579,7 +580,7 @@ fn rejects_approval_before_assignment() {
 		|r| r
 	).unwrap();
 
-	assert_eq!(res, ApprovalCheckResult::Bad);
+	assert_eq!(res, ApprovalCheckResult::Bad(ApprovalCheckError::NoAssignment(ValidatorIndex(0))));
 	assert!(actions.is_empty());
 }
 
@@ -611,7 +612,7 @@ fn rejects_approval_if_no_candidate_entry() {
 		|r| r
 	).unwrap();
 
-	assert_eq!(res, ApprovalCheckResult::Bad);
+	assert_eq!(res, ApprovalCheckResult::Bad(ApprovalCheckError::InvalidCandidate(0, candidate_hash)));
 	assert!(actions.is_empty());
 }
 
@@ -649,7 +650,7 @@ fn rejects_approval_if_no_block_entry() {
 		|r| r
 	).unwrap();
 
-	assert_eq!(res, ApprovalCheckResult::Bad);
+	assert_eq!(res, ApprovalCheckResult::Bad(ApprovalCheckError::UnknownBlock(block_hash)));
 	assert!(actions.is_empty());
 }
 

node/network/approval-distribution/src/lib.rs

@@ -624,13 +624,29 @@ impl State {
 					if let Some(peer_knowledge) = entry.known_by.get_mut(&peer_id) {
 						peer_knowledge.received.insert(fingerprint);
 					}
+					tracing::debug!(
+						target: LOG_TARGET,
+						?peer_id,
+						"Got an `AcceptedDuplicate` assignment",
+					);
 					return;
 				}
 				AssignmentCheckResult::TooFarInFuture => {
+					tracing::debug!(
+						target: LOG_TARGET,
+						?peer_id,
+						"Got an assignment too far in the future",
+					);
 					modify_reputation(ctx, peer_id, COST_ASSIGNMENT_TOO_FAR_IN_THE_FUTURE).await;
 					return;
 				}
-				AssignmentCheckResult::Bad => {
+				AssignmentCheckResult::Bad(error) => {
+					tracing::info!(
+						target: LOG_TARGET,
+						?peer_id,
+						%error,
+						"Got a bad assignment from peer",
+					);
 					modify_reputation(ctx, peer_id, COST_INVALID_MESSAGE).await;
 					return;
 				}
@@ -844,11 +860,12 @@ impl State {
 						peer_knowledge.received.insert(fingerprint.clone());
 					}
 				}
-				ApprovalCheckResult::Bad => {
+				ApprovalCheckResult::Bad(error) => {
 					modify_reputation(ctx, peer_id, COST_INVALID_MESSAGE).await;
 					tracing::info!(
 						target: LOG_TARGET,
 						?peer_id,
+						%error,
 						"Got a bad approval from peer",
 					);
 					return;

node/network/approval-distribution/src/tests.rs

@@ -17,6 +17,7 @@
 use std::time::Duration;
 use futures::{future, Future, executor};
 use assert_matches::assert_matches;
+use polkadot_node_subsystem::messages::ApprovalCheckError;
 use polkadot_node_subsystem_test_helpers as test_helpers;
 use polkadot_node_subsystem_util::TimeoutExt as _;
 use polkadot_node_network_protocol::{view, ObservedRole};
@@ -594,7 +595,7 @@ fn import_approval_bad() {
 				tx,
 			)) => {
 				assert_eq!(vote, approval);
-				tx.send(ApprovalCheckResult::Bad).unwrap();
+				tx.send(ApprovalCheckResult::Bad(ApprovalCheckError::UnknownBlock(hash))).unwrap();
 			}
 		);
 

node/subsystem/src/messages.rs

@@ -646,7 +646,7 @@ impl CollationGenerationMessage {
 }
 
 /// The result type of [`ApprovalVotingMessage::CheckAndImportAssignment`] request.
-#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+#[derive(Debug, Clone, PartialEq, Eq)]
 pub enum AssignmentCheckResult {
 	/// The vote was accepted and should be propagated onwards.
 	Accepted,
@@ -655,16 +655,56 @@ pub enum AssignmentCheckResult {
 	/// The vote was valid but too far in the future to accept right now.
 	TooFarInFuture,
 	/// The vote was bad and should be ignored, reporting the peer who propagated it.
-	Bad,
+	Bad(AssignmentCheckError),
+}
+
+/// The error result type of [`ApprovalVotingMessage::CheckAndImportAssignment`] request.
+#[derive(Error, Debug, Clone, PartialEq, Eq)]
+#[allow(missing_docs)]
+pub enum AssignmentCheckError {
+	#[error("Unknown block: {0:?}")]
+	UnknownBlock(Hash),
+	#[error("Unknown session index: {0}")]
+	UnknownSessionIndex(SessionIndex),
+	#[error("Invalid candidate index: {0}")]
+	InvalidCandidateIndex(CandidateIndex),
+	#[error("Invalid candidate {0}: {1:?}")]
+	InvalidCandidate(CandidateIndex, CandidateHash),
+	#[error("Invalid cert: {0:?}")]
+	InvalidCert(ValidatorIndex),
+	#[error("Internal state mismatch: {0:?}, {1:?}")]
+	Internal(Hash, CandidateHash),
 }
 
 /// The result type of [`ApprovalVotingMessage::CheckAndImportApproval`] request.
-#[derive(Debug, Clone, Copy, PartialEq, Eq)]
+#[derive(Debug, Clone, PartialEq, Eq)]
 pub enum ApprovalCheckResult {
 	/// The vote was accepted and should be propagated onwards.
 	Accepted,
 	/// The vote was bad and should be ignored, reporting the peer who propagated it.
-	Bad,
+	Bad(ApprovalCheckError)
+}
+
+/// The error result type of [`ApprovalVotingMessage::CheckAndImportApproval`] request.
+#[derive(Error, Debug, Clone, PartialEq, Eq)]
+#[allow(missing_docs)]
+pub enum ApprovalCheckError {
+	#[error("Unknown block: {0:?}")]
+	UnknownBlock(Hash),
+	#[error("Unknown session index: {0}")]
+	UnknownSessionIndex(SessionIndex),
+	#[error("Invalid candidate index: {0}")]
+	InvalidCandidateIndex(CandidateIndex),
+	#[error("Invalid validator index: {0:?}")]
+	InvalidValidatorIndex(ValidatorIndex),
+	#[error("Invalid candidate {0}: {1:?}")]
+	InvalidCandidate(CandidateIndex, CandidateHash),
+	#[error("Invalid signature: {0:?}")]
+	InvalidSignature(ValidatorIndex),
+	#[error("No assignment for {0:?}")]
+	NoAssignment(ValidatorIndex),
+	#[error("Internal state mismatch: {0:?}, {1:?}")]
+	Internal(Hash, CandidateHash),
 }
 
 /// Message to the Approval Voting subsystem.

roadmap/implementers-guide/src/types/overseer-protocol.md

@@ -58,14 +58,34 @@ enum AssignmentCheckResult {
     // The vote was valid but too far in the future to accept right now.
     TooFarInFuture,
     // The vote was bad and should be ignored, reporting the peer who propagated it.
-    Bad,
+    Bad(AssignmentCheckError),
+}
+
+pub enum AssignmentCheckError {
+    UnknownBlock(Hash),
+    UnknownSessionIndex(SessionIndex),
+    InvalidCandidateIndex(CandidateIndex),
+    InvalidCandidate(CandidateIndex, CandidateHash),
+    InvalidCert(ValidatorIndex),
+    Internal(Hash, CandidateHash),
 }
 
 enum ApprovalCheckResult {
     // The vote was accepted and should be propagated onwards.
     Accepted,
     // The vote was bad and should be ignored, reporting the peer who propagated it.
-    Bad,
+    Bad(ApprovalCheckError),
+}
+
+pub enum ApprovalCheckError {
+    UnknownBlock(Hash),
+    UnknownSessionIndex(SessionIndex),
+    InvalidCandidateIndex(CandidateIndex),
+    InvalidValidatorIndex(ValidatorIndex),
+    InvalidCandidate(CandidateIndex, CandidateHash),
+    InvalidSignature(ValidatorIndex),
+    NoAssignment(ValidatorIndex),
+    Internal(Hash, CandidateHash),
 }
 
 enum ApprovalVotingMessage {