文章目录

  • 问题描述
  • 问题排查
  • (1)观察日志以及监控
  • (2)推断问题
  • (3)定位问题
  • 解决方法

关键信息 (1)发现一些生产中异步提交的线程任务延迟执行严重,甚至不执行 (2)异常时发现服务器线程数飙升,某些组件拿不到线程,甚至需要异常重启

问题描述

(1)发现最近一个项目服务,经常忘记更新某些信息。查询代码,发现这些信息都是放在一个线程里面异步提交。而根据日志发现,线程的前后代码均已执行,只有这个线程提交
的异步任务迟迟不执行,也不报错。

(2)发现该项目经常报出druid,dubbo等一些需要申请线程的服务出现异常。

问题排查

(1)观察日志以及监控

先从未及时更新的请求入手,追踪代码逻辑到更新信息的接口。结合日志,发现存在以下关键点:

1----更新信息的接口被放在一个异步线程任务中执行。

2----异步任务前后均已执行,即可推断任务肯定被提交了。

3----更新信息接口被try catch捕捉,没有打印错误日志,也没有看到该接口的请求记录。说明异步任务一直没有被执行。

(2)推断问题

这个时候有了如下推断

推断1:服务在该时刻存在重启或者异常中断的现象,丢失了当前的任务。

查看了该时刻的性能监控,发现短时间内只是服务的线程数增加了,内存,CPU均正常。但是

推断2:任务被直接拒绝。

查看了线程池的构造参数,拒绝策略为抛出异常。但是在日志中并未出现相关日志,并且线程池的队列长度较长,线程池不太可能被打满队列。

推断3:任务在队列中,一直在排队执行。

查看了线程池的构造参数,队列长度较大,延时肯定是因为在队列中。

(3)定位问题

仔细观察服务器那个时间段的运行状态,发现节点的active thread数量一直上升,并且运行的越来越慢。数据库的连接数也在一直上升,最后过
了一段时间,服务器异常后重启。联系运维要异常节点日志,联系DBA查看数据库的连接中的执行任务,排查最近上线的代码,发现以下关键点:

关键点1:服务节点的active thread 数量一直上升,平均执行时间也越来越长,直至服务挂掉,服务异常退出的时候抛出了一堆InterruptedException。
这里说明某些active thread中的任务被堵塞了,并且一直不能退出。抛出的InterruptedException说明服务退出时存在一堆未执行完的任务(包括前面排查的
已提交但未执行的异步线程任务)

关键点2:数据库的连接数一直上升,但DBA反馈大部分是空闲状态,且并没有慢SQL或者如何异常信息。这里说明异常应该与数据库层面无关,要从服务的代码去
寻找问题。

关键点3:最近项目上线了一个新功能,所以应该是新上线的代码引出的问题。观察代码,发现代码中存在一个执行时间较长的操作(处理文件),并且是用
异步线程池提交,后续要等到改操作的一个返回值,并且该操作没有设置超时时间,线程池参数不合理(核心线程2,队列长度30000
)。观察相关接口的执行时间,发现在出问题的时间段,这个接口经常出现超时。

问题复现

在测试环境,模拟调用该接口。发现并发数量增加情况下(或者处理文件较多时,网络波动时),该接口执行时间愈发缓慢,并且不会超时失败。观察测试节点的状态,
发现active thread一直上升,数据库连接也在上升。上升到一定数量后,服务异常退出,并抛出一堆InterruptedException。

原因剖析

上线一个新需求,这个需求里假设A里面使用了future.get()方法获取异步任务的返回值,该方法未设置超时时间。该任务的线程池参数为----
核心线程是2,由于缓存队列30000。这时候A方法被执行了多次,导致一直卡在future.get()方法里等待,从而activeThread一直上升,导致其他线程包括dubbo、druid的线程也被阻塞。druid的线程池直接被打满。
最后服务异常退出,中断所有未完成任务的线程,抛出一大堆InterruptedException。

未及时更新的请求就是因为当时服务出现了这种异常状态,这些请求的更新操作提交到线程池中,线程池将其放入队列中而得不到执行,最后服务异常退出,一直没执行

解决方法

(1)设置合理的线程池参数。一定不要用默认或者已有的设置,要根据业务场景选择。

(2)future.get()方法要设置超时时间。由于异步任务的执行可能会被放在队列中,或者其他的意外情况,一定要设置合理的超时时间来等待异步任务返回值,
不设置超时时间(或者时间过长),都会导致线程一直等待堵塞。

(3)如果有必要可以设置一个线程池的监控报警系统,更好的观测线程池的状态。