问题排查 | Kylin 2.0-HBase 0.98 重启

背景：目前当 HBase 添加、删除节点，重启、移动 rgroup，或者 HBase table 移动 region server 等操作后，均需要 Kylin 的所有节点重启，理论上这些操作可以对上层应用透明，或者只有短暂的不可用后自行恢复。但是，目前咱们有 8 套 Kylin 集群均需要在 HBase 变动后进行 Kylin 重启，才可以继续提供相应的服务，对上层服务影响较大，HBase 的变更也会变得复杂。但是咱们提供的 Kylin 3.0 版本却没有此问题，Kylin 3.0 版本对应的 HBase 版本是 1.4.8 版本，有问题的八套 Kylin 集群的版本为 2.0，HBase 版本为 0.98。本文就如何排查和解决此问题进行总结。

注：大家可以跳过前面第一和第二步直接从第三步（排查 HBase 0.98 和 1.4.8 代码区别）开始阅读，第三步为引发此问题的代码所在。

一、定位问题

首先分别在 Kylin 3.0 和 2.0 集群上找到一个 cube对应的 HBase table 表，然后移动对应 table 的 rgroup 即换存储的机器。发现 Kylin 3.0 仍然可以查询，但是 2.0 无法在获取到结果，Kylin 2.0 抛出的异常如下：

2019-07-18 16:43:59,148 ERROR [http-bio-8088-exec-438] controller.BasicController:54 :org.apache.kylin.rest.exception.InternalErrorException: Error while executing SQL "select * from DPS_DATA_CENTER.SYS_PROBE limit 2": java.net.SocketTimeoutException: callTimeout=1200000, callDuration=1200108: row '' on table 'DPS_DATA_CENTER:KYLIN_N59AHNZIMB' at region=DPS_DATA_CENTER:KYLIN_N59AHNZIMB,,1542085088058.6b1f069c03aa1cfc6649b6762bc79451., hostname=bigdata-dnn-hbase33.gs.com,60020,1551705541907, seqNum=3 at org.apache.kylin.rest.service.QueryService.doQueryWithCache(QueryService.java:402) at org.apache.kylin.rest.controller.QueryController.query(QueryController.java:71) at sun.reflect.GeneratedMethodAccessor201.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:743) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:672) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:82) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:933) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:867) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:951) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:853) at javax.servlet.http.HttpServlet.service(HttpServlet.java:650) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:827) at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)

通过错误可以看到查询此表的某个 region 时还是去之前的机器（bigdata-dnn-hbase33.gs.com）查询，理论上这个查询是会自动失败重试到新机器查询的，但是 Kylin 的这个错误显然还是到了之前的节点查询。根据之前的经验和其他 HBase 的用户并无此问题，大致猜想可能是没有配置 HBase 失败重试(实际后来排查配置了此选项且配置的 35 次)或 Kylin 调用代码有问题，所以有了下面 2.0 代码和 3.0 代码的对比。

二、排查 Kylin 2.0 和 3.0 代码区别

首先定位查询服务的 Kylin 代码逻辑（主要是 Kylin 通过 rpc 调用对应的 HBase table 所在节点的 coprocessor 进行查询），分别对比 Kylin 2.0 和 Kylin 3.0 的代码，发现虽然两边的代码在写法上有些许不同，但是与 HBase 通信的最底层的地方并无差别。分别进行了如下尝试：

1. Debug 3.0 的服务，意在确定 Kylin 本身是否会获取 region 的 location 或者进行相应的失败重试（实际没有，均是 HBase 自身的失败重试）；

2. 修改 3.0 的失败重试机制到 0（修改为 0 后，无论是否移动 group 均无法正确获取到数据，抛出异常失败重试大于 0 次，说明配置的 HBase 失败重试的参数是生效的）；
   

3. 修改 3.0 的失败重试机制到 1（修改为 1 后，移动前可以正确查询并获得结果，移动后无法查询获取结果并抛出异常失败重试大于 1 次）；

4. 修改 3.0 的失败重试机制大于 1（移动前后均可以正常查询并获得结果。）

