search

VeriBlock / nodecore-releases

Other
37 stars 11 forks source link

[Nodecore v0.2.17][Regression] Peer connections not working anymore (on outdated Linux system) #104

Closed a123b closed 6 years ago

a123b commented 6 years ago

My secondary node can't connect to other peers with the latest nodecore version. It's actually a fairly dated Linux distro, so I don't know if more up-to-date systems are also affected...

This is the command line output, there is no additional info in the log files:

2018-09-11 11:14:29.964+0200 [main] INFO  nodecore.Program - VeriBlock NodeCore v0.2.17-release
2018-09-11 11:14:29.997+0200 [main] INFO  nodecore.Program - Available Processors: 4 | Max Memory: 5592576KB
2018-09-11 11:14:30.154+0200 [main] INFO  nodecore.Program - {
  "java_runtime_name": "Java(TM) SE Runtime Environment",
  "sun_boot_library_path": "/usr/java/jre1.8.0_181-amd64/lib/amd64",
  "java_runtime_version": "1.8.0_181-b13",
  "java_specification_version": "1.8",
  "os_name": "Linux",
  "os_arch": "amd64",
  "os_version": "3.12.67-64-desktop",
  "memory_total_gb": "0,15 GB",
  "memory_max_gb": "5,33 GB",
  "datetime_now_utc": "2018-09-11 11:14:30.039+0200"
}
2018-09-11 11:14:30.198+0200 [main] INFO  nodecore.h - NodeCore operating state is now: Started
2018-09-11 11:14:30.213+0200 [main] INFO  nodecore.h - NodeCore network state is now: Disconnected
2018-09-11 11:14:30.213+0200 [main] INFO  nodecore.h - NodeCore blockchain state is now: Initializing
2018-09-11 11:14:30.213+0200 [main] INFO  nodecore.h - NodeCore operating state is now: Initializing
2018-09-11 11:14:30.676+0200 [main] INFO  nodecore.Program - Network: TestNet
2018-09-11 11:14:32.402+0200 [main] INFO  nodecore.j.b - Loaded key for address: V2vLs2Fa8yA1CcDvqByy4mLSuEBcHp
2018-09-11 11:14:32.749+0200 [main] INFO  nodecore.c.a.q - Write json blocks to file: false
2018-09-11 11:14:32.752+0200 [main] INFO  nodecore.Program - Preparing to load blockchain (please note: loading the blockchain from disk may take several minutes!)
2018-09-11 11:14:32.768+0200 [main] INFO  nodecore.h - NodeCore blockchain state is now: Loading
2018-09-11 11:14:32.778+0200 [main] INFO  nodecore.c.a.q - Preloading endorsement context
2018-09-11 11:14:32.781+0200 [main] INFO  nodecore.c.a.q - No block index present at latest milestone, rebuilding index
2018-09-11 11:14:32.808+0200 [main] INFO  nodecore.c.a.q - Loading blocks beginning at -1
2018-09-11 11:14:32.878+0200 [main] INFO  nodecore.c.a.q - Beginning block validations on 0000000012CC67437013DAEC1B0299F0AC3D676D7DF9AD8C @ 0
2018-09-11 11:14:32.891+0200 [main] INFO  nodecore.c.a.q - Beginning apply validations on 0000000012CC67437013DAEC1B0299F0AC3D676D7DF9AD8C @ 0
2018-09-11 11:14:32.902+0200 [main] INFO  nodecore.c.a.q - Applying block 0000000012CC67437013DAEC1B0299F0AC3D676D7DF9AD8C @ 0
2018-09-11 11:14:32.932+0200 [main] INFO  nodecore.c.a.q - Done applying block 0000000012CC67437013DAEC1B0299F0AC3D676D7DF9AD8C!
2018-09-11 11:14:32.933+0200 [main] INFO  nodecore.c.a.q - Added a new block (0000000012CC67437013DAEC1B0299F0AC3D676D7DF9AD8C @ 0) to best chain.
2018-09-11 11:14:32.950+0200 [main] INFO  nodecore.c.a.q - Done loading!
2018-09-11 11:14:32.958+0200 [main] INFO  nodecore.h - NodeCore blockchain state is now: Loaded
2018-09-11 11:14:32.958+0200 [main] INFO  nodecore.Program - Program done loading blockchain from disk...
2018-09-11 11:14:32.958+0200 [main] INFO  nodecore.Program - got wallet service...
2018-09-11 11:14:32.988+0200 [main] INFO  nodecore.Program - got pool...
2018-09-11 11:14:33.043+0200 [main] INFO  nodecore.Program - Got admin service...
2018-09-11 11:14:33.044+0200 [main] INFO  nodecore.g.c - Starting Admin RPC service using security mode "None" on /127.0.0.1:10501 with password disabled
2018-09-11 11:14:34.434+0200 [main] INFO  nodecore.Program - Started admin service...
2018-09-11 11:14:34.471+0200 [main] INFO  nodecore.e.o - Initializing peer table
2018-09-11 11:14:34.601+0200 [nc-peer-listener] INFO  nodecore.e.o - Available connections: 7
2018-09-11 11:14:34.602+0200 [nc-peer-listener] INFO  nodecore.e.o - Connection lease acquired
2018-09-11 11:14:34.613+0200 [main] INFO  nodecore.h - NodeCore operating state is now: Running
2018-09-11 11:14:37.951+0200 [nc-block-thread-0] INFO  nodecore.c.a.q - Waiting for blocks in queue
2018-09-11 11:14:54.494+0200 [pool-5-thread-1] INFO  nodecore.e.o - Establishing connection with 5 / 5 configured peers.
2018-09-11 11:14:54.495+0200 [pool-5-thread-1] INFO  nodecore.e.i - Attempting to establish client connection to peer 88.198.35.14:7501
2018-09-11 11:14:54.523+0200 [input-thread-88.198.35.14] INFO  nodecore.e.l - Waiting for input from peer...
2018-09-11 11:14:54.524+0200 [pool-5-thread-1] INFO  nodecore.e.o - Added peer 88.198.35.14
2018-09-11 11:14:54.540+0200 [input-thread-88.198.35.14] ERROR nodecore.e.l - Socket error: 
java.io.EOFException: null
        at java.io.DataInputStream.readFully(Unknown Source)
        at java.io.DataInputStream.readFully(Unknown Source)
        at nodecore.e.l.run(PeerInputStream.java:67)
