一次dubbo线程池打满导致dubbo调用全部超时的故障(Thread pool is EXHAUSTED!)

一、故障现象

今早6点到7点之间,线上突然出现大量的dubbo调用超时,且所有服务都存在超时的问题,共出现5次,每次持续1分钟左右,7:10左右最后一次故障出现后,全部服务自行恢复正常。

二、故障定位

发现这一故障后,首先怀疑的是我们应用部署的云服务的k8s集群和vpc是否出现故障,导致dubbo provider和customer间的网络不通,所以dubbo调用全部超时。后经云服务合作方调查,排除这一可能。

排除网络原因后,问题排查重新回到应用本身,查看日志后发现provider在故障时出现大量Thread pool is EXHAUSTED!的报警:

Caused by: java.util.concurrent.RejectedExecutionException: Thread pool is EXHAUSTED! Thread Name: DubboServerHandler-172.20.2.165:23801, Pool Size: 200 (active: 200, core: 200, max: 200, largest: 200), Task: 437931 (completed: 437731), Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://172.20.2.165:23801!

三、故障原因

奇怪的是,当时并非我们的业务高峰期,并发量并不大。业务高峰期都没有把dubbo的线程池打满,为何业务低峰反而出现了这一故障?而且故障竟然在没有人工干预的情况下自动恢复了。

仔细分析customer调用超时的日志,终于发现了问题的原因:大部分调用超时,都是获取微信分享配置信息处理微信公众号消息回调这两个服务,而由于我们调用微信时经常出现微信服务器响应速度极慢的情况,因而调大了这两个服务的超时时间和重试次数,调整成了30秒超时、重试4次。今早6点到7点之间,很可能微信的服务器再次出现了响应速度极慢的情况,导致每次dubbo请求都需要花费4*30=120秒来处理,最终将dubbo线程池打满,殃及其他所有dubbo服务。

四、故障解决

定位了问题,解决起来也就很简单了。这两个服务在业务上并不重要,出现问题时影响仅仅是用户在微信内分享h5时无法显示正常的样式、以及在公众号内回复时得不到响应而已,大可不必为了这样的问题而殃及其他服务,因而我们把这两个服务的超时时间降为6秒、失败后不再重试。

五、总结

处理这一问题的过程中,有几个地方是值得总结的。

第一,dubbo对于线程池打满这种可能引起全部dubbo服务不可用的重要问题,仅仅只打印了WARN级别的报警,这是很值得商榷的,如果打印的是ERROR级别的报警,我们在排查问题时就不会先认为是网路故障从而走弯路了。

第二,dubbo provider在处理请求时,如果处理逻辑中存在http调用,超时时间和重试次数一定要谨慎设定,不重要的业务要最好及时放弃,避免dubbo线程池被打满,从而导致整个项目都无法提供服务。