Thanks for the logs! I'm far for digging deep enough (unfortunately I don't have much time right now). A few observations:
(1) Looks like we have a problem with the order of the leader election notifications. Here for example we get the message from round 0xf8 before the one from the previous round (0xf7): I would assume the leader election protocol should handle this (although I haven't checked this). 2021-02-27 11:42:39,432] INFO Notification: 2 (message format version), 102 (n.leader), 0x2800000866 (n.zxid), 0xf8 (n.round), LOOKING (n.state), 102 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) (org.apache.zookeeper.server.quorum.FastLeaderElection) [2021-02-27 11:42:39,434] INFO Notification: 2 (message format version), 103 (n.leader), 0x2700000611 (n.zxid), 0xf7 (n.round), FOLLOWING (n.state), 102 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) (org.apache.zookeeper.server.quorum.FastLeaderElection) We saw cases when the kubernetes networking mesh was slow to propagate a socket close between quorum members and this caused problems. I wonder if this would be some similar issue... If this is indeed some Kubernetes specific issue, then it will be hard to reproduce. But we can give a try. (2) In the leader election started on 2021-02-28 09:11:38,133, we see that the server (id=111) sent out notifications, but haven't received any from the other servers. We should check the logs of the other two servers, check if they even get the notifications. We saw cases (e.g. ZOOKEEPER-3769 fixed in 3.5.8) when the other server hasn't received the notification due to some receiver thread dying. E.g. we could check the other servers for log message: 03/24/20 11:16:16,297 [WorkerReceiver[myid=1]] ERROR [org.apache.zookeeper.server.NIOServerCnxnFactory] (NIOServerCnxnFactory.java:92) - Thread Thread[WorkerReceiver[myid=1],5,main] died There were some other related changes in more recent ZooKeeper versions (ZOOKEEPER-3756, ZOOKEEPER-2164). So it is possible that if you upgrade to a more recent ZooKeeper version, then you won't see this problem again. But it is hard to tell, until we found out what exactly happened. I think it would be good to create a new Jira ticket for this. Could you maybe create it, and also attach all the logs from the three ZooKeeper servers since the last restart? Also, can you attach the ZooKeeper configuration? Please ping me on the ticket or assign it to me and I'm happy to check this further. (although I will be slow due to other projects) Best Regards, Mate On Tue, Mar 2, 2021 at 12:51 PM Jhanssen Fávaro <jhanssenfav...@gmail.com> wrote: > Hi, Mate! Thanks by the reply! > > > Which ZooKeeper version are youusing? > This is the current ZK Version we're using, "*INFO Server > environment:zookeeper.version=3.5.7*". We're still planning the migration > to 3.6 in a few weeks. > > > 2021-02-28 09:11:38,119 and after the previous successful leader > election? > Sure, follow the logs, but after our last restart ( [2021-02-18 > 11:38:34,316] ) there was only one exception/wan(Sorry by the flooding > logs): > > > > *#############################################################All messages > before these were related to Purge task started / Purge task completed. > #############################################################* > [2021-02-27 08:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 09:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 09:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 09:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 10:38:33,006] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 10:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 10:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 11:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 11:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 11:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 11:42:39,139] INFO Received connection request from / > 10.1.1.93:43572 (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 11:42:39,293] INFO Accepted TLS connection from > zk-xpto-b7.production.com/10.1.1.93:43572 - TLSv1.2 - > TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256 > (org.apache.zookeeper.server.quorum.UnifiedServerSocket) > [2021-02-27 11:42:39,298] INFO Successfully authenticated learner: > authenticationID=quorum-zkxpto-prod; authorizationID=quorum-zkxpto-prod. > (org.apache.zookeeper.server.quorum.auth.SaslQuorumServerCallbackHandler) > [2021-02-27 11:42:39,299] INFO Successfully completed the authentication > using SASL. learner addr: zk-xpto-b7.production.com/10.1.1.93:43572 > (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthServer) > [2021-02-27 11:42:39,301] WARN Interrupted while waiting for message on > queue (org.apache.zookeeper.server.quorum.QuorumCnxManager) > java.lang.InterruptedException > at > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) > at > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:1308) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$700(QuorumCnxManager.java:85) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:1143) > [2021-02-27 11:42:39,304] WARN Send worker leaving thread id 102 my id = > 111 (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 11:42:39,303] WARN Connection broken for id 102, my id = 111, > error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) > javax.net.ssl.SSLException: Socket closed > at sun.security.ssl.Alert.createSSLException(Alert.java:127) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:324) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:267) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:262) > at > sun.security.ssl.SSLSocketImpl.handleException(SSLSocketImpl.java:1303) > at sun.security.ssl.SSLSocketImpl.access$300(SSLSocketImpl.java:72) > at > sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:831) > at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) > at java.io.BufferedInputStream.read(BufferedInputStream.java:265) > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:1226) > Caused by: java.net.SocketException: Socket closed > at java.net.SocketInputStream.socketRead0(Native Method) > at > java.net.SocketInputStream.socketRead(SocketInputStream.java:116) > at java.net.SocketInputStream.read(SocketInputStream.java:171) > at java.net.SocketInputStream.read(SocketInputStream.java:141) > at > sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:457) > at > > sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68) > at > > sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1095) > at sun.security.ssl.SSLSocketImpl.access$200(SSLSocketImpl.java:72) > at > sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:815) > ... 4 more > [2021-02-27 11:42:39,312] WARN Interrupting SendWorker thread from > RecvWorker. sid: 102. myId: 111 > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 11:42:39,425] INFO SSL handshake complete with > zk-xpto-b7.production.com/10.1.1.93:3888 - TLSv1.2 - > TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256 > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 11:42:39,425] INFO QuorumLearner will use DIGEST-MD5 as SASL > mechanism. (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-27 11:42:39,429] INFO Successfully completed the authentication > using SASL. server addr: zk-xpto-b7.production.com/10.1.1.93:3888, status: > SUCCESS (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-27 11:42:39,432] INFO Notification: 2 (message format version), > 102 (n.leader), 0x2800000866 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 102 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-27 11:42:39,434] INFO Notification: 2 (message format version), > 103 (n.leader), 0x2700000611 (n.zxid), 0xf7 (n.round), FOLLOWING (n.state), > 102 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-27 12:29:51,962] INFO Received connection request from / > 10.1.1.92:35532 (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 12:29:52,084] INFO Accepted TLS connection from > 10.1.1.92:35532 > - TLSv1.2 - TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256 > (org.apache.zookeeper.server.quorum.UnifiedServerSocket) > [2021-02-27 12:29:52,088] INFO Successfully authenticated learner: > authenticationID=quorum-zkxpto-prod; authorizationID=quorum-zkxpto-prod. > (org.apache.zookeeper.server.quorum.auth.SaslQuorumServerCallbackHandler) > [2021-02-27 12:29:52,088] INFO Successfully completed the authentication > using SASL. learner addr: zk-xpto-ae.production.com/10.1.1.92:35532 > (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthServer) > [2021-02-27 12:29:52,088] WARN Interrupted while waiting for message on > queue (org.apache.zookeeper.server.quorum.QuorumCnxManager) > java.lang.InterruptedException > at > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) > at > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:1308) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$700(QuorumCnxManager.java:85) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:1143) > [2021-02-27 12:29:52,088] WARN Connection broken for id 104, my id = 111, > error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) > javax.net.ssl.SSLException: Socket closed > at sun.security.ssl.Alert.createSSLException(Alert.java:127) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:324) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:267) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:262) > at > sun.security.ssl.SSLSocketImpl.handleException(SSLSocketImpl.java:1303) > at sun.security.ssl.SSLSocketImpl.access$300(SSLSocketImpl.java:72) > at > sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:831) > at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) > at java.io.BufferedInputStream.read(BufferedInputStream.java:265) > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > > org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:1226) > Caused by: java.net.SocketException: Socket closed > at java.net.SocketInputStream.socketRead0(Native Method) > at > java.net.SocketInputStream.socketRead(SocketInputStream.java:116) > at java.net.SocketInputStream.read(SocketInputStream.java:171) > at java.net.SocketInputStream.read(SocketInputStream.java:141) > at > sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:457) > at > > sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68) > at > > sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1095) > at sun.security.ssl.SSLSocketImpl.access$200(SSLSocketImpl.java:72) > at > sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:815) > ... 4 more > [2021-02-27 12:29:52,089] WARN Interrupting SendWorker thread from > RecvWorker. sid: 104. myId: 111 > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 12:29:52,089] WARN Send worker leaving thread id 104 my id = > 111 (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 12:29:53,213] INFO SSL handshake complete with > zk-xpto-ae.production.com/10.1.1.92:3888 - TLSv1.2 - > TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256 > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-27 12:29:53,214] INFO QuorumLearner will use DIGEST-MD5 as SASL > mechanism. (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-27 12:29:53,219] INFO Successfully completed the authentication > using SASL. server addr: zk-xpto-ae.production.com/10.1.1.92:3888, status: > SUCCESS (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-27 12:29:53,228] INFO Notification: 2 (message format version), > 104 (n.leader), 0x280000093d (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 104 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-27 12:29:53,230] INFO Notification: 2 (message format version), > 103 (n.leader), 0x2700000611 (n.zxid), 0xf7 (n.round), FOLLOWING (n.state), > 104 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-27 12:38:33,006] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 12:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 12:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 12:54:31,627] INFO Notification: 2 (message format version), > 104 (n.leader), 0x2800000aa1 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 104 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-27 12:54:31,663] INFO Notification: 2 (message format version), > 102 (n.leader), 0x2800000aa1 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 102 (n.sid), 0x28 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-27 13:38:33,006] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 13:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 13:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 14:38:33,006] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 14:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 14:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 15:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 15:38:33,005] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 15:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 16:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 16:38:33,005] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 16:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 17:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 17:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 17:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 18:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 18:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 18:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 19:38:33,006] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 19:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 19:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 20:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 20:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 20:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 21:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 21:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 21:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 22:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 22:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 22:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 23:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-27 23:38:33,005] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-27 23:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 00:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 00:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 00:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 01:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 01:38:33,005] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 01:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 02:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 02:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 02:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 03:38:33,006] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 03:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 03:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 04:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 04:38:33,005] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 04:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 05:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 05:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 05:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 06:38:33,006] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 06:38:33,006] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 06:38:33,007] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 07:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 07:38:33,005] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 07:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 08:38:33,005] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 08:38:33,005] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 08:38:33,006] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > > > *#############################################################Already Sent > Log Chunk#############################################################* > [2021-02-28 09:11:38,119] WARN Exception when following the leader > (org.apache.zookeeper.server.quorum.Learner) > java.io.EOFException > at java.io.DataInputStream.readInt(DataInputStream.java:392) > at > org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:84) > at > > org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:86) > at > org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:118) > at > org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:158) > at > org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:92) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1253) > [2021-02-28 09:11:38,119] WARN Closing connection to leader, exception > during packet send > (org.apache.zookeeper.server.quorum.SendAckRequestProcessor) > javax.net.ssl.SSLException: Connection or outbound has been closed > at sun.security.ssl.Alert.createSSLException(Alert.java:127) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:324) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:267) > at > sun.security.ssl.TransportContext.fatal(TransportContext.java:262) > at > > sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:979) > at > java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) > at > java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) > at > org.apache.zookeeper.server.quorum.Learner.writePacket(Learner.java:144) > at > > org.apache.zookeeper.server.quorum.SendAckRequestProcessor.flush(SendAckRequestProcessor.java:62) > at > > org.apache.zookeeper.server.SyncRequestProcessor.flush(SyncRequestProcessor.java:186) > at > > org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:113) > Caused by: java.net.SocketException: Connection or outbound has been closed > at > > sun.security.ssl.SSLSocketOutputRecord.deliver(SSLSocketOutputRecord.java:267) > at > > sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:974) > ... 6 more > [2021-02-28 09:11:38,120] INFO shutdown called > (org.apache.zookeeper.server.quorum.Learner) > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:201) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1257) > [2021-02-28 09:11:38,120] INFO Shutting down > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:11:38,120] INFO shutting down > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:11:38,120] INFO Shutting down > (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) > [2021-02-28 09:11:38,121] INFO Shutting down > (org.apache.zookeeper.server.quorum.CommitProcessor) > [2021-02-28 09:11:38,121] INFO FollowerRequestProcessor exited loop! > (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) > [2021-02-28 09:11:38,121] INFO CommitProcessor exited loop! > (org.apache.zookeeper.server.quorum.CommitProcessor) > [2021-02-28 09:11:38,123] INFO shutdown of request processor complete > (org.apache.zookeeper.server.FinalRequestProcessor) > [2021-02-28 09:11:38,132] INFO Shutting down > (org.apache.zookeeper.server.SyncRequestProcessor) > [2021-02-28 09:11:38,132] INFO SyncRequestProcessor exited! > (org.apache.zookeeper.server.SyncRequestProcessor) > [2021-02-28 09:11:38,132] WARN PeerState set to LOOKING > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:11:38,132] INFO LOOKING > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:11:38,133] INFO New election. My id = 111, proposed > zxid=0x2800000dd6 (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:38,135] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:38,336] INFO Notification time out: 400 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:38,337] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:38,737] INFO Notification time out: 800 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:38,738] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:39,538] INFO Notification time out: 1600 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:39,539] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:41,139] INFO Notification time out: 3200 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:41,140] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:44,340] INFO Notification time out: 6400 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:44,341] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:50,741] INFO Notification time out: 12800 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:11:50,741] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:12:03,542] INFO Notification time out: 25600 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:12:03,542] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:12:29,142] INFO Notification time out: 51200 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:12:29,143] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:13:20,344] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:13:20,345] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:14:20,345] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:14:20,346] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:15:20,346] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:15:20,347] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:16:20,347] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:16:20,348] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:17:20,348] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:17:20,350] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:18:20,350] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:18:20,351] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:19:20,352] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:19:20,352] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:20:20,353] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:20:20,357] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:21:20,357] INFO Notification time out: 60000 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:21:20,358] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING (n.state), > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > *#############################################################Needed tio > manually restart to force reconnect to the ensemble > cluster.#############################################################* > [2021-02-28 09:21:56,110] INFO Reading configuration from: > /opt/kafka/config/zookeeper.properties > (org.apache.zookeeper.server.quorum.QuorumPeerConfig) > [2021-02-28 09:21:56,113] INFO clientPort is not set > (org.apache.zookeeper.server.quorum.QuorumPeerConfig) > [2021-02-28 09:21:56,115] INFO secureClientPortAddress is 0.0.0.0:3184 > (org.apache.zookeeper.server.quorum.QuorumPeerConfig) > [2021-02-28 09:21:56,118] INFO Setting -D > jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated > TLS renegotiation (org.apache.zookeeper.common.X509Util) > [2021-02-28 09:21:56,126] INFO autopurge.snapRetainCount set to 10 > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 09:21:56,126] INFO autopurge.purgeInterval set to 1 > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 09:21:56,129] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 09:21:56,129] INFO Log4j 1.2 jmx support found and enabled. > (org.apache.zookeeper.jmx.ManagedUtil) > [2021-02-28 09:21:56,135] INFO Starting quorum peer > (org.apache.zookeeper.server.quorum.QuorumPeerMain) > [2021-02-28 09:21:56,137] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 09:21:56,146] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 09:21:56,187] INFO zookeeper.client.portUnification=false > (org.apache.zookeeper.server.NettyServerCnxnFactory) > [2021-02-28 09:21:56,220] INFO Using > org.apache.zookeeper.server.NettyServerCnxnFactory as server connection > factory (org.apache.zookeeper.server.ServerCnxnFactory) > [2021-02-28 09:21:56,228] INFO Server successfully logged in. > (org.apache.zookeeper.Login) > [2021-02-28 09:21:56,242] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 09:21:56,242] INFO Local sessions disabled > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,242] INFO Local session upgrading disabled > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,243] INFO tickTime set to 2000 > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,243] INFO minSessionTimeout set to 4000 > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,243] INFO maxSessionTimeout set to 40000 > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,243] INFO initLimit set to 5 > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,253] INFO zookeeper.snapshotSizeFactor = 0.33 > (org.apache.zookeeper.server.ZKDatabase) > [2021-02-28 09:21:56,255] INFO Using TLS encrypted quorum communication > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO Port unification disabled > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO quorum.auth.enableSasl set to true > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO quorum.auth.serverRequireSasl set to true > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO quorum.auth.learnerRequireSasl set to true > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO quorum.auth.kerberos.servicePrincipal set to > zkquorum/localhost (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO quorum.auth.server.saslLoginContext set to > QuorumServer (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO quorum.auth.learner.saslLoginContext set to > QuorumLearner (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,255] INFO quorum.cnxn.threads.size set to 20 > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,257] INFO QuorumServer successfully logged in. > (org.apache.zookeeper.Login) > [2021-02-28 09:21:56,258] INFO QuorumLearner successfully logged in. > (org.apache.zookeeper.Login) > [2021-02-28 09:21:56,260] INFO Reading snapshot > /zookeeper-datastore/version-2/snapshot.2400000034 > (org.apache.zookeeper.server.persistence.FileSnap) > [2021-02-28 09:21:56,511] INFO binding to port 0.0.0.0/0.0.0.0:3184 > (org.apache.zookeeper.server.NettyServerCnxnFactory) > [2021-02-28 09:21:56,565] INFO bound to port 3184 > (org.apache.zookeeper.server.NettyServerCnxnFactory) > [2021-02-28 09:21:56,571] INFO Election port bind maximum retries is 3 > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-28 09:21:56,574] INFO Creating TLS-only quorum server socket > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-28 09:21:56,575] INFO 111 is accepting connections now, my > election bind port: zk-xpto.production.com/10.1.1.99:3888 > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > [2021-02-28 09:21:56,587] INFO LOOKING > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 09:21:56,592] INFO New election. My id = 111, proposed > zxid=0x2800000dd6 (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > > *#############################################################Messages > after restart#############################################################* > [2021-02-28 09:21:57,508] INFO Server > > environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,508] INFO Server environment:java.io.tmpdir=/tmp > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,508] INFO Server environment:java.compiler=<NA> > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,508] INFO Server environment:os.name=Linux > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,508] INFO Server environment:os.arch=amd64 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,508] INFO Server > environment:os.version=zk_user_xpto_OS_Version.x86_64 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,508] INFO Server environment:user.name=zk_user_xpto > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,516] INFO Server > environment:user.home=/home/zk_user_xpto > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,516] INFO Server environment:user.dir=/ > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,516] INFO Server environment:os.memory.free=492MB > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,516] INFO Server environment:os.memory.max=1024MB > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,516] INFO Server environment:os.memory.total=512MB > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,508] INFO Notification: 2 (message format version), > 103 (n.leader), 0x2800000dd9 (n.zxid), 0xf8 (n.round), FOLLOWING (n.state), > 101 (n.sid), 0x29 (n.peerEPoch), FOLLOWING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 09:21:57,517] INFO minSessionTimeout set to 4000 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,517] INFO maxSessionTimeout set to 40000 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,517] INFO Created server with tickTime 2000 > minSessionTimeout 4000 maxSessionTimeout 40000 datadir > /opt/zookeeper_dir_datalog/version-2 snapdir > /opt/zookeeper_dir_datastore/version-2 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 09:21:57,518] INFO FOLLOWING - LEADER ELECTION TOOK - 19 MS > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 09:21:57,653] INFO QuorumLearner will use DIGEST-MD5 as SASL > mechanism. (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-28 09:21:57,657] INFO Successfully completed the authentication > using SASL. server addr: zk-xpto-ad.production.com/10.1.1.97:2888, status: > SUCCESS (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-28 09:21:57,666] INFO Getting a diff from the leader 0x2900000089 > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 09:21:57,670] WARN Got zxid 0x2800000dd7 expected 0x1 > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 09:21:57,670] WARN Got zxid 0x2900000001 expected 0x2800000dda > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 09:21:57,672] INFO Learner received NEWLEADER message > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 09:21:57,688] INFO Learner received UPTODATE message > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 09:21:57,692] INFO Configuring CommitProcessor with 4 worker > threads. (org.apache.zookeeper.server.quorum.CommitProcessor) > [2021-02-28 09:21:57,696] INFO Creating new log file: log.2800000dd7 > (org.apache.zookeeper.server.persistence.FileTxnLog) > [2021-02-28 09:51:15,121] WARN Got zxid 0x290000008a expected 0x1 > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 10:21:56,127] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 10:21:56,127] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 10:21:56,127] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > > > > *#############################################################At this > point, we got an exception but it was due to another VMWare Host getting > updatedThis time the ensemble was able to restablished without needing to > restart this node > manually#############################################################* > [2021-02-28 10:38:16,756] WARN Exception when following the leader > (org.apache.zookeeper.server.quorum.Learner) > java.net.SocketTimeoutException: Read timed out > at java.net.SocketInputStream.socketRead0(Native Method) > at > java.net.SocketInputStream.socketRead(SocketInputStream.java:116) > at java.net.SocketInputStream.read(SocketInputStream.java:171) > at java.net.SocketInputStream.read(SocketInputStream.java:141) > at > sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:457) > at > > sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68) > at > > sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1095) > at sun.security.ssl.SSLSocketImpl.access$200(SSLSocketImpl.java:72) > at > sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:815) > at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) > at java.io.BufferedInputStream.read(BufferedInputStream.java:265) > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:84) > at > > org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:86) > at > org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:118) > at > org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:158) > at > org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:92) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1253) > [2021-02-28 10:38:16,760] INFO shutdown called > (org.apache.zookeeper.server.quorum.Learner) > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:201) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1257) > [2021-02-28 10:38:16,760] INFO Shutting down > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 10:38:16,760] INFO shutting down > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 10:38:16,760] INFO Shutting down > (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) > [2021-02-28 10:38:16,760] INFO Shutting down > (org.apache.zookeeper.server.quorum.CommitProcessor) > [2021-02-28 10:38:16,761] INFO FollowerRequestProcessor exited loop! > (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) > [2021-02-28 10:38:16,761] INFO CommitProcessor exited loop! > (org.apache.zookeeper.server.quorum.CommitProcessor) > [2021-02-28 10:38:16,761] INFO shutdown of request processor complete > (org.apache.zookeeper.server.FinalRequestProcessor) > [2021-02-28 10:38:16,764] INFO Shutting down > (org.apache.zookeeper.server.SyncRequestProcessor) > [2021-02-28 10:38:16,764] INFO SyncRequestProcessor exited! > (org.apache.zookeeper.server.SyncRequestProcessor) > [2021-02-28 10:38:16,764] WARN PeerState set to LOOKING > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 10:38:16,764] INFO LOOKING > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 10:38:16,765] INFO New election. My id = 111, proposed > zxid=0x2900000383 (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,766] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2900000383 (n.zxid), 0xf9 (n.round), LOOKING (n.state), > 111 (n.sid), 0x29 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,766] INFO Notification: 2 (message format version), > 104 (n.leader), 0x2900000383 (n.zxid), 0xf9 (n.round), LOOKING (n.state), > 104 (n.sid), 0x29 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,769] INFO Notification: 2 (message format version), > 111 (n.leader), 0x2900000383 (n.zxid), 0xf9 (n.round), LOOKING (n.state), > 104 (n.sid), 0x29 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,769] INFO Notification: 2 (message format version), > 103 (n.leader), 0x2800000dd9 (n.zxid), 0xf8 (n.round), LEADING (n.state), > 103 (n.sid), 0x29 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,769] INFO Notification: 2 (message format version), > 103 (n.leader), 0x2800000dd9 (n.zxid), 0xf8 (n.round), FOLLOWING (n.state), > 102 (n.sid), 0x29 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,801] INFO Notification: 2 (message format version), > 102 (n.leader), 0x2900000383 (n.zxid), 0xf9 (n.round), LOOKING (n.state), > 102 (n.sid), 0x29 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,982] INFO Notification: 2 (message format version), > 103 (n.leader), 0x2800000dd9 (n.zxid), 0xf8 (n.round), FOLLOWING (n.state), > 101 (n.sid), 0x29 (n.peerEPoch), LOOKING (my state)0 (n.config version) > (org.apache.zookeeper.server.quorum.FastLeaderElection) > [2021-02-28 10:38:16,982] INFO FOLLOWING > (org.apache.zookeeper.server.quorum.QuorumPeer) > [2021-02-28 10:38:16,983] INFO minSessionTimeout set to 4000 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 10:38:16,983] INFO maxSessionTimeout set to 40000 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 10:38:16,983] INFO Created server with tickTime 2000 > minSessionTimeout 4000 maxSessionTimeout 40000 datadir > /opt/zookeeper_dir_datalog/version-2 snapdir > /opt/zookeeper_dir_datastore/version-2 > (org.apache.zookeeper.server.ZooKeeperServer) > [2021-02-28 10:38:16,983] INFO FOLLOWING - LEADER ELECTION TOOK - 0 MS > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 10:38:16,992] INFO QuorumLearner will use DIGEST-MD5 as SASL > mechanism. (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-28 10:38:16,996] INFO Successfully completed the authentication > using SASL. server addr: zk-xpto-ad.production.com/10.1.1.97:2888, status: > SUCCESS (org.apache.zookeeper.server.quorum.auth.SaslQuorumAuthLearner) > [2021-02-28 10:38:17,001] INFO Getting a diff from the leader 0x290000039a > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 10:38:17,001] WARN Got zxid 0x2900000384 expected 0x1 > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 10:38:17,001] INFO Learner received NEWLEADER message > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 10:38:17,004] INFO Learner received UPTODATE message > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 10:38:17,004] INFO Configuring CommitProcessor with 4 worker > threads. (org.apache.zookeeper.server.quorum.CommitProcessor) > [2021-02-28 10:38:17,140] WARN Got zxid 0x290000039b expected 0x1 > (org.apache.zookeeper.server.quorum.Learner) > [2021-02-28 11:21:56,127] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 11:21:56,127] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 11:21:56,128] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 12:21:56,127] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 12:21:56,127] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 12:21:56,128] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 13:21:56,126] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 13:21:56,126] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > [2021-02-28 13:21:56,127] INFO Purge task completed. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 14:21:56,126] INFO Purge task started. > (org.apache.zookeeper.server.DatadirCleanupManager) > [2021-02-28 14:21:56,126] INFO zookeeper.snapshot.trust.empty : false > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > > > Best Regards! > Jhanssen Fávaro de Oliveira > > > On Tue, Mar 2, 2021 at 2:22 AM Szalay-Bekő Máté < > szalay.beko.m...@gmail.com> > wrote: > > > > it was supposed to get back "automatically" right ? > > absolutely > > > > I haven't seen this exact problem before. Which ZooKeeper version are you > > using? > > > > Can you maybe check the logs for any earlier exceptions / errors before > > 2021-02-28 09:11:38,119 and after the previous successful leader > election? > > One possibility is that one of the threads responsible for the leader > > election communication (e.g. sending out notifications or receiving the > > answers) were killed and never restarted in this ZooKeeper Server. If > this > > would be the case, we should see a reason / stack trace earlier > explaining > > the unhandled exception, and we could fix this in the code. > > > > I saw somewhat similar cases, when the current leader had the same issue > > with threads that are receiving the leader election notifications. But in > > that case no one was able to rejoin the quorum and the leader needed to > be > > restarted. Your case is different, as restarting a single follower solved > > the issue. > > > > Regards, > > Mate > > > > On Mon, Mar 1, 2021 at 8:26 PM Jhanssen Fávaro <jhanssenfav...@gmail.com > > > > wrote: > > > > > Hi all, yesterday during a short VMWare Patching apply, there a was a > > very > > > short network outage, something about 3/5 seconds, but for one of our > > > ZooKeeper node it didn't come back automatically. > > > Our ensemble cluster has 5 members and only one got this kind of > > behavior. > > > I needed to manually restart it to get it back. In this case this > > > member/zk was not receving connections from kafka, it's only a > repository > > > backup, but anyway it was supposed to get back "automatically" right ? > > > It was trying to call the leader, but only this got this kind of > > behavior, > > > all the others nodes got the ellection process and reestablished the > > > ensemble. > > > Bellow there is a log's chunk: > > > > > > > > > > > > > > > > > > [2021-02-28 09:11:38,119] WARN Exception when following the leader > > > (org.apache.zookeeper.server.quorum.Learner) > > > java.io.EOFException > > > at java.io.DataInputStream.readInt(DataInputStream.java:392) > > > at > > > org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:84) > > > at > > > > > > org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:86) > > > at > > > > > > org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:118) > > > at > > > org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:158) > > > at > > > > > > org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:92) > > > at > > > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1253) > > > [2021-02-28 09:11:38,119] WARN Closing connection to leader, exception > > > during packet send > > > (org.apache.zookeeper.server.quorum.SendAckRequestProcessor) > > > javax.net.ssl.SSLException: Connection or outbound has been closed > > > at sun.security.ssl.Alert.createSSLException(Alert.java:127) > > > at > > > sun.security.ssl.TransportContext.fatal(TransportContext.java:324) > > > at > > > sun.security.ssl.TransportContext.fatal(TransportContext.java:267) > > > at > > > sun.security.ssl.TransportContext.fatal(TransportContext.java:262) > > > at > > > > > > sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:979) > > > at > > > java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) > > > at > > > java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) > > > at > > > > org.apache.zookeeper.server.quorum.Learner.writePacket(Learner.java:144) > > > at > > > > > > org.apache.zookeeper.server.quorum.SendAckRequestProcessor.flush(SendAckRequestProcessor.java:62) > > > at > > > > > > org.apache.zookeeper.server.SyncRequestProcessor.flush(SyncRequestProcessor.java:186) > > > at > > > > > > org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:113) > > > Caused by: java.net.SocketException: Connection or outbound has been > > closed > > > at > > > > > > sun.security.ssl.SSLSocketOutputRecord.deliver(SSLSocketOutputRecord.java:267) > > > at > > > > > > sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:974) > > > ... 6 more > > > [2021-02-28 09:11:38,120] INFO shutdown called > > > (org.apache.zookeeper.server.quorum.Learner) > > > java.lang.Exception: shutdown Follower > > > at > > > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:201) > > > at > > > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1257) > > > [2021-02-28 09:11:38,120] INFO Shutting down > > > (org.apache.zookeeper.server.ZooKeeperServer) > > > [2021-02-28 09:11:38,120] INFO shutting down > > > (org.apache.zookeeper.server.ZooKeeperServer) > > > [2021-02-28 09:11:38,120] INFO Shutting down > > > (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) > > > [2021-02-28 09:11:38,121] INFO Shutting down > > > (org.apache.zookeeper.server.quorum.CommitProcessor) > > > [2021-02-28 09:11:38,121] INFO FollowerRequestProcessor exited loop! > > > (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) > > > [2021-02-28 09:11:38,121] INFO CommitProcessor exited loop! > > > (org.apache.zookeeper.server.quorum.CommitProcessor) > > > [2021-02-28 09:11:38,123] INFO shutdown of request processor complete > > > (org.apache.zookeeper.server.FinalRequestProcessor) > > > [2021-02-28 09:11:38,132] INFO Shutting down > > > (org.apache.zookeeper.server.SyncRequestProcessor) > > > [2021-02-28 09:11:38,132] INFO SyncRequestProcessor exited! > > > (org.apache.zookeeper.server.SyncRequestProcessor) > > > [2021-02-28 09:11:38,132] WARN PeerState set to LOOKING > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:11:38,132] INFO LOOKING > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:11:38,133] INFO New election. My id = 111, proposed > > > zxid=0x2800000dd6 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:38,135] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:38,336] INFO Notification time out: 400 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:38,337] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:38,737] INFO Notification time out: 800 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:38,738] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:39,538] INFO Notification time out: 1600 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:39,539] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:41,139] INFO Notification time out: 3200 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:41,140] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:44,340] INFO Notification time out: 6400 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:44,341] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:50,741] INFO Notification time out: 12800 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:11:50,741] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:12:03,542] INFO Notification time out: 25600 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:12:03,542] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:12:29,142] INFO Notification time out: 51200 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:12:29,143] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:13:20,344] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:13:20,345] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:14:20,345] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:14:20,346] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:15:20,346] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:15:20,347] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:16:20,347] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:16:20,348] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:17:20,348] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:17:20,350] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:18:20,350] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:18:20,351] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:19:20,352] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:19:20,352] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:20:20,353] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:20:20,357] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:21:20,357] INFO Notification time out: 60000 > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > [2021-02-28 09:21:20,358] INFO Notification: 2 (message format > version), > > > 111 (n.leader), 0x2800000dd6 (n.zxid), 0xf8 (n.round), LOOKING > (n.state), > > > 111 (n.sid), 0x28 (n.peerEPoch), LOOKING (my state)0 (n.config version) > > > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > ############################################################# > > > Needed to manually restart to force reconnect to ensemble cluster. > > > ############################################################# > > > [2021-02-28 09:21:56,110] INFO Reading configuration from: > > > /opt/kafka/config/zookeeper.properties > > > (org.apache.zookeeper.server.quorum.QuorumPeerConfig) > > > [2021-02-28 09:21:56,113] INFO clientPort is not set > > > (org.apache.zookeeper.server.quorum.QuorumPeerConfig) > > > [2021-02-28 09:21:56,115] INFO secureClientPortAddress is 0.0.0.0:3184 > > > (org.apache.zookeeper.server.quorum.QuorumPeerConfig) > > > [2021-02-28 09:21:56,118] INFO Setting -D > > > jdk.tls.rejectClientInitiatedRenegotiation=true to disable > > client-initiated > > > TLS renegotiation (org.apache.zookeeper.common.X509Util) > > > [2021-02-28 09:21:56,126] INFO autopurge.snapRetainCount set to 10 > > > (org.apache.zookeeper.server.DatadirCleanupManager) > > > [2021-02-28 09:21:56,126] INFO autopurge.purgeInterval set to 1 > > > (org.apache.zookeeper.server.DatadirCleanupManager) > > > [2021-02-28 09:21:56,129] INFO Purge task started. > > > (org.apache.zookeeper.server.DatadirCleanupManager) > > > [2021-02-28 09:21:56,129] INFO Log4j 1.2 jmx support found and enabled. > > > (org.apache.zookeeper.jmx.ManagedUtil) > > > [2021-02-28 09:21:56,135] INFO Starting quorum peer > > > (org.apache.zookeeper.server.quorum.QuorumPeerMain) > > > [2021-02-28 09:21:56,137] INFO zookeeper.snapshot.trust.empty : false > > > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > > > [2021-02-28 09:21:56,146] INFO Purge task completed. > > > (org.apache.zookeeper.server.DatadirCleanupManager) > > > [2021-02-28 09:21:56,187] INFO zookeeper.client.portUnification=false > > > (org.apache.zookeeper.server.NettyServerCnxnFactory) > > > [2021-02-28 09:21:56,220] INFO Using > > > org.apache.zookeeper.server.NettyServerCnxnFactory as server connection > > > factory (org.apache.zookeeper.server.ServerCnxnFactory) > > > [2021-02-28 09:21:56,228] INFO Server successfully logged in. > > > (org.apache.zookeeper.Login) > > > [2021-02-28 09:21:56,242] INFO zookeeper.snapshot.trust.empty : false > > > (org.apache.zookeeper.server.persistence.FileTxnSnapLog) > > > [2021-02-28 09:21:56,242] INFO Local sessions disabled > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,242] INFO Local session upgrading disabled > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,243] INFO tickTime set to 2000 > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,243] INFO minSessionTimeout set to 4000 > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,243] INFO maxSessionTimeout set to 40000 > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,243] INFO initLimit set to 5 > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,253] INFO zookeeper.snapshotSizeFactor = 0.33 > > > (org.apache.zookeeper.server.ZKDatabase) > > > [2021-02-28 09:21:56,255] INFO Using TLS encrypted quorum communication > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO Port unification disabled > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO quorum.auth.enableSasl set to true > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO quorum.auth.serverRequireSasl set to > true > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO quorum.auth.learnerRequireSasl set to > true > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO quorum.auth.kerberos.servicePrincipal > set > > > to zkquorum/localhost (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO quorum.auth.server.saslLoginContext set > to > > > QuorumServer (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO quorum.auth.learner.saslLoginContext set > > to > > > QuorumLearner (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,255] INFO quorum.cnxn.threads.size set to 20 > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,257] INFO QuorumServer successfully logged in. > > > (org.apache.zookeeper.Login) > > > [2021-02-28 09:21:56,258] INFO QuorumLearner successfully logged in. > > > (org.apache.zookeeper.Login) > > > [2021-02-28 09:21:56,260] INFO Reading snapshot > > > /zookeeper-datastore/version-2/snapshot.2400000034 > > > (org.apache.zookeeper.server.persistence.FileSnap) > > > [2021-02-28 09:21:56,511] INFO binding to port 0.0.0.0/0.0.0.0:3184 > > > (org.apache.zookeeper.server.NettyServerCnxnFactory) > > > [2021-02-28 09:21:56,565] INFO bound to port 3184 > > > (org.apache.zookeeper.server.NettyServerCnxnFactory) > > > [2021-02-28 09:21:56,571] INFO Election port bind maximum retries is 3 > > > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > > > [2021-02-28 09:21:56,574] INFO Creating TLS-only quorum server socket > > > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > > > [2021-02-28 09:21:56,575] INFO 111 is accepting connections now, my > > > election bind port: zk-xpto.production.com/10.1.1.99:3888 > > > (org.apache.zookeeper.server.quorum.QuorumCnxManager) > > > [2021-02-28 09:21:56,587] INFO LOOKING > > > (org.apache.zookeeper.server.quorum.QuorumPeer) > > > [2021-02-28 09:21:56,592] INFO New election. My id = 111, proposed > > > zxid=0x2800000dd6 > (org.apache.zookeeper.server.quorum.FastLeaderElection) > > > > > > > > > > > >
