Not giving any feedback not syncing, data-storage-format=BONSAI, sync-mode=X_SNAP

[AntoBrajkovic]

Description

Switching over from infura, prysm to besu and teku. Besu has locked my computer up twice although the bigger issue is what I brought up in the tittle not giving any feedback seeming not to sync since the database file is not getting bigger. Tried native and docker instances of besu have had the same issue of no progress. I might be missing something obvious

Steps to Reproduce (Bug)

1. it should be as simple as running the docker command with a mounted directory and network set to host, example:
   sudo docker run --network="host" --user 1000:1000 --mount type=bind,source=/media/otna/besu/besuDatabase/,target=/var/lib/besu hyperledger/besu:latest --data-path=/var/lib/besu --data-storage-format=BONSAI --sync-mode=X_SNAP --engine-jwt-secret=/var/lib/besu/token.txt

Expected behavior: Besu to sync up with the EL

Actual behavior: Besu does nothing and sometimes freezes my machine

Frequency: Every time

Versions (Add all that apply)

• Software version: hyperledger/besu:latest, v22.7.2
• Java version: hyperledger/besu:latest
• OS Name & Version: kubuntu
• Kernel Version: Linux ethValidator 5.15.0-47-generic 51-Ubuntu SMP Thu Aug 11 07:51:15 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
• Docker Version:
  Client:
  Version: 20.10.12
  API version: 1.41
  Go version: go1.17.3
  Git commit: 20.10.12-0ubuntu4
  Built: Mon Mar 7 17:10:06 2022
  OS/Arch: linux/amd64
  Context: default
  Experimental: true

Server:
Engine:
Version: 20.10.12
API version: 1.41 (minimum version 1.12)
Go version: go1.17.3
Git commit: 20.10.12-0ubuntu4
Built: Mon Mar 7 15:57:50 2022
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.5.9-0ubuntu3
GitCommit:
runc:
Version: 1.1.0-0ubuntu1
GitCommit:
docker-init:
Version: 0.19.0
GitCommit:

• System info - 48GB DDR4, I9-9900KF, KINGSTON 2TB NVME main boot drive for OS and teku and another 2TB NVME KINGSTON for besu database

log:

