鲸品堂｜记一次HBASE的故障分析和排查过程

2022-11-28 121

HBASE在大数据技术栈中，是一个常用的组件，可以在单表存储量以百亿级的数据，并且提供毫秒级的读写能力，通过线性扩展可达超高TPS能力，在大规模清单存储和查询场景中大显身手，然而在实际生产中，也时常会有意想不到的烦恼。

今年笔者支撑的某项目一个部署HBASE的大规模集群中发生了连续的宕机事件，对业务造成严重影响。每次宕机后，启动消耗时间都很长，导致业务出现中断。其最关键的问题是，连续宕机且原因不明，所以大概率存在再次宕机的风险，在根因没有定位出来的情况下，这个故障就是达摩克利斯之剑依然悬在半空，谁也不知道什么时候会落下来。下面的篇幅就依此故障排查分析过程为主线展开。

一、故障线索，机会出现

该HBASE集群发生的严重宕机事件，具体表现为管理节点HMaster异常退出，并且超过一半的RegionServer也出现宕机退出，导致业务生产中断。运维人员根据常规步骤进行启动集群操作，之后进行故障分析定位，由于日志级别设置为DEBUG级别，日志刷新速度较快，重启后没有及时进行备份转存，故障的时间点的日志没有办法获取，这给查找故障原因造成了很大的麻烦。就在大家面对缺少关键日志，不知道该如何进行故障分析复盘的时候，在不到24小时的时间里面，集群出现了又一次宕机！现象是和第一次是一样的，也是HMaster异常退出，期间也有大量的RegionServer出现宕机。

虽然说连续的故障带来客户的严重不满，但是也给了我们揭开故障根因面纱的大好机会。

二、问题排查，迷雾重重

有了前期的教训，这一次次故障产生后，立即在第一时间将HBASE的相关日志都转储保存好，然后就马上着手进行分析和定位。这次故障表象实在有些特殊，HBASE的日志反应的是Zookeeper连接异常：

‍

这个时候所有的思路焦点都聚集到Zookeeper的这个异常点上面，为什么会出现Session expired呢？Zookeeper是不是出现了什么异常的情况?

之前集群也出现过HBASE的故障，因为Zookeeper连接超时导致，当时进行过以下举措解决:

1.Hbase连接Zookeeper的会话超时调大(120S)。重启ZK与Hbase；ipa 升级完成后再操作；

2.ZK连接数监控，当前最大连接数600，超过80%告警；临时调整最大连接数—已经调整；

3. JVM 参数优化。

所以比较肯定，故障应该还是出在Zookeeper上，所以第一时间分析ZK的日志。但是ZK在整个故障过程中，始终没有出现异常及宕机行为，这个就给问题定位带来很大的不确定性了，因为Zookeeper正常，即使是HBASE的日志显示连接ZK异常，但这个时候依然没有办法定位到具体的原因是由哪个参数哪个配置导致的，也就是说真正有说服力的原因是没有定位到，这样肯定是没有办法结案，而且系统随时可能再次宕机，危机仍在。

只能再次分析Zookeeper的日志，查找可能出现异常的原因。通过ZK的日志，发现到一个情况，某几台主机连接数特别多，一天下来都有上百万次连接了，这个根据经验来看是不正常的，是不是因为访问量过大导致异常呢？迅速地，进行了对ZK的各项指标进行全面的监控，查找可能的连接异常。

排查异常连接数据的主机是哪些程序发出的

在所内模拟对ZK进行高负载的连接，测试稳定性

然而结果并不顺利，主机没有部署特别的程序，仅是HADOOP集群的计算节点，内测也进行过百万次级别的高负载连接压测，ZK没有出现异常。

三、拔云见日，真相大白

在经过一天的艰苦研究后，终于看到了曙光！

通过分析日志，发现连接Zookeeper的sessionid是有异常的。HMaster和Zookeeper是通过session维持连接的，这里日志显示了sessionId 是：0xff8201f4b7b63a73

检测所有的ZK服务器的日志，又发现了一段信息：

这个sessionid，不是HMaster的主机，是10.26.9.35 发出的，也就是说sessionid出现了冲突的情况。而由于sessionid出现了冲突，并且修改了原session的元数据信息，导致Master连接ZK的长连接出现了过期异常，无法正常续约，HMaster退出。

那接下来的事情就明了：查明白为什么ZK的sessionid会出现冲突

首先检测ZK产生sessionid的源代码：

这里肯定看到是通过时间和ZK的实例ID作为基准进行生成的，现在的问题就是同样的ID会参数相同的开始ID段。

通过对这段代码进行测试，就发现了问题，无论送的是什么id过来，结果都是一样的，这样不同的ZK实例，必定会产生相同的sessionid，也就是说是一个BUG来了！

仔细分析了这段代码，发现的是带符号右移，导致溢出了，然后马上检查了后续的版本，发现并进行了修复：

代码确实很少，就是 >>8 变成了 >>>8

符号移位日常使用比较少，确实容易出错：

Java提供了两种右移运算符：“>>” 和">>>"。其中，“>>”被称为有符号右移运算符，“>>>”被称为无符号右移运算符，它们的功能是将参与运算的对象对应的二进制数右移指定的位数。二者的不同点在于“>>”在执行右移操作时，若参与运算的数字为正数，则在高位补0；若为负数，则在高位补1。而“>>>”则不同，无论参与运算的数字为正数或为负数，在执运算时，都会在高位补0。

上述的问题在于，左移24位，再右移8位后，当前时间出现了溢出，导致变成负数，真相大白。

ZK的更新补丁说明：

ZOOKEEPER-1622 session ids will be negative in the year 2022

确实到了2022年后，由于sessionid出现负数，导致所有的ZK实例都会产生相同的sessionid初始值，所以才出现冲突。

四、故障解决

由于是ZOOKEEPER的BUG导致，所以后续还是必然还是会有可能再次出现异常，所以根本原因必须要对ZK打补丁，才能彻底解决。在没有进行充分验证的情况下，只能通过避免程序到ZK的频繁连接，要求对应用程序进行整改，才能降低BUG被触发的风险，并且再更新之前每天进行系统及业务巡检。

经过一个业务周期运行观察，系统稳定运行。

五、经验总结

这次的故障定位是一波三折，付出了很大的努力才最终完成问题的定位。由于是组件的BUG引起，并且在2022年才会触发，这个在之前多年的运维HADOOP集群还是第一回出现。

故障分析处理过程中分析日志包括：HBASE的MASTER，REGIONSERVER实例日志，ZOOKEEPER的5台主机实例日志，YARN调度程序运行记录日志。

通过这次故障分析可以看出，往往造成原因多方面的，也体现了大数据生态体系复杂性，不同组件的兼容和协同能力是至关重要的，需要研发和运维团队有较强的生态和源代码把控能力，而不是简单的把开源组件堆起即可使用。

几点寄语：

故障发生后，现场需要第一时间保留所有的日志

需要从故障发生点的异常日志里面，查找有价值的信息

需要通过整合所有的日志文件，进行综合分析，大数据集群相对复杂，所有的需要综合分析所有的组件信息，才能在复杂的环境中定位出真正的问题

九州(中国)科技有限公司官网

九州(中国)科技有限公司官网

鲸品堂｜记一次HBASE的故障分析和排查过程

关于我们

产品与解决方案

成功故事

九州(中国)科技有限公司官网