From bdb32563969d146e2cced7e221fd198470d0d296 Mon Sep 17 00:00:00 2001
From: Robert Habermeier <rphmeier@gmail.com>
Date: Fri, 12 Mar 2021 17:24:35 -0600
Subject: [PATCH] more diagnostic logs for approval-voting (#2618)
---
polkadot/node/core/approval-voting/src/lib.rs | 58 +++++++++++++++++--
.../approval-voting/src/persisted_entries.rs | 9 +++
2 files changed, 61 insertions(+), 6 deletions(-)
diff --git a/polkadot/node/core/approval-voting/src/lib.rs b/polkadot/node/core/approval-voting/src/lib.rs
index 82424586ebf..78daa39e562 100644
--- a/polkadot/node/core/approval-voting/src/lib.rs
+++ b/polkadot/node/core/approval-voting/src/lib.rs
@@ -715,6 +715,7 @@ async fn handle_approved_ancestor(
lower_bound: BlockNumber,
) -> SubsystemResult<Option<(Hash, BlockNumber)>> {
const MAX_TRACING_WINDOW: usize = 200;
+ const ABNORMAL_DEPTH_THRESHOLD: usize = 5;
use bitvec::{order::Lsb0, vec::BitVec};
@@ -789,8 +790,53 @@ async fn handle_approved_ancestor(
// ancestry is moving backwards.
all_approved_max = Some((block_hash, target_number - i as BlockNumber));
}
+ } else if bits.len() <= ABNORMAL_DEPTH_THRESHOLD {
+ all_approved_max = None;
} else {
all_approved_max = None;
+
+ let unapproved: Vec<_> = entry.unapproved_candidates().collect();
+ tracing::debug!(
+ target: LOG_TARGET,
+ "Block {} is {} blocks deep and has {}/{} candidates approved",
+ block_hash,
+ bits.len() - 1,
+ unapproved.len(),
+ entry.candidates().len(),
+ );
+
+ for candidate_hash in unapproved {
+ match db.load_candidate_entry(&candidate_hash)? {
+ None => {
+ tracing::warn!(
+ target: LOG_TARGET,
+ ?candidate_hash,
+ "Missing expected candidate in DB",
+ );
+
+ continue;
+ }
+ Some(c_entry) => {
+ match c_entry.approval_entry(&block_hash) {
+ None => {
+ tracing::warn!(
+ target: LOG_TARGET,
+ ?candidate_hash,
+ ?block_hash,
+ "Missing expected approval entry under candidate.",
+ );
+ }
+ Some(a_entry) => {
+ let our_assignment = a_entry.our_assignment();
+ tracing::debug!(
+ target: LOG_TARGET,
+ ?our_assignment,
+ );
+ }
+ }
+ }
+ }
+ }
}
}
@@ -898,7 +944,7 @@ fn schedule_wakeup_action(
};
match maybe_action {
- Some(Action::ScheduleWakeup { ref tick, .. }) => tracing::debug!(
+ Some(Action::ScheduleWakeup { ref tick, .. }) => tracing::trace!(
target: LOG_TARGET,
"Scheduling next wakeup at {} for candidate {} under block ({}, tick={})",
tick,
@@ -906,7 +952,7 @@ fn schedule_wakeup_action(
block_hash,
block_tick,
),
- None => tracing::debug!(
+ None => tracing::trace!(
target: LOG_TARGET,
"No wakeup needed for candidate {} under block ({}, tick={})",
candidate_hash,
@@ -1354,7 +1400,7 @@ fn process_wakeup(
let tranche_now = state.clock.tranche_now(state.slot_duration_millis, block_entry.slot());
- tracing::debug!(
+ tracing::trace!(
target: LOG_TARGET,
"Processing wakeup at tranche {} for candidate {} under block {}",
tranche_now,
@@ -1413,7 +1459,7 @@ fn process_wakeup(
.position(|(_, h)| &candidate_hash == h);
if let Some(i) = index_in_candidate {
- tracing::debug!(
+ tracing::trace!(
target: LOG_TARGET,
"Launching approval work for candidate {:?} in block {}",
(&candidate_hash, candidate_entry.candidate_receipt().descriptor.para_id),
@@ -1472,7 +1518,7 @@ async fn launch_approval(
let candidate_hash = candidate.hash();
- tracing::debug!(
+ tracing::trace!(
target: LOG_TARGET,
"Recovering data for candidate {:?}",
(candidate_hash, candidate.descriptor.para_id),
@@ -1576,7 +1622,7 @@ async fn launch_approval(
// Validation checked out. Issue an approval command. If the underlying service is unreachable,
// then there isn't anything we can do.
- tracing::debug!(
+ tracing::trace!(
target: LOG_TARGET,
"Candidate Valid {:?}",
(candidate_hash, para_id),
diff --git a/polkadot/node/core/approval-voting/src/persisted_entries.rs b/polkadot/node/core/approval-voting/src/persisted_entries.rs
index 1464cf82083..6a8edbf61b1 100644
--- a/polkadot/node/core/approval-voting/src/persisted_entries.rs
+++ b/polkadot/node/core/approval-voting/src/persisted_entries.rs
@@ -323,6 +323,15 @@ impl BlockEntry {
self.approved_bitfield.all()
}
+ /// Iterate over all unapproved candidates.
+ pub fn unapproved_candidates(&self) -> impl Iterator<Item = CandidateHash> + '_ {
+ self.approved_bitfield.iter().enumerate().filter_map(move |(i, a)| if *a {
+ Some(self.candidates[i].1)
+ } else {
+ None
+ })
+ }
+
#[cfg(test)]
pub fn block_hash(&self) -> Hash {
self.block_hash
--
GitLab