otna@ethValidator:~$ sudo docker run --network="host" --user 1000:1000 --mount type=bind,source=/media/otna/besu/besuDatabase/,target=/var/lib/besu hyperledger/besu:latest --data-path=/var/lib/besu --data-storage-format=BONSAI --sync-mode=X_SNAP --engine-jwt-secret=/var/lib/besu/token.txt
2022-09-16 20:43:15.444+00:00 | main | INFO | Besu | Using LibEthPairings native alt bn128
2022-09-16 20:43:15.446+00:00 | main | INFO | Besu | Using the native implementation of the signature algorithm
2022-09-16 20:43:15.449+00:00 | main | INFO | Besu | Starting Besu version: besu/v22.7.2/linux-x86_64/openjdk-java-11
2022-09-16 20:43:15.685+00:00 | main | WARN | Besu | --rpc-http-host has been ignored because --rpc-http-enabled was not defined on the command line.
2022-09-16 20:43:15.688+00:00 | main | WARN | Besu | --rpc-http-host has been ignored because --rpc-http-enabled was not defined on the command line.
2022-09-16 20:43:15.689+00:00 | main | WARN | Besu | --graphql-http-host has been ignored because --graphql-http-enabled was not defined on the command line.
2022-09-16 20:43:15.690+00:00 | main | WARN | Besu | --rpc-ws-host has been ignored because --rpc-ws-enabled was not defined on the command line.
2022-09-16 20:43:15.691+00:00 | main | INFO | Besu | Static Nodes file = /var/lib/besu/static-nodes.json
2022-09-16 20:43:15.691+00:00 | main | INFO | StaticNodesParser | StaticNodes file /var/lib/besu/static-nodes.json does not exist, no static connections will be created.
2022-09-16 20:43:15.691+00:00 | main | INFO | Besu | Connecting to 0 static nodes.
2022-09-16 20:43:15.693+00:00 | main | INFO | Besu | Security Module: localfile
2022-09-16 20:43:15.703+00:00 | main | INFO | DatabaseMetadata | Lookup database metadata file in data directory: /var/lib/besu
2022-09-16 20:43:15.737+00:00 | main | INFO | RocksDBKeyValueStorageFactory | Existing database detected at /var/lib/besu. Version 2
2022-09-16 20:43:16.053+00:00 | main | INFO | KeyPairUtil | Loaded public key 0xb3383903f17699d47e54fe97c0449bbe94f1f5408bf6e821a2cb3fe46a183d1ff45189ea9885e8c49d31b31fc9a764eef809803b71488886dd999bb67fd5d6e9 from /var/lib/besu/key
2022-09-16 20:43:16.141+00:00 | main | INFO | ProtocolScheduleBuilder | Protocol schedule created with milestones: [Frontier: 0, Homestead: 1150000, DaoRecoveryInit: 1920000, DaoRecoveryTransition: 1920001, Homestead: 1920010, TangerineWhistle: 2463000, SpuriousDragon: 2675000, Byzantium: 4370000, Petersburg: 7280000, Istanbul: 9069000, MuirGlacier: 9200000, Berlin: 12244000, London: 12965000, ArrowGlacier: 13773000, GrayGlacier: 15050000]
2022-09-16 20:43:16.156+00:00 | main | INFO | ProtocolScheduleBuilder | Protocol schedule created with milestones: [Frontier: 0, Homestead: 1150000, DaoRecoveryInit: 1920000, DaoRecoveryTransition: 1920001, Homestead: 1920010, TangerineWhistle: 2463000, SpuriousDragon: 2675000, Byzantium: 4370000, Petersburg: 7280000, Istanbul: 9069000, MuirGlacier: 9200000, Berlin: 12244000, London: 12965000, ArrowGlacier: 13773000, GrayGlacier: 15050000]
2022-09-16 20:43:16.669+00:00 | main | INFO | EthPeers | Updating the default best peer comparator
2022-09-16 20:43:16.679+00:00 | main | INFO | BesuControllerBuilder | TTD difficulty is present, creating initial sync phase with transition to PoS support
2022-09-16 20:43:16.773+00:00 | main | INFO | TransitionBesuControllerBuilder | TTD present, creating DefaultSynchronizer that stops propagating after finalization
2022-09-16 20:43:16.806+00:00 | main | INFO | RunnerBuilder | Detecting NAT service.
2022-09-16 20:43:16.921+00:00 | main | INFO | Runner | Starting external services ...
2022-09-16 20:43:16.923+00:00 | main | INFO | JsonRpcService | Starting JSON-RPC service on 0.0.0.0:8551
2022-09-16 20:43:16.995+00:00 | vert.x-eventloop-thread-1 | INFO | JsonRpcService | JSON-RPC service started and listening on 0.0.0.0:8551
2022-09-16 20:43:16.998+00:00 | main | INFO | AutoTransactionLogBloomCachingService | Starting auto transaction log bloom caching service.
2022-09-16 20:43:16.998+00:00 | main | INFO | LogBloomCacheMetadata | Lookup cache metadata file in data directory: /var/lib/besu/caches
2022-09-16 20:43:17.002+00:00 | main | INFO | Runner | Starting Ethereum main loop ...
2022-09-16 20:43:17.003+00:00 | main | INFO | NatService | No NAT environment detected so no service could be started
2022-09-16 20:43:17.003+00:00 | main | INFO | NetworkRunner | Starting Network.
2022-09-16 20:43:17.004+00:00 | main | INFO | DefaultP2PNetwork | Starting DNS discovery with URL enrtree://AKA3AM6LPBYEUDMVNU3BSVQJ5AD45Y7YPOHJLEF6W26QOE4VTUDPE@all.mainnet.ethdisco.net
2022-09-16 20:43:17.039+00:00 | nioEventLoopGroup-2-1 | INFO | RlpxAgent | P2P RLPx agent started and listening on /0:0:0:0:0:0:0:0:30303.
2022-09-16 20:43:17.040+00:00 | main | INFO | PeerDiscoveryAgent | Starting peer discovery agent on host=0.0.0.0, port=30303
2022-09-16 20:43:17.065+00:00 | vert.x-eventloop-thread-1 | INFO | VertxPeerDiscoveryAgent | Started peer discovery agent successfully, on effective host=0:0:0:0:0:0:0:0%0 and port=30303
2022-09-16 20:43:17.066+00:00 | vert.x-eventloop-thread-1 | INFO | PeerDiscoveryAgent | P2P peer discovery agent started and listening on /0:0:0:0:0:0:0:0%0:30303
2022-09-16 20:43:17.107+00:00 | vert.x-eventloop-thread-1 | INFO | PeerDiscoveryAgent | Writing node record to disk. NodeRecord{seq=7, publicKey=0x03b3383903f17699d47e54fe97c0449bbe94f1f5408bf6e821a2cb3fe46a183d1f, udpAddress=Optional[/127.0.0.1:30303], tcpAddress=Optional[/127.0.0.1:30303], asBase64=-Jq4QE1xe_IA6FF73O99sZsUfSl2DjL9ivP2ggv1HoLdZ3kaSEXVD0MKRJn7iE-kwwmH8U2zEaxukru-EOoSIExP_dQHg2V0aMrJhPxk7ASDEYwwgmlkgnY0gmlwhH8AAAGJc2VjcDI1NmsxoQOzODkD8XaZ1H5U_pfARJu-lPH1QIv26CGiyz_kahg9H4N0Y3CCdl-DdWRwgnZf, nodeId=0x2f5615cd34423b0d1711859103da5f7cc926708cae0e711ea24fb4c81c3eeb0c, customFields={tcp=30303, udp=30303, ip=0x7f000001, eth=[[0xfc64ec04, 0x118c30]], id=V4, secp256k1=0x03b3383903f17699d47e54fe97c0449bbe94f1f5408bf6e821a2cb3fe46a183d1f}}
2022-09-16 20:43:17.140+00:00 | main | INFO | DefaultP2PNetwork | Enode URL enode://b3383903f17699d47e54fe97c0449bbe94f1f5408bf6e821a2cb3fe46a183d1ff45189ea9885e8c49d31b31fc9a764eef809803b71488886dd999bb67fd5d6e9@127.0.0.1:30303
2022-09-16 20:43:17.141+00:00 | main | INFO | DefaultP2PNetwork | Node address 0x03da5f7cc926708cae0e711ea24fb4c81c3eeb0c
2022-09-16 20:43:17.142+00:00 | main | INFO | DefaultSynchronizer | Starting synchronizer.
2022-09-16 20:43:17.143+00:00 | main | INFO | SnapSyncDownloader | Starting sync.
2022-09-16 20:43:17.145+00:00 | main | INFO | WaitForPeersTask | Waiting for 5 total peers to connect. 0 peers currently connected.
2022-09-16 20:43:17.147+00:00 | main | INFO | Runner | Ethereum main loop is up.
2022-09-16 20:43:17.897+00:00 | Timer-0 | INFO | DNSResolver | Resolved 2409 nodes
2022-09-16 20:43:27.553+00:00 | EthScheduler-Timer-0 | INFO | WaitForPeersTask | Waiting for 5 total peers to connect. 4 peers currently connected.
2022-09-16 20:43:52.706+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 2 / 5 required peers currently available.
2022-09-16 20:43:57.708+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:02.709+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:07.710+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:12.711+00:00 | EthScheduler-Timer-0 | INFO | WaitForPeersTask | Waiting for 5 total peers to connect. 4 peers currently connected.
2022-09-16 20:44:17.316+00:00 | nioEventLoopGroup-3-3 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:22.316+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:27.318+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:32.319+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:37.321+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:42.322+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:47.323+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:44:52.323+00:00 | EthScheduler-Timer-0 | INFO | WaitForPeersTask | Waiting for 5 total peers to connect. 4 peers currently connected.
2022-09-16 20:45:00.584+00:00 | nioEventLoopGroup-3-10 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:05.584+00:00 | EthScheduler-Timer-0 | INFO | WaitForPeersTask | Waiting for 5 total peers to connect. 4 peers currently connected.
2022-09-16 20:45:16.951+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 20:45:17.788+00:00 | nioEventLoopGroup-3-4 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:22.789+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:27.791+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:32.792+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:37.793+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:42.795+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:47.796+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:52.797+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:45:57.799+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:46:02.800+00:00 | EthScheduler-Timer-0 | INFO | FastSyncActions | Waiting for valid peers with chain height information. 4 / 5 required peers currently available.
2022-09-16 20:47:17.051+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 20:49:17.151+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 20:51:17.210+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 20:53:17.310+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 20:55:17.411+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 20:57:17.511+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 20:59:17.611+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 21:01:17.630+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 21:03:17.727+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 21:05:17.770+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 21:07:17.871+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 21:09:17.971+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected
2022-09-16 21:11:18.072+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected

