diff --git a/polkadot/node/service/src/relay_chain_selection.rs b/polkadot/node/service/src/relay_chain_selection.rs index 9635878182..31d878218e 100644 --- a/polkadot/node/service/src/relay_chain_selection.rs +++ b/polkadot/node/service/src/relay_chain_selection.rs @@ -136,6 +136,11 @@ where /// Create a new [`SelectRelayChain`] wrapping the given chain backend /// and a handle to the overseer. pub fn new(backend: Arc, overseer: Handle, is_relay_chain: bool, metrics: Metrics) -> Self { + tracing::debug!( + target: LOG_TARGET, + "Using {} as chain selection algorithm", + if is_relay_chain { "dispute aware relay" } else { "longest" } + ); SelectRelayChain { longest_chain: sc_consensus::LongestChain::new(backend.clone()), selection: SelectRelayChainInner::new(backend, overseer, metrics), @@ -284,9 +289,14 @@ where .send_msg(ChainSelectionMessage::Leaves(tx), std::any::type_name::()) .await; - rx.await + let leaves = rx + .await .map_err(Error::OverseerDisconnected) - .map_err(|e| ConsensusError::Other(Box::new(e))) + .map_err(|e| ConsensusError::Other(Box::new(e)))?; + + tracing::trace!(target: LOG_TARGET, ?leaves, "Chain selection leaves"); + + Ok(leaves) } /// Among all leaves, pick the one which is the best chain to build upon. @@ -301,6 +311,8 @@ where .ok_or_else(|| ConsensusError::Other(Box::new(Error::EmptyLeaves)))? .clone(); + tracing::trace!(target: LOG_TARGET, ?best_leaf, "Best chain"); + self.block_header(best_leaf) } @@ -320,6 +332,7 @@ where maybe_max_number: Option, ) -> Result { let mut overseer = self.overseer.clone(); + tracing::trace!(target: LOG_TARGET, ?best_leaf, "Longest chain"); let subchain_head = if cfg!(feature = "disputes") { let (tx, rx) = oneshot::channel(); @@ -335,12 +348,15 @@ where .map_err(Error::OverseerDisconnected) .map_err(|e| ConsensusError::Other(Box::new(e)))?; + tracing::trace!(target: LOG_TARGET, ?best, "Best leaf containing"); + match best { // No viable leaves containing the block. None => return Ok(target_hash), Some(best) => best, } } else { + tracing::trace!(target: LOG_TARGET, ?best_leaf, "Dummy disputes active"); if best_leaf == target_hash { return Ok(target_hash) } else { @@ -369,6 +385,7 @@ where let subchain_header = self.block_header(subchain_head)?; if subchain_header.number <= max { + tracing::trace!(target: LOG_TARGET, ?best_leaf, "Constrained sub-chain head",); subchain_head } else { let (ancestor_hash, _) = @@ -378,7 +395,11 @@ where &subchain_header, ) .map_err(|e| ConsensusError::ChainLookup(format!("{:?}", e)))?; - + tracing::trace!( + target: LOG_TARGET, + ?ancestor_hash, + "Grandpa walk backwards sub-chain head" + ); ancestor_hash } }, @@ -409,6 +430,12 @@ where } }; + tracing::trace!( + target: LOG_TARGET, + ?subchain_head, + "Ancestor approval restriction applied", + ); + let lag = initial_leaf_number.saturating_sub(subchain_number); self.metrics.note_approval_checking_finality_lag(lag); @@ -451,6 +478,12 @@ where (lag, subchain_head) }; + tracing::trace!( + target: LOG_TARGET, + ?subchain_head, + "Disputed blocks in ancestry restriction applied", + ); + // 4. Apply the maximum safeguard to the finality lag. if lag > MAX_FINALITY_LAG { // We need to constrain our vote as a safety net to @@ -458,6 +491,7 @@ where let safe_target = initial_leaf_number - MAX_FINALITY_LAG; if safe_target <= target_number { + tracing::warn!(target: LOG_TARGET, ?target_hash, "Safeguard enforced finalization"); // Minimal vote needs to be on the target number. Ok(target_hash) } else { @@ -470,6 +504,12 @@ where ) .map_err(|e| ConsensusError::ChainLookup(format!("{:?}", e)))?; + tracing::warn!( + target: LOG_TARGET, + ?forced_target, + "Safeguard enforced finalization of child" + ); + Ok(forced_target) } } else {