silkworm: invalid block encountered during execution

[canepat]

Restarting standalone Silkworm at commit20ec45ad1a3e550afbbe05a63a5cc350d8374bbd after fixing #2349, an invalid block error pops up while doing the initial cleanup forward cycle:

...
  INFO [09-12|07:00:54.787 UTC] Total reopened bundles: 68 snapshots: 204 indexes: 272 max block available: 20'461'999
  INFO [09-12|07:00:54.787 UTC] SnapshotSync: database Senders stage progress updated [20'461'999]
  INFO [09-12|07:00:54.787 UTC] Revalidate canonical chain up to number=20'726'754 hash=3b79e0b2446357490a79240d017133396dd96e503c070dfcabe6ef57a2f58070
  INFO [09-12|07:00:54.787 UTC] sentry                                   Sentry received initial status message
  INFO [09-12|07:00:54.787 UTC] ExecutionPipeline                        Forward start
  INFO [09-12|07:00:54.787 UTC] [4/12 Senders]                           op=Forward from=20461999 to=20726754 span=264755 max_batch_size=139810 
...
  INFO [09-12|07:03:16.171 UTC] [4/12 Senders]                           op=Forward done=2m 21s 
  INFO [09-12|07:03:16.171 UTC] [5/12 Execution]                         op=Forward from=20460999 to=20726754 span=265755 
...
  INFO [09-12|07:42:46.177 UTC] [5/12 Execution]                         block=20581339 blocks/s=65 txns/s=9784 Mgas/s=992 
  INFO [09-12|07:42:48.147 UTC] sync::SentryClient                       Peer 8df34663c567f2dd0d8923b5e08459b243d17d80 connected, active 72, info: client_id=Nethermind/v1.28.0+9c4816c2/linux-x64/dotnet8.0.8 / enode_url=enode://8df34663c567f2dd0d8923b5e08459b243d17d80f66ecc5b0ba56947131ee32e2c526282ad64c7f8ab32b6ddd38a155b849600dd09e0c4b15f28578e83913e84@91.187.65.237:30404
  INFO [09-12|07:42:48.546 UTC] Flushed state                            size=24.03 MB in=1.225s 
  WARN [09-12|07:42:48.561 UTC] [5/12 Execution]                         block=20581423 hash=0x3214e0f942973e0f0b863d8fe571aaaa25018b1fafbe6b0ce36a7ac7e2077bd5 error=kInsufficientFunds 
 ERROR [09-12|07:42:48.566 UTC] [5/12 Execution]                         function=forward exception=kInvalidBlock 
 ERROR [09-12|07:42:48.566 UTC] [5/12 Execution]                         op=Forward returned=kInvalidBlock 
 ERROR [09-12|07:42:48.566 UTC] ExecPipeline                             Forward interrupted due to stage Execution failure
  INFO [09-12|07:42:48.566 UTC] MainChain::collect_bad_headers bad_count=145'332 skip=1
  INFO [09-12|07:42:48.566 UTC] ExecutionPipeline                        Unwind start
  INFO [09-12|07:42:48.566 UTC] [9/12 Senders]                           op=Unwind from=20726754 to=20581422 span=145332 
  INFO [09-12|07:42:49.608 UTC] sync::SentryClient                       Peer f50ad13decd40b434b1173f414143a88974718b3 disconnected, active 71, info: -info-not-found-
  INFO [09-12|07:42:49.656 UTC] sync::SentryClient                       Peer dd9f2b398c4c27658d6e0fa24903b526f7cd4d39 disconnected, active 70, info: -info-not-found-
  INFO [09-12|07:42:52.127 UTC] sync::SentryClient                       Peer 66abe0dd0a35cac43ab8b6affab328b02f555d88 connected, active 71, info: client_id=Nethermind/v1.27.1+d2d5d4ae/linux-x64/dotnet8.0.7 / enode_url=enode://66abe0dd0a35cac43ab8b6affab328b02f555d884ba3c2c50374baf6b7603bcc6cd09a8ec1161bad26e77b96dee864bc990e0de0a0889ea6ff6f8533faf96f92@108.217.32.157:30303
  INFO [09-12|07:42:54.861 UTC] [9/12 Senders]                           op=Unwind done=6.295s 
  INFO [09-12|07:42:54.861 UTC] [10/12 Bodies]                           op=Unwind from=20726754 to=20581422 span=145332 
  INFO [09-12|07:42:54.861 UTC] [11/12 BlockHashes]                      op=Unwind from=20726754 to=20581422 span=145332 
  INFO [09-12|07:42:54.862 UTC] [12/12 Headers]                          op=Unwind from=20726754 to=20581422 span=145332 
  INFO [09-12|07:42:54.862 UTC] ExecutionPipeline                        Unwind done
  INFO [09-12|07:42:54.943 UTC] PoSSync: Waiting for blocks... from=20'726'754
...

Block hash 0x3214e0f942973e0f0b863d8fe571aaaa25018b1fafbe6b0ce36a7ac7e2077bd5 written in the log in incorrect for block 20581423, see here.

This is the result looking at the content of Silkworm database:

db_toolbox --datadir /Volumes/Extreme\ SSD/Library/silkworm/silkworm blocks --from 20581423 --to 20581423

Block number=20581423