经过上面 4 种尝试和 Debug，首先说明 HBase 失败重试配置是生效的，且移动 rgroup 后会导致第一次查询失败，需要进行二次尝试,且本身的尝试代码是 HBase 实现，基本排除是 Kylin 代码的问题，由于 2.0 是从其他团队接管过来的集群生产任务居多且暂无测试环境，只能通过硬看代码的方式排查，比较费时。

三、排查 HBase 0.98 和 1.4.8 代码区别（真正问题原因）

之前所有的猜想（配置或 Kylin 两个版本代码调用区别导致）基本排除掉，只能重新来看 2.0 查询抛出的异常。很奇怪 2.0 抛出的异常为 java.net.SocketTimeoutException 异常，但是 3.0 失败重试机制到达后抛出的是“Call exception, tries=”异常，决定好好看下 HBase retry 的代码。果然在 HBase 的 RpcRetryingCaller 类发现了 java.net.SocketTimeoutException 抛出的原因。HBase 在 retry 的时候有两个逻辑判断是否继续重试：

1. 重试次数如果达到配置的次数则不再重试，并抛出“Call exception, tries=”等关键字的异常代码（3.0 中的尝试也说明了这点）；

2. 重试过程中整个时长如果大于了配置的超时时长也会不再重试，并抛出“java.net.SocketTimeoutException”等关键字的异常代码（2.0 中正是这个异常）。

HBase 有问题的代码也正是这个超时异常的代码。接下来咱们看下这块儿失败重试的具体代码：

