more robust sidechain block import logic

[brenzi]

closes #1544

• sort queue by sidechain block number
• group blocks with same number and sort them by hash (deterministic ordering less likely to produce forks - compared to "prefer self-authored block")
• attempt to import in order and ignore failures, just try next candidate

the goal here is: even if a fork happens, each fork should continue producing blocks. Only then can finality be established on L1 and orphans can reliably be identified

[brenzi]

does the trick. can't prevent forks, but will continue:

SCV1:

[Sidechain] propose block 594418 summary: executed 0 failed 0 from 0 in queue in 681ms
[2023-12-27T17:21:57.000854Z TRACE its_consensus_common::block_import_queue_worker] processing import queue with Ok(1) sidechain blocks
[2023-12-27T17:21:57.000956Z TRACE its_consensus_common::block_import_queue_worker] nr of competitors for block 594418: 1
[2023-12-27T17:21:57.001100Z TRACE its_consensus_common::peer_block_sync] attempt to import block 594418 with hash 0x2d7c280613ed69b12285dd323e7f65d56bc543f3ad3e0e336bf001150b376bef and author 
[2023-12-27T17:21:57.001245Z DEBUG its_consensus_common::block_import] Attempting to import sidechain block (number: 594418, hash: 0x2d7c280613ed69b12285dd323e7f65d56bc543f3ad3e0e336bf001150b376bef, parentchain hash: 0xd0eb130918c568ce6e42222b518d10418d3be62d78fad5f4ed7ced4ac226c3e1)
[2023-12-27T17:21:57.058455Z INFO  its_consensus_common::block_import] Applying state diff for block 594418 of size 219 bytes
[2023-12-27T17:21:57.072238Z INFO  its_consensus_common::block_import] Applying state update from block 594418 took 13 ms
[2023-12-27T17:21:57.072497Z INFO  its_consensus_common::block_import] Importing block 594418 took 71 ms
[Sidechain] imported block (number: 594418, tcalls: 0, author: 0xa26ad684039c978b68957f3f42ac0d9dadd6ba5b132d30c9b14b87eea0677fa8), based on parentchain block 3757181
[2023-12-27T17:21:57.072621Z DEBUG its_consensus_common::block_import_queue_worker] Imported 1 blocks in 71 ms (average of 71 ms per block)
[2023-12-27T17:21:57.283Z WARN  its_storage::storage] Could not find starting block in storage, returning empty vector
[2023-12-27T17:21:58.000986Z TRACE its_consensus_common::block_import_queue_worker] processing import queue with Ok(1) sidechain blocks
[2023-12-27T17:21:58.001097Z TRACE its_consensus_common::block_import_queue_worker] nr of competitors for block 594363: 1
[2023-12-27T17:21:58.001289Z TRACE its_consensus_common::peer_block_sync] attempt to import block 594363 with hash 0xe5b531549980571b8aaed86f3da8d6ad62c8fe49e9e147b96219ce38f5763c93 and author 
[2023-12-27T17:21:58.001471Z DEBUG its_consensus_common::block_import] Attempting to import sidechain block (number: 594363, hash: 0xe5b531549980571b8aaed86f3da8d6ad62c8fe49e9e147b96219ce38f5763c93, parentchain hash: 0xd0eb130918c568ce6e42222b518d10418d3be62d78fad5f4ed7ced4ac226c3e1)
[2023-12-27T17:21:58.042191Z WARN  its_consensus_common::peer_block_sync] Sidechain block from queue (number: 594363) was already imported (current block number: 594418). Block will be ignored.
[2023-12-27T17:21:58.042335Z DEBUG its_consensus_common::block_import_queue_worker] Imported 1 blocks in 41 ms (average of 41 ms per block)
[Sidechain] propose block 594419 summary: executed 0 failed 0 from 0 in queue in 670ms
[2023-12-27T17:21:59.001098Z TRACE its_consensus_common::block_import_queue_worker] processing import queue with Ok(1) sidechain blocks
[2023-12-27T17:21:59.001208Z TRACE its_consensus_common::block_import_queue_worker] nr of competitors for block 594419: 1
[2023-12-27T17:21:59.001372Z TRACE its_consensus_common::peer_block_sync] attempt to import block 594419 with hash 0xfc225ad29eb39b24455967ccfa7a65f85053c6590db86009add2f08f235a186a and author 
[2023-12-27T17:21:59.001529Z DEBUG its_consensus_common::block_import] Attempting to import sidechain block (number: 594419, hash: 0xfc225ad29eb39b24455967ccfa7a65f85053c6590db86009add2f08f235a186a, parentchain hash: 0xd0eb130918c568ce6e42222b518d10418d3be62d78fad5f4ed7ced4ac226c3e1)
[2023-12-27T17:21:59.071994Z INFO  its_consensus_common::block_import] Applying state diff for block 594419 of size 219 bytes
[2023-12-27T17:21:59.086141Z INFO  its_consensus_common::block_import] Applying state update from block 594419 took 14 ms
[2023-12-27T17:21:59.086421Z INFO  its_consensus_common::block_import] Importing block 594419 took 84 ms
[Sidechain] imported block (number: 594419, tcalls: 0, author: 0xa26ad684039c978b68957f3f42ac0d9dadd6ba5b132d30c9b14b87eea0677fa8), based on parentchain block 3757181

