search

hyperledger / besu

An enterprise-grade Java-based, Apache 2.0 licensed Ethereum client https://wiki.hyperledger.org/display/besu
https://www.hyperledger.org/projects/besu
Apache License 2.0
1.52k stars 847 forks source link

Failing to connect to peers. #1915

Closed skoya closed 3 years ago

skoya commented 3 years ago

Description

As an home user, I want to connect to main net so that I can mine

Acceptance Criteria

Steps to Reproduce (Bug)

Start

Expected behavior: [What you expect to happen] Peers connect and sync

Actual behavior: [What actually happens] 0 peers. I think due to a bug in the handshake.

Frequency: [What percentage of the time does it occur?]

Versions (Add all that apply)

2021-02-15 09:08:06.436+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:11.417+00:00 | vert.x-eventloop-thread-2 | DEBUG | PeerDiscoveryController | Peer table refresh triggered by timer expiry

2021-02-15 09:08:11.419+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Start peer search.

2021-02-15 09:08:11.419+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Skipping bonding round because no candidates are available

2021-02-15 09:08:11.419+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Iterative peer search complete. 0 peers processed over 1 rounds.

2021-02-15 09:08:11.437+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:11.437+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:13.944+00:00 | nioEventLoopGroup-3-1 | DEBUG | AbstractHandshakeHandler | Handshake error:

org.hyperledger.besu.ethereum.p2p.rlpx.handshake.HandshakeException: Failed to decrypt handshake message

at org.hyperledger.besu.ethereum.p2p.rlpx.handshake.ecies.ECIESHandshaker.handleMessage(ECIESHandshaker.java:202) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

at org.hyperledger.besu.ethereum.p2p.rlpx.connections.netty.HandshakeHandlerInbound.nextHandshakeMessage(HandshakeHandlerInbound.java:54) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

at org.hyperledger.besu.ethereum.p2p.rlpx.connections.netty.AbstractHandshakeHandler.channelRead0(AbstractHandshakeHandler.java:85) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

at org.hyperledger.besu.ethereum.p2p.rlpx.connections.netty.AbstractHandshakeHandler.channelRead0(AbstractHandshakeHandler.java:43) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) ~[netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-transport-4.1.49.Final.jar:4.1.49.Final]

at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.49.Final.jar:4.1.49.Final]

at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.49.Final.jar:4.1.49.Final]

at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.49.Final.jar:4.1.49.Final]

at java.lang.Thread.run(Unknown Source) [?:?]

Caused by: org.bouncycastle.crypto.InvalidCipherTextException: Invalid MAC.

at org.hyperledger.besu.ethereum.p2p.rlpx.handshake.ecies.ECIESEncryptionEngine.decrypt(ECIESEncryptionEngine.java:272) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

at org.hyperledger.besu.ethereum.p2p.rlpx.handshake.ecies.ECIESEncryptionEngine.decrypt(ECIESEncryptionEngine.java:206) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

at org.hyperledger.besu.ethereum.p2p.rlpx.handshake.ecies.EncryptedMessage.decryptMsg(EncryptedMessage.java:62) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

at org.hyperledger.besu.ethereum.p2p.rlpx.handshake.ecies.ECIESHandshaker.handleMessage(ECIESHandshaker.java:188) ~[besu-p2p-1.5.0-RC2.jar:1.5.0-RC2]

... 20 more

2021-02-15 09:08:16.437+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:16.437+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:21.438+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:21.438+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:26.438+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:26.439+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:31.439+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:31.439+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:36.440+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:36.440+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:41.440+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:41.440+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:41.441+00:00 | vert.x-eventloop-thread-2 | DEBUG | PeerDiscoveryController | Peer table refresh triggered by insufficient peers

2021-02-15 09:08:41.447+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Start peer search.

2021-02-15 09:08:41.447+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Skipping bonding round because no candidates are available

2021-02-15 09:08:41.447+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Iterative peer search complete. 0 peers processed over 1 rounds.

2021-02-15 09:08:46.441+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:46.441+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:51.441+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:51.442+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:08:56.442+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:08:56.442+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:09:01.443+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:09:01.443+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:09:06.443+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:09:06.444+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:09:11.428+00:00 | vert.x-eventloop-thread-2 | DEBUG | PeerDiscoveryController | Peer table refresh triggered by insufficient peers

2021-02-15 09:09:11.429+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Start peer search.

2021-02-15 09:09:11.430+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Skipping bonding round because no candidates are available

2021-02-15 09:09:11.431+00:00 | vert.x-eventloop-thread-2 | DEBUG | RecursivePeerRefreshState | Iterative peer search complete. 0 peers processed over 1 rounds.

2021-02-15 09:09:11.444+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:09:11.444+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

2021-02-15 09:09:16.444+00:00 | EthScheduler-Timer-0 | INFO | FullSyncTargetManager | No sync target, waiting for peers: 0

2021-02-15 09:09:16.445+00:00 | EthScheduler-Timer-0 | DEBUG | WaitForPeerTask | Waiting for new peer connection. 0 peers currently connected.

shemnon commented 3 years ago

Two things,

First I would recommend a newer version. We added DNS based peer discovery which should accelerate initial peering. version 20.10.4 is the latest production release.

Second you should ensure NAT is properly bridged. Most residential routers support UPNP port forwarding so you can pass in --nat-method=upnp or you can explicitly open up an external port and set --p2p-host= as well as --p2p-interface=0.0.0.0. The best way to get full peers is to let outside peers connect to you and you need the NAT bridged to accomplish this.

skoya commented 3 years ago

So it works fine using 21.1 Using 20.10.4: I get a web3j issue.

skoya commented 3 years ago

I deleted the data directory and restarted with 20.10.4. Now seems better and getting less errors.