高并发场景创建JedisPool有哪些注意事项?

一、背景

一个平静的下午,报警、Moji 群里接连传来并行 MOA 默认集群 /service/parallel 出现异常的提示信息,服务维护人员查看日志发现是发生了并行任务线程池被打满的问题。线程池满会导致新请求直接被拒绝,大量业务请求报错,极速版附近的人、基因、聊天室等多个业务进入降级状态... 而导致这一系列严重影响的问题原因,是大家最熟悉不过的 new JedisPool() 这一行代码。

Jedis 是 Java 访问 Redis 最常用的客户端组件

二、问题分析

从慢请求日志我们发现,单一请求阻塞线程的时间最长可达到 10 分钟以上。简单的 new JedisPool()为何会长时间阻塞线程?通过搭建测试服务、复现问题、抓取 jstack 分析后,我们发现 JedisPool 中向 JMX 注册对象的逻辑,在特定的场景会出现严重的锁竞争与阻塞问题。

包依赖说明

并行 MOA 工程 ->MOA(MOARedisClient) ->MCF(RedisDao) ->Jedis(JedisPool) ->commons-pool(BaseGenericObjectPool) ->JDK(JMX)

问题出现在并行 MOA 通过 MOARedisClient 访问下游服务新启动实例的过程中,此时需要通过 new JedisPool()创建与下游实例的连接池。

new JedisPool()中与 JMX 的交互

JedisPool 使用 commons-pool 来管理连接对象,commons-pool 创建对象池时会向 JMX 注册,以便于在运行时通过 JMX 接口获取对象池相关的监控数据。但向 JMX 注册的过程,包含以下逻辑

  1. commons-pool 向 JMX 注册 BaseGenericObjectPool 对象,JMX 要求每个对象有不同的名字
  2. commons-pool 生成不同名字的方式是:基于一个默认相同的名字,末尾添加一个自增 ID
  3. 每次 new JedisPool()时 ID 从 1 开始尝试,发现名字重复后 ID 自增+1 后再次重试,直至发现一个未被占用的 ID、重试成功为止
  4. 尝试某个名字是否被占用,会共用一把全局的锁,同一时刻只能有一个 JedisPool 对象对某一个名字 ID 验证是否重复

commons-pool 中遍历 ID 尝试注册 objName 的代码

JMX 中注册对象的代码,会获取一把全局的锁

问题产生的条件

  1. 当前进程中已创建了大量的 JedisPool,有大量的自增 ID 已被占用(如 1~1w 已被占用)
  2. 此时创建下一个 JedisPool,需要遍历 1w 次已有 ID 才能以 1w + 1 这个 ID 注册对象,这 1w 次尝试每次都需要加锁
  3. 当有多个线程同时创建 JedisPool 时,每个线程都需要遍历所有 ID,并且遍历过程中每次加锁都会导致其他线程无法重试、只能等待
  4. 假设 1 个线程遍历 1w 次需要 1 秒,100 个线程各遍历 1w 次、共计 100w 次尝试需要串行执行,并且 100 个线程是交替获得锁、交替重试,最终导致 100 个线程都需要 100 秒才能重试完

三、问题排查过程

问题产生

16:14 /service/phpmoa/v1_microvideo_index 执行常规的发布操作 16:16 /service/parallel 并行任务线程池被打满、开始通过扩容和隔离实例解决 16:26 服务逐步恢复

并行 MOA 使用了 MSC 线程池组件,从活跃线程数监控可以看到每个并行 MOA 实例线程池被打满到恢复的时间

被阻塞的线程是能够自动恢复的,并且恢复的时间并不统一。从日志中我们首先找到了阻塞线程的慢请求

execution finished after parallel timeout: /service/phpmoa/v1_microvideo_index,isRiskFeeds, startTime = 2020-11-30 16:26:02,428, server = 10.116.88.15:20000, routeTime = 2020-11-30 16:26:02,428, blacklistTime = 2020-11-30 16:26:02,428, executeTime = 2020-11-30 16:37:21,657, timeCost = 679229

复制代码

刚好是调用 /service/phpmoa/v1_microvideo_index 服务,但记录的执行时间最长可达到 10 分钟以上。慢日志中包含各个阶段的耗时,因此耗时的逻辑可以锁定在 blacklistTime 和 executeTime 之间,这里只对应一行通过 MOA 框架 MOARedisClient 调用下游服务的代码

初步分析