[howardrcc]

I'm having a similar issue. The funny thing is... I have another machine where it is running perfectly.

When I try to create a 2nd node, nothing happens (no blocks get imported). Even with a fresh clean database. The Target Chain Height information does get updated, and peers are connected. Local Chain Height is not increasing, keeps sitting at 0.

In your logs I'm seeing : enode://b3383903f17699d47e54fe97c0449bbe94f1f5408bf6e821a2cb3fe46a183d1ff45189ea9885e8c49d31b31fc9a764eef809803b71488886dd999bb67fd5d6e9@127.0.0.1:30303)

maybe p2phost has to be set to your external / 0.0.0.0 IP?

[daniellehrner]

There seems to be a problem with the connection to Teku:

2022-09-16 21:11:18.072+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected

This log message means that Teku is not calling Besu's API endpoints. Post merge Besu needs Teku to sync. It cannot do it without it. What are the Teku logs saying? Do you see any error?

[ibhagwan]

I'm having the same issue starting a fresh sync on Goerli, deleted the database and started from scratch and the sync just stops at block 0x441031, both attempts stop at the exact same block, JSON RPC response from eth_syncing:

{
  "jsonrpc" : "2.0",
  "id" : 1,
  "result" : {
    "startingBlock" : "0x441031",
    "currentBlock" : "0x441031",
    "highestBlock" : "0x7428a8"
  }
}

