版本:

IoTDB:re/0.12  f37650922294702ef459dd61ab90dc8cee8991cb

现象:

启动 3 节点单副本分布式,使用 benchmark 向集群注入读写混合的负载。几个小时后,分布式合并出现卡顿,极少数 tsfile 不再参与合并。

debug 过程:

合并模块自查:

遇到这个问题后,合并模块难辞其咎,首先先去测试环境检测复现的原因,即在 TsFileResource 中获取和释放读写锁的四处添加了线程名,堆栈,读引用个数等信息。

通过对 log 和 jstack 的分析,基本可以明确。合并之所以不再执行是由于拿不到对应 tsfileresource 的写锁,之所以拿不到写锁是因为读引用并未清空。那么这个读引用到底为什么没有被清空?从 log 分析可以得出,最后拿这个 tsfileresource 读锁的线程名是 DataClientThread。这是一个集群间通信的线程,找到这儿,已经基本可以明确此问题跟合并本身没太大关系,应该是一个分布式查询释放资源的 bug,其在拿了读锁之后并没有进行释放。

分布式查询初分析:

接下来进入分布式查询流程的分析阶段,相关文档可以参考分布式查询文档

首先我们检查了在数据节点注册 queryContext 和 endquery 的代码,确定了没有并发问题。接着我们打了日志,这样便可以看出是否存在协调者节点注册了 queryId 但没 endquery 的情况。 

但是通过 log 打下来。我们可以看到注册远比释放多。但通过查看代码,我们也确认了不论协调者节点来这边注册 reader 还是 fetch 数据,均需要取这个 context,然而 endquery 却只会有一次。这里前者多看起来是符合预期的(实际上 bug 藏于此处,但我们此时不得而知)。


接着我们查看代码的堆栈,发现基本都是在 querySingleSeries 和 querySingleSeriesByTimestamp 两个函数处,因而我们顺手在返回值上打了 log。(伏笔!!!)

接着我们往内部看,看到 FileReaderManager 的 closedReferenceMap 实际上是一个引用计数的方式,其结构为 Map<String, Long>,我们只知道后面的 long 不能清零,但不知道到底是哪个 queryId 导致的,这与集群中其它地方打的 log 不能组成一条调用线,因而我们将这里修改为了引用记录的方式,即将这里的 value 置为了 queryId 的 set,以期望能与其他 log 连起来。


接着也没什么信息了,开始复测吧。

并发问题猜测:

不出意外,复测一轮后,依然复现了此 bug,此时我们开始就此轮的 log 进行了分析。在看代码并苦思冥想中,我们忽然发现了实验室一位已经毕业的学姐在两年前向我们打的招呼。

可以看到,这种 contains 再 add 的实现在多线程并发的时候一定可能会存在问题,结合到这种跑很久且极少数tsfile才会卡主的现象。我们想当然的认为这里可能是存在并发问题的。我们进行了一些分析,通过”印象“大家得出了”单机不会出现并发问题而分布式会在此处出现并发问题“的结论。因此,我们迅速在此处改为了 concurrentHashMap 并实现了一个线程安全的版本。

实际上这一轮我们并没有仔细去看日志,仅凭直觉和印象就觉得这里有问题。匆匆改了后边尝试再去复测了。此时我们乐观的认为这个 bug 已经被修复了。当然,现实很骨感。

黑科技 udf 下仔细剖析:

再次复测一轮后,依然复现了此 bug,此刻心中是绝望的,然而多多少少也唤醒了我们心中的一丝好强之心。为此,我们仔细的过了一遍查询的代码,然而我们惊奇的发现,”单机不会出现并发问题而分布式会在此处出现并发问题“的结论并不正确,这里在分布式中依然是串行的,由此可见。大家的印象依然是不太靠谱的,即使是自己实现的代码,过了很久也可能会忘掉。既然如此,那上个修复显然是没有意义的。


此刻能做什么的?只能耐心的回到本质来分析。我们首先利用黑科技 udf 来打出了 FileReaderManager 的 closedReferenceMap。可以看到,这些文件刚好是没有继续合并的文件,其都存在读引用尚未释放。在分布式查询的实现中,每个查询在协调者节点生成一个 queryId,这些 queryId 在其他节点查询时为了避免冲突又会生成一个数据节点本地的 queryId 并保存到 context 中。所以 udf 打出来的这些 queryId 都是数据节点本地的 queryId,跟前面的 regist queryid 里面的 id 并不相等,虽然他们是一一对应的。但至少,在再次复测前我们无法找到这个对应关系。

既然无法从 queryId 入手,那我们便从 tsfile 的名字入手,我们用 grep 命令查了所有 log 找这些 tsfile 获取和释放读锁的日志,并定位到了有问题的时间段。 

