Leader throws continuous exceptions when starting a Follower

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Leader throws continuous exceptions when starting a Follower

Cantrell, Curtis
We have a 5 server farm.   This behavior has happened before, and it has brought our servers to their knees...    But today I was manually working and made it happen.

We are running zookeeper-3.5.2-alpha on Red Hat Enterprise Linux Server release 6.8

All five are running.
#1 Following
#2. Following
#3. Following
#4. LEADING
#5. Following

2017-03-23 09:26:40  I stoped #1 with /bin/zkServer.sh stop   to adjust the log levels in log4j.properties

2017-03-23 09:31:47 I started #1 with /bin/zkServer.sh start

All the Logs went CRAZY...   ( I have added the Log snippets)

It was not until I stopped #1 again, that the logs settled back down.

I tried to Start #1 again.... The same thing happened.  All the logs went crazy, so I stopped #1

Seeing that the Leader was saying GOODBYE over and over, I decided to stop the Leader.  

I stopped #4 with /bin/zkServer.sh stop..   Everything seemed fine.  At this point we have 3 of the 5 zookeepers running.

I started #4 with /bin/zkServer.sh start.   Everything was fine.  #4 entered the ensemble.

I went back and started #1.   This time, #1 entered the ensemble as normal.

What in the world can cause the entire ensemble go into the infinite kind of error condition..

Below are the parts of each log when I attempted to restart #1 after it being shut down for only 3 minutes.


#04 LEADER LOGS At Stratup of #1
The Leader logged this over and over 1000's of times.
2017-03-23 09:31:47,441 [myid:4] - INFO  [jtcprflegwap04/10.49.129.7:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:44018
2017-03-23 09:31:47,462 [myid:4] - INFO  [WorkerReceiver[myid=4]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LEADING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,501 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38020:LearnerHandler@382] - Follower sid: 1 : info : jtcprflegwap01:49601:49602:participant
2017-03-23 09:31:47,503 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38020:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x3750000007d minCommittedLog=0x37400000001 lastProcessedZxid=0x3750000007d peerLastZxid=0x0
2017-03-23 09:31:47,506 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38020:LearnerHandler@619] - ******* GOODBYE /10.49.129.4:38020 ********
2017-03-23 09:31:47,512 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38020:ZooKeeperThread@55] - Exception occured from thread LearnerHandler-/10.49.129.4:38020
java.lang.NullPointerException
        at org.apache.zookeeper.server.ZKDatabase.calculateTxnLogSizeLimit(ZKDatabase.java:279)
        at org.apache.zookeeper.server.quorum.LearnerHandler.syncFollower(LearnerHandler.java:753)
        at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:427)
2017-03-23 09:31:47,527 [myid:4] - INFO  [WorkerReceiver[myid=4]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LEADING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,537 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38022:LearnerHandler@382] - Follower sid: 1 : info : jtcprflegwap01:49601:49602:participant
2017-03-23 09:31:47,539 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38022:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x3750000007d minCommittedLog=0x37400000001 lastProcessedZxid=0x3750000007d peerLastZxid=0x0
2017-03-23 09:31:47,540 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38022:LearnerHandler@619] - ******* GOODBYE /10.49.129.4:38022 ********
2017-03-23 09:31:47,542 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38022:ZooKeeperThread@55] - Exception occured from thread LearnerHandler-/10.49.129.4:38022
java.lang.NullPointerException
        at org.apache.zookeeper.server.ZKDatabase.calculateTxnLogSizeLimit(ZKDatabase.java:279)
        at org.apache.zookeeper.server.quorum.LearnerHandler.syncFollower(LearnerHandler.java:753)
        at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:427)
2017-03-23 09:31:47,551 [myid:4] - INFO  [WorkerReceiver[myid=4]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LEADING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,563 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38024:LearnerHandler@382] - Follower sid: 1 : info : jtcprflegwap01:49601:49602:participant
2017-03-23 09:31:47,566 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38024:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x3750000007d minCommittedLog=0x37400000001 lastProcessedZxid=0x3750000007d peerLastZxid=0x0
2017-03-23 09:31:47,567 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38024:LearnerHandler@619] - ******* GOODBYE /10.49.129.4:38024 ********
2017-03-23 09:31:47,568 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38024:ZooKeeperThread@55] - Exception occured from thread LearnerHandler-/10.49.129.4:38024
java.lang.NullPointerException
        at org.apache.zookeeper.server.ZKDatabase.calculateTxnLogSizeLimit(ZKDatabase.java:279)
        at org.apache.zookeeper.server.quorum.LearnerHandler.syncFollower(LearnerHandler.java:753)
        at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:427)



#02 FOLLOWER LOGS At Stratup of #1
A single connection request and then 1000's of FastLeaderElection messges

