本篇内容介绍了“高并发场景创建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()创建与下游实例的连接池。
JedisPool使用commons-pool来管理连接对象,commons-pool创建对象池时会向JMX注册,以便于在运行时通过JMX接口获取对象池相关的监控数据。但向JMX注册的过程,包含以下逻辑
commons-pool向JMX注册BaseGenericObjectPool对象,JMX要求每个对象有不同的名字
commons-pool生成不同名字的方式是:基于一个默认相同的名字,末尾添加一个自增ID
每次new JedisPool()时ID从1开始尝试,发现名字重复后ID自增+1后再次重试,直至发现一个未被占用的ID、重试成功为止
尝试某个名字是否被占用,会共用一把全局的锁,同一时刻只能有一个JedisPool对象对某一个名字ID验证是否重复
commons-pool中遍历ID尝试注册objName的代码
JMX中注册对象的代码,会获取一把全局的锁
当前进程中已创建了大量的JedisPool,有大量的自增ID已被占用(如1~1w已被占用)
此时创建下一个JedisPool,需要遍历1w次已有ID才能以1w + 1这个ID注册对象,这1w次尝试每次都需要加锁
当有多个线程同时创建JedisPool时,每个线程都需要遍历所有ID,并且遍历过程中每次加锁都会导致其他线程无法重试、只能等待
假设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堆栈信息,才进一步分析到问题的根本原因。
问题复现后的jstack堆栈,611个线程停留在等待锁的步骤
将JMX关闭后,对比其他未关闭的实例没有再复现该问题
调用的下游服务极多、下游实例数极多,需要创建大量的JedisPool
下游重启过程中并行MOA需要创建大量新的JedisPool,并且并行创建的线程数很多(最多800个)
下游服务发布后出问题(microvideo_index)、下游实例数多的服务发布问题严重(230个)、发布速度快的服务问题严重(2分钟)、多个服务同时发布的时候问题严重(microvideo_index和user_location在同一时间段做发布)
各个并行MOA实例能够自动恢复,但恢复的时间点差异较大(具体耗时取决于已有ID数量、并行创建JedisPool的线程数据量,各实例的情况可能不一致)
异常期间并行MOA服务的CPU使用率大幅升高(在频繁获取锁)
相同时刻其他并行MOA的集群未出问题(因为请求量低、并行创建JedisPool的线程少)
业务上使用JedisPool的场景,多通过MCF的RedisDao封装。RedisDao主要用于两个场景
通过MomoStore访问Redis数据源、访问OneStore底层使用RedisDao。由于MomoStore对于新实例的连接建立是在接收事件通知后单线程执行的,受并发创建JedisPool的影响较少。
由于与下游新实例创建连接的动作是在业务请求中完成的,所以使用MOARedisClient的场景受并发创建JedisPool影响的可能性较大。当服务与并行MOA具备类似的特征:下游服务多、实例多,并行执行的请求多,在下游服务发布时也容易出现相同的问题。使用MOARedisClient在某些场景下的执行时间超出设定的timeout时间,也与该问题有关。
最简单有效的解决方案是关闭JedisPool的JMX配置,可以在MCF的代码中统一修改、通过升级MCF版本修复。对于已接入Mesh的服务,由于MOARedisClient实际与下游通信的地址是127.0.0.1,所需建立的连接池很少,所以不会受该问题影响。后续我们会扫描所有使用MOARedisClient、但尚未接入Mesh的服务,推动升级MCF版本消除这一隐患。
在MSC线程池中加入线程池满自动打印jstack的机制。
“高并发场景创建JedisPool有哪些注意事项”的内容就介绍到这里了,感谢大家的阅读。如果想了解更多行业相关的知识可以关注亿速云网站,小编将为大家输出更多高质量的实用文章!
免责声明:本站发布的内容(图片、视频和文字)以原创、转载和分享为主,文章观点不代表本网站立场,如果涉及侵权请联系站长邮箱:is@yisu.com进行举报,并提供相关证据,一经查实,将立刻删除涉嫌侵权内容。