记录一次Spring Boot假死诊断

转载自本人博客
原文地址： https://www.deanwangpro.com/2...

这两天遇到一个服务假死的问题，具体现象就是服务再也不接收任何请求，客户端会抛出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进程误认为服务正常，没有触发告警。若是你也遇到相似的状况欢迎一块儿讨论。