Besu stalled when syncing on Kintsugi

[luisnaranjo733]

Description

As an Ethereum user, I want to sync Besu on Kintsugi to the tip of the chain so that I can help test the merge

Acceptance Criteria

• Besu should finish syncing to the latest block height, when running against the parameters in the Kintsugi testnet guide

Steps to Reproduce (Bug)

1. Download source and compile Besu with Java 11 against the c6eddef39fabdf2cf5ea98cf0b8d98402c5b9147 commit in the "merge" branch (listed below)
2. Run Besu with the parameters listed in the Kintsugi testnet guide (linked earlier). I also set the --miner-coinbase flag to the zero address because of this bug
3. Detailed instructions can be found here https://luisnaranjo733.hashnode.dev/want-to-help-test-the-merge-run-a-node-on-kintsugi where I'm trying to help people run the Besu/Teku combo

[Unit]
Description=Ethereum Besu execution client
After=network.target
Before=network.target

[Service]
User=besu
Group=besu
Type=simple
Restart=always
RestartSec=5
Environment="JAVA_OPTS=-Xmx4g"
ExecStart=/usr/local/bin/besu/bin/besu \
    --data-path="<path to your besu data dir>" \
    --genesis-file="/home/<username>/merge-testnets/kintsugi/besu_genesis.json" \
    --rpc-http-enabled \
    --rpc-http-api=ADMIN,MINER,ETH,NET,DEBUG,TXPOOL,EXECUTION \
    --network-id=1337702 \
    --p2p-enabled=true \
    --Xmerge-support=true \
    --bootnodes=enode://6f377dd1ef5a3272d7e02fac9064c4f95d74f7edfd866e59ded774ee5b4649ff61c3f24c95f5c3d07d692b447f0569716b8921b6861810b96a705c92e1d27ff9@161.35.67.219:30303 \
    --miner-coinbase=0x0000000000000000000000000000000000000000

[Install]
WantedBy=multi-user.target

Expected behavior: Besu should finish syncing at some point, and the block height should match the block height in the Kintsugi block explorer.

Actual behavior: Besu thinks it is done syncing, but the block height it reports over HTTP RPC is pretty far behind the actual tip

According to the Besu RPC server, the node thinks it is done syncing and the block height is much lower than what it should be.
I assume 0x2824E is the hexadecimal block height (which is 164,430 in b10). Meanwhile, the actual blockheight is in the 242k range

Detailed logs at the bottom of this issue

Frequency: [What percentage of the time does it occur?]
This happened 2/2 for me. After the first time, I deleted my VM and started over, same result the 2nd time

Versions (Add all that apply)

• Software version: [besu --version]
  besu/v22.1.0-RC2-dev-c6eddef3/linux-x86_64/openjdk-java-11

• Java version: [java -version]
  openjdk version "11.0.13" 2021-10-19
  OpenJDK Runtime Environment (build 11.0.13+8-Ubuntu-0ubuntu1.20.04)
  OpenJDK 64-Bit Server VM (build 11.0.13+8-Ubuntu-0ubuntu1.20.04, mixed mode, sharing)