接着我们又从 log 中查看该时间段附近的日志,进而从中找到了协调者节点 queryiD 和数据节点 queryid 的对应关系。虽然在当时看到这个对应关系之后依然没想到有什么用,但是我们依然记住了那几个数字。接着我们又分析来分析去,整理流程,但依然想不到有问题问题。而且此时还出现了 logger 犯病丢日志的问题,这进一步增大了我们 debug 的难度。


就在我们快要放弃之时,我们决定给乔老师和田原讲解一下问题。在讲解的过程中,我们对一些问题有了更深的理解,同时,我们也随手打开了 error 日志。之前埋的伏笔起了作用,这里返回 readerId 为 -1 的几个 queryId,恰好是之前出现泄漏的几个本地 queryid 对应的协调者节点的 queryid。这里面有什么巧合吗?

问题根因:

绝对有!我们开始研究 -1 的 readerid 是什么意思。

在数据节点来看,readerid 为 -1 是指一个查询过来后,其给 tsfile resource 加了读引用,查了之后发现没有满足要求的数据,接着它就会返回 -1 以让协调者节点得知。

在协调者节点来看,当我创建 remoteReader 的时候,如果不返回 -1 我才会将这个节点注册到 context 的 remoteNodes 里面,之后 endquery 的时候便会向这个节点发送 ednquery 的 rpc。如果是 -1,那么便不会注册该节点,因为本来也没有数据,不需要去 endquery...哎?是这样吗?

哦不,不是这样。实际上他在获取 readerid 的时候就已经自增过读引用了,如果没有数据,我们也应该自减这个读引用才对,但自减读引用的逻辑只有在 endquery 的时候才会触发。然而分布式对于 readerid 为 -1 的节点都不会注册该 node 到 context 中,到时候发送 rpc 肯定也不会在这个节点上 endquery 了。那不就泄露了吗?


由此可见,不论 readerId 为不为 -1,我们都应该注册该节点,因为在数据节点那边已经增过读引用了,自然也需要 endquery。此外,分布式系统对于 rpc 有头疼的三态问题:成功,失败,超时。对于第三种情况,一旦协调者节点获取 readerId 超时,我们也不知到底该 rpc 在数据节点是否已经执行过,它可能已经增加了读引用也可能没有。但不论如何,对于此种情况,我们必须要去发 endquery,这样才能达到绝对的 safety。这也是我们为什么要把注册节点的逻辑写到 finally 里面而不是获取 readerid 之后。


如此改了之后,岁月静好。终于经过一天的长测,合并卡顿的 bug 也没有复现。我们可以放心的认为该 bug 已经被修复了。

总结:

看到这儿,相信大家已基本明白这个 bug 的原因。总结来看就是分布式查询在实现过程中没有仔细去思考这些 rpc 在底层对应的读写锁逻辑,从而产生了这种近似于查询锁泄露的 bug。

这个 bug 可以说自分布式诞生以来就存在,已经坚挺了近两年。今年暑假四维上线时也曾遇到这个问题,但当时也没有找出来问题的根因。这次总算是解决了。

思考:

这篇分析文档夹杂了太多个人的心路历程,这些其实大家不用关注。就这个过程而言,我总结了一些经验,对我自己是有益的,也希望对大家有益。

  • 凭印象和灵机一动来 debug 是不靠谱的。最不会说慌的还是代码,从流程看起,理清整个流程对于 debug 会有很大的帮助。
  • 每个人的关注点不一样,遇到瓶颈时可以向别人讲解自己的 debug 过程,这样一方面有助于理顺自己的 debug 思路(也可能发现自己想错的一些地方),另一方面也便于其他人用另一个视角来帮助 debug。
  • 对于资源泄露类 bug,最靠谱的还是直接 dump 内存或者通过 runtime 的形式把对应的值打出来。如果这次 debug 我们早早的去看 ClusterQueryManager 的成员变量,可能就更早的发现实际有协调者节点注册的 queryId 没释放。 

拓展:

虽然这个 bug 也解了,但是在更进一步了解了查询流程后,也有了一层隐隐的担忧。因为集群任何一个节点都可能发生宕机,所以这种跨节点管理引用的方式需要多次 rpc 才能释放引用,这是非常危险的,一旦有节点宕机,便可能导致其他节点的部分引用没办法释放。

对于这种困境,我勉强想了想几种可能的解决方案:

  1. 参照 2pc + 共识组的设计,将锁的管理共识化,这样便可以保证最终最会有人释放锁。当然这在咱们的场景下几乎是完全不可用的,对性能影响太大了。
  2. 为单机的引用计数提供 ttl 的属性,即超过一段时间不再获取该数据便释放引用。这可能又会有 safety 的问题,毕竟由于 flp 定理,分布式锁是无法保证绝对的 safety 的。

总之这个问题先抛在这儿,我目前还没有什么好的想法,欢迎大家找我讨论。




  • No labels