Besu log just stays like this forever:

2022-09-17 17:26:31.423-07:00 | main | INFO  | Besu | Using LibEthPairings native alt bn128
2022-09-17 17:26:31.432-07:00 | main | INFO  | Besu | Using the native implementation of the signature algorithm
2022-09-17 17:26:31.450-07:00 | main | INFO  | Besu | Starting Besu version: besu/v22.7.2/linux-x86_64/openjdk-java-17
2022-09-17 17:26:32.291-07:00 | main | INFO  | Besu | Static Nodes file = /var/lib/besu/goerli/static-nodes.json
2022-09-17 17:26:32.293-07:00 | main | INFO  | StaticNodesParser | StaticNodes file /var/lib/besu/goerli/static-nodes.json does not exist, no static connections will be created.
2022-09-17 17:26:32.294-07:00 | main | INFO  | Besu | Connecting to 0 static nodes.
2022-09-17 17:26:32.301-07:00 | main | INFO  | Besu | Security Module: localfile
2022-09-17 17:26:32.343-07:00 | main | INFO  | DatabaseMetadata | Lookup database metadata file in data directory: /var/lib/besu/goerli
2022-09-17 17:26:32.459-07:00 | main | INFO  | RocksDBKeyValueStorageFactory | Existing database detected at /var/lib/besu/goerli. Version 2
2022-09-17 17:26:35.946-07:00 | main | INFO  | KeyPairUtil | Loaded public key <pubkey> from /var/lib/besu/goerli/key
2022-09-17 17:26:36.320-07:00 | main | INFO  | ProtocolScheduleBuilder | Protocol schedule created with milestones: [Petersburg: 0, Istanbul: 1561651, Berlin: 4460644, London: 5062605]
2022-09-17 17:26:36.378-07:00 | main | INFO  | ProtocolScheduleBuilder | Protocol schedule created with milestones: [Petersburg: 0, Istanbul: 1561651, Berlin: 4460644, London: 5062605]
2022-09-17 17:26:36.755-07:00 | main | INFO  | EthPeers | Updating the default best peer comparator
2022-09-17 17:26:36.792-07:00 | main | INFO  | BesuControllerBuilder | TTD difficulty is present, creating initial sync phase with transition to PoS support
2022-09-17 17:26:37.390-07:00 | main | INFO  | TransitionBesuControllerBuilder | TTD present, creating DefaultSynchronizer that stops propagating after finalization
2022-09-17 17:26:37.447-07:00 | main | INFO  | RunnerBuilder | Detecting NAT service.
2022-09-17 17:26:37.945-07:00 | main | INFO  | Runner | Starting external services ...
2022-09-17 17:26:37.947-07:00 | main | INFO  | MetricsHttpService | Starting metrics http service on 0.0.0.0:9545
2022-09-17 17:26:38.097-07:00 | vert.x-eventloop-thread-1 | INFO  | MetricsHttpService | Metrics service started and listening on 0.0.0.0:9545
2022-09-17 17:26:38.098-07:00 | main | INFO  | JsonRpcHttpService | Starting JSON-RPC service on 0.0.0.0:8545
2022-09-17 17:26:38.129-07:00 | vert.x-eventloop-thread-1 | INFO  | JsonRpcHttpService | JSON-RPC service started and listening on 0.0.0.0:8545
2022-09-17 17:26:38.130-07:00 | main | INFO  | JsonRpcService | Starting JSON-RPC service on 0.0.0.0:8551
2022-09-17 17:26:38.148-07:00 | vert.x-eventloop-thread-1 | INFO  | JsonRpcService | JSON-RPC service started and listening on 0.0.0.0:8551
2022-09-17 17:26:38.157-07:00 | main | INFO  | WebSocketService | Starting Websocket service on 0.0.0.0:8546
2022-09-17 17:26:38.165-07:00 | vert.x-eventloop-thread-1 | INFO  | WebSocketService | Websocket service started and listening on 0.0.0.0:8546
2022-09-17 17:26:38.175-07:00 | main | INFO  | AutoTransactionLogBloomCachingService | Starting auto transaction log bloom caching service.
2022-09-17 17:26:38.177-07:00 | main | INFO  | LogBloomCacheMetadata | Lookup cache metadata file in data directory: /var/lib/besu/goerli/caches
2022-09-17 17:26:38.195-07:00 | main | INFO  | Runner | Starting Ethereum main loop ...
2022-09-17 17:26:38.195-07:00 | main | INFO  | NatService | No NAT environment detected so no service could be started
2022-09-17 17:26:38.196-07:00 | main | INFO  | NetworkRunner | Starting Network.
2022-09-17 17:26:38.201-07:00 | main | INFO  | DefaultP2PNetwork | Starting DNS discovery with URL enrtree://AKA3AM6LPBYEUDMVNU3BSVQJ5AD45Y7YPOHJLEF6W26QOE4VTUDPE@all.goerli.ethdisco.net
2022-09-17 17:26:38.333-07:00 | nioEventLoopGroup-2-1 | INFO  | RlpxAgent | P2P RLPx agent started and listening on /[0:0:0:0:0:0:0:0]:30303.
2022-09-17 17:26:38.334-07:00 | main | INFO  | PeerDiscoveryAgent | Starting peer discovery agent on host=0.0.0.0, port=30303
2022-09-17 17:26:38.408-07:00 | vert.x-eventloop-thread-1 | INFO  | VertxPeerDiscoveryAgent | Started peer discovery agent successfully, on effective host=0:0:0:0:0:0:0:0%0 and port=30303
2022-09-17 17:26:38.411-07:00 | vert.x-eventloop-thread-1 | INFO  | PeerDiscoveryAgent | P2P peer discovery agent started and listening on /[0:0:0:0:0:0:0:0%0]:30303
2022-09-17 17:26:38.584-07:00 | vert.x-eventloop-thread-1 | INFO  | PeerDiscoveryAgent | Writing node record to disk. NodeRecord{<data>}}
2022-09-17 17:26:38.695-07:00 | main | INFO  | DefaultP2PNetwork | Enode URL enode://<data>@<ip>:30303
2022-09-17 17:26:38.696-07:00 | main | INFO  | DefaultP2PNetwork | Node address <addr>
2022-09-17 17:26:38.702-07:00 | main | INFO  | DefaultSynchronizer | Starting synchronizer.
2022-09-17 17:26:38.706-07:00 | main | INFO  | SnapSyncDownloader | Starting sync.
2022-09-17 17:26:38.718-07:00 | main | INFO  | WaitForPeersTask | Waiting for 1 total peers to connect. 0 peers currently connected.
2022-09-17 17:26:38.732-07:00 | main | INFO  | Runner | Ethereum main loop is up.
2022-09-17 17:26:43.732-07:00 | EthScheduler-Timer-0 | INFO  | WaitForPeersTask | Waiting for 1 total peers to connect. 0 peers currently connected.
2022-09-17 17:26:46.296-07:00 | Timer-0 | INFO  | DNSResolver | Resolved 426 nodes
2022-09-17 17:26:47.816-07:00 | nioEventLoopGroup-3-4 | INFO  | SnapWorldStateDownloader | Downloading world state from peers for block 4460593 (0x5a69d132ab8019b805b5925a73738087ac3986caee992fcaf22b762e9039e1ad). State root 0xa346bd190e9d56e2fe6563bdc76d7ac9d43b3222822d11c8f7ca8a0f4ddd5fde pending request 0
2022-09-17 17:26:48.247-07:00 | nioEventLoopGroup-3-4 | INFO  | FastSyncTargetManager | No sync target, checking current peers for usefulness: 11
2022-09-17 17:26:48.389-07:00 | nioEventLoopGroup-3-5 | INFO  | FastSyncTargetManager | No sync target, checking current peers for usefulness: 13
2022-09-17 17:26:48.510-07:00 | nioEventLoopGroup-3-6 | INFO  | FastSyncTargetManager | No sync target, checking current peers for usefulness: 11
2022-09-17 17:26:48.553-07:00 | nioEventLoopGroup-3-2 | INFO  | FastSyncTargetManager | No sync target, checking current peers for usefulness: 11
2022-09-17 17:26:48.647-07:00 | nioEventLoopGroup-3-3 | INFO  | FastSyncTargetManager | No sync target, checking current peers for usefulness: 10

