Hello,
I'm wondering what can cause a ZK follower to check out like this:
2018-07-03T13:43:28,814 [myid:] - ERROR [LearnerHandler-/10.0.0.248:40282
:LearnerHandler@620] - Unexpected exception causing shutdown while sock
still open
java.io.EOFException: null
at java.io.DataInputStream.readInt(DataInputStream.java:392)
~[?:1.8.0_171]
at
org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
at
org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
~[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
at
org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:514)
[zookeeper-3.5.0-alpha.jar:?]
2018-07-03T13:43:28,814 [myid:] - WARN [LearnerHandler-/10.0.0.248:40282
:LearnerHandler@635] - ******* GOODBYE /10.0.0.248:40282 ********
2018-07-03T13:43:28,814 [myid:] - ERROR [LearnerHandler-/10.0.0.237:54408
:LearnerHandler@620] - Unexpected exception causing shutdown while sock
still open
java.io.EOFException: null
at java.io.DataInputStream.readInt(DataInputStream.java:392)
~[?:1.8.0_171]
at
org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
at
org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
~[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
~[zookeeper-3.5.0-alpha.jar:3.5.2-alpha-SNAPSHOT-1702518]
at
org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:514)
[zookeeper-3.5.0-alpha.jar:?]
2018-07-03T13:43:28,814 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:46754
2018-07-03T13:43:28,814 [myid:] - WARN [LearnerHandler-/10.0.0.237:54408
:LearnerHandler@635] - ******* GOODBYE /10.0.0.237:54408 ********
2018-07-03T13:43:28,814 [myid:] - INFO
[ConnnectionExpirer:MBeanRegistry@128] - Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=10.0.0.111,name5=0x200005f37660000]
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33198
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:46780
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33268
2018-07-03T13:43:28,815 [myid:] - INFO
[ConnnectionExpirer:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.111:39162 which had sessionid 0x200005f37660000
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:46810
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:46824
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:46826
2018-07-03T13:43:28,815 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@613]
- Shutting down
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33316
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33548
2018-07-03T13:43:28,815 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@619]
- Shutdown called
java.lang.Exception: shutdown Leader! reason: Not sufficient followers
synced, only synced with sids: [ [2] ]
at
org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:619)
[zookeeper-3.5.0-alpha.jar:?]
at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:590)
[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1077)
[zookeeper-3.5.0-alpha.jar:?]
2018-07-03T13:43:28,815 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:33198 (no session
established for client)
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
- Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=10.0.0.237,name5=0x20000629130001b]
2018-07-03T13:43:28,815 [myid:] - INFO
[WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message
format version), 3 (n.leader), 0x9000001cb (n.zxid), 0x0 (n.round), LOOKING
(n.state), 3 (n.sid), 0x9 (n.peerEPoch), LEADING (my state)300000066
(n.config version)
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.237:45602 which had sessionid
0x20000629130001b
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
- Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=10.0.0.248,name5=0x2000005cf2a0008]
2018-07-03T13:43:28,816 [myid:] - INFO
[WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message
format version), 3 (n.leader), 0x9000001cb (n.zxid), 0x7 (n.round), LOOKING
(n.state), 3 (n.sid), 0x9 (n.peerEPoch), LEADING (my state)300000066
(n.config version)
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:53764 which had sessionid
0x2000005cf2a0008
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:33268 (no session
established for client)
2018-07-03T13:43:28,816 [myid:] - WARN
[NIOWorkerThread-20:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
- Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=10.0.0.248,name5=0x2000005cf2a000a]
2018-07-03T13:43:28,816 [myid:] - INFO
[NIOWorkerThread-20:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.237:46826 (no session established for client)
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:53758 which had sessionid
0x2000005cf2a000a
2018-07-03T13:43:28,816 [myid:] - INFO
[LearnerCnxAcceptor-0.0.0.0/0.0.0.0:2888:Leader$LearnerCnxAcceptor@373] -
exception while shutting down acceptor: java.net.SocketException: Socket
closed
2018-07-03T13:43:28,816 [myid:] - WARN
[NIOWorkerThread-20:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T13:43:28,816 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
- Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=10.0.0.248,name5=0x30000209a080002]
2018-07-03T13:43:28,816 [myid:] - INFO
[NIOWorkerThread-20:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.237:46810 (no session established for client)
2018-07-03T13:43:28,817 [myid:] - WARN [NIOWorkerThread-6:NIOServerCnxn@369]
- Exception causing close of session 0x0: ZooKeeperServer not running
2018-07-03T13:43:28,817 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:53760 which had sessionid
0x30000209a080002
2018-07-03T13:43:28,817 [myid:] - INFO [NIOWorkerThread-6:NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.237:46780 (no session
established for client)
2018-07-03T13:43:28,817 [myid:] - WARN [NIOWorkerThread-4:NIOServerCnxn@369]
- Exception causing close of session 0x0: ZooKeeperServer not running
2018-07-03T13:43:28,817 [myid:] - INFO [SessionTracker:ZooKeeperServer@384]
- Expiring session 0x300006dbd91000b, timeout of 15000ms exceeded
2018-07-03T13:43:28,817 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@498]
- shutting down
2018-07-03T13:43:28,817 [myid:] - INFO [NIOWorkerThread-4:NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:33548 (no session
established for client)
2018-07-03T13:43:28,817 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):SessionTrackerImpl@232]
- Shutting down
2018-07-03T13:43:28,817 [myid:] - INFO
[SessionTracker:QuorumZooKeeperServer@132] - Submitting global closeSession
request for session 0x300006dbd91000b
2018-07-03T13:43:28,817 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):LeaderRequestProcessor@77]
- Shutting down
2018-07-03T13:43:28,817 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):PrepRequestProcessor@967]
- Shutting down
2018-07-03T13:43:28,817 [myid:] - INFO
[SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
2018-07-03T13:43:28,817 [myid:] - INFO [ProcessThread(sid:2
cport:-1)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
2018-07-03T13:43:28,815 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:46908
2018-07-03T13:43:28,817 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33786
2018-07-03T13:43:28,817 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:46954
2018-07-03T13:43:28,817 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33992
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47010
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34240
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47084
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47142
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47248
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34532
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47314
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47342
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47384
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34706
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47452
2018-07-03T13:43:28,818 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47496
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47512
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34878
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47580
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47620
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35086
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47700
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47748
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47772
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47886
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47894
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47920
2018-07-03T13:43:28,819 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:47998
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48018
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48020
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48136
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48138
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48140
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48172
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35898
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48294
2018-07-03T13:43:28,820 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48296
2018-07-03T13:43:28,817 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ProposalRequestProcessor@88]
- Shutting down
2018-07-03T13:43:28,816 [myid:] - INFO
[WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message
format version), 1 (n.leader), 0x9000001cb (n.zxid), 0x7 (n.round), LOOKING
(n.state), 1 (n.sid), 0x9 (n.peerEPoch), LEADING (my state)300000066
(n.config version)
2018-07-03T13:43:28,817 [myid:] - WARN
[NIOWorkerThread-20:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T13:43:28,821 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48298
2018-07-03T13:43:28,821 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):CommitProcessor@358]
- Shutting down
2018-07-03T13:43:28,821 [myid:] - INFO
[NIOWorkerThread-20:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.237:46754 (no session established for client)
2018-07-03T13:43:28,821 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:48334
2018-07-03T13:43:28,821 [myid:] - INFO
[CommitProcessor:2:CommitProcessor@193] - CommitProcessor exited loop!
2018-07-03T13:43:28,821 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:36162
2018-07-03T13:43:28,821 [myid:] - WARN
[NIOWorkerThread-20:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T13:43:28,821 [myid:] - WARN
[NIOWorkerThread-16:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T13:43:28,821 [myid:] - WARN
[NIOWorkerThread-31:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T13:43:28,821 [myid:] - WARN
[NIOWorkerThread-11:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
The rest are more failed clients connections attempts and "ZooKeeperServer
not running" messages for hours.
There was an event before that that could be linked:
2018-07-03T12:42:27,639 [myid:] - INFO [NIOWorkerThread-7:NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.237:35536 (no session
established for client)
2018-07-03T12:47:28,864 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33256
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:35568
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33544
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:35672
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:33788
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:35756
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34014
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:35840
2018-07-03T12:47:28,865 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34244
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:35924
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34466
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:35994
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34730
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36086
2018-07-03T12:47:28,866 [myid:] - WARN
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Follower@93]
- Exception when following the leader
java.net.SocketException: Broken pipe (Write failed)
at java.net.SocketOutputStream.socketWrite0(Native Method)
~[?:1.8.0_171]
at
java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
~[?:1.8.0_171]
at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
~[?:1.8.0_171]
at
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
~[?:1.8.0_171]
at
java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
~[?:1.8.0_171]
at
org.apache.zookeeper.server.quorum.Learner.writePacket(Learner.java:141)
~[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.Learner.ping(Learner.java:609)
~[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.Follower.processPacket(Follower.java:116)
~[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:90)
[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1064)
[zookeeper-3.5.0-alpha.jar:?]
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34944
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36166
2018-07-03T12:47:28,866 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
- Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Follower]
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:34952
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36172
2018-07-03T12:47:28,866 [myid:] - INFO
[QuorumPeer[myid=2](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)
[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1068)
[zookeeper-3.5.0-alpha.jar:?]
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35178
2018-07-03T12:47:28,866 [myid:] - INFO
[NIOWorkerThread-14:ZooKeeperServer@969] - Client attempting to establish
new session at /10.0.0.248:33256
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36262
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35244
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36276
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35396
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36334
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35472
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36368
2018-07-03T12:47:28,867 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35708
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36446
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:35930
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36530
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:36150
2018-07-03T12:47:28,867 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:33544 (no session
established for client)
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36608
2018-07-03T12:47:28,868 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /10.0.0.248:33256 which had sessionid
0x200003aa13c0010
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36692
2018-07-03T12:47:28,868 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):LearnerZooKeeperServer@167]
- Shutting down
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.248:36418
2018-07-03T12:47:28,868 [myid:] - ERROR
[FollowerRequestProcessor:2:ZooKeeperCriticalThread@48] - Severe
unrecoverable error, from thread : FollowerRequestProcessor:2
java.net.SocketException: Socket closed
at
java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118)
~[?:1.8.0_171]
at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
~[?:1.8.0_171]
at
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
~[?:1.8.0_171]
at
java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
~[?:1.8.0_171]
at
org.apache.zookeeper.server.quorum.Learner.writePacket(Learner.java:141)
~[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.Learner.request(Learner.java:190)
~[zookeeper-3.5.0-alpha.jar:?]
at
org.apache.zookeeper.server.quorum.FollowerRequestProcessor.run(FollowerRequestProcessor.java:101)
[zookeeper-3.5.0-alpha.jar:?]
2018-07-03T12:47:28,868 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@498]
- shutting down
2018-07-03T12:47:28,868 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FollowerRequestProcessor@138]
- Shutting down
2018-07-03T12:47:28,868 [myid:] - INFO
[FollowerRequestProcessor:2:ZooKeeperServer$ZooKeeperServerListenerImpl@475]
- Thread FollowerRequestProcessor:2 exits, error code 1
2018-07-03T12:47:28,868 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):CommitProcessor@358]
- Shutting down
2018-07-03T12:47:28,869 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FinalRequestProcessor@492]
- shutdown of request processor complete
2018-07-03T12:47:28,869 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):MBeanRegistry@128]
- Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Follower,name3=InMemoryDataTree]
2018-07-03T12:47:28,870 [myid:] - INFO
[QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):SyncRequestProcessor@191]
- Shutting down
2018-07-03T12:47:28,870 [myid:] - WARN
[NIOWorkerThread-17:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T12:47:28,870 [myid:] - INFO
[NIOWorkerThread-17:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.248:34952 (no session established for client)
2018-07-03T12:47:28,870 [myid:] - WARN
[NIOWorkerThread-17:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T12:47:28,870 [myid:] - INFO
[NIOWorkerThread-17:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.248:34014 (no session established for client)
2018-07-03T12:47:28,870 [myid:] - WARN
[NIOWorkerThread-32:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T12:47:28,868 [myid:] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181
:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /
10.0.0.237:36766
2018-07-03T12:47:28,871 [myid:] - INFO
[NIOWorkerThread-32:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.248:36150 (no session established for client)
2018-07-03T12:47:28,871 [myid:] - WARN
[NIOWorkerThread-32:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T12:47:28,871 [myid:] - WARN
[NIOWorkerThread-17:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T12:47:28,871 [myid:] - INFO
[NIOWorkerThread-32:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.248:33788 (no session established for client)
2018-07-03T12:47:28,871 [myid:] - INFO
[NIOWorkerThread-17:NIOServerCnxn@606] - Closed socket connection for
client /10.0.0.248:35930 (no session established for client)
2018-07-03T12:47:28,871 [myid:] - WARN
[NIOWorkerThread-32:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T12:47:28,871 [myid:] - WARN
[NIOWorkerThread-17:NIOServerCnxn@369] - Exception causing close of session
0x0: ZooKeeperServer not running
2018-07-03T12:47:28,871 [myid:] - INFO
[CommitProcessor:2:CommitProcessor@193] - CommitProcessor exited loop!
In particular I don't like the sound of this "Severe unrecoverable error,
from thread : FollowerRequestProcessor" from "ZooKeeperCriticalThread".
Is this a fatal event for the whole ZK server?
Thanks
Benjamin