2018-09-11 11:14:54.549+0200 [pool-5-thread-1] INFO  nodecore.h - NodeCore network state is now: Connected
2018-09-11 11:14:54.550+0200 [pool-5-thread-1] INFO  nodecore.e.i - Attempting to establish client connection to peer 144.76.83.73:7501
2018-09-11 11:14:54.557+0200 [input-thread-88.198.35.14] INFO  nodecore.e.i - Error while attempting to self-heal P2P connection!
java.lang.InterruptedException: sleep interrupted
        at java.lang.Thread.sleep(Native Method)
        at nodecore.e.i.a(Peer.java:219)
        at nodecore.e.l.run(PeerInputStream.java:81)
2018-09-11 11:14:54.559+0200 [input-thread-88.198.35.14] INFO  nodecore.e.o - Removed 88.198.35.14 from peer list
2018-09-11 11:14:54.560+0200 [output-thread-88.198.35.14] INFO  nodecore.e.m - Output stream thread shutting down
2018-09-11 11:14:54.579+0200 [input-thread-144.76.83.73] INFO  nodecore.e.l - Waiting for input from peer...
2018-09-11 11:14:54.585+0200 [pool-5-thread-1] INFO  nodecore.e.o - Added peer 144.76.83.73
2018-09-11 11:14:54.596+0200 [input-thread-144.76.83.73] ERROR nodecore.e.l - Socket error: 
java.io.EOFException: null
        at java.io.DataInputStream.readFully(Unknown Source)
        at java.io.DataInputStream.readFully(Unknown Source)
        at nodecore.e.l.run(PeerInputStream.java:67)
2018-09-11 11:14:54.603+0200 [input-thread-144.76.83.73] INFO  nodecore.e.i - Error while attempting to self-heal P2P connection!
java.lang.InterruptedException: sleep interrupted
        at java.lang.Thread.sleep(Native Method)
        at nodecore.e.i.a(Peer.java:219)
        at nodecore.e.l.run(PeerInputStream.java:81)
2018-09-11 11:14:54.604+0200 [output-thread-144.76.83.73] INFO  nodecore.e.m - Output stream thread shutting down
2018-09-11 11:14:54.607+0200 [pool-5-thread-1] INFO  nodecore.e.i - Attempting to establish client connection to peer 176.9.123.26:7501
2018-09-11 11:14:54.609+0200 [input-thread-88.198.35.14] INFO  nodecore.h - NodeCore network state is now: Disconnected
2018-09-11 11:14:54.611+0200 [input-thread-144.76.83.73] INFO  nodecore.e.o - Removed 144.76.83.73 from peer list
2018-09-11 11:14:54.639+0200 [pool-5-thread-1] INFO  nodecore.e.o - Added peer 176.9.123.26
2018-09-11 11:14:54.639+0200 [pool-5-thread-1] INFO  nodecore.h - NodeCore network state is now: Connected
2018-09-11 11:14:54.640+0200 [pool-5-thread-1] INFO  nodecore.e.i - Attempting to establish client connection to peer 94.130.18.249:7501
2018-09-11 11:14:54.640+0200 [input-thread-176.9.123.26] INFO  nodecore.e.l - Waiting for input from peer...
2018-09-11 11:14:54.654+0200 [input-thread-176.9.123.26] ERROR nodecore.e.l - Socket error: 
java.io.EOFException: null
        at java.io.DataInputStream.readFully(Unknown Source)
        at java.io.DataInputStream.readFully(Unknown Source)
        at nodecore.e.l.run(PeerInputStream.java:67)
