Issue reading NodeRecord

q9f commented 3 years ago

Description

After upgrading Besu to 21.2.0-RC1, it does not longer support my previous configuration. The triggered exception does indicate a cast from RLP list to RLP string but does not give any hint what may have caused this nor how to circumvent this.

Acceptance Criteria

Running Besu on Classic, Kotti, and Mordor.

Steps to Reproduce (Bug)

Compile latest Besu from tags/21.2.0-RC1

Run

besu --network mordor \
--data-path /data/besu/mordor \
--host-whitelist "*" \
--sync-mode "full" \
--p2p-port 31355 \
--pruning-enabled \
--rpc-http-cors-origins "all" \
--rpc-http-enabled \
--rpc-http-host 0.0.0.0 \
--rpc-http-port 9555

Get exception: java.util.concurrent.CompletionException: java.lang.ClassCastException: class org.web3j.rlp.RlpList cannot be cast to class org.web3j.rlp.RlpString (org.web3j.rlp.RlpList and org.web3j.rlp.RlpString are in unnamed module of loader 'app')

Versions (Add all that apply)

Software version: besu/v21.1.1-dev-17af1265/linux-x86_64/oracle_openjdk-java-11
Java version: openjdk 11.0.11 2021-04-20
OS Name & Version: NAME="Arch Linux"
Kernel Version: Linux ceibo 5.8.1-arch1-1 #1 SMP PREEMPT Wed, 12 Aug 2020 18:50:43 +0000 x86_64 GNU/Linux

Additional Information