• OS Name & Version: [cat /etc/*release]

DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=20.04
DISTRIB_CODENAME=focal
DISTRIB_DESCRIPTION="Ubuntu 20.04.3 LTS"
NAME="Ubuntu"
VERSION="20.04.3 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.3 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal

• Kernel Version: [uname -a]

Linux kintsugi-vm 5.11.0-1025-azure #27~20.04.1-Ubuntu SMP Fri Jan 7 15:02:06 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

• Virtual Machine software & version: [vmware -v] N/A
• Docker Version: [docker version] N/A
• Cloud VM, type, size: Azure B2ms VM with an attached standard performance 2TB data disk mounted at /datadrive

Additional Information

More logs

luis@kintsugi2-vm:~$ curl -X POST --data '{"jsonrpc":"2.0","id":"1","method":"eth_getBlockByNumber","params":["latest", false]}' http://127.0.0.1:8545
{
  "jsonrpc" : "2.0",
  "id" : "1",
  "result" : {
    "number" : "0x2824e",
    "hash" : "0xfd8fffee65e42337d898e66dedec2a7efa64d9492bc3795866aae011babc6774",
    "mixHash" : "0xe5837db486edc3fcf475c41896c9d0595ccb396fc217dd9a9ddbb9062ff8c02b",
    "parentHash" : "0x03a39a04193ab75319d2a4ac4a8159bb591662d4769ea21ea37d761a2c43dac6",
    "nonce" : "0x0000000000000000",
    "sha3Uncles" : "0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347",
    "logsBloom" : "0x00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000",
    "transactionsRoot" : "0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421",
    "stateRoot" : "0x8f561281dee794f98a5094e29522650f950296702419a351f5389ee10e9d0d4d",
    "receiptsRoot" : "0x56e81f171bcc55a6ff8345e692c0f86e5b48e01b996cadc001622fb5e363b421",
    "miner" : "0x0000000000000000000000000000000000000001",
    "difficulty" : "0x0",
    "totalDifficulty" : "0x12a0eee4a",
    "extraData" : "0x",
    "baseFeePerGas" : "0x7",
    "size" : "0x200",
    "gasLimit" : "0x9e25fc",
    "gasUsed" : "0x0",
    "timestamp" : "0x61e27a74",
    "uncles" : [ ],
    "transactions" : [ ]
  }
}
luis@kintsugi2-vm:~$curl -X POST --data '{"jsonrpc":"2.0","id":"1","method":"eth_blockNumber","params":[]}' http://127.0.0.1:8545
{
  "jsonrpc" : "2.0",
  "id" : "1",
  "result" : "0x2824e"
}

luis@kintsugi2-vm:~$ curl -X POST --data '{"jsonrpc":"2.0","id":"1","method":"eth_syncing","params":[]}' http://127.0.0.1:8545
{
  "jsonrpc" : "2.0",
  "id" : "1",
  "result" : false
}

luis@kintsugi2-vm:~$sudo journalctl -fu besu.service
-- Logs begin at Mon 2022-01-24 02:27:43 UTC. --
Jan 25 20:11:08 kintsugi2-vm besu[11962]: 2022-01-25 20:11:08.414+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0x14e4fd0011ce54b8969d7669441aaa8ea033889197bc3d46aedda2874a6ce0eb, finalized: 0x14e4fd0011ce54b8969d7669441aaa8ea033889197bc3d46aedda2874a6ce0eb
Jan 25 20:11:08 kintsugi2-vm besu[11962]: 2022-01-25 20:11:08.567+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0x188646c4370e43452702cd859802e7ded87afe0a189459b5dc25ccc4ed380774, finalized: 0x188646c4370e43452702cd859802e7ded87afe0a189459b5dc25ccc4ed380774
Jan 25 20:11:08 kintsugi2-vm besu[11962]: 2022-01-25 20:11:08.654+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0x912d98edd1ac5e909e564baf0064d92d952155b58071d432450e12f58ff75120, finalized: 0x912d98edd1ac5e909e564baf0064d92d952155b58071d432450e12f58ff75120
Jan 25 20:11:08 kintsugi2-vm besu[11962]: 2022-01-25 20:11:08.801+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0x314667feb777bc237742d4141170b7f177e3751cbf89d74f0a87e4450c078e82, finalized: 0x314667feb777bc237742d4141170b7f177e3751cbf89d74f0a87e4450c078e82
Jan 25 20:11:08 kintsugi2-vm besu[11962]: 2022-01-25 20:11:08.877+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0x87b932b081e7cd758d71bbe51506a7e491298527ecf949fce3e716fe101506b1, finalized: 0x87b932b081e7cd758d71bbe51506a7e491298527ecf949fce3e716fe101506b1
Jan 25 20:11:09 kintsugi2-vm besu[11962]: 2022-01-25 20:11:09.018+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0xe4eaa7026cf177d86195899df92341f2c78a05a1c93af897a3e856f470e46a46, finalized: 0xe4eaa7026cf177d86195899df92341f2c78a05a1c93af897a3e856f470e46a46
Jan 25 20:11:09 kintsugi2-vm besu[11962]: 2022-01-25 20:11:09.065+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0xf2668ecdca17787ec6ca5c7210232a90d782c2612d79ec6a66f56719ff362b13, finalized: 0xf2668ecdca17787ec6ca5c7210232a90d782c2612d79ec6a66f56719ff362b13
Jan 25 20:11:09 kintsugi2-vm besu[11962]: 2022-01-25 20:11:09.110+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0x6bcef1c0eb301addf3d1748dc04120a09934a57d16a020f0390a8aa82e5e74dc, finalized: 0x6bcef1c0eb301addf3d1748dc04120a09934a57d16a020f0390a8aa82e5e74dc
Jan 25 20:11:09 kintsugi2-vm besu[11962]: 2022-01-25 20:11:09.151+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0x03a39a04193ab75319d2a4ac4a8159bb591662d4769ea21ea37d761a2c43dac6, finalized: 0x03a39a04193ab75319d2a4ac4a8159bb591662d4769ea21ea37d761a2c43dac6
Jan 25 20:11:09 kintsugi2-vm besu[11962]: 2022-01-25 20:11:09.193+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | Consensus fork-choice-update: head: 0xfd8fffee65e42337d898e66dedec2a7efa64d9492bc3795866aae011babc6774, finalized: 0xfd8fffee65e42337d898e66dedec2a7efa64d9492bc3795866aae011babc6774

luis@kintsugi2-vm:~$ sudo journalctl -fu teku.service
-- Logs begin at Mon 2022-01-24 02:27:43 UTC. --
Jan 26 15:05:52 kintsugi2-vm teku[12159]: 2022-01-26 15:05:52.101 INFO  - Slot Event  *** Slot: 295804, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 74
Jan 26 15:06:04 kintsugi2-vm teku[12159]: 2022-01-26 15:06:04.100 INFO  - Slot Event  *** Slot: 295805, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 73
Jan 26 15:06:16 kintsugi2-vm teku[12159]: 2022-01-26 15:06:16.101 INFO  - Slot Event  *** Slot: 295806, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 73
Jan 26 15:06:28 kintsugi2-vm teku[12159]: 2022-01-26 15:06:28.100 INFO  - Slot Event  *** Slot: 295807, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 74
Jan 26 15:06:28 kintsugi2-vm teku[12159]: 2022-01-26 15:06:28.626 WARN  - Ignoring calculated payload attributes since it violates ordering
Jan 26 15:06:36 kintsugi2-vm teku[12159]: 2022-01-26 15:06:36.100 INFO  - Epoch Event *** Epoch: 9244, Justified checkpoint: 6698, Finalized checkpoint: 6697, Finalized root: a253d50c06db0eae41abbde3b4e53bc4f7ce9447f71a2b13923829f9bf3dd519
Jan 26 15:06:40 kintsugi2-vm teku[12159]: 2022-01-26 15:06:40.101 INFO  - Slot Event  *** Slot: 295808, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 74
Jan 26 15:06:52 kintsugi2-vm teku[12159]: 2022-01-26 15:06:52.101 INFO  - Slot Event  *** Slot: 295809, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 74
Jan 26 15:07:04 kintsugi2-vm teku[12159]: 2022-01-26 15:07:04.102 INFO  - Slot Event  *** Slot: 295810, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 74
Jan 26 15:07:16 kintsugi2-vm teku[12159]: 2022-01-26 15:07:16.101 INFO  - Slot Event  *** Slot: 295811, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 73
Jan 26 15:07:28 kintsugi2-vm teku[12159]: 2022-01-26 15:07:28.101 INFO  - Slot Event  *** Slot: 295812, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 73
Jan 26 15:07:40 kintsugi2-vm teku[12159]: 2022-01-26 15:07:40.101 INFO  - Slot Event  *** Slot: 295813, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 74
Jan 26 15:07:52 kintsugi2-vm teku[12159]: 2022-01-26 15:07:52.100 INFO  - Slot Event  *** Slot: 295814, Block:    ... empty, Justified: 6698, Finalized: 6697, Peers: 74