Skip to content

Commit 81951a9

Browse files
perfogicperfogic
committed
chore: add log debug trace
1 parent 3a68581 commit 81951a9

8 files changed

Lines changed: 226 additions & 28 deletions

File tree

‎crates/common/chain/beacon/src/beacon_chain.rs‎

Lines changed: 25 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,7 @@ use ream_storage::{
2121
};
2222
use ream_sync_committee_pool::SyncCommitteePool;
2323
use tokio::sync::{Mutex, broadcast};
24-
use tracing::warn;
24+
use tracing::{info, warn};
2525

2626
/// BeaconChain is the main struct which manages the nodes local beacon chain.
2727
pub struct BeaconChain {
@@ -47,6 +47,11 @@ impl BeaconChain {
4747
}
4848

4949
pub async fn process_block(&self, signed_block: SignedBeaconBlock) -> anyhow::Result<()> {
50+
let slot = signed_block.message.slot;
51+
let root = signed_block.message.block_root();
52+
let parent_root = signed_block.message.parent_root;
53+
let proposer_index = signed_block.message.proposer_index;
54+
let attestation_count = signed_block.message.body.attestations.len();
5055
let mut store = self.store.lock().await;
5156

5257
on_block(
@@ -56,15 +61,32 @@ impl BeaconChain {
5661
signed_block.message.slot >= beacon_network_spec().slot_n_days_ago(17),
5762
)
5863
.await?;
64+
let finalized_checkpoint = store.db.finalized_checkpoint_provider().get().ok();
65+
info!(
66+
slot,
67+
%root,
68+
%parent_root,
69+
proposer_index,
70+
attestation_count,
71+
finalized_epoch = finalized_checkpoint.as_ref().map(|checkpoint| checkpoint.epoch),
72+
"beacon_e2e_trace: chain block imported"
73+
);
5974

6075
for attestation in signed_block.message.body.attestations.iter() {
6176
if let Err(err) = on_attestation(&mut store, attestation.clone(), true) {
62-
warn!("Failed to process block attestation through fork choice: {err:?}");
77+
warn!(
78+
block_slot = slot,
79+
block_root = %root,
80+
attestation_slot = attestation.data.slot,
81+
attestation_beacon_block_root = %attestation.data.beacon_block_root,
82+
target_epoch = attestation.data.target.epoch,
83+
target_root = %attestation.data.target.root,
84+
"beacon_e2e_trace: failed to process block attestation through fork choice: {err:?}"
85+
);
6386
}
6487
}
6588

6689
// Build and Emit Block event
67-
let finalized_checkpoint = store.db.finalized_checkpoint_provider().get().ok();
6890
let block_event =
6991
BlockEvent::from_block(&signed_block, finalized_checkpoint, |block_root, epoch| {
7092
store.get_checkpoint_block(block_root, epoch)

‎crates/common/validator/beacon/src/validator.rs‎

Lines changed: 58 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -467,18 +467,52 @@ impl ValidatorService {
467467
ProduceBlockData::Full(full_block) => {
468468
let signed_beacon_block =
469469
sign_beacon_block(slot, full_block.block, &keystore.private_key)?;
470+
let root = signed_beacon_block.message.tree_hash_root();
471+
let parent_root = signed_beacon_block.message.parent_root;
472+
let attestation_count = signed_beacon_block.message.body.attestations.len();
473+
info!(
474+
slot,
475+
validator_index,
476+
%root,
477+
%parent_root,
478+
attestation_count,
479+
"beacon_e2e_trace: validator publishing full block"
480+
);
470481

471482
self.beacon_api_client
472483
.publish_block(BroadcastValidation::Gossip, signed_beacon_block)
473484
.await?;
485+
info!(
486+
slot,
487+
validator_index,
488+
%root,
489+
%parent_root,
490+
"beacon_e2e_trace: validator published full block"
491+
);
474492
}
475493
ProduceBlockData::Blinded(blinded_block) => {
476494
let signed_blinded_block =
477495
sign_blinded_beacon_block(slot, blinded_block, &keystore.private_key)?;
496+
let root = signed_blinded_block.message.tree_hash_root();
497+
let parent_root = signed_blinded_block.message.parent_root;
498+
info!(
499+
slot,
500+
validator_index,
501+
%root,
502+
%parent_root,
503+
"beacon_e2e_trace: validator publishing blinded block"
504+
);
478505

479506
self.beacon_api_client
480507
.publish_blinded_block(BroadcastValidation::Gossip, signed_blinded_block)
481508
.await?;
509+
info!(
510+
slot,
511+
validator_index,
512+
%root,
513+
%parent_root,
514+
"beacon_e2e_trace: validator published blinded block"
515+
);
482516
}
483517
};
484518

@@ -645,12 +679,28 @@ async fn make_attestation_for_duty(
645679
.await?
646680
.data;
647681

648-
Ok(beacon_api_client
649-
.submit_attestation(vec![SingleAttestation {
650-
attester_index: validator_index,
651-
committee_index,
652-
signature: sign_attestation_data(&attestation_data, &keystore.private_key)?,
653-
data: attestation_data,
654-
}])
655-
.await?)
682+
let single_attestation = SingleAttestation {
683+
attester_index: validator_index,
684+
committee_index,
685+
signature: sign_attestation_data(&attestation_data, &keystore.private_key)?,
686+
data: attestation_data,
687+
};
688+
info!(
689+
slot,
690+
validator_index,
691+
committee_index,
692+
beacon_block_root = %single_attestation.data.beacon_block_root,
693+
target_epoch = single_attestation.data.target.epoch,
694+
target_root = %single_attestation.data.target.root,
695+
"beacon_e2e_trace: validator submitting attestation"
696+
);
697+
beacon_api_client
698+
.submit_attestation(vec![single_attestation])
699+
.await?;
700+
info!(
701+
slot,
702+
validator_index, committee_index, "beacon_e2e_trace: validator submitted attestation"
703+
);
704+
705+
Ok(())
656706
}

‎crates/networking/manager/src/gossipsub/handle.rs‎

Lines changed: 69 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -145,13 +145,30 @@ async fn import_gossip_attestation(
145145
.insert_attestation(attestation.clone(), single_attestation.committee_index);
146146

147147
let current_slot = store.get_current_slot()?;
148+
info!(
149+
current_slot,
150+
attestation_slot = single_attestation.data.slot,
151+
committee_index = single_attestation.committee_index,
152+
attester_index = single_attestation.attester_index,
153+
beacon_block_root = %single_attestation.data.beacon_block_root,
154+
target_epoch = single_attestation.data.target.epoch,
155+
target_root = %single_attestation.data.target.root,
156+
"beacon_e2e_trace: gossip attestation inserted"
157+
);
148158
(
149159
attestation,
150160
current_slot >= single_attestation.data.slot + MIN_ATTESTATION_INCLUSION_DELAY,
151161
)
152162
};
153163

154164
if should_process_attestation {
165+
info!(
166+
attestation_slot = attestation.data.slot,
167+
beacon_block_root = %attestation.data.beacon_block_root,
168+
target_epoch = attestation.data.target.epoch,
169+
target_root = %attestation.data.target.root,
170+
"beacon_e2e_trace: gossip attestation processing fork choice"
171+
);
155172
beacon_chain.process_attestation(attestation, false).await?;
156173
}
157174

@@ -175,10 +192,18 @@ pub async fn handle_gossipsub_message(
175192
match GossipsubMessage::decode(&message.topic, &message.data) {
176193
Ok(gossip_message) => match gossip_message {
177194
GossipsubMessage::BeaconBlock(signed_block) => {
195+
let slot = signed_block.message.slot;
196+
let root = signed_block.message.block_root();
197+
let parent_root = signed_block.message.parent_root;
198+
let proposer_index = signed_block.message.proposer_index;
199+
let attestation_count = signed_block.message.body.attestations.len();
178200
info!(
179-
"Beacon block received over gossipsub: slot: {}, root: {}",
180-
signed_block.message.slot,
181-
signed_block.message.block_root()
201+
slot,
202+
%root,
203+
%parent_root,
204+
proposer_index,
205+
attestation_count,
206+
"beacon_e2e_trace: gossip block received"
182207
);
183208

184209
let tick_time = {
@@ -208,17 +233,55 @@ pub async fn handle_gossipsub_message(
208233

209234
match validation_result {
210235
ValidationResult::Accept => {
236+
info!(
237+
slot,
238+
%root,
239+
%parent_root,
240+
proposer_index,
241+
attestation_count,
242+
"beacon_e2e_trace: gossip block accepted"
243+
);
211244
let signed_block_bytes = signed_block.as_ssz_bytes();
212245
if let Err(err) = beacon_chain.process_block(*signed_block).await {
213-
error!("Failed to process gossipsub beacon block: {err}");
246+
error!(
247+
slot,
248+
%root,
249+
%parent_root,
250+
"beacon_e2e_trace: gossip block import failed: {err}"
251+
);
252+
} else {
253+
info!(
254+
slot,
255+
%root,
256+
%parent_root,
257+
"beacon_e2e_trace: gossip block imported"
258+
);
214259
}
215260
forward_gossip_message(&message, p2p_sender, signed_block_bytes);
261+
info!(
262+
slot,
263+
%root,
264+
%parent_root,
265+
"beacon_e2e_trace: gossip block forwarded"
266+
);
216267
}
217268
ValidationResult::Ignore(reason) => {
218-
warn!("Ignoring gossipsub beacon block: {reason}");
269+
warn!(
270+
slot,
271+
%root,
272+
%parent_root,
273+
reason,
274+
"beacon_e2e_trace: gossip block ignored"
275+
);
219276
}
220277
ValidationResult::Reject(reason) => {
221-
warn!("Rejecting gossipsub beacon block: {reason}");
278+
warn!(
279+
slot,
280+
%root,
281+
%parent_root,
282+
reason,
283+
"beacon_e2e_trace: gossip block rejected"
284+
);
222285
}
223286
}
224287
}

‎crates/networking/manager/src/gossipsub/validate/beacon_block.rs‎

Lines changed: 4 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -165,13 +165,12 @@ pub async fn validate_beacon_block(
165165
.slot_index_provider()
166166
.get_highest_slot()?
167167
.unwrap_or_default();
168+
let slot = block.message.slot;
169+
let root = block.message.block_root();
170+
let parent_root = block.message.parent_root;
168171
// [IGNORE] The block's parent (defined by block.parent_root) has been seen.
169172
return Ok(ValidationResult::Ignore(format!(
170-
"Parent block not found: slot={}, root={}, parent_root={}, local_highest_slot={}",
171-
block.message.slot,
172-
block.message.block_root(),
173-
block.message.parent_root,
174-
local_highest_slot
173+
"Parent block not found: slot={slot}, root={root}, parent_root={parent_root}, local_highest_slot={local_highest_slot}"
175174
)));
176175
}
177176
}

‎crates/networking/syncer/src/block_range/mod.rs‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -138,6 +138,12 @@ impl BlockRangeSyncer {
138138
sleep(SLEEP_DURATION).await;
139139
continue;
140140
};
141+
info!(
142+
peer_id = %peer.peer_id,
143+
start_slot = range.start_slot,
144+
count = range.count,
145+
"beacon_e2e_trace: range sync requesting block range"
146+
);
141147

142148
task_handles.push(DownloadTask::new_block_range(
143149
PeerRangeDownloader::start(
@@ -337,6 +343,17 @@ fn poll_ready_tasks(
337343
continue;
338344
}
339345
};
346+
let first_slot = blocks.first().map(|block| block.message.slot);
347+
let last_slot = blocks.last().map(|block| block.message.slot);
348+
info!(
349+
peer_id = %peer_id,
350+
requested_start_slot = range.start_slot,
351+
requested_count = range.count,
352+
block_count = blocks.len(),
353+
?first_slot,
354+
?last_slot,
355+
"beacon_e2e_trace: range sync received block range"
356+
);
340357

341358
if blocks.is_empty() {
342359
warn!("Received empty block range from peer: {peer_id}");

‎crates/networking/syncer/src/block_range/peer_manager.rs‎

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -106,9 +106,8 @@ impl PeerManager {
106106
}
107107

108108
format!(
109-
"Total Peers: {total_peers}, Idle: {idle_peers}, Downloading: {downloading_peers}, Banned: {}, Finalized Epochs: {:?}",
110-
self.banned_peers.len(),
111-
finalized_epochs
109+
"Total Peers: {total_peers}, Idle: {idle_peers}, Downloading: {downloading_peers}, Banned: {banned_peers}, Finalized Epochs: {finalized_epochs:?}",
110+
banned_peers = self.banned_peers.len(),
112111
)
113112
}
114113

‎crates/rpc/beacon/src/handlers/block.rs‎

Lines changed: 37 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -533,6 +533,11 @@ async fn publish_and_process_block(
533533
beacon_chain: Data<Arc<BeaconChain>>,
534534
p2p_sender: Data<Arc<P2PSender>>,
535535
) -> Result<HttpResponse, ApiError> {
536+
let slot = signed_block.message.slot;
537+
let root = signed_block.message.block_root();
538+
let parent_root = signed_block.message.parent_root;
539+
let proposer_index = signed_block.message.proposer_index;
540+
let attestation_count = signed_block.message.body.attestations.len();
536541
process_tick_now(beacon_chain.as_ref())
537542
.await
538543
.map_err(|err| {
@@ -550,18 +555,47 @@ async fn publish_and_process_block(
550555
topic,
551556
data: signed_block.as_ssz_bytes(),
552557
});
558+
info!(
559+
slot,
560+
%root,
561+
%parent_root,
562+
proposer_index,
563+
attestation_count,
564+
"beacon_e2e_trace: validator block published to gossip"
565+
);
553566

554567
// Integrate into state (after broadcast)
555568
let integration_success = match beacon_chain.process_block(signed_block.clone()).await {
556-
Ok(()) => true,
569+
Ok(()) => {
570+
info!(
571+
slot,
572+
%root,
573+
%parent_root,
574+
proposer_index,
575+
attestation_count,
576+
"beacon_e2e_trace: validator block imported locally"
577+
);
578+
true
579+
}
557580
Err(err) => {
558581
if err.to_string().contains("already known")
559582
|| err.to_string().contains("ALREADY_KNOWN")
560583
{
561-
warn!("Block already known, ignoring: {err}");
584+
warn!(
585+
slot,
586+
%root,
587+
%parent_root,
588+
"beacon_e2e_trace: validator block already known, ignoring: {err}"
589+
);
562590
return Ok(HttpResponse::Ok().finish());
563591
}
564-
error!("Failed to integrate block into state: {err}");
592+
error!(
593+
slot,
594+
%root,
595+
%parent_root,
596+
proposer_index,
597+
"beacon_e2e_trace: validator block import failed: {err}"
598+
);
565599
false
566600
}
567601
};

0 commit comments

Comments
 (0)