2017-03-23 09:31:47,571 [myid:2] - INFO  [jtcprflegwap02/10.49.129.5:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:45670
2017-03-23 09:31:47,600 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,667 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,690 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)



#03 FOLLOWER LOGS At Stratup of #1
A single connection request and then 1000's of FastLeaderElection messges

2017-03-23 09:31:47,558 [myid:3] - INFO  [jtcprflegwap03/10.49.129.6:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:40956
2017-03-23 09:31:47,575 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,647 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)


#05 FOLLOWER LOGS At Stratup of #1
A single connection request and then 1000's of FastLeaderElection messages

2017-03-23 09:31:47,467 [myid:5] - INFO  [jtcprflegwdm01/10.49.193.109:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:57884
2017-03-23 09:31:47,486 [myid:5] - INFO  [WorkerReceiver[myid=5]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,548 [myid:5] - INFO  [WorkerReceiver[myid=5]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)




#01 FOLLOWING Again after STARTING it up....
As soon as it started following the Leader, an Exception occurred and it disconnected.. only to do it again.. 1000's of times.

2017-03-23 09:31:47,365 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,367 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 20 MS
2017-03-23 09:31:47,399 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,406 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,407 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
2017-03-23 09:31:47,408 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1158] - PeerState set to LOOKING
2017-03-23 09:31:47,408 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1033] - LOOKING
2017-03-23 09:31:47,409 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FastLeaderElection@894] - New election. My id =  1, proposed zxid=0x0
2017-03-23 09:31:47,410 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,415 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,416 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,416 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 5 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,417 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1109] - FOLLOWING
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@858] - minSessionTimeout set to 4000
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@867] - maxSessionTimeout set to 40000
2017-03-23 09:31:47,419 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,419 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 1 MS
2017-03-23 09:31:47,427 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,429 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,429 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
2017-03-23 09:31:47,430 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1158] - PeerState set to LOOKING
2017-03-23 09:31:47,430 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1033] - LOOKING
2017-03-23 09:31:47,431 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FastLeaderElection@894] - New election. My id =  1, proposed zxid=0x0
2017-03-23 09:31:47,434 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,439 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,441 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,443 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,444 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 5 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,444 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
2017-03-23 09:31:47,445 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1109] - FOLLOWING
2017-03-23 09:31:47,445 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@858] - minSessionTimeout set to 4000
2017-03-23 09:31:47,445 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@867] - maxSessionTimeout set to 40000
2017-03-23 09:31:47,446 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,446 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 1 MS
2017-03-23 09:31:47,454 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,456 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,457 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
2017-03-23 09:31:47,457 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1158] - PeerState set to LOOKING
2017-03-23 09:31:47,457 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1033] - LOOKING
2017-03-23 09:31:47,458 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FastLeaderElection@894] - New election. My id =  1, proposed zxid=0x0
2017-03-23 09:31:47,462 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,464 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,465 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 5 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,466 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,467 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,467 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1109] - FOLLOWING
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@858] - minSessionTimeout set to 4000
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@867] - maxSessionTimeout set to 40000
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 0 MS
2017-03-23 09:31:47,476 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,477 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,477 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)



Thank you,
Curtis Cantrell




The information contained in this message is proprietary and/or confidential. If you are not the intended recipient, please: (i) delete the message and all copies; (ii) do not disclose, distribute or use the message in any manner; and (iii) notify the sender immediately. In addition, please be aware that any message addressed to our domain is subject to archiving and review by persons other than the intended recipient. Thank you.

Reply | Threaded
Open this post in threaded view
|

RE: Leader throws continuous exceptions when starting a Follower

Cantrell, Curtis
I found this in the user list.  It seems to be the EXACT same problem...

http://zookeeper-user.578899.n2.nabble.com/NullPointerException-in-ZKDatabase-calculateTxnLogSizeLimit-td7581143.html

A while back, we had an issue in our code that was causing the node structure grow unwantedly which, in turn, was making the snapshots get really big.

The problem in the code was fix, but there was also a command added to the zookeeper startup script to delete the snapshots and translogs.

This really seems to be some kind of problem with a missing snapshot, if the link above is related.

I looked at the servers and there are no snapshot files....  


Thank you,
Curtis Cantrell


-----Original Message-----
From: Cantrell, Curtis [mailto:[hidden email]]
Sent: Thursday, March 23, 2017 11:03 AM
To: [hidden email]
Subject: Leader throws continuous exceptions when starting a Follower

We have a 5 server farm.   This behavior has happened before, and it has brought our servers to their knees...    But today I was manually working and made it happen.

We are running zookeeper-3.5.2-alpha on Red Hat Enterprise Linux Server release 6.8