2021-05-31 09:27:43.634+02:00 | main | INFO  | AbstractAltBnPrecompiledContract | Using LibEthPairings native alt bn128                                                              
2021-05-31 09:27:45.683+02:00 | main | INFO  | SECP256K1 | Using native secp256k1                                                                                                                                                                                                                                            
2021-05-31 09:27:45.696+02:00 | main | INFO  | Besu | Starting Besu version: besu/v21.1.1-dev-17af1265/linux-x86_64/oracle_openjdk-java-11                                                                                                                                                                                                                                 
2021-05-31 09:27:46.235+02:00 | main | INFO  | Besu | Static Nodes file = /data/besu/mordor/static-nodes.json                                                 
2021-05-31 09:27:46.237+02:00 | main | INFO  | StaticNodesParser | StaticNodes file /data/besu/mordor/static-nodes.json does not exist, no static connections will be created.                                                                                                                                                                                             
2021-05-31 09:27:46.237+02:00 | main | INFO  | Besu | Connecting to 0 static nodes.                                                                           
2021-05-31 09:27:46.242+02:00 | main | INFO  | Besu | Security Module: localfile                                                                              
2021-05-31 09:27:46.391+02:00 | main | INFO  | KeyPairUtil | Loaded public key 0x8fa15f5012ac3c47619147220b7772fcc5db0cb7fd132b5d196e7ccacb166ac1fcf83be1dace6cd288e288a85e032423b6e7e9e57f479fe7373edea045caa56b from /data/besu/mordor/key                                                                                                                                                                                           
2021-05-31 09:27:46.548+02:00 | main | INFO  | DatabaseMetadata | Lookup database metadata file in data directory: /data/besu/mordor                          
2021-05-31 09:27:46.811+02:00 | main | INFO  | RocksDBKeyValueStorageFactory | Existing database detected at /data/besu/mordor. Version 1                                                                                                                                                                                                                                                                                              
2021-05-31 09:28:00.958+02:00 | main | INFO  | ProtocolScheduleBuilder | Protocol schedule created with milestones: [Atlantis: 0, Agharta: 301243, Phoenix: 999983, Thanos: 2520000]                                                                                                                                                                                                                                                   
2021-05-31 09:28:01.302+02:00 | main | INFO  | RunnerBuilder | Detecting NAT service.                                                                         
2021-05-31 09:28:01.699+02:00 | main | INFO  | Runner | Starting Ethereum main loop ...                                                                                                                                                                                                                                                                                                                                                
2021-05-31 09:28:01.707+02:00 | main | INFO  | NatService | No NAT environment detected so no service could be started                                                                                                                                                                                                                                                                                                                 
2021-05-31 09:28:01.707+02:00 | main | INFO  | NetworkRunner | Starting Network.                                      
2021-05-31 09:28:02.124+02:00 | nioEventLoopGroup-2-1 | INFO  | RlpxAgent | P2P RLPx agent started and listening on /0:0:0:0:0:0:0:0:31355.                                                                                                                                                                                                                                                                                                                                                                                 
2021-05-31 09:28:02.132+02:00 | main | INFO  | PeerDiscoveryAgent | Starting peer discovery agent on host=0.0.0.0, port=31355
2021-05-31 09:28:02.366+02:00 | vert.x-eventloop-thread-1 | INFO  | VertxPeerDiscoveryAgent | Started peer discovery agent successfully, on effective host=0:0:0:0:0:0:0:0 and port=31355                                                                                                                                                                                                                                                                                                                                   
2021-05-31 09:28:02.367+02:00 | vert.x-eventloop-thread-1 | INFO  | PeerDiscoveryAgent | P2P peer discovery agent started and listening on /0:0:0:0:0:0:0:0:31355                                                                                                                                                                                                                                                                                                                                                           
2021-05-31 09:28:02.416+02:00 | main | ERROR | Runner | Startup failed                                                                                        
java.util.concurrent.CompletionException: java.lang.ClassCastException: class org.web3j.rlp.RlpList cannot be cast to class org.web3j.rlp.RlpString (org.web3j.rlp.RlpList and org.web3j.rlp.RlpString are in unnamed module of loader 'app')                                                                                                                                                                                          
        at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)                                                                                                                                                                                                                                                                                                                                
        at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)                                                     
        at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:645)                                                                                                                                                                                                                                                                                                                               
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)                                                          
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)                                                                                    
        at org.hyperledger.besu.ethereum.p2p.discovery.VertxPeerDiscoveryAgent.handleListenerSetup(VertxPeerDiscoveryAgent.java:143)                                                                                                                                                                                         
        at org.hyperledger.besu.ethereum.p2p.discovery.VertxPeerDiscoveryAgent.lambda$listenForConnections$3(VertxPeerDiscoveryAgent.java:103)
        at io.vertx.core.datagram.impl.DatagramSocketImpl.lambda$null$0(DatagramSocketImpl.java:206)                                                                                                                                                                                                                                                                                                                                                                                                                        
        at io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:366)                                                                                                                                                                                                                                                                                                
        at io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:43)                                                                              
        at io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:229)                                                                                                                                                                                                                                                                                                                                                                                                                                               
        at io.vertx.core.net.impl.ChannelFutureListenerAdapter.operationComplete(ChannelFutureListenerAdapter.java:39)                                                               
        at io.vertx.core.net.impl.ChannelFutureListenerAdapter.operationComplete(ChannelFutureListenerAdapter.java:24)   
        at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:578)                                                                   
        at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:552)                                                                
        at io.netty.util.concurrent.DefaultPromise.access$200(DefaultPromise.java:35)                                                                                                
        at io.netty.util.concurrent.DefaultPromise$1.run(DefaultPromise.java:502)                                                                                                                                                                                                                                            
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)                                                                                
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)                                                                                                      
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)                                                                                                                                                                                                                                                                                                    
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)                                                       
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)                                                                          
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)                                                              
        at java.base/java.lang.Thread.run(Thread.java:829)                                                                                                    
