JVM实践-记录一次jstack分析(十一)
线程状态可参考
https://www.cnblogs.com/LQBlog/p/15268773.html
问题
测试环境dubbo服务出现问题,一直刷警告日志,前端反应各个功能模块很慢,看日志是dubbo线程池满了,但是测试环境没有压力
2021-09-14 09:32:07,957 WARN [New I/O server worker #1-9] com.alibaba.dubbo.common.threadpool.support.AbortPolicyWithReport:warn:54 [DUBBO] Thread pool is EXHAUSTED!
Thread Name: DubboServerHandler-172.***:62075, Pool Size: 200 (active: 200, core: 200, max: 200, largest: 200), Task: 771 (completed: 571),
Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://172.***:62075!, dubbo version: 2.5.3, current host: 172.16.6.3
排查分析
dump jstack日志
1.先通过grep或者top查看进程id
[root@iz2ze9ufq5ehrayz6j88saz logs]# ps -ef | grep order root 14584 6482 0 14:42 pts/7 00:00:00 tail -f order.log root 14610 1 18 17:41 ? 00:02:41 /home/jdk1.8.0_251/bin/java -jar -Xms512m -Xmx1g -XX:MaxPermSize=256M -XX:+PrintGCDetails -XX:+PrintHeapAtGC -XX:+PrintClassHistogram -Dcsp.sentinel.dashboard.server=localhost:9999 -Dcom.biz.pushOrder=true -Dbiz.mark=soa.order /home/dubbo_service/order/order.jar root 17478 10434 0 17:55 pts/4 00:00:00 grep --color=auto order
2.通过jstack把jstack日志dump下来
jstack -l 14610 >/home/order2.jstack
日志分析
1.查看进行中的线程
[root@iz2ze9ufq5ehrayz6j88saz home]# cat order.jstack |grep RUNNABLE|wc -l
279
可以发现进行中等待cpu调度的线程有279 已经占满
2.先排除是不是内部代码问题
cat order.jstack | grep "com.biz"
com.biz是我们的包名前缀
发现都是同样一个方法 这个方法被task服务调用dubbo 这个方法里面死循环了