Using nimbus for the beacon client, tried both the latest version (22.9.0) and also compiled from unstable, it connects succesfully to the EL:

INF 2022-09-17 17:29:56.551-07:00 Established connection to execution layer  topics="eth1" url=ws://localhost:8551
INF 2022-09-17 17:29:56.596-07:00 Exchanged engine configuration             topics="eth1" terminalTotalDifficulty=10790000 terminalBlockHash=0x0000000000000000000000000000000000000000000000000000000000000000 terminalBlockNumber=0
INF 2022-09-17 17:29:56.596-07:00 Starting Eth1 deposit contract monitoring  topics="eth1" contract=0xff50ed3d0ec03ac01d4c79aad74928bff48a7b2b
INF 2022-09-17 17:29:56.599-07:00 Waiting for new Eth1 block headers         topics="eth1"

@daniellehrner can you please clarify the below?

Post merge Besu needs Teku to sync.

Can't besu indepdentely sync the entire chain post merge? given that my goerli nimbus is still syncing could this be the issue why besu won't continue past block 0x441031?

Edit: in addition, nimbus also spits these once in a while:

WRN 2022-09-17 18:01:10.157-07:00 Eth1 chain monitoring failure, restarting  topics="eth1" err="No eth1 chain progress for too long"

[AntoBrajkovic]

