HBase ZooKeeper NullPointerException

Posted by AlstonWilliams on April 12, 2019

今天在调试客户环境的时候,发现了这么一个很诡异的问题:

java.lang.NullPointerException
  at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.getMetaReplicaNodes(ZooKeeperWatcher.java:489)
  at org.apache.hadoop.hbase.zookeeper.MetaTableLocator.blockUntilAvailable(MetaTableLocator.java:550)
  ....
  at org.apache.hadoop.hbase.client.HTable.coprocessorService(HTable.java:1785)
  ....

我们用的HBase版本是cdh5-1.2.0_5.12.1。

从HBase中找到上述代码:

/**
 * Get the znodes corresponding to the meta replicas from ZK
 * @return list of znodes
 * @throws KeeperException
 */
public List<String> getMetaReplicaNodes() throws KeeperException {
  List<String> childrenOfBaseNode = ZKUtil.listChildrenNoWatch(this, baseZNode);
  List<String> metaReplicaNodes = new ArrayList<String>(2);
  String pattern = conf.get("zookeeper.znode.metaserver","meta-region-server");
  for (String child : childrenOfBaseNode) {
    if (child.startsWith(pattern)) metaReplicaNodes.add(child);
  }
  return metaReplicaNodes;
}

即上述代码中的childrenOfBaseNode是null.我们继续顺着代码往下看,发现最终只不过就是调用的ZooKeeper的获取children节点的代码。用zk-cli.sh可以这样表示:

ls /hbase

好,知道问题出在这儿了。我们就开始调试。起初,我们猜测,是HBase设置的zookeeper.znode.parent这个属性设置的有问题。此时并没有注意到这其实是HBase client出现的问题。我们以为,是HBase的HRegionServer,由于要用coprocessor来处理数据,所以coprocessor中需要先定位到HRegionServer,然后再读,出现的问题。

其实这种方法经不起推敲,很可笑。因为coprocessor都已经位于HRegionServer上了,怎么可能还需要跟ZooKeeper交互,获取HRegionServer的位置呢?

排除掉这种想法。我们又猜测,是调用coprocessor的client节点,zookeeper.znode.parent属性配置错误。

由于我们是在Spark中调用的coprocessor client,而我们又是在客户的环境调试,无法登陆到它们的集群,也就无法上去看是不是那个节点上的hbase-site.xml有问题。

而我们用的hbase-site.xml,其实很混乱。在Spark任务启动的时候,我们通过–jars参数传了一个,然后运行的Jar包中还包含一个,而且这两个hbase-site.xml的内容还不一样。而我们其实并不知道是用的哪个。

幸好Spark的Executor日志中,会打印出来连接的是哪个Zookeeper节点,以及哪个znode.相关片段如下:

INFO ZooKeeper: Initiating client connection, connectString=host1:2181,host2:2181,host3:2181,baseZnode=/hbase

从这里面,我们看到host都正确,znode也都正确。那到底是什么问题呢???

此时,我连上host1去看看存不存在这个znode:

zk-cli.sh --server host1:2181
ls /hbase

发现是能获取到的。这就纳闷了。

而此时我们又偶然看到日志中有这么一个片段:

INFO: ZooKeeper - Session establishment complete on server host1: 2181, sessionid=0x111, negotiated timeout=40000
INFO: ZooKeeper - Session establishment complete on server host2: 2181, sessionid=0x111, negotiated timeout=40000

也就是说,coprocessor client其实只连了host1和host2这两台ZooKeeper Server,来获取HBase的元数据的。

这样子调试范围就小了很多了,然后我又连上host2去看看存不存在这个znode:

zk-cli.sh --server host2:2181
ls /hbase

结果是:

Node does not exist: /hbase

然后将这个节点从hbase-site.xml的zookeeper.quorum中删掉,就一切正常了。

但是为什么呢?

以前读过ZooKeeper的源码,知道client和ZooKeeper交互的时候,如果是读的话,会随即分配到Follower节点上。而如果此Follower节点挂掉了,会重新分配到其它的Follower节点上。

而这里我们有一点忘记了,就是ZooKeeper并不是强一致性的。所以我们才会检查了host1上存在这个znode,就以为全部的Follower上都存在。而实际上,ZooKeeper是顺序一致性的。这就导致中间可能存在某些时间窗口,host1上存在这个znode,host2上不存在。

正常来说,这个时间窗口应该很小很小,但是,我们客户环境上,一整天了都没有将/hbase这个znode同步到host2上。这应该是ZooKeeper的bug。因为,如果一个Follower很长时间都没有跟其它的Follower保持同步,那么这台Follower可能会相对其它Follower少了很多数据,而我们读取数据的时候,如果刚好选择的是这个Follower,那么就会导致获取不到。而ZooKeeper client选择Follower来获取数据的时候,没有过滤掉这些长时间没有保持同步的节点。

这个没有深入研究,因为环境是客户的,没有办法进入看到底发生了什么。