一个HBase客户端超时问题的排查

时间:2021-03-18 14:52:21

最近处理了一个客户端scan超时问题,记录在此,希望能够帮助到遇到同样问题的同学。

问题的错误堆栈如下面所示:

java.lang.RuntimeException: org.apache.hadoop.hbase.client.ScannerTimeoutException: 76745ms passed since the last invocation, timeout is currently set to 60000

        at org.apache.hadoop.hbase.client.AbstractClientScanner$1.hasNext(AbstractClientScanner.java:97) ~[hbase-client-1.1.2.jar:1.1.2]

        at com.mogujie.fulldump.task.HBaseUtil.scanTable(HBaseUtil.java:109) ~[fulldump-indexbuildingcomponent-1.0-SNAPSHOT.jar:na]

        at com.mogujie.fulldump.task.HbaseScanner$Task.run(HbaseScanner.java:114) [fulldump-indexbuildingcomponent-1.0-SNAPSHOT.jar:na]

        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_60]


业务方报告超时错误后,我们按惯常的思路对服务端进行了排查,包括对更改表配置,对表数据进行major compact操作等等,但是,经过对集群及表结构的一阵调整之后,超时错误仍然存在。解决问题的最好出发点就是分析源码,看看问题出在哪里,于是决定阅读源码,找到错误的根节点。

从上面的异常可以看出错误出现在org.apache.hadoop.hbase.client.ScannerTimeoutException中,进入源码看看这个错误在哪里被打印。

在客户端的ClientScanner类的loadcache方法,我们找到了错误输出的地方,代码片段如下所示:

一个HBase客户端超时问题的排查

在上面的代码中,lastNext是前一次调用loadcache时的系统时间,scannerTimeout是用户设置的超时时间。每次进入loadcache函数的时候,都会将当前的时间与前两者之和做对比,如果当前时间大于了两者之和,则会报出Timeout错误。好啦,错误的原因已经知道了,解决方法就是增大scannerTimeout。scannerTimeout是由hbase.client.scanner.timeout.period控制的,默认值是60s,我们将上述配置增大到120s之后,问题解决,不再发生超时错误。

这个问题深入思考一下,为什么会有这么一个错误。loadcache的作用是将服务端的数据缓存到本地,客户端中维护一个LinkedList<Result>类型的变量cache用于缓存从服务端region中拉下的数据。客户端的scanner迭代时调用的next实际上是从这个cache中取的数据,直到cache中的数据被消费空,此时,会重新调用loadcache开始新一轮从服务端拉取数据。

根据源码,我们判断是数据的消费逻辑比较复杂,导致iterator下次调用next时,间隔时间超过了设置时间,出现了超时错误。经过与业务方的交流,结果验证了我们的猜想。

可以再思考一下,hbase为什么要增加这么一个超时时间呢,个人认为是避免客户端数据消费和数据生产的速度不匹配而可以导致的服务器雪崩问题。当然了,上面的是我的猜想,验证还需要进一步地分析源码才可以。