Skip to content

Commit 22e56f1

Browse files
authored
debug(blockchain): trace-level instrumentation for build_block loop (lambdaclass#381)
## Summary Adds tracing inside `build_block`'s fixed-point attestation-selection loop so we can investigate sparse or empty blocks. Each iteration emits: - a `start` event with candidate count, current justified checkpoint, and how many `AttestationData` entries are already chosen; - `skipped` events tagged with a reason — `max_attestation_data_cap`, `head_root_unknown`, `source_not_justified`, `chain_mismatch`, or `target_already_justified`; - `selected` events with available vs selected bits and proof counts; - a `converged` or `post-block checkpoint` event when the inner loop ends or the fixed point continues. ## Implementation notes - Uses `trace_span!("build_block", slot, proposer_index)` + `trace_span!("iter", iteration)` so those fields ride along on every event instead of being typed out each time. - Skip paths go through a single `trace_skipped_attestation` helper. - `available_bits` / `selected_bits` `HashSet` computation is gated behind `tracing::enabled!(tracing::Level::TRACE)` so no allocations happen when trace logging is off. Enable with `RUST_LOG=ethlambda_blockchain=trace`. ## Test plan - [x] `cargo build -p ethlambda-blockchain` passes. - [ ] `make lint` clean. - [ ] `make test` passes (no behavior changes; logging only). - [ ] Devnet run with `RUST_LOG=ethlambda_blockchain=trace` shows the expected `start` / `skipped` / `selected` / `converged` / `post-block checkpoint` events under the `build_block{…}:iter{…}` span path.
1 parent 260d068 commit 22e56f1

1 file changed

Lines changed: 83 additions & 3 deletions

File tree

crates/blockchain/src/store.rs

Lines changed: 83 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1032,6 +1032,21 @@ fn extend_proofs_greedily(
10321032
}
10331033
}
10341034

1035+
fn trace_skipped_attestation(reason: &'static str, att: &AttestationData, data_root: &H256) {
1036+
trace!(
1037+
reason,
1038+
attestation_slot = att.slot,
1039+
source_slot = att.source.slot,
1040+
source_root = %ShortRoot(&att.source.root.0),
1041+
target_slot = att.target.slot,
1042+
target_root = %ShortRoot(&att.target.root.0),
1043+
head_slot = att.head.slot,
1044+
head_root = %ShortRoot(&att.head.root.0),
1045+
data_root = %ShortRoot(&data_root.0),
1046+
"skipped"
1047+
);
1048+
}
1049+
10351050
/// Build a valid block on top of this state.
10361051
///
10371052
/// Works directly with aggregated payloads keyed by data_root, filtering
@@ -1072,29 +1087,50 @@ fn build_block(
10721087
let mut sorted_entries: Vec<_> = aggregated_payloads.iter().collect();
10731088
sorted_entries.sort_by_key(|(_, (data, _))| data.target.slot);
10741089

1090+
info!(slot, proposer_index, "Building block");
1091+
10751092
loop {
10761093
let mut found_new = false;
1094+
let mut iter_selected: u32 = 0;
1095+
let mut iter_skipped: u32 = 0;
1096+
1097+
trace!(
1098+
candidates = sorted_entries.len(),
1099+
already_selected = processed_data_roots.len(),
1100+
current_justified_slot = current_justified.slot,
1101+
current_justified_root = %ShortRoot(&current_justified.root.0),
1102+
"start"
1103+
);
10771104

10781105
for &(data_root, (att_data, proofs)) in &sorted_entries {
10791106
if processed_data_roots.contains(data_root) {
10801107
continue;
10811108
}
1109+
10821110
// Cap distinct AttestationData entries per block (leanSpec #536).
10831111
if processed_data_roots.len() >= MAX_ATTESTATIONS_DATA {
1112+
trace_skipped_attestation("max_attestation_data_cap", att_data, data_root);
1113+
iter_skipped += 1;
10841114
break;
10851115
}
10861116
if !known_block_roots.contains(&att_data.head.root) {
1117+
trace_skipped_attestation("head_root_unknown", att_data, data_root);
1118+
iter_skipped += 1;
10871119
continue;
10881120
}
10891121
if !justified_slots_ops::is_slot_justified(
10901122
&current_justified_slots,
10911123
current_finalized_slot,
10921124
att_data.source.slot,
10931125
) {
1126+
trace_skipped_attestation("source_not_justified", att_data, data_root);
1127+
iter_skipped += 1;
10941128
continue;
10951129
}
10961130

10971131
if !attestation_data_matches_chain(&extended_historical_block_hashes, att_data) {
1132+
trace_skipped_attestation("chain_mismatch", att_data, data_root);
1133+
iter_skipped += 1;
10981134
continue;
10991135
}
11001136

@@ -1110,16 +1146,52 @@ fn build_block(
11101146
att_data.target.slot,
11111147
)
11121148
{
1149+
trace_skipped_attestation("target_already_justified", att_data, data_root);
1150+
iter_skipped += 1;
11131151
continue;
11141152
}
11151153

11161154
processed_data_roots.insert(*data_root);
11171155
found_new = true;
11181156

1157+
let before = selected.len();
11191158
extend_proofs_greedily(proofs, &mut selected, att_data);
1159+
1160+
if tracing::enabled!(tracing::Level::TRACE) {
1161+
let available_bits: HashSet<u64> = proofs
1162+
.iter()
1163+
.flat_map(|p| p.participant_indices())
1164+
.collect();
1165+
let selected_bits: HashSet<u64> = selected[before..]
1166+
.iter()
1167+
.flat_map(|(att, _)| validator_indices(&att.aggregation_bits))
1168+
.collect();
1169+
trace!(
1170+
attestation_slot = att_data.slot,
1171+
source_slot = att_data.source.slot,
1172+
source_root = %ShortRoot(&att_data.source.root.0),
1173+
target_slot = att_data.target.slot,
1174+
target_root = %ShortRoot(&att_data.target.root.0),
1175+
head_slot = att_data.head.slot,
1176+
head_root = %ShortRoot(&att_data.head.root.0),
1177+
data_root = %ShortRoot(&data_root.0),
1178+
available_bits = available_bits.len(),
1179+
selected_bits = selected_bits.len(),
1180+
available_proofs = proofs.len(),
1181+
selected_proofs = selected.len() - before,
1182+
"selected"
1183+
);
1184+
}
1185+
iter_selected += 1;
11201186
}
11211187

11221188
if !found_new {
1189+
trace!(
1190+
iter_selected,
1191+
iter_skipped,
1192+
selected_total = processed_data_roots.len(),
1193+
"converged: no new candidates"
1194+
);
11231195
break;
11241196
}
11251197

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

1144-
if post_state.latest_justified != current_justified
1145-
|| post_state.latest_finalized.slot != current_finalized_slot
1146-
{
1216+
let advanced = post_state.latest_justified != current_justified
1217+
|| post_state.latest_finalized.slot != current_finalized_slot;
1218+
trace!(
1219+
iter_selected,
1220+
iter_skipped,
1221+
advanced,
1222+
justified_slot = post_state.latest_justified.slot,
1223+
justified_root = %ShortRoot(&post_state.latest_justified.root.0),
1224+
"post-block checkpoint"
1225+
);
1226+
if advanced {
11471227
current_justified = post_state.latest_justified;
11481228
current_justified_slots = post_state.justified_slots.clone();
11491229
current_finalized_slot = post_state.latest_finalized.slot;

0 commit comments

Comments
 (0)