besu failure on mnsf7

• TTD was at 2022-06-22 18:34:49 block 15008990
• Everyone receives these future blocks right before TTD. Once TTD passes, and the validation rules change, they are rejected correctly:
  • 2022-06-22 18:34:49.921+00:00 | EthScheduler-Workers-0 | ERROR | MainnetBlockValidator | Invalid block header. Block 15008991 (0x92427994bc89929f6e29ea39d03f794f82e7bddbb06fb899165537936ee3f8cb)
  • 2022-06-22 18:34:49.924+00:00 | EthScheduler-Workers-0 | ERROR | MainnetBlockValidator | Invalid block header. Block 15008991 (0xa24efa66fa4995a32a82eb7216b8b6ab30564ffdbacefc107e99eae84fe8ec4a)

Version was:

hyperledger/besu 22.7.RC1-SNAPSHOT-openjdk-11-debug 3cae566a8e63 38 hours ago

And they had been up for 26 hours.

So far nothing more than some normal behavior we could maybe make look better in the logs. Then I started checking the proposals coming from besu, and they are empty. All the CLs connected to besus are proposing empty blocks. They should be full moments after TTD on mainnet, plenty of txs to use.

About 90 minutes after TTD, I noticed that finalization times were really unstable. about 15 minutes after that, we just stopped finalizing. Thats when the panic set in, and I started checking every besu node in the mnsf7 group. Timestamps and hashes for each failure are below.

I also tried bouncing both the besu and teku on besu-teku2 just for fun, I did not expect anything to happen since besu is now halted on the block it thinks is bad.

Somehow, the network managed to finalize again later in the evening around 9:34 UTC. Finalization times were still unstable for a couple of epochs, and then stopped again.

at 10:55 UTC I tried bouncing just the teku again to see if it was related to the phantom recurrence of finalization. It had no impact on the network, as expected.

And now for the failures:

• teku-besu-1 hit a state mismatch, 30 seconds before ttd.
  • 2022-06-22 18:34:34.924+00:00 | EthScheduler-Workers-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x6122b995f47395484e2264d215864f4728542f08d9837fc0c4289ea3ef0712ba calculated 0x5f2bb3902f8208bd2a0116fa8763f0d74aece3d40de248083442ad39093a6c5e
  • teku went into a "exec client offline" loop right after that happened
• teku-besu-2 had one after ttd:
  • 2022-06-22 18:42:58.043+00:00 | ForkJoinPool.commonPool-worker-9 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x9b40ce14987be95b3a4018862056abce1c15e306cae9ea32971033c523e6e600 calculated 0xa6df7331b13113af261a6a43eb02c73dc9c72f398177ce7c24ad77e8e13d1991
• prysm-besu-2 had one after ttd:
  • 2022-06-22 19:46:01.046+00:00 | ForkJoinPool.commonPool-worker-3 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x058cd8f1e90f2c18fddfe5de7f87f5cebf249fac09702cc395362ac69ded32b3 calculated 0x73335fc1aac0c0d70bbd955d3157502d371793e0452657355c89c82f7c4f742e
• prysm-besu-1 had one after ttd:
  • 2022-06-22 19:20:27.340+00:00 | vert.x-worker-thread-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x01ca82e223c0815a06802d45b0516e6b7aa8a7b716332eaa45987da5d84df02a calculated 0xe533f8357bdc895db0195c28f9d26c8ba6166a4992818bfd01cad08e1a3d35e3
• nimbus-besu-1 had one after ttd:
  • 2022-06-22 18:43:50.489+00:00 | vert.x-worker-thread-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x575ff2bf927c7e33bbddf44ec4a9ca4a08a2ce59053ad76a26bf6827c143c385 calculated 0x35950b3a2a8db81a67d2efaf89bc02b08146adacaf77966e1505f972f0fdd826
• nimbus-besu-2 had one after ttd:
  • 2022-06-22 18:41:04.965+00:00 | vert.x-worker-thread-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x5d6720f1b5547bdf0d800475f0540c7469cb986fc988fc266a238ef53159e814 calculated 0x41402697fc6db8a1a450ba53465a9cb290be9f50f38c2ba5d26200360fe9e925
• lighthouse-besu-1 had one after ttd:
  • 2022-06-22 19:02:36.368+00:00 | vert.x-worker-thread-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0xc8c5744e4a6ba3528499cffb8930d11c9067aeebdd86f658c9088cc2d1c4c5de calculated 0x4f547c26d0847a0582d7eddedc47618a118d430f2b55a43faa5e13baf1ef480f
• lighthouse-besu-2 had one after ttd:
  • 2022-06-22 18:46:20.287+00:00 | vert.x-worker-thread-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x3021355815ddfc98b2023441803e3256806fdb4fe96b50e34a2a7be522789b83 calculated 0x2f9d4afe955b122fa37e4e897619519f29ff6c0a960c29546ea6e1e85b045274
• lodestar-besu-1 had one after ttd:
  • 2022-06-22 18:42:51.913+00:00 | vert.x-worker-thread-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x9b40ce14987be95b3a4018862056abce1c15e306cae9ea32971033c523e6e600 calculated 0x37e8b0d2dea7dcbd9eeaccccc059fa3abfcf2e9a554cf2e7f6eeb145de77a5c5
• lodestar-besu-2 had one after ttd:
  • 2022-06-22 18:37:24.315+00:00 | vert.x-worker-thread-0 | ERROR | AbstractBlockProcessor | failed persisting block
  • java.lang.RuntimeException: World State Root does not match expected value, header 0x72c2bd8d7c14cc028a79873e1d6b51f9d61e7203f0c9b0f1fa27056f87664d5a calculated 0x13f05b97098bb82ef937e55b680f82ee6b57e59c6b74df4af3a1b36ff78129ae

1. teku-besu-1 deserves some sort of prize for crapping out 15 seconds before ttd was hit.
2. prysms held out the longest.