在 MOARedisClient.exeuteByServer()内部,仅有 2 个逻辑可能出现较长的耗时,一个是 RedisFactory.getRedisDao(),这里会与下游实例创建连接。另一个是 doInvoke()真正发起请求,由于后者的耗时会提交到 Hubble,并且未发现达到分钟级的耗时,因此问题的原因更可能出现在创建 RedisDao 的逻辑中。

排查瓶颈

由于 RedisFactory.getRedisDao()各个阶段的耗时缺少监控,并且服务出现异常期间没有及时通过 jstack 打印堆栈信息,问题排查到这一步仅靠分析很难继续进行。

问题复现

我们查找了 /service/phpmoa/v1_microvideo_index 的发布记录,发现这个服务每次发布的时候,/service/parallel 都会有短暂的 errorCount 波动,因此推断该问题是能够通过重启 /service/phpmoa/v1_microvideo_index 来复现的。

搭建测试服务

重启线上服务有可能再次导致服务异常、影响线上业务,所以我们先尝试在线上环境复制上下游项目、发布成不同的 ServiceUri,并增加一个测试接口,通过压测平台制造流量,搭建起和线上调用链路基本一致的测试环境。

增加监控

除了在 MOA 和 MCF 的代码中增加各阶段耗时的日志外,对于并行 MOA 出现线程池满拒绝请求、以及出现 10 秒以上慢请求的场景,均增加了自动打印 jstack 的机制。

获得排查依据

在适当调整模拟流量的压力后,重启测试的 /service/phpmoa/v1_microvideo_index 服务后,问题提复现了。这一次我们拿到了详细的耗时信息,以及线程池满后的 jstack 堆栈信息,才进一步分析到问题的根本原因。

四、问题验证

测试服务验证

  1. 问题复现后的 jstack 堆栈,611 个线程停留在等待锁的步骤
  2. 将 JMX 关闭后,对比其他未关闭的实例没有再复现该问题

与问题现象匹配

并行 MOA 的特征

  1. 调用的下游服务极多、下游实例数极多,需要创建大量的 JedisPool
  2. 下游重启过程中并行 MOA 需要创建大量新的 JedisPool,并且并行创建的线程数很多(最多 800 个)

问题发生过程

  1. 下游服务发布后出问题(microvideo_index)、下游实例数多的服务发布问题严重(230 个)、发布速度快的服务问题严重(2 分钟)、多个服务同时发布的时候问题严重(microvideo_index 和 user_location 在同一时间段做发布)
  2. 各个并行 MOA 实例能够自动恢复,但恢复的时间点差异较大(具体耗时取决于已有 ID 数量、并行创建 JedisPool 的线程数据量,各实例的情况可能不一致)
  3. 异常期间并行 MOA 服务的 CPU 使用率大幅升高(在频繁获取锁)
  4. 相同时刻其他并行 MOA 的集群未出问题(因为请求量低、并行创建 JedisPool 的线程少)

五、解决方案

问题影响范围

业务上使用 JedisPool 的场景,多通过 MCF 的 RedisDao 封装。RedisDao 主要用于两个场景

MomoStore

通过 MomoStore 访问 Redis 数据源、访问 OneStore 底层使用 RedisDao。由于 MomoStore 对于新实例的连接建立是在接收事件通知后单线程执行的,受并发创建 JedisPool 的影响较少。

MOARedisClient

由于与下游新实例创建连接的动作是在业务请求中完成的,所以使用 MOARedisClient 的场景受并发创建 JedisPool 影响的可能性较大。当服务与并行 MOA 具备类似的特征:下游服务多、实例多,并行执行的请求多,在下游服务发布时也容易出现相同的问题。使用 MOARedisClient 在某些场景下的执行时间超出设定的 timeout 时间,也与该问题有关。

修复方案

最简单有效的解决方案是关闭 JedisPool 的 JMX 配置,可以在 MCF 的代码中统一修改、通过升级 MCF 版本修复。对于已接入 Mesh 的服务,由于 MOARedisClient 实际与下游通信的地址是 127.0.0.1,所需建立的连接池很少,所以不会受该问题影响。后续我们会扫描所有使用 MOARedisClient、但尚未接入 Mesh 的服务,推动升级 MCF 版本消除这一隐患。

其他改进项

在 MSC 线程池中加入线程池满自动打印 jstack 的机制。

  • 发表于:
  • 本文为 InfoQ 中文站特供稿件
  • 首发地址https://www.infoq.cn/article/e774c2abdcc5831eee4d9ec09
  • 如有侵权,请联系 cloudcommunity@tencent.com 删除。

扫码关注腾讯云开发者

领取腾讯云代金券