dropped teku in favor of nimbus. Teku failed to sync, nimbus already synced 40% without any hiccups. Besu displays the warning:
2022-09-18 00:28:38.686+00:00 | vert.x-eventloop-thread-0 | WARN | EngineExchangeTransitionConfiguration | not called in 120 seconds, consensus client may not be connected

@daniellehrner it seems just to be a warning it would get stuck with teku connected I had it connected but teku keeps failing. Had to switch to nimbus which is syncing for the last 10 hours already synced 40% without issues. I'll experiment with besu and nimbus when the sync completes. I had also a case of besu syncing normally a few days ago/before the merge but for some reason did not let it complete I think it froze my PC but not sure. Again I'll play with it after nimbus syncs

[howardrcc]

besu keeps on displaying over and over again:

2022-09-18 14:45:49.324+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | SYNCING for fork-choice-update: head: 0xeb65bbec224374d13e8afe868656f1d0c7bb7a4d765e1f813f977df547c7b198, finalized: 0x3b50cfe3e2882f21f909baef91c53d1105c77639d02dcc9346f7e08351b2dd90, safeBlockHash: 0x6a28a15135ed7f2a8077b7c3beb4c26ade99d3f457069f4afd3ed8a8e10e3954
2022-09-18 14:46:26.768+00:00 | ForkJoinPool.commonPool-worker-5 | INFO  | BackwardsSyncAlgorithm | Waiting for preconditions...

Teku is properly synced and is waiting for execution layer:
4:48:35.373 INFO - Syncing *** Target slot: 4724041, Head slot: 4724040, Waiting for execution layer sync, Connected peers: 100
I'm not running a validator on this machine. I am on another machine (where besu is properly working)
So my question:

