记录一次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 进程误认为服务正常，没有触发告警。如果你也遇到类似的情况欢迎一起讨论。