All five are running.
#1 Following
#2. Following
#3. Following
#4. LEADING
#5. Following

2017-03-23 09:26:40  I stoped #1 with /bin/zkServer.sh stop   to adjust the log levels in log4j.properties

2017-03-23 09:31:47 I started #1 with /bin/zkServer.sh start

All the Logs went CRAZY...   ( I have added the Log snippets)

It was not until I stopped #1 again, that the logs settled back down.

I tried to Start #1 again.... The same thing happened.  All the logs went crazy, so I stopped #1

Seeing that the Leader was saying GOODBYE over and over, I decided to stop the Leader.  

I stopped #4 with /bin/zkServer.sh stop..   Everything seemed fine.  At this point we have 3 of the 5 zookeepers running.

I started #4 with /bin/zkServer.sh start.   Everything was fine.  #4 entered the ensemble.

I went back and started #1.   This time, #1 entered the ensemble as normal.

What in the world can cause the entire ensemble go into the infinite kind of error condition..

Below are the parts of each log when I attempted to restart #1 after it being shut down for only 3 minutes.


#04 LEADER LOGS At Stratup of #1
The Leader logged this over and over 1000's of times.
2017-03-23 09:31:47,441 [myid:4] - INFO  [jtcprflegwap04/10.49.129.7:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:44018
2017-03-23 09:31:47,462 [myid:4] - INFO  [WorkerReceiver[myid=4]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LEADING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,501 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38020:LearnerHandler@382] - Follower sid: 1 : info : jtcprflegwap01:49601:49602:participant
2017-03-23 09:31:47,503 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38020:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x3750000007d minCommittedLog=0x37400000001 lastProcessedZxid=0x3750000007d peerLastZxid=0x0
2017-03-23 09:31:47,506 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38020:LearnerHandler@619] - ******* GOODBYE /10.49.129.4:38020 ********
2017-03-23 09:31:47,512 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38020:ZooKeeperThread@55] - Exception occured from thread LearnerHandler-/10.49.129.4:38020 java.lang.NullPointerException
        at org.apache.zookeeper.server.ZKDatabase.calculateTxnLogSizeLimit(ZKDatabase.java:279)
        at org.apache.zookeeper.server.quorum.LearnerHandler.syncFollower(LearnerHandler.java:753)
        at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:427)
2017-03-23 09:31:47,527 [myid:4] - INFO  [WorkerReceiver[myid=4]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LEADING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,537 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38022:LearnerHandler@382] - Follower sid: 1 : info : jtcprflegwap01:49601:49602:participant
2017-03-23 09:31:47,539 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38022:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x3750000007d minCommittedLog=0x37400000001 lastProcessedZxid=0x3750000007d peerLastZxid=0x0
2017-03-23 09:31:47,540 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38022:LearnerHandler@619] - ******* GOODBYE /10.49.129.4:38022 ********
2017-03-23 09:31:47,542 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38022:ZooKeeperThread@55] - Exception occured from thread LearnerHandler-/10.49.129.4:38022 java.lang.NullPointerException
        at org.apache.zookeeper.server.ZKDatabase.calculateTxnLogSizeLimit(ZKDatabase.java:279)
        at org.apache.zookeeper.server.quorum.LearnerHandler.syncFollower(LearnerHandler.java:753)
        at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:427)
2017-03-23 09:31:47,551 [myid:4] - INFO  [WorkerReceiver[myid=4]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LEADING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,563 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38024:LearnerHandler@382] - Follower sid: 1 : info : jtcprflegwap01:49601:49602:participant
2017-03-23 09:31:47,566 [myid:4] - INFO  [LearnerHandler-/10.49.129.4:38024:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x3750000007d minCommittedLog=0x37400000001 lastProcessedZxid=0x3750000007d peerLastZxid=0x0
2017-03-23 09:31:47,567 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38024:LearnerHandler@619] - ******* GOODBYE /10.49.129.4:38024 ********
2017-03-23 09:31:47,568 [myid:4] - WARN  [LearnerHandler-/10.49.129.4:38024:ZooKeeperThread@55] - Exception occured from thread LearnerHandler-/10.49.129.4:38024 java.lang.NullPointerException
        at org.apache.zookeeper.server.ZKDatabase.calculateTxnLogSizeLimit(ZKDatabase.java:279)
        at org.apache.zookeeper.server.quorum.LearnerHandler.syncFollower(LearnerHandler.java:753)
        at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:427)



#02 FOLLOWER LOGS At Stratup of #1
A single connection request and then 1000's of FastLeaderElection messges

2017-03-23 09:31:47,571 [myid:2] - INFO  [jtcprflegwap02/10.49.129.5:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:45670
2017-03-23 09:31:47,600 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,667 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,690 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)



