背景&现象
背景
有个qps较高的rpc,使用了线程池来并发请求多个下游服务,且设定了对于下游的超时时间。
现象
rpc服务调用下游时,时不时出现耗时很高的情况,平均耗时挺低的,但是p99和p995就比较高了,达到秒级,超过了设定的调用下游的超时时间。
从rpc monitor上看,调用下游实际也用不了这么长时间,说明不是跨span的耗时;
使用arthas trace查看方法级的耗时:


可以发现是频繁start新的thread导致的。
再查看日志里的线程编号:
-thread-7665821
已经达到七百万了!
参考以前的学习:
http://xiaoyue26.github.io/2022/03/14/2022-03/%E4%B8%AD%E6%96%AD%E6%A2%B3%E7%90%86/

由于jvm线程与内核线程一一对应(hotpot jvm下),频繁回收、创建带来的内核态切换、系统调用开销过于大了。
解决方案
综上可以发现线程池里有频繁的线程回收、再创建操作,需要关闭core线程自动回收的机制(基础框架内默认是开启回收)
1 | DynamicThreadExecutor.dynamic(POOL_SIZE::get, "csc-center-executor-%d", false); |
字段注释:
1 | allowCoreThreadTimeout 是否允许核心线程超时后被回收, |
收益
请求耗时p99\p995、超时异常大幅降低;


更多参考代码
也可以自己选择喜欢的builder创建:
1 | private final DynamicThreadExecutor fromBuilder = DynamicThreadExecutor.dynamic(POOL_SIZE::get, |
注意事项(可能的坑)
- 摘要中的代码默认创建的是BlockingThreadPool,不支持嵌套使用。不要在提交的任务中再次提交任务到同一个线程池,以免死锁。
(jdk中的支持嵌套调用)