diff --git a/beacon_node/beacon_chain/src/beacon_chain.rs b/beacon_node/beacon_chain/src/beacon_chain.rs index 39089c0b0..deeda491d 100644 --- a/beacon_node/beacon_chain/src/beacon_chain.rs +++ b/beacon_node/beacon_chain/src/beacon_chain.rs @@ -2796,6 +2796,12 @@ impl BeaconChain { } } } + Err(BlockError::BlockIsAlreadyKnown(block_root)) => { + debug!(self.log, + "Ignoring already known blocks while processing chain segment"; + "block_root" => ?block_root); + continue; + } Err(error) => { return ChainSegmentResult::Failed { imported_blocks, @@ -3032,7 +3038,7 @@ impl BeaconChain { match import_block.await { // The block was successfully verified and imported. Yay. Ok(status @ AvailabilityProcessingStatus::Imported(block_root)) => { - trace!( + debug!( self.log, "Beacon block imported"; "block_root" => ?block_root, @@ -3045,7 +3051,7 @@ impl BeaconChain { Ok(status) } Ok(status @ AvailabilityProcessingStatus::MissingComponents(slot, block_root)) => { - trace!( + debug!( self.log, "Beacon block awaiting blobs"; "block_root" => ?block_root, diff --git a/beacon_node/beacon_chain/src/block_verification_types.rs b/beacon_node/beacon_chain/src/block_verification_types.rs index edba7a211..d35c40297 100644 --- a/beacon_node/beacon_chain/src/block_verification_types.rs +++ b/beacon_node/beacon_chain/src/block_verification_types.rs @@ -7,6 +7,7 @@ use crate::{get_block_root, GossipVerifiedBlock, PayloadVerificationOutcome}; use derivative::Derivative; use ssz_types::VariableList; use state_processing::ConsensusContext; +use std::fmt::{Debug, Formatter}; use std::sync::Arc; use types::blob_sidecar::{BlobIdentifier, BlobSidecarError, FixedBlobSidecarList}; use types::{ @@ -27,13 +28,19 @@ use types::{ /// Note: We make a distinction over blocks received over gossip because /// in a post-deneb world, the blobs corresponding to a given block that are received /// over rpc do not contain the proposer signature for dos resistance. -#[derive(Debug, Clone, Derivative)] +#[derive(Clone, Derivative)] #[derivative(Hash(bound = "E: EthSpec"))] pub struct RpcBlock { block_root: Hash256, block: RpcBlockInner, } +impl Debug for RpcBlock { + fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { + write!(f, "RpcBlock({:?})", self.block_root) + } +} + impl RpcBlock { pub fn block_root(&self) -> Hash256 { self.block_root diff --git a/beacon_node/beacon_chain/src/data_availability_checker.rs b/beacon_node/beacon_chain/src/data_availability_checker.rs index a578c484e..7d8af48c7 100644 --- a/beacon_node/beacon_chain/src/data_availability_checker.rs +++ b/beacon_node/beacon_chain/src/data_availability_checker.rs @@ -110,8 +110,6 @@ impl DataAvailabilityChecker { self.processing_cache.read().get(&block_root).cloned() } - /// A `None` indicates blobs are not required. - /// /// If there's no block, all possible ids will be returned that don't exist in the given blobs. /// If there no blobs, all possible ids will be returned. pub fn get_missing_blob_ids>( diff --git a/beacon_node/network/src/network_beacon_processor/sync_methods.rs b/beacon_node/network/src/network_beacon_processor/sync_methods.rs index 35b65540e..887974c6e 100644 --- a/beacon_node/network/src/network_beacon_processor/sync_methods.rs +++ b/beacon_node/network/src/network_beacon_processor/sync_methods.rs @@ -117,6 +117,7 @@ impl NetworkBeaconProcessor { "Gossip block is being processed"; "action" => "sending rpc block to reprocessing queue", "block_root" => %block_root, + "process_type" => ?process_type, ); // Send message to work reprocess queue to retry the block @@ -149,6 +150,7 @@ impl NetworkBeaconProcessor { "proposer" => block.message().proposer_index(), "slot" => block.slot(), "commitments" => commitments_formatted, + "process_type" => ?process_type, ); let result = self @@ -418,7 +420,11 @@ impl NetworkBeaconProcessor { } } (imported_blocks, Ok(_)) => { - debug!(self.log, "Parent lookup processed successfully"); + debug!( + self.log, "Parent lookup processed successfully"; + "chain_hash" => %chain_head, + "imported_blocks" => imported_blocks + ); BatchProcessResult::Success { was_non_empty: imported_blocks > 0, } diff --git a/beacon_node/network/src/sync/block_lookups/common.rs b/beacon_node/network/src/sync/block_lookups/common.rs index d989fbb33..cad187ad7 100644 --- a/beacon_node/network/src/sync/block_lookups/common.rs +++ b/beacon_node/network/src/sync/block_lookups/common.rs @@ -380,7 +380,7 @@ impl RequestState for BlobRequestState BlockLookups { if let Some(components) = child_components { lookup.add_child_components(components); } + debug!(self.log, "Already searching for block"; "block_root" => ?block_root); return; } @@ -162,6 +163,7 @@ impl BlockLookups { // If the block was already downloaded, or is being downloaded in this moment, do not // request it. + debug!(self.log, "Already searching for block in a parent lookup request"; "block_root" => ?block_root); return; } @@ -171,6 +173,7 @@ impl BlockLookups { .any(|(hashes, _last_parent_request)| hashes.contains(&block_root)) { // we are already processing this block, ignore it. + debug!(self.log, "Already processing block in a parent request"; "block_root" => ?block_root); return; } @@ -221,15 +224,23 @@ impl BlockLookups { }) { parent_lookup.add_peer(peer_id); // we are already searching for this block, ignore it + debug!(self.log, "Already searching for parent block"; + "block_root" => ?block_root, "parent_root" => ?parent_root); return; } if self .processing_parent_lookups - .values() - .any(|(hashes, _peers)| hashes.contains(&block_root) || hashes.contains(&parent_root)) + .iter() + .any(|(chain_hash, (hashes, _peers))| { + chain_hash == &block_root + || hashes.contains(&block_root) + || hashes.contains(&parent_root) + }) { // we are already processing this block, ignore it. + debug!(self.log, "Already processing parent block"; + "block_root" => ?block_root, "parent_root" => ?parent_root); return; } let parent_lookup = ParentLookup::new( @@ -298,6 +309,12 @@ impl BlockLookups { }; let expected_block_root = lookup.block_root(); + debug!(self.log, + "Peer returned block for single lookup"; + "peer_id" => %peer_id , + "id" => ?id, + "block_root" => ?expected_block_root, + ); match self.single_lookup_response_inner::(peer_id, response, seen_timestamp, cx, lookup) { @@ -478,6 +495,13 @@ impl BlockLookups { return; }; + debug!(self.log, + "Peer returned block for parent lookup"; + "peer_id" => %peer_id , + "id" => ?id, + "block_root" => ?parent_lookup.current_parent_request.block_request_state.requested_block_root, + ); + match self.parent_lookup_response_inner::( peer_id, response, @@ -540,7 +564,7 @@ impl BlockLookups { | ParentVerifyError::NoBlockReturned | ParentVerifyError::NotEnoughBlobsReturned | ParentVerifyError::ExtraBlocksReturned - | ParentVerifyError::UnrequestedBlobId + | ParentVerifyError::UnrequestedBlobId(_) | ParentVerifyError::ExtraBlobsReturned | ParentVerifyError::InvalidIndex(_) => { let e = e.into(); @@ -728,6 +752,8 @@ impl BlockLookups { "Block component processed for lookup"; "response_type" => ?R::response_type(), "block_root" => ?root, + "result" => ?result, + "id" => target_id, ); match result { @@ -901,7 +927,7 @@ impl BlockLookups { debug!(self.log, "Parent block processing succeeded"; &parent_lookup, "block_root" => ?block_root) } AvailabilityProcessingStatus::MissingComponents(_, block_root) => { - debug!(self.log, "Parent missing parts, triggering single block lookup "; &parent_lookup,"block_root" => ?block_root) + debug!(self.log, "Parent missing parts, triggering single block lookup"; &parent_lookup,"block_root" => ?block_root) } }, BlockProcessingResult::Err(e) => { @@ -1223,7 +1249,7 @@ impl BlockLookups { ) -> Result<(), LookupRequestError> { match cx.beacon_processor_if_enabled() { Some(beacon_processor) => { - trace!(self.log, "Sending block for processing"; "block" => ?block_root, "process" => ?process_type); + debug!(self.log, "Sending block for processing"; "block" => ?block_root, "process" => ?process_type); if let Err(e) = beacon_processor.send_rpc_beacon_block( block_root, block, diff --git a/beacon_node/network/src/sync/block_lookups/parent_lookup.rs b/beacon_node/network/src/sync/block_lookups/parent_lookup.rs index 5c2e90b48..1901925cf 100644 --- a/beacon_node/network/src/sync/block_lookups/parent_lookup.rs +++ b/beacon_node/network/src/sync/block_lookups/parent_lookup.rs @@ -12,6 +12,7 @@ use std::collections::VecDeque; use std::sync::Arc; use store::Hash256; use strum::IntoStaticStr; +use types::blob_sidecar::BlobIdentifier; /// How many attempts we try to find a parent of a block before we give up trying. pub(crate) const PARENT_FAIL_TOLERANCE: u8 = 5; @@ -36,7 +37,7 @@ pub enum ParentVerifyError { NoBlockReturned, NotEnoughBlobsReturned, ExtraBlocksReturned, - UnrequestedBlobId, + UnrequestedBlobId(BlobIdentifier), ExtraBlobsReturned, InvalidIndex(u64), PreviousFailure { parent_root: Hash256 }, @@ -242,7 +243,7 @@ impl From for ParentVerifyError { E::RootMismatch => ParentVerifyError::RootMismatch, E::NoBlockReturned => ParentVerifyError::NoBlockReturned, E::ExtraBlocksReturned => ParentVerifyError::ExtraBlocksReturned, - E::UnrequestedBlobId => ParentVerifyError::UnrequestedBlobId, + E::UnrequestedBlobId(blob_id) => ParentVerifyError::UnrequestedBlobId(blob_id), E::ExtraBlobsReturned => ParentVerifyError::ExtraBlobsReturned, E::InvalidIndex(index) => ParentVerifyError::InvalidIndex(index), E::NotEnoughBlobsReturned => ParentVerifyError::NotEnoughBlobsReturned, diff --git a/beacon_node/network/src/sync/block_lookups/single_block_lookup.rs b/beacon_node/network/src/sync/block_lookups/single_block_lookup.rs index c4d912993..d393c6a8f 100644 --- a/beacon_node/network/src/sync/block_lookups/single_block_lookup.rs +++ b/beacon_node/network/src/sync/block_lookups/single_block_lookup.rs @@ -16,7 +16,7 @@ use std::marker::PhantomData; use std::sync::Arc; use store::Hash256; use strum::IntoStaticStr; -use types::blob_sidecar::FixedBlobSidecarList; +use types::blob_sidecar::{BlobIdentifier, FixedBlobSidecarList}; use types::EthSpec; #[derive(Debug, PartialEq, Eq)] @@ -31,7 +31,7 @@ pub enum LookupVerifyError { RootMismatch, NoBlockReturned, ExtraBlocksReturned, - UnrequestedBlobId, + UnrequestedBlobId(BlobIdentifier), ExtraBlobsReturned, NotEnoughBlobsReturned, InvalidIndex(u64), @@ -257,7 +257,9 @@ impl SingleBlockLookup { /// of which blobs still need to be requested. Returns `true` if there are no more blobs to /// request. pub(crate) fn blobs_already_downloaded(&mut self) -> bool { - self.update_blobs_request(); + if matches!(self.blob_request_state.state.state, State::AwaitingDownload) { + self.update_blobs_request(); + } self.blob_request_state.requested_ids.is_empty() } diff --git a/beacon_node/network/src/sync/block_lookups/tests.rs b/beacon_node/network/src/sync/block_lookups/tests.rs index b364d9a05..414b4886f 100644 --- a/beacon_node/network/src/sync/block_lookups/tests.rs +++ b/beacon_node/network/src/sync/block_lookups/tests.rs @@ -1803,6 +1803,7 @@ mod deneb_only { .expect_blobs_request() .expect_no_block_request(); } + #[test] fn too_few_blobs_response_then_block_response_attestation() { let Some(tester) = DenebTester::new(RequestTrigger::AttestationUnknownBlock) else {