Does Besu require a full synced validator node in order to import blocks? And what does the follwing message mean? BackwardsSyncAlgorithm | Waiting for preconditions...

[proteanx]

besu keeps on displaying over and over again:

2022-09-18 14:45:49.324+00:00 | vert.x-worker-thread-0 | INFO  | EngineForkchoiceUpdated | SYNCING for fork-choice-update: head: 0xeb65bbec224374d13e8afe868656f1d0c7bb7a4d765e1f813f977df547c7b198, finalized: 0x3b50cfe3e2882f21f909baef91c53d1105c77639d02dcc9346f7e08351b2dd90, safeBlockHash: 0x6a28a15135ed7f2a8077b7c3beb4c26ade99d3f457069f4afd3ed8a8e10e3954
2022-09-18 14:46:26.768+00:00 | ForkJoinPool.commonPool-worker-5 | INFO  | BackwardsSyncAlgorithm | Waiting for preconditions...

Teku is properly synced and is waiting for execution layer: 4:48:35.373 INFO - Syncing *** Target slot: 4724041, Head slot: 4724040, Waiting for execution layer sync, Connected peers: 100 I'm not running a validator on this machine. I am on another machine (where besu is properly working) So my question:

Does Besu require a full synced validator node in order to import blocks? And what does the follwing message mean? BackwardsSyncAlgorithm | Waiting for preconditions...

I'm having this same problem. I'm wondering if we should make a new issue on here for it though as our issue seems quite different than above.

Besu sync'd almost to full then I loaded the latest beacon chain state on teku using my nimbus node thats running on another machine (with geth) and ever since I've been stuck here. Teku says its waiting on besu while Besu does virtually nothing.

[howardrcc]

I think besu requires a full validator node (teku). I removed my teku validator keys from the config to test. and besu is no longer syncing/importing blocks.

Then i added my keys again (on the machine that was not syncing before) and it's starts importing blocks immediately.

I guess this is how it's suppose to work... maybe someone can confirm?

[proteanx]

I think besu requires a full validator node (teku). I removed my teku validator keys from the config to test. and besu is no longer syncing/importing blocks.

Then i added my keys again (on the machine that was not syncing before) and it's starts importing blocks immediately.

I guess this is how it's suppose to work... maybe someone can confirm?

This is definitely not how its supposed to work. You are not required to be a validator in order to run a full node. You just need a beacon node and engine api configured (with the execution client).

Where are you at in your sync? It's weird that importing validator keys made a difference, I may try generating/importing keys just to test behavior.

[AntoBrajkovic]

@ibhagwan, @howardrcc, I am looking at geth/have it installed. I read in the geth documentation that the behavior is to sync up to the merge and then stall in till a consensus client is connected. I think that should be/is the case the case with besu.
@proteanx where I'm having an issue is with the initial sync not progressing/the sync up to the merge, without besu giving any feedback. I can see that it is not progressing by checking the database directory/the size of the directory

[ibhagwan]

For those interested I was able to solve this, turns out Besu needs an in-sync consensus client in order to continue the sync past the "stuck" block and since my goerli nimbus sync was taking forever (testing on low-end home hardware) it didn't continue the sync.

The solution is rather simple, I used "checkpoint sync" instead of regular sync, this way the node is first considered in sync and then downloads the history using backfill.

For Nimbus, see how to use trusted node sync.

[proteanx]

For those interested I was able to solve this, turns out Besu needs an in-sync consensus client in order to continue the sync past the "stuck" block and since my goerli nimbus sync was taking forever (testing on low-end home hardware) it didn't continue the sync.

The solution is rather simple, I used "checkpoint sync" instead of regular sync, this way the node is first considered in sync and then downloads the history using backfill.

For Nimbus, see how to use trusted node sync.