Caused by: java.lang.ClassCastException: class org.web3j.rlp.RlpList cannot be cast to class org.web3j.rlp.RlpString (org.web3j.rlp.RlpList and org.web3j.rlp.RlpString are in unnamed module of loader 'app')                                                                                                                                                                                                                                                                                                              
        at org.ethereum.beacon.discovery.schema.NodeRecord.fromRawFields(NodeRecord.java:79)                                                                                         
        at org.ethereum.beacon.discovery.schema.NodeRecordFactory.fromRlpList(NodeRecordFactory.java:107)                                                                            
        at org.ethereum.beacon.discovery.schema.NodeRecordFactory.fromBytes(NodeRecordFactory.java:116)                                                                                                                                                                                                                                                                                                                                
        at org.ethereum.beacon.discovery.schema.NodeRecordFactory.fromBytes(NodeRecordFactory.java:66)                                                                                                             
        at org.hyperledger.besu.ethereum.p2p.discovery.PeerDiscoveryAgent.lambda$addLocalNodeRecord$3(PeerDiscoveryAgent.java:187)                                                                                 
        at java.base/java.util.Optional.flatMap(Optional.java:294)                                                                                                                                                 
        at org.hyperledger.besu.ethereum.p2p.discovery.PeerDiscoveryAgent.addLocalNodeRecord(PeerDiscoveryAgent.java:187)                                                                                          
        at org.hyperledger.besu.ethereum.p2p.discovery.PeerDiscoveryAgent.lambda$start$2(PeerDiscoveryAgent.java:163)                                                                                              
        at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:642)                                                                                                           
        ... 21 more                                                                                                                                                                                                
java.util.concurrent.CompletionException: java.lang.ClassCastException: class org.web3j.rlp.RlpList cannot be cast to class org.web3j.rlp.RlpString (org.web3j.rlp.RlpList and org.web3j.rlp.RlpString are in unnamed module of loader 'app')                                                                                                                                                                                                                                                                               

To display full help:                                                                                                                                                                                                                                         
besu [COMMAND] --help                                                                                                                                                                                                                                                                                                                                                                                                                  
^C^C^C2021-05-31 09:28:32.517+02:00 | Thread-1 | ERROR | AbstractMinerExecutor | Failed to shutdown EthHashMinerExecutor.                                                                                                                                     
^C2021-05-31 09:28:42.532+02:00 | Thread-1 | ERROR | Pruner | Failed to shutdown Pruner executor service.                                                                                                                                                     
2021-05-31 09:28:42.533+02:00 | Thread-1 | INFO  | NetworkRunner | Stopping Network.                                                                                                                                                                          
2021-05-31 09:28:42.553+02:00 | Thread-1 | INFO  | EthProtocolManager | Stopping eth Subprotocol.                                                                                                                  
2021-05-31 09:28:42.643+02:00 | Thread-1 | INFO  | EthProtocolManager | eth Subprotocol stopped.                                                                                                                   
2021-05-31 09:28:42.643+02:00 | Thread-1 | INFO  | NetworkRunner | Network stopped.                                                                                                                                
2021-05-31 09:28:42.643+02:00 | Thread-1 | INFO  | AutoTransactionLogBloomCachingService | Shutting down Auto transaction logs caching service.                                                                    
2021-05-31 09:28:42.645+02:00 | Thread-1 | INFO  | NatService | No NAT environment detected so no service could be stopped

atoulme commented 3 years ago

Thank you for the report. This error indicates that while reading the ENR exposed by a node over discovery, Besu failed to read the contents of the record. Most likely a record value is a list instead of a string.

This should not stop operation of the client, but will break discovery of nodes with such data.

this should not be closely tied to Mordor.

q9f commented 3 years ago

I cannot reproduce it on latest master besu/v21.1.7-dev-2cc67784/linux-x86_64/oracle_openjdk-java-11 so it might be specific to the 21.2.x release.

atoulme commented 3 years ago

You might just not have discovered a node with that form of metadata again. Since Besu uses the https://github.com/consensys/discovery library, I think the issue should be relayed there.

jflo commented 3 years ago

We believe this occurred when the node started up and tried to load its own NodeRecord from local keystore storage. Did anything about that keystore change between running 21.2.0-RC1 (is that a typo? that build doesn't exist here ) and running the 21.1.7 nightly build? I'm surprised the problem went from being regularly reproducible to not at all via that upgrade.

We'd like to close this as "cannot reproduce" unless being able to run older builds is a requirement for you, and you are able to provide that keystore.

hyperledger / besu