2018-09-11 11:14:54.661+0200 [input-thread-176.9.123.26] INFO  nodecore.e.i - Error while attempting to self-heal P2P connection!
java.lang.InterruptedException: sleep interrupted
        at java.lang.Thread.sleep(Native Method)
        at nodecore.e.i.a(Peer.java:219)
        at nodecore.e.l.run(PeerInputStream.java:81)
2018-09-11 11:14:54.662+0200 [output-thread-176.9.123.26] INFO  nodecore.e.m - Output stream thread shutting down
2018-09-11 11:14:54.662+0200 [input-thread-176.9.123.26] INFO  nodecore.e.o - Removed 176.9.123.26 from peer list
2018-09-11 11:14:54.662+0200 [input-thread-176.9.123.26] INFO  nodecore.h - NodeCore network state is now: Disconnected
2018-09-11 11:14:54.662+0200 [input-thread-94.130.18.249] INFO  nodecore.e.l - Waiting for input from peer...
2018-09-11 11:14:54.662+0200 [pool-5-thread-1] INFO  nodecore.e.o - Added peer 94.130.18.249
2018-09-11 11:14:54.663+0200 [pool-5-thread-1] INFO  nodecore.h - NodeCore network state is now: Connected
2018-09-11 11:14:54.663+0200 [pool-5-thread-1] INFO  nodecore.e.i - Attempting to establish client connection to peer 94.130.17.190:7501
2018-09-11 11:14:54.684+0200 [input-thread-94.130.18.249] ERROR nodecore.e.l - Socket error: 
java.io.EOFException: null
        at java.io.DataInputStream.readFully(Unknown Source)
        at java.io.DataInputStream.readFully(Unknown Source)
        at nodecore.e.l.run(PeerInputStream.java:67)
2018-09-11 11:14:54.692+0200 [input-thread-94.130.17.190] INFO  nodecore.e.l - Waiting for input from peer...
2018-09-11 11:14:54.698+0200 [pool-5-thread-1] INFO  nodecore.e.o - Added peer 94.130.17.190
2018-09-11 11:14:54.706+0200 [input-thread-94.130.18.249] INFO  nodecore.e.i - Error while attempting to self-heal P2P connection!
java.lang.InterruptedException: sleep interrupted
        at java.lang.Thread.sleep(Native Method)
        at nodecore.e.i.a(Peer.java:219)
        at nodecore.e.l.run(PeerInputStream.java:81)
2018-09-11 11:14:54.707+0200 [input-thread-94.130.18.249] INFO  nodecore.e.o - Removed 94.130.18.249 from peer list
2018-09-11 11:14:54.707+0200 [output-thread-94.130.18.249] INFO  nodecore.e.m - Output stream thread shutting down
2018-09-11 11:14:54.707+0200 [input-thread-94.130.17.190] ERROR nodecore.e.l - Socket error: 
java.io.EOFException: null
        at java.io.DataInputStream.readFully(Unknown Source)
        at java.io.DataInputStream.readFully(Unknown Source)
        at nodecore.e.l.run(PeerInputStream.java:67)
2018-09-11 11:14:54.716+0200 [input-thread-94.130.17.190] INFO  nodecore.e.i - Error while attempting to self-heal P2P connection!
java.lang.InterruptedException: sleep interrupted
        at java.lang.Thread.sleep(Native Method)
        at nodecore.e.i.a(Peer.java:219)
        at nodecore.e.l.run(PeerInputStream.java:81)
2018-09-11 11:14:54.717+0200 [input-thread-94.130.17.190] INFO  nodecore.e.o - Removed 94.130.17.190 from peer list
2018-09-11 11:14:54.717+0200 [input-thread-94.130.17.190] INFO  nodecore.h - NodeCore network state is now: Disconnected
2018-09-11 11:14:54.717+0200 [output-thread-94.130.17.190] INFO  nodecore.e.m - Output stream thread shutting down
a123b commented 6 years ago

On my up-to-date main node, everything is working, but I'm running on OpenJDK there. So I tried using OpenJDK on the problematic node, but the problem still remains. So I guess it really has to do with something being outdated on the system.

a123b commented 6 years ago

Never mind, the problem was probably that I had many peers that were already updated to the new version configured with port 6501 in nodecore.properties (didn't know the port was changed to 7501). After deleting nodecore.properties it worked just fine.