fix/chain_head: Ensure correct events for finalized branch

[lexnv]

Issue paritytech/polkadot-sdk#48 has detected a few flaky tests coming form the chainHead.

Error

The error encountered (extracted from here):

--- STDERR:              sc-rpc-spec-v2 chain_head::tests::follow_forks_pruned_block ---
thread 'chain_head::tests::follow_forks_pruned_block' panicked at 'assertion failed: `(left == right)`
  left: `Finalized(Finalized { finalized_block_hashes: ["0x0af997b079e96b7f333bf2fe71cb914ad3eb49355923fd3db96c0cc91243bd7a"], pruned_block_hashes: [] })`,
 right: `BestBlockChanged(BestBlockChanged { best_block_hash: "0x0af997b079e96b7f333bf2fe71cb914ad3eb49355923fd3db96c0cc91243bd7a" })

Investigation

The issue happens on the following code path:

• the finalized event is triggered before the new_block event

• finalized branch is responsible for generating NewBlock + BestBlock event
  

  substrate/client/rpc-spec-v2/src/chain_head/chain_head_follow.rs

  Lines 335 to 341 in 12c3235

  	/// Generates new block events from the given finalized hashes.
  	///
  	/// It may be possible that the `Finalized` event fired before the `NewBlock`
  	/// event. In that case, for each finalized hash that was not reported yet
  	/// generate the `NewBlock` event. For the final finalized hash we must also
  	/// generate one `BestBlock` event.
  	fn generate_finalized_events(

• the best_block_cache is set, however the intent was just to verify if we have encountered a gap in
  

  substrate/client/rpc-spec-v2/src/chain_head/chain_head_follow.rs

  Lines 394 to 404 in 0506da0

  	self.best_block_cache = Some(*hash);
  	},
  	// This is the first best block event that we generate.
  	None => {
  	self.best_block_cache = Some(*hash);
  	},
  	};
  	// This is the first time we see this block. Generate the `NewBlock` event; if this is
  	// the last block, also generate the `BestBlock` event.
  	events.extend(self.generate_import_events(*hash, *parent, true))

• the generate_import_events() checks if the best block was already encountered to not regenerate the event.
  

  substrate/client/rpc-spec-v2/src/chain_head/chain_head_follow.rs

  Lines 295 to 297 in 0506da0

  	if block_cache != block_hash {
  	self.best_block_cache = Some(block_hash);
  	vec![new_block, best_block_event]

Fix

Remove populating the best_block_cache on the finalized branch to allow generate_import_events() to properly generate the BestBlock event for the latest finalized hash.

Testing Done

• ran cargo test in a loop with stress-ng --cpu 6 --io 4 for 239 times on my machine. Although it gives us some confidence, I've only encountered the Finalized event arriving before NewBlock just a few times in a more intensive test while introducing the code.

Notes

• Renable chainHead tests if Ignore flaky test #13631 is merged first

// CC @paritytech/tools-team

[bkchr]

I don't get this piece of code? How do you know that there wasn't any new best block event for the last finalized block?

And why do you have this as part of of the for loop while it doesn't depend on any from the loop?

[lexnv]

Hey

How do you know that there wasn't any new best block event for the last finalized block?

We depend on the pin_block which returns true if this is the first time we "pin" the block and false if the block was previously pinned. We call pin_block twice for each block: from the import and finalized branches.

substrate/client/rpc-spec-v2/src/chain_head/chain_head_follow.rs

Lines 364 to 369 in df6a438

	for (hash, parent) in finalized_block_hashes.iter().zip(parents) {
	// This block is already reported by the import notification.
	if !self.sub_handle.pin_block(*hash)? {
	continue
	}

And why do you have this as part of of the for loop while it doesn't depend on any from the loop?

For any blocks that we have not seen yet we want to generate the NewBlock, except for the last block for which we want to generate the NewBlock + BestBlock events. For the last block, I've added the extra check to make sure we catch the following case:

[Block 0] -  [Block 1] - [Block 2] -  ...
                          ^^^ T0: Block import branch reports block 2 for the first time 

^^^^^^^^^^^^^^^ T1:  Finalized branch reports 0 and 1 for the first time

We could enter this path only if the BlockImport notification is not generated for 0, 1; but somehow we receive the BlockImport for block 2. And at the same time we get Finalized for 0 and 1 (blocks that we have not been reported by BlockImport).

This check may be an overcautious one, let me know what you think of it, thanks!

[bkchr]

For me the flow was a little bit hard to follow. I pushed a commit that improves the flow and adds some more docs. I hope that is okay.

[skunert]

super nit: This sounds like the block hash is absent, but its more HeaderNotFound or something.

[lexnv]

That makes sense! I've changed it to BlockHeaderAbsent to make it explicit that we are missing the header from the db, thanks!