记几次 [线上环境] Dubbo 线程池占满原因分析（第一次：HttpClient）
转载：https://blog.csdn.net/wsmalltiger/article/details/124236055
前言
我们一个核心应用，线上部署了4台机器（4c8g），某天晚上8点左右线上忽然出现dubbo线程池占满告警，上游应用error日志也疯狂报警，整个过程持续了4分钟左右系统自动恢复正常。
dubbo 默认200个线程池，报错日志信息：
03-26 20:22:32.740 ERROR 25110 --- [ThreadPoolMonitor-thread-1] c.*.*.c.scheduled.ScheduledContainer : [DUBBO] Pool status:OK, max:200, core:200, largest:200, active:0, task:260504, service port: 20881;Pool status:WARN, max:200, core:200, largest:200, active:200, task:5568440, service port: 20882, dubbo version: 3.2.3.8-RELEASE, current host: 10.*.*.7
03-26 20:23:32.740 ERROR 25110 --- [ThreadPoolMonitor-thread-1] c.*.*.c.scheduled.ScheduledContainer : [DUBBO] Pool status:OK, max:200, core:200, largest:200, active:0, task:261272, service port: 20881;Pool status:WARN, max:200, core:200, largest:200, active:200, task:5573570, service port: 20882, dubbo version: 3.2.3.8-RELEASE, current host: 10.*.*.7
03-26 20:24:32.740 ERROR 25110 --- [ThreadPoolMonitor-thread-1] c.*.*.c.scheduled.ScheduledContainer : [DUBBO] Pool status:OK, max:200, core:200, largest:200, active:0, task:262550, service port: 20881;Pool status:WARN, max:200, core:200, largest:200, active:200, task:5578245, service port: 20882, dubbo version: 3.2.3.8-RELEASE, current host: 10.*.*.7
03-26 20:25:32.740 ERROR 25110 --- [ThreadPoolMonitor-thread-1] c.*.*.c.scheduled.ScheduledContainer : [DUBBO] Pool status:OK, max:200, core:200, largest:200, active:0, task:264110, service port: 20881;Pool status:WARN, max:200, core:200, largest:200, active:200, task:5582899, service port: 20882, dubbo version: 3.2.3.8-RELEASE, current host: 10.*.*.7
一、问题分析
1、查看监控
公司的中间件监控系统做的比较完善，对dubbo框架的监控有进行定制化开发，并集成到统一运维平台，能够更加方便开发同学了解服务运行情况，出现问题时系统整体QPS流量：
对比前一天的系统QPS流量：
问题当天整体dubbo服务监控信息：
从上面监控信息中可以得出三个结论：
1、问题当天系统QPS流量开始相对平稳，下降的波动主要是由于问题期间dubbo线程池被占满导致无法处理其他请求，上升的波动是系统自动恢复后流量统计到同一时间上了，整体流量相比前一天流量没有明显增长；
2、Provider（服务端）平均RT上升较大，问题期间dubbo出现线程被长时间占用问题；
3、在RT上升机器，Consumer、Provider都有大量失败；
2、找到问题接口
查看dubbo接口RT监控，发现有一个接口问题期间平均RT达到 31秒多：
这么高的RT说明接口内部肯定出现了问题，继续查看接口RT耗时明细，最高RT将近达到 80秒：
3、分析接口
既然找到的问题接口，那么查看一下接口的日志信息，看看能否定位到原因：
日志使用spring AOP做的切面，针对系统接口耗时如果超过3秒，则会自动打印出固定格式的日志，方便后续对高RT接口进行优化。这里AOP的好处一下就表现出来了，根据日志轻松找到相关信息，继续正对一条请求查看日志明细：
看到这个日志原因基本就可以确定了：dubbo接口内部请求了某个http接口，而这个http接口耗时较长导致长时间占用dubbo线程不释放，最终引起dubbo线程池被占满。
4、问题验证
为什么http请求超时会导致dubbo线程长时间被占用呢？通过review接口代码，发现应用中使用了org. apache. http. impl. client. HttpClients工具类发送 http请求，继续 review 开源工具源码发现这个工具默认仅支持5个并发：
编写测试代码，验证一下超时是怎么形成的（为了模拟问题时的场景，请求的http接口内部会阻塞2秒）：
for (int i = 0; i < 100; i++) {
new Thread(()->{
long tempTime = System.currentTimeMillis();
try {
String code = restfulServiceClient.get("http://10.*.*.88:7001/account/get?bId=" + bId + "&buyerId=" + buyerId, String.class);
} catch (Exception e) {
logger.error("请求超时：" , e);
}
long useTime = System.currentTimeMillis() - tempTime;
if (useTime < 1000 * 4) {
logger.info("i=" + index.incrementAndGet() + " 单次耗时：{} ms", useTime);
} else {
logger.error("i=" + index.incrementAndGet() + " 超时，单次耗时：{} ms", useTime);
}
}).start();
}
查看输出日志：
这下原因清楚了：由于http工具默认仅支持 5 个并发，且有线程池队列，当请求量超过 5 个的时候，多余的请求会在队列中堆积。前一批http请求结束之后其他的请求才会继续执行，越到后面线程等待时间会越长。所以对应实际业务场景中dubbo线程等待的时间也会越长，当这个队列到一定数量之后，就会引起dubbo默认200个线程池被占满的情况，从而引起整个应用服务的报错。
二、解决方案
知道了问题原因，解决方案就变得简单起来：
1、系统中依赖 http 接口迁移到 java dubbo接口（对应业务方已经有相关dubbo接口）；
2、工具类封装并进行优化，调整到合适的并发执行数量，修改队列方式，设置超时超时时间（参数值根据业务场景具体分析）；
3、问题接口接入限流降级框架，配置限流阈值，防止在高流量的情况下导致接口被打挂；
总结
1、使用开源框架时要了解相关的原理，默认值不一定适合所有的场景，需要根据自己的场景分析选择对应的配置。
2、对代码存在敬畏之心，复杂的业务代码中，一个看似不起眼的http请求出现问题，最终会导致整个dubbo服务不可用。
3、完善监控系统，及时主动发现问题，及时处理降低影响面。
————————————————
版权声明：本文为CSDN博主「smatiger」的原创文章，遵循CC 4.0 BY-SA版权协议，转载请附上原文出处链接及本声明。
原文链接：https://blog.csdn.net/wsmalltiger/article/details/124236055
