记一次 Redis Cluster Pipeline 导致的死锁问题
作者:vivo 互联网服务器团队- Li Gang
本文介绍了一次排查 Dubbo 线程池耗尽问题的过程。通过查看 Dubbo 线程状态、分析 Jedis 连接池获取连接的源码、排查死锁条件等方面,最终确认是因为使用了 cluster pipeline 模式且没有设置超时时间导致死锁问题。
一、背景介绍
Redis Pipeline 是一种高效的命令批量处理机制,可以在 Redis 中大幅度降低网络延迟,提高读写能力。Redis Cluster Pipeline 是基于 Redis Cluster 的 pipeline,通过将多个操作打包成一组操作,一次性发送到 Redis Cluster 中的多个节点,减少了通信延迟,提高了整个系统的读写吞吐量和性能,适用于需要高效处理 Redis Cluster 命令的场景。
本次使用到 pipeline 的场景是批量从 Redis Cluster 批量查询预约游戏信息,项目内使用的 Redis Cluster Pipeline 的流程如下,其中的 JedisClusterPipeline 是我们内部使用的工具类,提供 Redis Cluster 模式下的 pipeline 能力:
JedisClusterPipeline 使用:
二、故障现场记录
某天,收到了 Dubbo 线程池耗尽的告警。查看日志发现只有一台机器有问题,并且一直没恢复,已完成任务数也一直没有增加。
查看请求数监控,发现请求数归零,很明显机器已经挂了。
使用 arthas 查看 Dubbo 线程,发现 400 个线程全部处于 waiting 状态。
三、故障过程分析
Dubbo 线程处于 waiting 状态这一点没有问题,Dubbo 线程等待任务的时候也是 waiting 状态,但是查看完整调用栈发现有问题,下面两张图里的第一张是问题机器的栈,第二张是正常机器的栈,显然问题机器的这个线程在等待 Redis 连接池里有可用连接。
使用 jstack 导出线程快照后发现问题机器所有的 Dubbo 线程都在等待 Redis 连接池里有可用连接。
调查到这里,能发现两个问题。
线程一直等待连接而没有被中断。
线程获取不到连接。
3.1 线程一直等待连接而没有被中断原因分析
Jedis 获取连接的逻辑在 org.apache.commons.pool2.impl.GenericObjectPool#borrowObject(long)方法下。
由于业务代码没有设置 borrowMaxWaitMillis,导致线程一直在等待可用连接 ,该值可以通过配置 jedis pool 的 maxWaitMillis 属性来设置。
到这里已经找到线程一直等待的原因,但线程获取不到连接的原因还需要继续分析。
3.2 线程获取不到连接原因分析
获取不到连接无非两种情况:
连不上 Redis,无法创建连接
连接池里的所有连接都被占用了,无法获取到连接
猜想一:是不是连不上 Redis?
询问运维得知发生问题的时间点确实有一波网络抖动,但是很快就恢复了,排查时问题机器是能正常连上 Redis 的。那有没有可能是创建 Redis 连接的流程写的有问题,无法从网络抖动中恢复导致线程卡死?这一点要从源码中寻找答案。
创建连接:
可以看到,连接 Redis 超时时会抛出异常,调用 create()函数的 borrowObject()也不会捕获这个异常,这个异常最终会在业务层被捕获,所以连不上 Redis 的话是不会一直等待下去的,网络恢复后再次调用 create()方法就能重新创建连接。
综上所诉,第一种情况可以排除,继续分析情况 2,连接被占用了没问题,但是一直不释放就有问题。
猜想二:是不是业务代码没有归还 Redis 连接?
连接没有释放,最先想到的是业务代码里可能有地方漏写了归还 Redis 连接的代码,pipeline 模式下需要在 finally 块中手动调用 JedisClusterPipeline#close()方法将连接归还给连接池,而普通模式下不需要手动释放(参考 redis.clients.jedis.JedisClusterCommand#runWithRetries,每次执行完命令后都会自动释放),在业务代码里全局搜索所有使用到了 cluster pipeline 的代码,均手动调用了 JedisClusterPipeline#close()方法,所以不是业务代码的问题。
猜想三:是不是 Jedis 存在连接泄露的问题?
既然业务代码没问题,那有没有可能是归还连接的代码有问题,存在连接泄露?2.10.0 版本的 Jedis 确实可能发生连接泄露,具体可以看这个 issue:https://github.com/redis/jedis/issues/1920,不过我们项目内使用的是 2.9.0 版本,所以排除连接泄露的情况。
猜想四:是不是发生了死锁?
排除以上可能性后,能想到原因的只剩死锁,思考后发现在没有设置超时时间的情况下,使用 pipeline 确实有概率发生死锁,这个死锁发生在从连接池(LinkedBlockingDeque)获取连接的时候。
先看下 cluster pipeline 模式下的 Redis 和普通的 Redis 有什么区别。Jedis 为每个 Redis 实例都维护了一个连接池,cluster pipeline 模式下,先使用查询用的 key 计算出其所在的 Redis 实例列表,再从这些实例对应的连接池里获取到连接,使用完后统一释放。而普通模式下一次只会获取一个连接池的连接,用完后立刻释放。这意味着 cluster pipeline 模式在获取连接时是符合死锁的“占有并等待”条件的,而普通模式不符合这个条件。
JedisClusterPipeline 使用:
JedisClusterPipeline 部分源码:
举个例子:
假设有一个集群有两台 Redis 主节点(集群模式下最小的主节点数量是 3,这里只是为了举例),记为节点 1/2,有个 java 程序有 4 个 Dubbo 线程,记为线程 1/2/3/4,每个 Redis 实例都有一个大小为 2 的连接池。
线程 1 和线程 2,先获取 Redis1 的连接再获取 Redis2 的连接。线程 3 和线程 4,先获取 Redis2 的连接再获取 Redis1 的连接,假设这四个线程在获取到连接第一个连接后都等待了一会,在获取第二个连接的时候就会发生死锁(等待时间越长,触发的概率越大)。
所以 pipeline 是可能导致死锁的,这个死锁的条件很容易破坏,等待连接的时候设置超时时间即可。还可以增大下连接池的大小,资源够的话也不会发生死锁。
四、死锁证明
以上只是猜想,为了证明确实发生了死锁,需要以下条件:
线程当前获取到了哪些连接池的连接
线程当前在等待哪些连接池的连接
每个连接池还剩多少连接
已知问题机器的 Dubbo 线程池大小为 400,Redis 集群主节点数量为 12,Jedis 配置的连接池大小为 20。
4.1 步骤一:获取线程在等待哪个连接池有空闲连接
第一步:先通过 jstack 和 jmap 分别导出栈和堆
第二步:通过分析栈可以知道线程在等待的锁的地址,可以看到 Dubbo 线程 383 在等待 0x6a3305858 这个锁对象,这个锁属于某个连接池,需要找到具体是哪个连接池。
第三步:使用 mat(Eclipse Memory Analyzer Tool)工具分析堆,通过锁的地址找到对应的连接池。
使用 mat 的 with incoming references 功能顺着引用一层层的往上找。
引用关系:ConditionObject->LinkedBlockingDeque
引用关系:LinkedBlockingDeque->GenericObjectPool
引用关系:GenericObjectPool->JedisPool。这里的 ox6a578ddc8 就是这个锁所属的连接池地址。
这样我们就能知道 Dubbo 线程 383 当前在等待 0x6a578ddc8 这个连接池的连接。
通过这一套流程,我们可以知道每个 Dubbo 线程分别在等待哪些连接池有可用连接。
4.2 步骤二:获取线程当前持有了哪些连接池的连接
第一步:使用 mat 在堆中查找所有 JedisClusterPipeline 类(正好 400 个,每个 Dubbo 线程都各有一个),然后查看里面的 poolToJedisMap,其中保存了当前 JedisClusterPipeline 已经持有的连接和其所属的连接池。
下图中,我们可以看到 JedisClusterPipeline(0x6ac40c088)对象当前的 poolToJedisMap 里有三个 Node 对象(0x6ac40dd40, 0x6ac40dd60, 0x6ac40dd80),代表其持有三个连接池的连接,可以从 Node 对象中找到 JedisPool 的地址。
第二步:第一步拿到 JedisClusterPipeline 持有哪个连接池的连接后,再查找持有此 JedisClusterPipeline 的 Dubbo 线程,这样就能得到 Dubbo 线程当前持有哪些连接池的连接。
4.3 死锁分析
通过流程一可以发现虽然 Redis 主节点有 12 个,但是所有的 Dubbo 线程都只在等待以下 5 个节点对应的连接池之一:
0x6a578e0c8
0x6a578e048
0x6a578ddc8
0x6a578e538
0x6a578e838
通过流程二我们可以得知这 5 个连接池的连接当前被哪些线程占用:
已知每个连接池的大小都配置为了 20,这 5 个连接池的所有连接已经被 100 个 Dubbo 线程占用完了,而所有的 400 个 Dubbo 线程又都在等待这 5 个连接池的连接,并且其等待的连接当前没被自己占用,通过这些条件,我们可以确定发生了死锁。
五、总结
这篇文章主要展现了一次系统故障的分析过程。在排查过程中,作者使用 jmap 和 jstack 保存故障现场,使用 arthas 分析故障现场,再通过阅读和分析源码,从多个可能的角度一步步的推演故障原因,推测是死锁引起的故障。在验证死锁问题时,作者使用 mat 按照一定的步骤来寻找线程在等待哪个连接池的连接和持有哪些连接池的连接,再结合死锁检测算法最终确认故障机器发生了死锁。
排查线上问题并非易事,不仅要对业务代码有足够的了解,还要对相关技术知识有系统性的了解,推测出可能导致问题的原因后,再熟练运用好排查工具,最终确认问题原因。
版权声明: 本文为 InfoQ 作者【vivo互联网技术】的原创文章。
原文链接:【http://xie.infoq.cn/article/36e82980324ddca675eb1d31d】。文章转载请联系作者。
评论