Ok, happy to hear if the information helped. Good luck and enjoy using ZooKeeper ;)
Mate On Wed, Mar 3, 2021, 18:18 Jhanssen Fávaro <[email protected]> wrote: > Hi Mate, thank you again! > These bug links cleared a lot to us and will help a lot!!! > > Yeah looks like that we're probably being caught by one of these BUGs. > Anyway, we'll take a closer look in each of the BUGs related by. > > About kubernetes, we're not using. Only clients(application connecting to > zookeeper/kafka). Our ZK are running on VMWare VMs. > > And yes, this is very rare to replicated issue, normally only during > VMWare patches/host reboots we face it, and not always. > > We have a SDN defined SNX(VMWare), so a lot of variables on the table. > > Anyway, by now, we just would like to say thank you. And we'll decide > wether open the jira or not, but you'll be notified for sure as soon as we > open. > > Thank you! > > On 2021/03/03 08:38:43, Szalay-Bekő Máté <[email protected]> > wrote: > > 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 < > [email protected]> > > 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é < > > > [email protected]> > > > 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 < > [email protected] > > > > > > > > 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) > > > > > > > > > > > > > > > > > > > > > > > > >
