一次线程池引发事故带来的思考
问题
系统中某个接口响应全部超时,dubbo线程池被全部占满,并堆积了大量待处理任务,整个应用无法响应任何外部请求,处于"假死"的状态,过去几分钟后,应用居然自己自动恢复了。 排查是不是流量暴增引起?排查后台流量监控,发现最近流量很平稳。
是不是有慢查导致整个应用拖慢?当应用的高QPS接口出现慢查时,会导致处理请求的线程池中(dubbo线程池),大量堆积处理慢查的线程,占用线程池资源,使新的请求线程处于线程池队列末端的等待状态,情况恶劣时,请求得不到及时响应,引发超时。但遗憾的是,出问题的时间段,并未发生慢查。 是不是频繁GC?如果JVM频繁的发生Stop The World,或者停顿时间较长,会一定程度的影响应用处理请求的能力。但是我们查看了GC日志,并没有任何的异常,看来也不是GC异常导致的。 排查日志,发现了一个异常现象,某个平时不怎么报错的接口,在1秒内被外部调用了500多次,此后在那个时间段内,根据traceid这500多次请求产生了400多条错误日志,并且错误日志最长有延后好几分钟的。
这是怎么回事呢?这里有两个问题让我们疑惑不解: 500QPS完全在这个接口承受范围内,压力还不够。 为什么产生的错误日志能够被延后好几分钟。
日志中明显的指出,这个http请求Read timed out。http请求中读超时设置过长的话,最终的效果会和慢查一样,导致线程长时间占用线程池资源(dubbo线程池),简言之,老的出不去,新的进不来。带着疑问,我们翻到了代码。
但是代码中确实是设置了读超时的,那么延后的错误日志是怎么来的呢?我们已经接近真相了吗? 破案
我们不免对这个RestTemplateBuilder起了疑心,是这个家伙有什么暗藏的设置嘛?针对这个工具类,将线上的情况回放到本地进行了模拟。我们构建了500个线程同时使用这个工具类去请求一个http接口,这个http接口让每个请求都等待2秒后再返回,具体的做法很简单就是Thread.sleep(2000),然后观察每次请求的response和rt。
我们发现response都是正常返回的(没有触发Read timed out),rt是规律的5个一组并且有2秒的递增。看到这里,大家是不是感觉到了什么?对!这里面有队列!通过继续跟踪代码,我们找到了"元凶"。
这个工具类默认使用了队列去发起http请求,形成了类似pool的方式,并且pool active size仅有5。
现在我们来还原下整个案件的经过: 500个并发的请求同时访问了我们应用的某个接口,将dubbo线程池迅速占满(dubbo线程池大小为200),这个接口内部逻辑需要访问一个内网的http接口 由于某些不可抗拒因素,这个时间段内这个内网的http接口全部返回超时 这个接口发起http请求时,使用队列形成了类似pool的方式,并且pool active size仅有5,所以消耗完500个请求大约需要(500/5)*2=200s,这200s内应用本身承担着大约3000QPS的请求,会有大约3000*200=600000个任务会进入dubbo线程池队列(如悬案中的日志截图)。PS:整个应用当然就凉凉咯。 消耗完这500个请求后,应用就开始慢慢恢复(恢复的速率与时间可以根据正常rt大致算一算,这里就不作展开了)。 思考
到这里,大家心里的一块石头已经落地。但回顾整个案件,无非就是我们工作中或者面试中,经常碰到或被问到的一个问题:"对象池是怎么用的呢?线程池是怎么用的呢?队列又是怎么用的呢?它们的核心参数是怎么设置的呢?"。答案是没有标准答案,核心参数的设置,一定需要根据场景来。拿本案举例,本案涉及两个方面:
发起http请求的队列
这个使用队列形成的pool的场景是侧重IO的操作,IO操作的一个特性是需要有较长的等待时间,那我们就可以为了提高吞吐量,而适当的调大pool active size(反正大家就一起等等咯),这和线程池的的maximum pool size有着异曲同工之处。那调大至多少合适呢?可以根据这个接口调用情况,平均QPS是多少,峰值QPS是多少,rt是多少等等元素,来调出一个合适的值,这一定是一个过程,而不是一次性决定的。那又有同学会问了,我是一个新接口,我不知道历史数据怎么办呢?对于这种情况,如果条件允许的话,使用压测是一个不错的办法。根据改变压测条件,来调试出一个相对靠谱的值,上线后对其观察,再决定是否需要调整。
dubbo线程池
在本案中,对于这个线程池的问题有两个,队列长度与拒绝策略。队列长度的问题显而易见,一个应用的负载能力,是可以通过各种手段衡量出来的。
就像我们去餐厅吃饭一样,顾客从上桌到下桌的平均时间(rt)是已知的,餐厅一天存储的食物也是已知的(机器资源)。回到本案,如果我们调低了队列的长度,增加了适当的拒绝策略,并且可以把长时间排队的任务移除掉(这么做有一定风险),可以一定程度的提高系统恢复的速度。
最后补一句,我们在使用一些第三方工具包的时候(就算它是spring的),需要了解其大致的实现,避免因参数设置不全,带来意外的"收获"。 补充
线程池的提交过程
线程池中的线程数小于核心线程数量(corePoolSize)时,开启新线程执行任务 线程数大于等于核心线程数时,将任务提交到队列(workQueue)中 如果队列也满了,就尝试启动非核心线程执行任务 如果已达到最大线程数量(maximumPoolSize),则根据拒绝策略(handler)进行任务拒绝 此后,核心线程会一直阻塞并监听队列中的任务,非核心线程也阻塞监听队列中的任务,但是会在等待固定的时间(keepAliveTime+unit)依然没有任务时,结束等待,销毁线程 AbortPolicy:任务过量,不处理,直接抛异常 CallerRunsPolicy:任务过量,哪来的回哪去,谁把任务给线程池的,就谁去执行,这里是main线程扔给线程池的,因此main线程执行,不抛异常 DiscardPolicy:过量的任务直接放弃,不抛异常 DiscardOldestPolicy:过量的任务会尝试和最早的竞争,不抛异常
案例分析 Executor executor = new ThreadPoolExecutor(1, 1, 60 * 3, TimeUnit.SECONDS,new LinkedBlockingQueue<>(1), Executors.defaultThreadFactory(), new ThreadPoolExecutor.CallerRunsPolicy()); executor.execute(线程1); executor.execute(线程2); executor.execute(线程3); r1.stop(); r2.stop(); r3.stop(); 线程处理逻辑 while (!stop) { Thread.sleep(1000L); if (stop) { break; } System.out.plintln("当前线程:"+Thread.currentThread()) }
结果:线程1和线程3死循环执行。
原因:线程1是核心线程,处于循环执行中,线程2放到队列中等待线程1完成,线程3看到队列满,又达到最大线程数,采取拒绝策略,根据CallerRunsPolicy策略要交给主线程执行。由于主线程处于循环逻辑,于是下面stop逻辑执行不到,进而线程1和线程3死循环执行。