[jira] [Commented] (ZOOKEEPER-4444) Follower doesn't get synchronized after process restart
[ https://issues.apache.org/jira/browse/ZOOKEEPER-?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17829769#comment-17829769 ] LINFUSHOU commented on ZOOKEEPER-: -- This issue happened in my environment, then zookeeper follower data was inconsistent with leader. znode was deleted, but could be read from one follower. 2023-09-22 06:14:59,309 [myid:3] - INFO [QuorumPeer[myid=3](plain=[0:0:0:0:0:0:0:0]:9639)(secure=disabled):Learner@737][] - Learner received NEWLEADER message 2023-09-22 06:14:59,310 [myid:3] - INFO [QuorumPeer[myid=3](plain=[0:0:0:0:0:0:0:0]:9639)(secure=disabled):QuorumPeer@921][] - Peer state changed: following - synchronization 2023-09-22 06:14:59,310 [myid:3] - INFO [QuorumPeer[myid=3](plain=[0:0:0:0:0:0:0:0]:9639)(secure=disabled):CommitProcessor@491][] - Configuring CommitProcessor with readBatchSize -1 commitBatchSize 1 2023-09-22 06:14:59,310 [myid:3] - INFO [QuorumPeer[myid=3](plain=[0:0:0:0:0:0:0:0]:9639)(secure=disabled):CommitProcessor@452][] - Configuring CommitProcessor with 28 worker threads. 2023-09-22 06:14:59,310 [myid:3] - INFO [QuorumPeer[myid=3](plain=[0:0:0:0:0:0:0:0]:9639)(secure=disabled):FollowerRequestProcessor@59][] - Initialized FollowerRequestProcessor with zookeeper.follower.skipLearnerRequestToNextProcessor as false 2023-09-22 06:14:59,311 [myid:3] - WARN [QuorumPeer[myid=3](plain=[0:0:0:0:0:0:0:0]:9639)(secure=disabled):MBeanRegistry@110][] - Failed to register MBean InMemoryDataTree 2023-09-22 06:14:59,311 [myid:3] - WARN [QuorumPeer[myid=3](plain=[0:0:0:0:0:0:0:0]:9639)(secure=disabled):LearnerZooKeeperServer@104][] - Failed to register with JMX org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=Follower,name3=InMemoryDataTree at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324) at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) at org.apache.zookeeper.jmx.MBeanRegistry.register(MBeanRegistry.java:106) at org.apache.zookeeper.server.quorum.LearnerZooKeeperServer.registerJMX(LearnerZooKeeperServer.java:102) at org.apache.zookeeper.server.ZooKeeperServer.startupWithServerState(ZooKeeperServer.java:715) at org.apache.zookeeper.server.ZooKeeperServer.startupWithoutServing(ZooKeeperServer.java:698) at org.apache.zookeeper.server.quorum.Learner.syncWithLeader(Learner.java:760) at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:108) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1522) 2023-09-22 06:15:00,292 [myid:3] - WARN [NIOWorkerThread-18:NIOServerCnxn@380][] - Close of session 0x0 ZooKeeperServer not running at org.apache.zookeeper.server.NIOServerCnxn.readLength(NIOServerCnxn.java:554) at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:339) at org.apache.zookeeper.server.NIOServerCnxnFactory$IOWorkRequest.doWork(NIOServerCnxnFactory.java:508) at org.apache.zookeeper.server.WorkerService$ScheduledWorkRequest.run(WorkerService.java:154) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) // 30065370041 2023-09-22 06:15:00,292 [myid:3] - WARN [SyncThread:3:FileTxnLog@275][] - Current zxid 30065370041 is <= 30065371040 for 5 2023-09-22 06:15:00,292 [myid:3] - WARN [NIOWorkerThread-10:NIOServerCnxn@380][] - Close of session 0x0 ZooKeeperServer not running at org.apache.zookeeper.server.NIOServerCnxn.readLength(NIOServerCnxn.java:554) at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:339) at org.apache.zookeeper.server.NIOServerCnxnFactory$IOWorkRequest.doWork(NIOServerCnxnFactory.java:508) at org.apache.zookeeper.server.WorkerService$ScheduledWorkRequest.run(WorkerService.java:154) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2023-09-22 06:15:00,293 [myid:3] - WARN [SyncThread:3:FileTxnLog@275][] - Current zxid 30065370042 is <= 30065371040 for 1 2023-09-22 06:15:00,293 [myid:3] - WARN [SyncThread:3:FileTxnLog@275][] - Current zxid 30065370043 is <= 30065371040 for 1 2023-09-22 06:15:00,293
[jira] [Commented] (ZOOKEEPER-4444) Follower doesn't get synchronized after process restart
[
https://issues.apache.org/jira/browse/ZOOKEEPER-?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17485223#comment-17485223
]
David Bros commented on ZOOKEEPER-:
---
Hi,
I found the exact issue by enabling the following property in my
*log4j.properties*
* log4j.logger.org.apache.zookeeper=DEBUG
After setting that and restarting my zookeeper which was not synchronizing my
brokers information I found this in *server.log*
{noformat}
[2022-02-01 11:22:00,346] DEBUG Created new input archive:
/var/log/zookeeper/version-2/log.4a84d6
(org.apache.zookeeper.server.persistence.FileTxnLog)
[2022-02-01 11:22:00,349] DEBUG EOF exception
(org.apache.zookeeper.server.persistence.FileTxnLog)
java.io.EOFException: Failed to read /var/log/zookeeper/version-2/log.4a84d6
at
org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.next(FileTxnLog.java:771)
at
org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.(FileTxnLog.java:650)
at
org.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:462)
at
org.apache.zookeeper.server.persistence.FileTxnLog.read(FileTxnLog.java:449)
at
org.apache.zookeeper.server.persistence.FileTxnLog.getLastLoggedZxid(FileTxnLog.java:360)
at
org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:277)
at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:285)
at
org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:1094)
at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:1079)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:227)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:136)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:90)
[2022-02-01 11:22:00,351] DEBUG Created new input stream:
/var/log/zookeeper/version-2/log.4a84dc
(org.apache.zookeeper.server.persistence.FileTxnLog)
[2022-02-01 11:22:00,351] DEBUG Created new input archive:
/var/log/zookeeper/version-2/log.4a84dc
(org.apache.zookeeper.server.persistence.FileTxnLog)
[2022-02-01 11:22:00,351] DEBUG EOF exception
(org.apache.zookeeper.server.persistence.FileTxnLog)
java.io.EOFException: Failed to read /var/log/zookeeper/version-2/log.4a84dc
at
org.apache.zookeeper.server.persistence.FileTxnLog$FileTxnIterator.next(FileTxnLog.java:771)
at
org.apache.zookeeper.server.persistence.FileTxnLog.getLastLoggedZxid(FileTxnLog.java:362)
at
org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:277)
at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:285)
at
org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:1094)
at org.apache.zookeeper.server.quorum.QuorumPeer.start(QuorumPeer.java:1079)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:227)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:136)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:90)
[2022-02-01 11:22:00,352] WARN No snapshot found, but there are log entries.
This should only be allowed during upgrading.
(org.apache.zookeeper.server.persistence.FileTxnSnapLog)
[2022-02-01 11:22:00,352] DEBUG Created new input stream:
/var/log/zookeeper/version-2/log.41
(org.apache.zookeeper.server.persistence.FileTxnLog)
[2022-02-01 11:22:00,352] DEBUG Created new input archive:
/var/log/zookeeper/version-2/log.41
(org.apache.zookeeper.server.persistence.FileTxnLog)
[2022-02-01 11:22:00,377] DEBUG Failed:
218688867411165184,4,274877906946,1607953214895,5
:'/config/topics/netflow_pre_agg,#7b2276657273696f6e223a312c22636f6e666967223a7b22726574656e74696f6e2e6d73223a223836343030303030227d7d,1
(org.apache.zookeeper.server.DataTree)
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode
at org.apache.zookeeper.server.DataTree.setData(DataTree.java:659)
at org.apache.zookeeper.server.DataTree.processTxn(DataTree.java:955)
at org.apache.zookeeper.server.DataTree.processTxn(DataTree.java:873)
at
org.apache.zookeeper.server.persistence.FileTxnSnapLog.processTransaction(FileTxnSnapLog.java:433)
at
org.apache.zookeeper.server.persistence.FileTxnSnapLog.fastForwardFromEdits(FileTxnSnapLog.java:341)
at
org.apache.zookeeper.server.persistence.FileTxnSnapLog.lambda$restore$0(FileTxnSnapLog.java:258)
at
org.apache.zookeeper.server.persistence.FileTxnSnapLog.restore(FileTxnSnapLog.java:284)
at org.apache.zookeeper.server.ZKDatabase.loadDataBase(ZKDatabase.java:285)
at
org.apache.zookeeper.server.quorum.QuorumPeer.loadDataBase(QuorumPeer.java:1094)
at
