ZooKeeper相关错误的解决

一、错误1

1.1、错误描述

ZooKeeper Server（“FOLLOWER和LEADER”都有）的日志中显示有以下所示错误：

2016-05-14 15:33:01,818 [myid:2] - ERROR [CommitProcessor:2:NIOServerCnxn@178] - Unexpected Exception:java.nio.channels.CancelledKeyException        at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:55)        at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:59)        at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)        at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)        at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:170)        at org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:74)

1.2、错误原因分析

ZooKeeper Server发送回复时，Socket连接已经被关闭。

1.3、错误解决

当ZooKeeper Server发送回复时，增加一个“sk.isValid()”的判断。以上其实是一个bug，在ZooKeeper 3.4.8版本中得到修复。

1.4、其他

这个错误在上线“使用ZooKeeper获取MQ地址方案”之前也存在。

二、错误2

2.1、错误描述

ZooKeeper Server（“FOLLOWER”）日志中显示有以下所示错误，出现该错误后，作为“FOLLOWER”的该ZooKeeper Server在一段时间内会停止工作：

2016-05-15 04:04:40,569 [myid:1] - WARN  [SyncThread:1:FileTxnLog@334] - fsync-ing the write ahead log in SyncThread:1 took 2243ms which will adversely effect operation latency. See theZooKeeper troubleshooting guide

2016-05-14 15:32:50,764 [myid:1] - WARN  [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Follower@89] - Exception when following the leaderjava.io.EOFException        at java.io.DataInputStream.readInt(DataInputStream.java:375)        at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)        at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)        at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:103)        at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:153)        at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:85)        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:786)2016-05-14 15:32:50,764 [myid:1] - INFO  [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:2181:Follower@166] - shutdown calledjava.lang.Exception: shutdown Follower        at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166)        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:790)

相应的ZooKeeper Server（“LEADER”）日志中显示有如下所示错误：

2016-05-14 15:32:42,605 [myid:3] - WARN  [SyncThread:3:FileTxnLog@334] - fsync-ing the write ahead log in SyncThread:3 took 3041ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide

2016-05-14 15:32:50,764 [myid:3] - WARN  [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:2181:LearnerHandler@687] - Closing connection to peer due to transaction timeout.2016-05-14 15:32:50,764 [myid:3] - WARN  [LearnerHandler-/10.110.20.23:39390:LearnerHandler@646] - ******* GOODBYE /10.110.20.23:39390 ********2016-05-14 15:32:50,764 [myid:3] - WARN  [LearnerHandler-/10.110.20.23:39390:LearnerHandler@658] - Ignoring unexpected exceptionjava.lang.InterruptedException        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1199)        at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:312)        at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:294)        at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:656)        at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:649)

2.2、错误原因分析

“FOLLOWER”在跟“LEADER”同步时，fsync操作时间过长，导致超时。

2.3、错误解决

增加“tickTime”或者“initLimit和syncLimit”的值，或者两者都增大。

2.4、其他

这个错误在上线“使用ZooKeeper获取MQ地址方案”之前也存在，只不过没有这么高频率，而上线了“使用ZooKeeper获取MQ地址方案”之后，ZooKeeper Server之间的同步数据量增大，ZooKeeper Server的负载加重，因而最终导致高频率出现上述错误。

参考文献：
[1]https://mail-archives.apache.org/mod_mbox/zookeeper-dev/201602.mbox/[e-mail]%3E
[2]https://issues.apache.org/jira/browse/ZOOKEEPER-1237