/** * Retries if invocation fails. * @param callTimeout Timeout for this call * @param callable The {@link RetryingCallable} to run. * @return an object of type T * @throws IOException if a remote or network exception occurs * @throws RuntimeException other unspecified error */@edu.umd.cs.findbugs.annotations.SuppressWarnings (value = "SWL_SLEEP_WITH_LOCK_HELD", justification = "na")public synchronized T callWithRetries(RetryingCallable<T> callable, int callTimeout)throws IOException, RuntimeException { this.callTimeout = callTimeout; List<RetriesExhaustedException.ThrowableWithExtraContext> exceptions = new ArrayList<RetriesExhaustedException.ThrowableWithExtraContext>(); this.globalStartTime = EnvironmentEdgeManager.currentTimeMillis(); for (int tries = 0;; tries++) { long expectedSleep = 0; try { beforeCall(); callable.prepare(tries != 0); // if called with false, check table status on ZK return callable.call(); } catch (Throwable t) { if (tries > startLogErrorsCnt) { LOG.info("Call exception, tries=" + tries + ", retries=" + retries + ", retryTime=" + (EnvironmentEdgeManager.currentTimeMillis() - this.globalStartTime) + "ms, msg=" + callable.getExceptionMessageAdditionalDetail()); } // translateException throws exception when should not retry: i.e. when request is bad. t = translateException(t); callable.throwable(t, retries != 1); RetriesExhaustedException.ThrowableWithExtraContext qt = new RetriesExhaustedException.ThrowableWithExtraContext(t, EnvironmentEdgeManager.currentTimeMillis(), toString()); exceptions.add(qt); ExceptionUtil.rethrowIfInterrupt(t); if (tries >= retries - 1) { throw new RetriesExhaustedException(tries, exceptions); } // If the server is dead, we need to wait a little before retrying, to give // a chance to the regions to be // get right pause time, start by RETRY_BACKOFF[0] * pause expectedSleep = callable.sleep(pause, tries); // If, after the planned sleep, there won't be enough time left, we stop now. long duration = singleCallDuration(expectedSleep);//有问题的代码，实现逻辑可以看singleCallDuration方法的源码 if (duration > this.callTimeout) {//由于singleCallDuration实现的问题+用户的配置，duration永远都会大于callTimeout，所以无法真正进行失败重试 String msg = "callTimeout=" + this.callTimeout + ", callDuration=" + duration + ": " + callable.getExceptionMessageAdditionalDetail(); throw (SocketTimeoutException)(new SocketTimeoutException(msg).initCause(t)); } } finally { afterCall(); } try { Thread.sleep(expectedSleep); } catch (InterruptedException e) { throw new InterruptedIOException("Interrupted after " + tries + " tries on " + retries); } }}

singleCallDuration 方法源码：

/** * @param expectedSleep * @return Calculate how long a single call took */private long singleCallDuration(final long expectedSleep) {/**此处代码原本的意思应该是要获取一共花费了多少时间，即从开始执行到现在 + 下一次失败重试需要的时间 ，但是此处他还加了rpcTimeout的时间（这个值用户*在hbase-site.xml中可以配置，且正好2.0的8套Kylin集群对应的HBase客户端配置了此值为1200000）。Hbase 3.0此处的代码是没有加rpcTimeout的时间的，*理论也不应该加**/ int timeout = rpcTimeout > 0 ? rpcTimeout : MIN_RPC_TIMEOUT; return (EnvironmentEdgeManager.currentTimeMillis() - this.globalStartTime) + timeout + expectedSleep;}

总结下原因：

HBase 失败重试的时候判断是否超时，首先会获取从执行到下次失败重试一共要花费的时间（duration），但是这块儿在计算 duration 的逻辑有问题(已经花费的时间+ rpctimeout（1200000） + expectedSleep（下次尝试的时间）)），然后在用 duration 时间与 callTimeout（默认1200000，正好与配置的 rpctimeout 相等）比较，看 duration 计算公式知道，duration 如果配置的时间和 callTimeout 相等或者大于，则永远无法进行失败重试。HBase 1.4.8 已经修复了此问题 duration 的计算公式改为（已经花费的时间 + expectedSleep（下次尝试的时间））。

四、解决问题

第一步：修改 Kylin

集群所有的 HBase 客户端 hbase.rpc.timeout 配置，将其时间由 1200000 改为 120000，重启 Kylin 集群，再次实验问题解决，可以在不重启 Kylin 节点的情况查询查询；

第二步：修复 HBase 此处超时判断代码逻辑，彻底解决问题。

补充一点：因为一次 call 请求可能会包含多次 RPC，所以 rpctimeout 的值设置最好小于 callTimeout 时间。

作者介绍：王小静，滴滴大数据架构专家工程师，目前是滴滴 Kylin 引擎的负责人。曾负责架构和运营了滴滴数据中台相关系统——大数据任务调度系统、大数据资产管理、大数据权限管理、数据导入、数据开发等，具有丰富的大数据中台建设和 OLAP 相关经验。

往期案例与实践

▼ 社区福利 ▼ 

推荐 4 个 Apache 顶级项目的官方公众号，希望对大家了解开源大数据生态，扩展技术视野有所帮助。

Ververica

由 Apache Flink Community China 运营管理，旨在联合国内的 Flink 大 V，向国内宣传和普及 Flink 相关的技术。公众号将持续输出 Flink 最新社区动态，入门教程、Meetup 资讯、应用案例以及源码解析等内容，希望联合社区同学一起推动国内大数据技术发展。

Apache Pulsar

Apache Pulsar 是下一代云原生流数据平台，助力企业快速分析实时数据，激活数据价值，实现 C 位出道。这里是 Pulsar 前沿技术的传播圣地，也是技术爱好者、开发者和终极用户时刻关注的技术平台。我们定时分享 Pulsar 优质内容，包括社区活动、技术文章、用户案例、行业动态和热点话题等，让你全面拥抱 Pulsar 的一手讯息。Apache Pulsar，助力千万企业和技术人开疆拓土、共同成长。

HBase 技术社区

研究探讨 Apache HBase 内核原理，源码剖析，周边生态以及实践应用，汇集众多Apache HBase PMC & Committer以及爱好使用者，提供一线Apache HBase企业实战以及Flink集成等资讯。

Apache Kylin

介绍 Kylin 的功能特性、应用案例、经验分享、社区资讯、活动等。开源大数据分布式 OLAP 引擎 Apache Kylin 于 2014 年开源，在 2015 年和 2016 年连续获得 InfoWorld 的 BOSSIE 奖：年度最佳开源大数据工具奖，发展至今在全球已经拥有超过 1000 家企业用户。作为首个被 Apache 软件基金会认证的由中国人主导的顶级开源项目，Kylin 为万亿数据提供亚秒级查询，并可以和现有的 Hadoop/Spark 及 BI 无缝集成。