diff --git a/polkadot/node/core/provisioner/src/lib.rs b/polkadot/node/core/provisioner/src/lib.rs index 5593ab2a7b..73f26a0613 100644 --- a/polkadot/node/core/provisioner/src/lib.rs +++ b/polkadot/node/core/provisioner/src/lib.rs @@ -269,6 +269,14 @@ impl ProvisionerJob { self.metrics.on_inherent_data_request(Err(())); } else { self.metrics.on_inherent_data_request(Ok(())); + gum::debug!( + target: LOG_TARGET, + signed_bitfield_count = self.signed_bitfields.len(), + backed_candidates_count = self.backed_candidates.len(), + leaf_hash = ?self.leaf.hash, + disputes_enabled, + "inherent data sent successfully" + ); } } @@ -330,12 +338,24 @@ async fn send_inherent_data( // Only include bitfields on fresh leaves. On chain reversions, we want to make sure that // there will be at least one block, which cannot get disputed, so the chain can make progress. let bitfields = match leaf.status { - LeafStatus::Fresh => select_availability_bitfields(&availability_cores, bitfields), + LeafStatus::Fresh => + select_availability_bitfields(&availability_cores, bitfields, &leaf.hash), LeafStatus::Stale => Vec::new(), }; let candidates = select_candidates(&availability_cores, &bitfields, candidates, leaf.hash, from_job).await?; + gum::debug!( + target: LOG_TARGET, + disputes_enabled = disputes_enabled, + availability_cores_len = availability_cores.len(), + disputes_count = disputes.len(), + bitfields_count = bitfields.len(), + candidates_count = candidates.len(), + leaf_hash = ?leaf.hash, + "inherent data prepared", + ); + let inherent_data = ProvisionerInherentData { bitfields, backed_candidates: candidates, disputes }; @@ -361,11 +381,20 @@ async fn send_inherent_data( fn select_availability_bitfields( cores: &[CoreState], bitfields: &[SignedAvailabilityBitfield], + leaf_hash: &Hash, ) -> Vec { let mut selected: BTreeMap = BTreeMap::new(); + gum::debug!( + target: LOG_TARGET, + bitfields_count = bitfields.len(), + ?leaf_hash, + "bitfields count before selection" + ); + 'a: for bitfield in bitfields.iter().cloned() { if bitfield.payload().0.len() != cores.len() { + gum::debug!(target: LOG_TARGET, ?leaf_hash, "dropping bitfield due to length mismatch"); continue } @@ -374,12 +403,24 @@ fn select_availability_bitfields( .map_or(true, |b| b.payload().0.count_ones() < bitfield.payload().0.count_ones()); if !is_better { + gum::trace!( + target: LOG_TARGET, + val_idx = bitfield.validator_index().0, + ?leaf_hash, + "dropping bitfield due to duplication - the better one is kept" + ); continue } for (idx, _) in cores.iter().enumerate().filter(|v| !v.1.is_occupied()) { // Bit is set for an unoccupied core - invalid if *bitfield.payload().0.get(idx).as_deref().unwrap_or(&false) { + gum::debug!( + target: LOG_TARGET, + val_idx = bitfield.validator_index().0, + ?leaf_hash, + "dropping invalid bitfield - bit is set for an unoccupied core" + ); continue 'a } } @@ -387,6 +428,14 @@ fn select_availability_bitfields( let _ = selected.insert(bitfield.validator_index(), bitfield); } + gum::debug!( + target: LOG_TARGET, + ?leaf_hash, + "selected {} of all {} bitfields (each bitfield is from a unique validator)", + selected.len(), + bitfields.len() + ); + selected.into_iter().map(|(_, b)| b).collect() } @@ -403,6 +452,8 @@ async fn select_candidates( let mut selected_candidates = Vec::with_capacity(candidates.len().min(availability_cores.len())); + gum::debug!(target: LOG_TARGET, leaf_hash=?relay_parent, "{} candidates before selection", candidates.len()); + for (core_idx, core) in availability_cores.iter().enumerate() { let (scheduled_core, assumption) = match core { CoreState::Scheduled(scheduled_core) => (scheduled_core, OccupiedCoreAssumption::Free), @@ -453,6 +504,7 @@ async fn select_candidates( let candidate_hash = candidate.hash(); gum::trace!( target: LOG_TARGET, + leaf_hash=?relay_parent, "Selecting candidate {}. para_id={} core={}", candidate_hash, candidate.descriptor.para_id, diff --git a/polkadot/node/core/provisioner/src/tests.rs b/polkadot/node/core/provisioner/src/tests.rs index d747075855..2cbfa97e17 100644 --- a/polkadot/node/core/provisioner/src/tests.rs +++ b/polkadot/node/core/provisioner/src/tests.rs @@ -84,7 +84,8 @@ mod select_availability_bitfields { block_on(signed_bitfield(&keystore, bitvec, ValidatorIndex(1))), ]; - let mut selected_bitfields = select_availability_bitfields(&cores, &bitfields); + let mut selected_bitfields = + select_availability_bitfields(&cores, &bitfields, &Hash::repeat_byte(0)); selected_bitfields.sort_by_key(|bitfield| bitfield.validator_index()); assert_eq!(selected_bitfields.len(), 2); @@ -122,7 +123,8 @@ mod select_availability_bitfields { block_on(signed_bitfield(&keystore, bitvec2.clone(), ValidatorIndex(2))), ]; - let selected_bitfields = select_availability_bitfields(&cores, &bitfields); + let selected_bitfields = + select_availability_bitfields(&cores, &bitfields, &Hash::repeat_byte(0)); // selects only the valid bitfield assert_eq!(selected_bitfields.len(), 1); @@ -145,7 +147,8 @@ mod select_availability_bitfields { block_on(signed_bitfield(&keystore, bitvec1.clone(), ValidatorIndex(1))), ]; - let selected_bitfields = select_availability_bitfields(&cores, &bitfields); + let selected_bitfields = + select_availability_bitfields(&cores, &bitfields, &Hash::repeat_byte(0)); assert_eq!(selected_bitfields.len(), 1); assert_eq!(selected_bitfields[0].payload().0, bitvec1.clone()); } @@ -182,7 +185,8 @@ mod select_availability_bitfields { block_on(signed_bitfield(&keystore, bitvec1.clone(), ValidatorIndex(1))), ]; - let selected_bitfields = select_availability_bitfields(&cores, &bitfields); + let selected_bitfields = + select_availability_bitfields(&cores, &bitfields, &Hash::repeat_byte(0)); assert_eq!(selected_bitfields.len(), 4); assert_eq!(selected_bitfields[0].payload().0, bitvec0); assert_eq!(selected_bitfields[1].payload().0, bitvec1);