#03 FOLLOWER LOGS At Stratup of #1
A single connection request and then 1000's of FastLeaderElection messges

2017-03-23 09:31:47,558 [myid:3] - INFO  [jtcprflegwap03/10.49.129.6:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:40956
2017-03-23 09:31:47,575 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,647 [myid:3] - INFO  [WorkerReceiver[myid=3]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)


#05 FOLLOWER LOGS At Stratup of #1
A single connection request and then 1000's of FastLeaderElection messages

2017-03-23 09:31:47,467 [myid:5] - INFO  [jtcprflegwdm01/10.49.193.109:49602:QuorumCnxManager$Listener@637] - Received connection request /10.49.129.4:57884
2017-03-23 09:31:47,486 [myid:5] - INFO  [WorkerReceiver[myid=5]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,548 [myid:5] - INFO  [WorkerReceiver[myid=5]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)




#01 FOLLOWING Again after STARTING it up....
As soon as it started following the Leader, an Exception occurred and it disconnected.. only to do it again.. 1000's of times.

2017-03-23 09:31:47,365 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,367 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 20 MS
2017-03-23 09:31:47,399 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,406 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,407 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
2017-03-23 09:31:47,408 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1158] - PeerState set to LOOKING
2017-03-23 09:31:47,408 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1033] - LOOKING
2017-03-23 09:31:47,409 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FastLeaderElection@894] - New election. My id =  1, proposed zxid=0x0
2017-03-23 09:31:47,410 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,415 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,416 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,416 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 5 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,417 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1109] - FOLLOWING
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@858] - minSessionTimeout set to 4000
2017-03-23 09:31:47,418 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@867] - maxSessionTimeout set to 40000
2017-03-23 09:31:47,419 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,419 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 1 MS
2017-03-23 09:31:47,427 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,429 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,429 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
2017-03-23 09:31:47,430 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1158] - PeerState set to LOOKING
2017-03-23 09:31:47,430 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1033] - LOOKING
2017-03-23 09:31:47,431 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FastLeaderElection@894] - New election. My id =  1, proposed zxid=0x0
2017-03-23 09:31:47,434 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,439 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,441 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,443 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,444 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 5 (n.sid), 0x375 (n.peerEPoch), FOLLOWING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,444 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
2017-03-23 09:31:47,445 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1109] - FOLLOWING
2017-03-23 09:31:47,445 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@858] - minSessionTimeout set to 4000
2017-03-23 09:31:47,445 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@867] - maxSessionTimeout set to 40000
2017-03-23 09:31:47,446 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,446 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 1 MS
2017-03-23 09:31:47,454 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,456 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,457 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
2017-03-23 09:31:47,457 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1158] - PeerState set to LOOKING
2017-03-23 09:31:47,457 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1033] - LOOKING
2017-03-23 09:31:47,458 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FastLeaderElection@894] - New election. My id =  1, proposed zxid=0x0
2017-03-23 09:31:47,462 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x0 (n.round), LOOKING (n.state), 1 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,464 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 2 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,465 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 5 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,466 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), FOLLOWING (n.state), 3 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,467 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message format version), 4 (n.leader), 0x37400000020 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 4 (n.sid), 0x375 (n.peerEPoch), LOOKING (my state)36f00000000 (n.config version)
2017-03-23 09:31:47,467 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1109] - FOLLOWING
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@858] - minSessionTimeout set to 4000
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@867] - maxSessionTimeout set to 40000
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /opt/eg/zookeeper/tranlog/version-2 snapdir /opt/eg/zookeeper/data/version-2
2017-03-23 09:31:47,468 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 0 MS
2017-03-23 09:31:47,476 [myid:1] - WARN  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93] - Exception when following the leader java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
        at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:361)
        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:86)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
2017-03-23 09:31:47,477 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
2017-03-23 09:31:47,477 [myid:1] - INFO  [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@198] - shutdown called
java.lang.Exception: shutdown Follower
        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)



Thank you,
Curtis Cantrell




The information contained in this message is proprietary and/or confidential. If you are not the intended recipient, please: (i) delete the message and all copies; (ii) do not disclose, distribute or use the message in any manner; and (iii) notify the sender immediately. In addition, please be aware that any message addressed to our domain is subject to archiving and review by persons other than the intended recipient. Thank you.


IMPORTANT- This message sourced from an external mail server outside of BKFS

The information contained in this message is proprietary and/or confidential. If you are not the intended recipient, please: (i) delete the message and all copies; (ii) do not disclose, distribute or use the message in any manner; and (iii) notify the sender immediately. In addition, please be aware that any message addressed to our domain is subject to archiving and review by persons other than the intended recipient. Thank you.