记zookeeper 扰动导致HBase的一次不可用

HBase运维过程中，最大的问题除了自己一些bug外，就是网络的延迟。这种延迟会导致hadoop的append的timeout，本来只是一个小事，但是会导致HBase因为无法append WAL log 退出。

而这次遇到的却是zookeeper的问题。

我们的集群里面有3台zookeeper。首先lead（A） 和其中的一台follower B（xx.xx.xx.85）连接出现异常，而这台zookeeper的follower B之后退出。

2011-08-01 03:28:30,013 [LearnerHandler-/xx.xx.xx.85:48270] ERROR org.apache.zookeeper.server.quorum.LearnerHandler: Unexpected exception causing shutdown while sock still open
java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
	at java.io.DataInputStream.readInt(DataInputStream.java:370)
	at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
	at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:84)
	at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:108)
	at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:375)

2011-08-01 03:28:30,013 [LearnerHandler-/xx.xx.xx.85:48270] WARN org.apache.zookeeper.server.quorum.LearnerHandler: ******* GOODBYE /xx.xx.xx.85:48270 ********

B试图退出，但是退出失败。大量的session连接关闭。

而后，follower c 也出现异常。

2011-08-01 03:29:38,562 [CommitProcessor:0] ERROR org.apache.zookeeper.server.NIOServerCnxn: 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:148)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1043)
	at org.apache.zookeeper.server.NIOServerCnxn.process(NIOServerCnxn.java:1080)
	at org.apache.zookeeper.server.DataTree.setWatches(DataTree.java:1154)
	at org.apache.zookeeper.server.ZKDatabase.setWatches(ZKDatabase.java:383)
	at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:297)
	at org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:73)

整个过程中，zookeeper和Hbase的session都中断了。导致master遇到fatal的error而退出

2011-08-01 03:29:38,953 [main-EventThread] FATAL org.apache.hadoop.hbase.master.HMaster: Unexpected zk exception getting RS nodes
org.apache.zookeeper.KeeperException$NoAuthException: KeeperErrorCode = NoAuth for /SPN-hbase/rs
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:104)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.listChildrenAndWatchForNewChildren(ZKUtil.java:307)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndGetNewChildren(ZKUtil.java:418)
	at org.apache.hadoop.hbase.zookeeper.RegionServerTracker.nodeChildrenChanged(RegionServerTracker.java:86)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:315)
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:560)
	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:536)
2011-08-01 03:29:38,953 [main-EventThread] INFO org.apache.hadoop.hbase.master.HMaster: Aborting
2011-08-01 03:29:38,954 [main-EventThread] WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: master:8100-0x230684e82d6738d-0x230684e82d6738d Unable to list children of znode /SPN-hbase/tokenauth/keys 
org.apache.zookeeper.KeeperException$NoAuthException: KeeperErrorCode = NoAuth for /SPN-hbase/tokenauth/keys
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:104)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.listChildrenAndWatchForNewChildren(ZKUtil.java:307)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndGetNewChildren(ZKUtil.java:418)
	at org.apache.hadoop.hbase.security.token.ZKSecretWatcher.nodeChildrenChanged(ZKSecretWatcher.java:116)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:315)
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:560)
	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:536)
2011-08-01 03:29:38,954 [main-EventThread] ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: master:8100-0x230684e82d6738d-0x230684e82d6738d Received unexpected KeeperException, re-throwing exception
org.apache.zookeeper.KeeperException$NoAuthException: KeeperErrorCode = NoAuth for /SPN-hbase/tokenauth/keys
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:104)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.listChildrenAndWatchForNewChildren(ZKUtil.java:307)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndGetNewChildren(ZKUtil.java:418)
	at org.apache.hadoop.hbase.security.token.ZKSecretWatcher.nodeChildrenChanged(ZKSecretWatcher.java:116)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:315)
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:560)
	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:536)
2011-08-01 03:29:38,954 [main-EventThread] ERROR org.apache.hadoop.hbase.security.token.ZKSecretWatcher: Error reading data from zookeeper
org.apache.zookeeper.KeeperException$NoAuthException: KeeperErrorCode = NoAuth for /SPN-hbase/tokenauth/keys
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:104)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.listChildrenAndWatchForNewChildren(ZKUtil.java:307)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndGetNewChildren(ZKUtil.java:418)
	at org.apache.hadoop.hbase.security.token.ZKSecretWatcher.nodeChildrenChanged(ZKSecretWatcher.java:116)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:315)
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:560)
	at 

由于我们还有backup master，然而，backup master因为zookeeper的缘故也无法正常工作。

之后，大量的regionserver down。

2011-08-01 03:29:38,565 [ZKSecretWatcher-leaderElector] INFO org.apache.hadoop.hbase.regionserver.HRegionServer: STOPPED: Unexpected error from ZK, stopping candidate
2011-08-01 03:29:38,565 [ZKSecretWatcher-leaderElector] INFO org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager: Stopping leader election, because: Unexpected error from ZK: KeeperErrorCode = InvalidACL for /SPN-hbase/tokenauth/keymaster

整个过程中，我们看到zookeeper的一次异常对HBase的致命打击。

现在，我们只能在regionserver和zookeeper上面加watchdog，对down的server快速重启来避免这种问题的发生。

HBase也意识到这个问题。

https://issues.apache.org/jira/browse/HBASE-3065

试图在zookeeper扰动的过程中尽量保证HBase的运行。增加了更多的retry

评论

1 楼 27g 2011-10-28  

11/10/28 15:40:06 INFO mapred.JobClient: Task Id : attempt_201110111715_0099_m_000003_0, Status : FAILED
Error: TOKENIZED

您好，在我将jar包在hadoop环境上跑的时候，包了以上错误（出现很多行同样的），请问这可能是什么情况啊？