记录一次Spring Boot假死诊断
source link: https://www.tuicool.com/articles/B3Yje22
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.
这两天遇到一个服务假死的问题，具体现象就是服务不再接收任何请求，客户端会抛出Broken Pipe。
检查系统状态
执行top，发现CPU和内存占用都不高，但是通过命令
netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
发现有大量的CLOSE_WAIT端口占用，继续调用该服务的api，等待超时之后发现CLOSE_WAIT的数量也没有上升，也就是说服务几乎完全僵死。
检查JVM情况
怀疑可能是线程有死锁，决定先dump一下线程情况，执行
jstack <pid> > /tmp/thread.hump
发现tomcat线程基本也正常，都是parking状态。
这就比较奇怪了，继续想是不是GC导致了STW，使用 jstat
查看垃圾回收情况
app@server:/tmp$ jstat -gcutil 1 2000 10 S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 27.79 65.01 15.30 94.75 92.23 1338 44.375 1881 475.064 519.439
一看吓一跳，FGC的次数居然超过了YGC，时长有475s。一定是有什么原因触发了FGC，好在我们打开了GC log。
发现一段时间内频繁发生Allocation Failure引起的Full GC。而且eden区的使用占比也很大，考虑有频繁新建对象逃逸到老年代造成问题。询问了一下业务的开发，确认有一个外部对接API没有分页，查询后可能会产生大量对象。
由于外部API暂时无法联系对方修改，所以为了先解决问题，对原有的MaxNewSize进扩容，从192MB扩容到一倍。经过几天的观察，发现gc基本趋于正常
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 3.37 60.55 8.60 95.08 92.98 87 2.421 0 0.000 2.421
扩容之前对heap进行了dump
jmap -dump:format=b,file=heapDump <PID>
通过MAT分析内存泄露，居然疑似是jdbc中的一个类，但其实整体占用堆容量并不多。
分析了线程数量，大约是240多条，与正常时也并没有很大的出入。而且大量的是在sleep的定时线程。
总结
本次排查其实并未找到真正的原因，间接表象是FGC频繁导致服务假死。而且acturator端口是正常工作的，导致health check进程误认为服务正常，没有触发告警。
Recommend
About Joyk
Aggregate valuable and interesting links.
Joyk means Joy of geeK