Too many Searching for block components

[dapplion]

TLDR: Not actively harmful, just wasted CPU cycles while block and blobs are in the da_checker and we keep getting attestations

• Introduced in Handle sync lookup request streams in network context #5583

17,901 hits on ho-h-bn-suit during 1 hour after 2024 May 2, @ 18:26:30.000 all of them for block 0xf26fcf6a6985185172b27782fda904a25c83a637e7268f0fd878fb9b55e12b7e

May 02 09:26:38.901 DEBG Received unknown block hash message     block_root: 0xf26f…2b7e, service: sync
May 02 09:26:38.902 DEBG Dropping completed lookup               block: 0xf26f…2b7e, service: sync
May 02 09:26:38.902 DEBG Searching for block components          block: 0xf26fcf6a6985185172b27782fda904a25c83a637e7268f0fd878fb9b55e12b7e, peer_ids: [PeerId("16Uiu2HAmUyPcQeJ123zf7RzhqxRd9Berjj9m7x4bNecmQMj2sUQ1")], service: sync

The condition to complete the lookup early is hit and it is dropped immediately. Then another unknown block event is processed and repeat

Block and blobs received in time, all 6 blobs. However, execution verification was very slow 4.7 sec.

May 02 09:26:37.701 DEBG Successfully verified gossip blob       commitment: 0xb1ce…5bab, index: 0, root: 0xf26f…2b7e, slot: 1561633
May 02 09:26:37.939 INFO New block received                      root: 0xf26fcf6a6985185172b27782fda904a25c83a637e7268f0fd878fb9b55e12b7e, slot: 1561633
May 02 09:26:42.980 DEBG Delayed head block                      set_as_head_time_ms: 32, imported_time_ms: 289, attestable_delay_ms: 6779, available_delay_ms: 6658, execution_time_ms: 4726, blob_delay_ms: 1838, observed_delay_ms: 1931, total_delay_ms: 6979, slot: 1561633, proposer_index: 788787, block_root: 0xf26fcf6a6985185172b27782fda904a25c83a637e7268f0fd878fb9b55e12b7e, service: beacon
May 02 09:26:42.948 DEBG Beacon block imported                   block_slot: 1561633, block_root: 0xf26fcf6a6985185172b27782fda904a25c83a637e7268f0fd878fb9b55e12b7e, service: beacon

While the block + blobs are in the da_checker we get lots of attestations referencing the block. For each attestation we create and drop a lookup.

May 02 09:26:38.902 DEBG Searching for block components          block: 0xf26fcf6a6985185172b27782fda904a25c83a637e7268f0fd878fb9b55e12b7e, peer_ids: [PeerId("16Uiu2HAmUyPcQeJ123zf7RzhqxRd9Berjj9m7x4bNecmQMj2sUQ1")], service: sync
May 02 09:26:42.661 DEBG Searching for block components          block: 0xf26fcf6a6985185172b27782fda904a25c83a637e7268f0fd878fb9b55e12b7e, peer_ids: [PeerId("16Uiu2HAmVt2q6mBeuPHstXtSH6minp1brK5BprKq7LTF4xCCsHeV")], service: sync

[realbigsean]

I'm confused where this log is coming from:
May 02 09:26:38.901 DEBG Received unknown block hash message block_root: 0xf26f…2b7e, service: sync

suit would have been on a version where I deleted it at that time. It was so spammy it was causing us to drop logs:
https://github.com/sigp/lighthouse/pull/5672/files

Either way I don't think that changes the analysis

[dapplion]

Fixed with

• Notify lookup sync of gossip processing results #5722