I had already done this (loaded beacon state from my already sync'd nimbus on teku). It does appear my issue may have cleared up. I'm getting progress just need to work out memory allocation as I'm seeing some java out of memory errors.

[ibhagwan]

I had already done this (loaded beacon state from my already sync'd nimbus on teku). It does appear my issue may have cleared up. I'm getting progress just need to work out memory allocation as I'm seeing some java out of memory errors.

@proteanx are you using JAVA_OPTS=-Xmx8g?

[proteanx]

I had already done this (loaded beacon state from my already sync'd nimbus on teku). It does appear my issue may have cleared up. I'm getting progress just need to work out memory allocation as I'm seeing some java out of memory errors.

@proteanx are you using JAVA_OPTS=-Xmx8g?

I had it set to less than 8gb but have since increased it. Hopefully that clears up any remaining issues.

[proteanx]

Update - still unable to fully sync. It appears it just never completes the Worldstate download. It imports blocks up to the current block and then just hangs while it downloads and then eventually it times out (you no longer see it in the log output).

Any suggestions? Luckily my geth/nimbus is working fine so it's not critical to fix now but I was very interested in testing/using besu.

[Twente-Mining]

exactly the same issue here.

[Propulsions]

It appears that it's not possible to synchronize Besu post-merge independently as a standalone Execution Client at this time.

Had a fully synchronized Besu node to post-merge then had to stop the service due to the Sync Committee Attestation issue and use Teku with Geth.

When attempting to bring Besu back in synchronization in the background without Teku connected, the client does not process any ingress connections or attempt to make any outbound ones. I was able to spin up Besu in this manner pre-merge running simultaneously with Geth and have verified that it's not a network issue.

[proteanx]

It appears that it's not possible to synchronize Besu post-merge independently as a standalone Execution Client at this time.

Had a fully synchronized Besu node to post-merge then had to stop the service due to the Sync Committee Attestation issue and use Teku with Geth.

When attempting to bring Besu back in synchronization in the background without Teku connected, the client does not process any ingress connections or attempt to make any outbound ones. I was able to spin up Besu in this manner pre-merge running simultaneously with Geth and have verified that it's not a network issue.

It's not possible to run any execution client by themselves now, including geth. So I'm not sure what this is supposed to mean.

[Propulsions]

It's not possible to run any execution client by themselves now, including geth. So I'm not sure what this is supposed to mean.

Hmmm, it'd be nice to be able to run two execution clients concurrently with one as a backup. Guess that would be a feature request with the consensus client teams then.

[ph1go]

It's not possible to run any execution client by themselves now, including geth. So I'm not sure what this is supposed to mean.

Hmmm, it'd be nice to be able to run two execution clients concurrently with one as a backup. Guess that would be a feature request with the consensus client teams then.

Without some fancy third party solution it's not possible to point a cl client at more than one el client, it's 1:1. Instead of having a cl client pointing to multiple el clients you now have to have a cl client for every el client and the failover is established at the validator client level, where you can point to multiple cl beacon nodes.

[syspulse]

Initial standalone (no beacon client) sync seems to be also affected. Very quick analysis:

1. Starting from scratch: --sync-mode=X_SNAP

2. No sensible progress information at INFO level:

2022-10-05 08:52:43.882+03:00 | EthScheduler-Timer-0 | INFO  | FastSyncActions | Waiting for valid peers with chain height information.  4 / 5 required peers currently available.
2022-10-05 08:54:43.028+03:00 | vert.x-eventloop-thread-0 | WARN  | EngineQosTimer | Execution engine not called in 120 seconds, consensus client may not be connected
2022-10-05 08:56:43.123+03:00 | vert.x-eventloop-thread-0 | WARN  | EngineQosTimer | Execution engine not called in 120 seconds, consensus client may not be connected
2022-10-05 08:58:43.221+03:00 | vert.x-eventloop-thread-0 | WARN  | EngineQosTimer | Execution engine not called in 120 seconds, consensus client may not be connected

...

3. Heavily consumed CPU (60% on i7-7820x)

4. At DEBUG level every ~5msec:
   vert.x-eventloop-thread-1 | DEBUG | PeerDiscoveryController | ignoring expired PING

5. Data directory content (and size) is not changing

[AntoBrajkovic]

To give an update. I've switched to geth and nimbus. I have to get things going since I have ETH that is staked. I will be playing around with besu and teku in the next few days. Will give an update

[non-fungible-nelson]

This issue should be resolved with many peering changes we have made and also post-Merge networks not requiring a minimum of five peers. You can drop down the --fast-sync-min-peers flag to 1 or 2 and it should progress. I anticipate you will get many more peers on 22.10.0. @AntoBrajkovic

[icemagno]

Why should I use Besu instead GETH ?
It seems much more younger and problematic and brings (at my POV) nothing new