Skip to content

debug(blockchain): trace-level instrumentation for build_block loop #381

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
MegaRedHand merged 3 commits into from
May 18, 2026
Merged

debug(blockchain): trace-level instrumentation for build_block loop #381

Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
8eebb74
debug(blockchain): trace-level instrumentation for build_block loop
MegaRedHand May 18, 2026
4d9a31b
debug(blockchain): replace build_block spans with one INFO line
MegaRedHand May 18, 2026
76b40cc
Merge branch 'main' into block-building-logs
MegaRedHand May 18, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
86 changes: 83 additions & 3 deletions crates/blockchain/src/store.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1032,6 +1032,21 @@ fn extend_proofs_greedily(
}
}

fn trace_skipped_attestation(reason: &'static str, att: &AttestationData, data_root: &H256) {
trace!(
reason,
attestation_slot = att.slot,
source_slot = att.source.slot,
source_root = %ShortRoot(&att.source.root.0),
target_slot = att.target.slot,
target_root = %ShortRoot(&att.target.root.0),
head_slot = att.head.slot,
head_root = %ShortRoot(&att.head.root.0),
data_root = %ShortRoot(&data_root.0),
"skipped"
);
}

/// Build a valid block on top of this state.
///
/// Works directly with aggregated payloads keyed by data_root, filtering
Expand Down Expand Up @@ -1072,29 +1087,50 @@ fn build_block(
let mut sorted_entries: Vec<_> = aggregated_payloads.iter().collect();
sorted_entries.sort_by_key(|(_, (data, _))| data.target.slot);

info!(slot, proposer_index, "Building block");

loop {
let mut found_new = false;
let mut iter_selected: u32 = 0;
let mut iter_skipped: u32 = 0;

trace!(
candidates = sorted_entries.len(),
already_selected = processed_data_roots.len(),
current_justified_slot = current_justified.slot,
current_justified_root = %ShortRoot(&current_justified.root.0),
"start"
);

for &(data_root, (att_data, proofs)) in &sorted_entries {
if processed_data_roots.contains(data_root) {
continue;
}

// Cap distinct AttestationData entries per block (leanSpec #536).
if processed_data_roots.len() >= MAX_ATTESTATIONS_DATA {
trace_skipped_attestation("max_attestation_data_cap", att_data, data_root);
iter_skipped += 1;
break;
}
Comment on lines 1110 to 1115
Copy link
Copy Markdown
Contributor

@greptile-apps greptile-apps Bot May 18, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 When max_attestation_data_cap fires, the loop breaks immediately, so only the single entry that triggered the cap is counted as skipped. Every subsequent entry in sorted_entries that would also have been blocked by the cap is silently unaccounted for. In a block where, say, 40 candidates remain after the cap is already full, iter_skipped will be 1 instead of 40, making the "post-block checkpoint" / "converged" trace events misleading for diagnosing why a block is sparse.

Suggested change
// Cap distinct AttestationData entries per block (leanSpec #536).
if processed_data_roots.len() >= MAX_ATTESTATIONS_DATA {
trace_skipped_attestation("max_attestation_data_cap", att_data, data_root);
iter_skipped += 1;
break;
}
// Cap distinct AttestationData entries per block (leanSpec #536).
if processed_data_roots.len() >= MAX_ATTESTATIONS_DATA {
// Count all remaining (unprocessed) entries as skipped so
// iter_skipped is accurate in the post-iteration trace events.
let remaining_unprocessed = sorted_entries
.iter()
.filter(|&&(r, _)| !processed_data_roots.contains(r))
.count();
iter_skipped += remaining_unprocessed as u32;
trace_skipped_attestation("max_attestation_data_cap", att_data, data_root);
break;
}
Prompt To Fix With AI 
This is a comment left during a code review.
Path: crates/blockchain/src/store.rs
Line: 1112-1117

Comment:
When `max_attestation_data_cap` fires, the loop `break`s immediately, so only the single entry that triggered the cap is counted as skipped. Every subsequent entry in `sorted_entries` that would also have been blocked by the cap is silently unaccounted for. In a block where, say, 40 candidates remain after the cap is already full, `iter_skipped` will be 1 instead of 40, making the "post-block checkpoint" / "converged" trace events misleading for diagnosing why a block is sparse.

```suggestion
                // Cap distinct AttestationData entries per block (leanSpec #536).
                if processed_data_roots.len() >= MAX_ATTESTATIONS_DATA {
                    // Count all remaining (unprocessed) entries as skipped so
                    // iter_skipped is accurate in the post-iteration trace events.
                    let remaining_unprocessed = sorted_entries
                        .iter()
                        .filter(|&&(r, _)| !processed_data_roots.contains(r))
                        .count();
                    iter_skipped += remaining_unprocessed as u32;
                    trace_skipped_attestation("max_attestation_data_cap", att_data, data_root);
                    break;
                }
```

How can I resolve this? If you propose a fix, please make it concise.

if !known_block_roots.contains(&att_data.head.root) {
trace_skipped_attestation("head_root_unknown", att_data, data_root);
iter_skipped += 1;
continue;
}
if !justified_slots_ops::is_slot_justified(
&current_justified_slots,
current_finalized_slot,
att_data.source.slot,
) {
trace_skipped_attestation("source_not_justified", att_data, data_root);
iter_skipped += 1;
continue;
}

if !attestation_data_matches_chain(&extended_historical_block_hashes, att_data) {
trace_skipped_attestation("chain_mismatch", att_data, data_root);
iter_skipped += 1;
continue;
}

Expand All @@ -1110,16 +1146,52 @@ fn build_block(
att_data.target.slot,
)
{
trace_skipped_attestation("target_already_justified", att_data, data_root);
iter_skipped += 1;
continue;
}

processed_data_roots.insert(*data_root);
found_new = true;

let before = selected.len();
extend_proofs_greedily(proofs, &mut selected, att_data);

if tracing::enabled!(tracing::Level::TRACE) {
let available_bits: HashSet<u64> = proofs
.iter()
.flat_map(|p| p.participant_indices())
.collect();
let selected_bits: HashSet<u64> = selected[before..]
.iter()
.flat_map(|(att, _)| validator_indices(&att.aggregation_bits))
.collect();
trace!(
attestation_slot = att_data.slot,
source_slot = att_data.source.slot,
source_root = %ShortRoot(&att_data.source.root.0),
target_slot = att_data.target.slot,
target_root = %ShortRoot(&att_data.target.root.0),
head_slot = att_data.head.slot,
head_root = %ShortRoot(&att_data.head.root.0),
data_root = %ShortRoot(&data_root.0),
available_bits = available_bits.len(),
selected_bits = selected_bits.len(),
available_proofs = proofs.len(),
selected_proofs = selected.len() - before,
"selected"
);
}
iter_selected += 1;
}

if !found_new {
trace!(
iter_selected,
iter_skipped,
selected_total = processed_data_roots.len(),
"converged: no new candidates"
);
break;
}

Expand All @@ -1141,9 +1213,17 @@ fn build_block(
process_slots(&mut post_state, slot)?;
process_block(&mut post_state, &candidate)?;

if post_state.latest_justified != current_justified
|| post_state.latest_finalized.slot != current_finalized_slot
{
let advanced = post_state.latest_justified != current_justified
|| post_state.latest_finalized.slot != current_finalized_slot;
trace!(
iter_selected,
iter_skipped,
advanced,
justified_slot = post_state.latest_justified.slot,
justified_root = %ShortRoot(&post_state.latest_justified.root.0),
"post-block checkpoint"
);
if advanced {
current_justified = post_state.latest_justified;
current_justified_slots = post_state.justified_slots.clone();
current_finalized_slot = post_state.latest_finalized.slot;
Expand Down
Loading