SCV2:

[Sidechain] imported block (number: 594362, tcalls: 0, author: 0x97048505b0502de1340da1615d52ca063c57948cc30631b4e2af60f5ede9949c), based on parentchain block 3757181
[2023-12-27T17:21:56.075081Z DEBUG its_consensus_common::block_import_queue_worker] Imported 1 blocks in 73 ms (average of 73 ms per block)
[2023-12-27T17:21:57.000493Z TRACE its_consensus_common::block_import_queue_worker] processing import queue with Ok(1) sidechain blocks
[2023-12-27T17:21:57.000591Z TRACE its_consensus_common::block_import_queue_worker] nr of competitors for block 594418: 1
[2023-12-27T17:21:57.000733Z TRACE its_consensus_common::peer_block_sync] attempt to import block 594418 with hash 0x2d7c280613ed69b12285dd323e7f65d56bc543f3ad3e0e336bf001150b376bef and author 
[2023-12-27T17:21:57.000860Z DEBUG its_consensus_common::block_import] Attempting to import sidechain block (number: 594418, hash: 0x2d7c280613ed69b12285dd323e7f65d56bc543f3ad3e0e336bf001150b376bef, parentchain hash: 0xd0eb130918c568ce6e42222b518d10418d3be62d78fad5f4ed7ced4ac226c3e1)
[2023-12-27T17:21:57.069088Z WARN  its_consensus_common::peer_block_sync] Got ancestry mismatch error upon block import. Attempting to fetch missing blocks from peer
[2023-12-27T17:21:57.069166Z INFO  its_consensus_common::peer_block_sync] Initiating fetch blocks from peer, last imported block hash: 0xe0864b76e28454affe1569d685815e88c77a283f3c9f34f92371015301ec9a30, until block hash: 0x2d7c280613ed69b12285dd323e7f65d56bc543f3ad3e0e336bf001150b376bef
[2023-12-27T17:21:57.287035Z INFO  its_consensus_common::peer_block_sync] Fetched 0 blocks from peer to import
[2023-12-27T17:21:57.287251Z DEBUG its_consensus_common::block_import] Attempting to import sidechain block (number: 594418, hash: 0x2d7c280613ed69b12285dd323e7f65d56bc543f3ad3e0e336bf001150b376bef, parentchain hash: 0xd0eb130918c568ce6e42222b518d10418d3be62d78fad5f4ed7ced4ac226c3e1)
[2023-12-27T17:21:57.359654Z DEBUG its_consensus_common::block_import_queue_worker] Imported 0 blocks in 359 ms (average of inf ms per block)
[Sidechain] propose block 594363 summary: executed 0 failed 0 from 0 in queue in 448ms
[2023-12-27T17:21:58.000726Z TRACE its_consensus_common::block_import_queue_worker] processing import queue with Ok(1) sidechain blocks
[2023-12-27T17:21:58.000826Z TRACE its_consensus_common::block_import_queue_worker] nr of competitors for block 594363: 1
[2023-12-27T17:21:58.000957Z TRACE its_consensus_common::peer_block_sync] attempt to import block 594363 with hash 0xe5b531549980571b8aaed86f3da8d6ad62c8fe49e9e147b96219ce38f5763c93 and author 
[2023-12-27T17:21:58.001129Z DEBUG its_consensus_common::block_import] Attempting to import sidechain block (number: 594363, hash: 0xe5b531549980571b8aaed86f3da8d6ad62c8fe49e9e147b96219ce38f5763c93, parentchain hash: 0xd0eb130918c568ce6e42222b518d10418d3be62d78fad5f4ed7ced4ac226c3e1)
[2023-12-27T17:21:58.074606Z INFO  its_consensus_common::block_import] Applying state diff for block 594363 of size 219 bytes
[2023-12-27T17:21:58.078293Z INFO  its_consensus_common::block_import] Applying state update from block 594363 took 3 ms
[2023-12-27T17:21:58.078381Z INFO  its_consensus_common::block_import] Importing block 594363 took 77 ms
[Sidechain] imported block (number: 594363, tcalls: 0, author: 0x97048505b0502de1340da1615d52ca063c57948cc30631b4e2af60f5ede9949c), based on parentchain block 3757181
[2023-12-27T17:21:58.078422Z DEBUG its_consensus_common::block_import_queue_worker] Imported 1 blocks in 77 ms (average of 77 ms per block)
[2023-12-27T17:21:59.000944Z TRACE its_consensus_common::block_import_queue_worker] processing import queue with Ok(1) sidechain blocks
[2023-12-27T17:21:59.001074Z TRACE its_consensus_common::block_import_queue_worker] nr of competitors for block 594419: 1
[2023-12-27T17:21:59.001225Z TRACE its_consensus_common::peer_block_sync] attempt to import block 594419 with hash 0xfc225ad29eb39b24455967ccfa7a65f85053c6590db86009add2f08f235a186a and author 
[2023-12-27T17:21:59.001366Z DEBUG its_consensus_common::block_import] Attempting to import sidechain block (number: 594419, hash: 0xfc225ad29eb39b24455967ccfa7a65f85053c6590db86009add2f08f235a186a, parentchain hash: 0xd0eb130918c568ce6e42222b518d10418d3be62d78fad5f4ed7ced4ac226c3e1)
[2023-12-27T17:21:59.070074Z WARN  its_consensus_common::peer_block_sync] Got ancestry mismatch error upon block import. Attempting to fetch missing blocks from peer
[2023-12-27T17:21:59.070103Z INFO  its_consensus_common::peer_block_sync] Initiating fetch blocks from peer, last imported block hash: 0xe5b531549980571b8aaed86f3da8d6ad62c8fe49e9e147b96219ce38f5763c93, until block hash: 0xfc225ad29eb39b24455967ccfa7a65f85053c6590db86009add2f08f235a186a
[2023-12-27T17:21:59.359928Z DEBUG its_consensus_common::block_import_queue_worker] Imported 0 blocks in 358 ms (average of inf ms per block)
[Sidechain] propose block 594364 summary: executed 0 failed 0 from 0 in queue in 447ms2-27T17:21:59.359928Z DEBUG its_consensus_common::block_import_queue_worker] Imported 0 blocks in 358 ms (average of inf ms per block)
[Sidechain] propose block 594364 summary: executed 0 failed 0 from 0 in queue in 447ms

[brenzi]

sidechain-rococo-1-0-0.12.9-dev3-4-bench.log
sidechain-rococo-2-0-0.12.9-dev3-4-bench.log

good logs!.
The fork happened because of this:
Could not peek parentchain block, returning latest parentchain block (Other("Failed to find parentchain header in import queue (hash: 0x2535…684b) that is associated with the current sidechain block that is to be imported (number: 594319, hash: 0x562c…28d9)"))

[brenzi]

in the end, exposing this was not necessary....

[clangenb]

I have some optional rust-feedback, but looks good to me otherwise. :)