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 这个方法里面死循环了