Hi Raghav, Would you please attach the full logs and config files of all 3 nodes, so that we could getter better insight of your setup?
Regards, Andor On Tue, May 29, 2018 at 6:23 PM, Raghav <[email protected]> wrote: > Ben > > So there are scripts that performed the stop and restart for us. Between > stop and restart there was 15 minutes of difference. > > Could it be possible that previous instance of zk didn't close cleanly and > that left 3888 to be busy and not available for the new instance ? > > I used "lsof -i :3888" to check and I can't see anything at the moment. Am > I missing anything ? > > Thanks for your help. > > On Tue, May 29, 2018 at 8:49 AM, Ben Wood <[email protected]> wrote: > > > Just to double check, you confirmed via netstat (or similar) that nothing > > is using the port, correct? > > > > On Tue, May 29, 2018 at 7:39 AM, Raghav <[email protected]> wrote: > > > > > Hi > > > > > > We have a 3 node zk ensemble. On all three nodes, we see following logs > > > that indicate that ZK can't bind to port 3888, and after three tries it > > > gives up. See the logs and highlighted in bold. Subsequently, ZK prints > > log > > > "*As I'm leaving the listener thread, I won't be able to participate in > > > leader election any longer: /1.1.1.143:3888 <http://1.1.1.143:3888>*". > > > > > > ZK was gracefully shutdown atleast 15 minutes before restarting again. > We > > > can rule out that anything was using that port already. > > > > > > Any help is greatly appreciated. > > > > > > ************************************************************ > > > ************************************** > > > 2018-05-28_07:38:56.15336 2018-05-28 07:38:56,148 [myid:] - INFO > > > [main:QuorumPeerConfig@136] - Reading configuration from: > > > conf/zoo.cfg > > > 2018-05-28_07:38:56.18385 2018-05-28 07:38:56,183 [myid:] - INFO > > > [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 1.1.1.144 to > > > address: /1.1.1.144 2018-05-28_07:38:56.18643 > > > 2018-05-28 07:38:56,184 [myid:] - INFO [main:QuorumPeer$QuorumServer@ > > 184] > > > - Resolved hostname: 1.1.1.143 to address: /1.1.1.143 > > > 2018-05-28_07:38:56.18666 2018-05-28 07:38:56,186 [myid:] - INFO > > > [main:QuorumPeer$QuorumServer@184] - Resolved hostname: 1.1.1.142 to > > > address: /1.1.1.142 2018-05-28_07:38:56.18700 > > > 2018-05-28 07:38:56,186 [myid:] - INFO [main:QuorumPeerConfig@398] - > > > Defaulting to majority > > > quorums > > > 2018-05-28_07:38:56.19613 2018-05-28 07:38:56,195 [myid:2] - INFO > > > [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to > > > 200 2018-05-28_07:38:56.19634 > > > 2018-05-28 07:38:56,196 [myid:2] - INFO [main:DatadirCleanupManager@79 > ] > > - > > > autopurge.purgeInterval set to > > > 24 2018-05-28_07:38:56.19835 > > > 2018-05-28 07:38:56,198 [myid:2] - INFO > > > [PurgeTask:DatadirCleanupManager$PurgeTask@138] - Purge task > > > started. > > 2018-05-28_07:38:56.21229 > > > 2018-05-28 07:38:56,212 [myid:2] - INFO > > > [PurgeTask:DatadirCleanupManager$PurgeTask@144] - Purge task > completed. > > > 2018-05-28_07:38:56.34200 2018-05-28 07:38:56,341 [myid:2] - INFO > > > [main:QuorumPeerMain@130] - Starting quorum > > > peer > > > 2018-05-28_07:38:56.34870 2018-05-28 07:38:56,348 [myid:2] - INFO > > > [main:ServerCnxnFactory@117] - Using > > > org.apache.zookeeper.server.NIOServerCnxnFactory as server connection > > > factory > > > 2018-05-28_07:38:56.35725 2018-05-28 07:38:56,357 [myid:2] - INFO > > > [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:2181 > > > 2018-05-28_07:38:56.36150 2018-05-28 07:38:56,361 [myid:2] - INFO > > > [main:QuorumPeer@1158] - tickTime set to > > > 2000 > > > 2018-05-28_07:38:56.36181 2018-05-28 07:38:56,361 [myid:2] - INFO > > > [main:QuorumPeer@1204] - initLimit set to > > > 10 > > > 2018-05-28_07:38:56.36211 2018-05-28 07:38:56,361 [myid:2] - INFO > > > [main:QuorumPeer@1178] - minSessionTimeout set to > > > -1 > > > 2018-05-28_07:38:56.36411 2018-05-28 07:38:56,362 [myid:2] - INFO > > > [main:QuorumPeer@1189] - maxSessionTimeout set to > > > -1 > > > 2018-05-28_07:38:56.37134 2018-05-28 07:38:56,371 [myid:2] - INFO > > > [main:QuorumPeer@1467] - QuorumPeer communication is not > > > secured! > > > 2018-05-28_07:38:56.37161 2018-05-28 07:38:56,371 [myid:2] - INFO > > > [main:QuorumPeer@1496] - quorum.cnxn.threads.size set to 20 > > > 2018-05-28_07:38:57.09036 2018-05-28 07:38:57,090 [myid:2] - INFO > > > [ListenerThread:QuorumCnxManager$Listener@736] - My election bind > port: > > / > > > 1.1.1.143:3888 > > > 2018-05-28_07:38:57.09877 2018-05-28 07:38:57,091 [myid:2] - ERROR > > > [/1.1.1.143:3888:QuorumCnxManager$Listener@760] - > > > *Exception while listening2018-05-28_07:38:57.09878 > > > java.net.BindException: > > > Cannot assign requested address* > > > 2018-05-28_07:38:57.09878 at > > > java.net.PlainSocketImpl.socketBind(Native Method) > > > 2018-05-28_07:38:57.09878 at > > > java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.java: > 382) > > > 2018-05-28_07:38:57.09878 at > > > java.net.ServerSocket.bind(ServerSocket.java:375) > > > 2018-05-28_07:38:57.09878 at > > > java.net.ServerSocket.bind(ServerSocket.java:329) > > > 2018-05-28_07:38:57.09879 at > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$ > > > Listener.run(QuorumCnxManager.java:739) > > > 2018-05-28_07:38:57.10491 2018-05-28 07:38:57,104 [myid:2] - INFO > > > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2181:QuorumPeer@909] - LOOKING > > > 2018-05-28_07:38:57.10613 2018-05-28 07:38:57,106 [myid:2] - INFO > > > [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2181:FastLeaderElection@813] - New > > > election. My id = 2, proposed zxid=0x9000023ff > > > > > > > > > > > > . > > > . > > > . > > > . > > > > > > > > > > > > 2018-05-28_07:38:59.10092 2018-05-28 07:38:59,100 [myid:2] - ERROR > > > [/1.1.1.143:3888:QuorumCnxManager$Listener@760] - Exception while > > > listening 2018-05-28_07:38:59.10093 > > > *java.net.BindException: > > > Cannot assign requested address* > > > 2018-05-28_07:38:59.10093 at > > > java.net.PlainSocketImpl.socketBind(Native > > > Method) > > > 2018-05-28_07:38:59.10093 at > > > java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.java: > 382) > > > 2018-05-28_07:38:59.10093 at > > > java.net.ServerSocket.bind(ServerSocket.java:375) > > > 2018-05-28_07:38:59.10094 at > > > java.net.ServerSocket.bind(ServerSocket.java:329) > > > 2018-05-28_07:38:59.10094 at > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$ > > > Listener.run(QuorumCnxManager.java:739) > > > 2018-05-28_07:39:00.10155 2018-05-28 07:39:00,101 [myid:2] - INFO > > > [/1.1.1.143:3888:QuorumCnxManager$Listener@773] - Leaving > > > listener > > > 2018-05-28_07:39:00.10186 2018-05-28 07:39:00,101 [myid:2] - ERROR > > > [/1.1.1.143:3888:QuorumCnxManager$Listener@775] - *As I'm leaving the > > > listener thread, I won't be able to participate in leader election any > > > longer: /1.1.1.143:3888 <http://1.1.1.143:3888>* > > > > > > > > > > > > R > > > > > > > > > > > -- > > Ben Wood > > Software Engineer - Data Agility > > Mesosphere > > > > > > -- > Raghav >