Header:
hash=c49d87a766d3a4b4360ca01ced7abeb8d32ddd2f0f683fae0ab789668b6faa0e
parent_hash=76c534d7553bd89d1821b3081919da3c1dae7fc94eaab7b28f350363b5d5b8e8
number=20581423
beneficiary=0x4838b106fce9647bdf1e7877bf73ce8b0bad5f97
ommers_hash=1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347
state_root=e9fa0092dbc26f5f2db5f484666b00b9ca78d6817c5bdf2a9f2d9889b64c7767
transactions_root=315be5aa1349b772e1785970997ee0e82f4b40d0db31d7db68f0f48af6ec4e2c
receipts_root=cd7326be2ab94f939aed138bcb5facc11ced6b82a549814615e068c85144597d
withdrawals_root=1c9b657c1d535d9ea9bdc5e540448f03170d8aa1338bd6a405fe9085b7565390
beneficiary=0x4838b106fce9647bdf1e7877bf73ce8b0bad5f97
timestamp=1724296811
nonce=0000000000000000
prev_randao=4b1b72f24c7c8ea12598f466bd399ba11f7130b40f9da0fcb28a287c630c4cc5
base_fee_per_gas=1005576881
difficulty=0
gas_limit=30000000
gas_used=15285707
blob_gas_used=524288
excess_blob_gas=786432
logs_bloom=88a377a223b44b16f2709354e0835690bb90c1859f7a20e9101f49107e5498f7a7874f66b8ad62083a00391ac7b25325aea1df188b01aac313b9f5c5b56e21907c274198128b2c29ef16c3aae450b2a5901c9cb3406d0f4d34005f809d6ac210984555340263e3b5aab952d00ea10cd54c09e47d99b4263c13082156241e125ae2ab535a376560dca04bb16926a283913293b1b9d7dd96a8f329d142e89296a42380c5871ba034504cd6d4e08fc16d0c86c7048f8a0e88e383ef4828ce298278dd422942f0516b134104491610eda8773c3b0a439d296cb5694d701a32bee3228df125e0a0026e6e080d91e60d21ad864501d510497ca0c297959a31b846f44e
extra_data=546974616e2028746974616e6275696c6465722e78797a29
rlp=f90263a076c534d7553bd89d1821b3081919da3c1dae7fc94eaab7b28f350363b5d5b8e8a01dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347944838b106fce9647bdf1e7877bf73ce8b0bad5f97a0e9fa0092dbc26f5f2db5f484666b00b9ca78d6817c5bdf2a9f2d9889b64c7767a0315be5aa1349b772e1785970997ee0e82f4b40d0db31d7db68f0f48af6ec4e2ca0cd7326be2ab94f939aed138bcb5facc11ced6b82a549814615e068c85144597db9010088a377a223b44b16f2709354e0835690bb90c1859f7a20e9101f49107e5498f7a7874f66b8ad62083a00391ac7b25325aea1df188b01aac313b9f5c5b56e21907c274198128b2c29ef16c3aae450b2a5901c9cb3406d0f4d34005f809d6ac210984555340263e3b5aab952d00ea10cd54c09e47d99b4263c13082156241e125ae2ab535a376560dca04bb16926a283913293b1b9d7dd96a8f329d142e89296a42380c5871ba034504cd6d4e08fc16d0c86c7048f8a0e88e383ef4828ce298278dd422942f0516b134104491610eda8773c3b0a439d296cb5694d701a32bee3228df125e0a0026e6e080d91e60d21ad864501d510497ca0c297959a31b846f44e8084013a0c2f8401c9c38083e93dcb8466c6ae6b98546974616e2028746974616e6275696c6465722e78797a29a04b1b72f24c7c8ea12598f466bd399ba11f7130b40f9da0fcb28a287c630c4cc5880000000000000000843befe2b1a01c9b657c1d535d9ea9bdc5e540448f03170d8aa1338bd6a405fe9085b756539083080000830c0000a099c29c23660f02a7df8db4038df2f835b50ad9219ecb7fa421ec2bfc33b3420f

Body:
base_txn_id=2523978385
txn_count=142
#ommers=0
#withdrawals=16
rlp=f9024b849670da91818ec0f90240e3840361d5db83056a7894b9d7934878b5fb9610b3fe8a5e441e8fad7e293f840122676ce3840361d5dc83056a7994b9d7934878b5fb9610b3fe8a5e441e8fad7e293f840121f913e3840361d5dd83056a7a94b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401231b70e3840361d5de83056a7b94b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8403de5313e3840361d5df83056a7c94b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401224c53e3840361d5e083056a7d94b9d7934878b5fb9610b3fe8a5e441e8fad7e293f840122c303e3840361d5e183056a8094b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401228dc3e3840361d5e283056a8194b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401222bc9e3840361d5e383056a8294b9d7934878b5fb9610b3fe8a5e441e8fad7e293f840122fbc7e3840361d5e483056a8394b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401228832e3840361d5e583056a8494b9d7934878b5fb9610b3fe8a5e441e8fad7e293f840122fad5e3840361d5e683056a8594b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401221a34e3840361d5e783056a8694b9d7934878b5fb9610b3fe8a5e441e8fad7e293f840121fcd4e3840361d5e883056a8794b9d7934878b5fb9610b3fe8a5e441e8fad7e293f84012092e8e3840361d5e983056a8894b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401228045e3840361d5ea83056a8994b9d7934878b5fb9610b3fe8a5e441e8fad7e293f8401229600

Block hash c49d87a766d3a4b4360ca01ced7abeb8d32ddd2f0f683fae0ab789668b6faa0e present in the db is correct for block 20581423.

sw_invalid_block.log

[canepat]

The root cause of this problem turned out to be an invalid set of block snapshots appeared on erigon-snapshot: notably, some body segment files contained misaligned data wrt the related transaction segment files.

Fixed by #2414