故障背景
线上批量发服务下线的告警邮件，偶发 nacos 连接超时。采用了 spring boot admin（以下称 sba）进行服务监控。
原因分析
因为 sba 服务是基于 nacos 对其它服务进行监控，所以遇到这个问题，第一怀疑对象是 nacos 发生问题，但不清楚具体是什么问题。由于服务过一段事件会恢复，所以 nacos 肯定是没有挂掉的，那么排查方向应该是针对 nacos 的配置，或者是服务器性能。
排查过程
首先查看 nacos 的堆情况，使用命令 jmap -heap PID，得到如下信息：
Heap Configuration: MinHeapFreeRatio = 0 MaxHeapFreeRatio = 100 MaxHeapSize = 2147483648 (2048.0MB) NewSize = 1073741824 (1024.0MB) MaxNewSize = 1073741824 (1024.0MB) OldSize = 1073741824 (1024.0MB) NewRatio = 2 SurvivorRatio = 8 MetaspaceSize = 134217728 (128.0MB) CompressedClassSpaceSize = 327155712 (312.0MB) MaxMetaspaceSize = 335544320 (320.0MB) G1HeapRegionSize = 0 (0.0MB)
Heap Usage:PS Young GenerationEden Space: capacity = 1058013184 (1009.0MB) used = 660154960 (629.5728302001953MB) free = 397858224 (379.4271697998047MB) 62.39572152628298% usedFrom Space: capacity = 7864320 (7.5MB) used = 6914048 (6.59375MB) free = 950272 (0.90625MB) 87.91666666666667% usedTo Space: capacity = 7864320 (7.5MB) used = 0 (0.0MB) free = 7864320 (7.5MB) 0.0% usedPS Old Generation capacity = 1073741824 (1024.0MB) used = 455548152 (434.44457244873047MB) free = 618193672 (589.5554275512695MB) 42.426227778196335% used
复制代码
可以看到 Heap Configuration 部分还是比较正常的，最大堆内存是 2G，新生代和老年代各 1G。Eden 区和 Survivor 的比例是默认的 8:2。但是观察 Heap Usage 发现了不对劲的部分，From 和 To 区怎么只有 7.5M，这点很奇怪，按道理来说是 102M 才对。于是发动搜索大法，找到一篇文章，描述如下：
JDK 1.8 默认使用 UseParallelGC 垃圾回收器，该垃圾回收器默认启动了 AdaptiveSizePolicy。AdaptiveSizePolicy(自适应大小策略) 是 JVM GC Ergonomics(自适应调节策略) 的一部分。如果开启 AdaptiveSizePolicy，则每次 GC 后会重新计算 Eden、From 和 To 区的大小，计算依据是 GC 过程中统计的 GC 时间、吞吐量、内存占用量。
复制代码
于是马上查看使用的是什么垃圾回收器，使用命令 jinfo -flags PID 查看 JVM 的启动参数配置：
JVM version is 25.331-b09Non-default VM flags: -XX:CICompilerCount=3 -XX:CompressedClassSpaceSize=327155712 -XX:GCLogFileSize=104857600 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=null -XX:InitialHeapSize=2147483648 -XX:MaxHeapSize=2147483648 -XX:MaxMetaspaceSize=335544320 -XX:MaxNewSize=1073741824 -XX:MetaspaceSize=134217728 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=1073741824 -XX:NumberOfGCLogFiles=10 -XX:OldSize=1073741824 -XX:-OmitStackTraceInFastThrow -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseGCLogFileRotation -XX:-UseLargePages -XX:+UseParallelGC Command line: -Xms2g -Xmx2g -Xmn1g -XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=320m -XX:-OmitStackTraceInFastThrow -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/nacos/logs/java_heapdump.hprof -XX:-UseLargePages -Dnacos.member.list= -Djava.ext.dirs=/jdk1.8.0_331/jre/lib/ext:/jdk1.8.0_331/lib/ext -Xloggc:/nacos/logs/nacos_gc.log -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M -Dloader.path=/nacos/plugins/health,/nacos/plugins/cmdb -Dnacos.home=/nacos
复制代码
以上信息可以看到确实使用的是 UseParallelGC 垃圾回收器。问题解决了吗？并没有哦，真是只是 AdaptiveSizePolicy 配置的问题么？
Tips:由于From和To区只有7.5M，当每次新生代GC时，如果在这一次GC中存活下来的对象内存大于7.5M那么会将存不下的那部分将直接放入老年代，就会导致老年代快速增长，触发Full GC。
复制代码
由于 From 和 To 区太小可能会导致 Full GC 过于频繁，于是我去查看了一下 nacos 的 GC 日志，发现 YGC 之间的间隔时间只有 10s 左右（非原服务器数据）：
16:08:31.801+0800: 478.123: [GC (Allocation Failure) [PSYoungGen: 256704K->2784K(258048K)] 381385K->127497K(520192K), 0.0057120 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 16:08:41.812+0800: 488.133: [GC (Allocation Failure) [PSYoungGen: 256736K->2720K(258048K)] 381449K->127457K(520192K), 0.0074081 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
复制代码
再执行 jstat -gc PID 命令，得到如下信息（运行 6 天的 GC 情况）：
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT 7680.0 7680.0 0.0 6176.0 1033216.0 834105.2 1048576.0 564595.0 87936.0 83749.9 10624.0 9990.6 29316 835.838 25 148.564 984.403
复制代码
参数解释：
S0C：第一个幸存区的大小S1C：第二个幸存区的大小S0U：第一个幸存区的使用大小S1U：第二个幸存区的使用大小EC：伊甸园区的大小EU：伊甸园区的使用大小OC：老年代大小OU：老年代使用大小MC：方法区大小MU：方法区使用大小CCSC:压缩类空间大小CCSU:压缩类空间使用大小YGC：年轻代垃圾回收次数YGCT：年轻代垃圾回收消耗时间FGC：老年代垃圾回收次数FGCT：老年代垃圾回收消耗时间GCT：垃圾回收消耗总时间
复制代码
平均一天需要进行 4 次 FGC，每次 FGC 大约需要 6s，这很不正常哦。sba 配置的是 5s 收不到心跳就触发告警，平均 FGC 却需要 6s，这里问题的关键已经比较明显了，有可能就是 Full GC 导致的 nacos 停顿时间过长，导致 sba 服务收不到其他服务的心跳，于是发生服务批量下线问题。那为什么 FGC 会需要这么久？我把主意打到了服务器身上，执行 top 命令，观察服务器的 CPU 使用情况，还真让我发现了一个问题，CPU 使用率会突然飙升到 300%，一看发现是 es 服务。到这里问题比较清晰了，es 服务飙升的 CPU 使用率导致占满了服务器的线程，nacos 的 FGC 获取不到线程来执行就需要等待，所以造成了长时间的服务停顿，于是发生了服务批量下线和 nacos 不可用问题。后来我在收到告警邮件之后，立马上服务器看 CPU 占用情况，果然 CPU 占用率高达 300%，然后查找 nacos 的 GC 日志，发现有 FGC 时间长达 45s（以下非原服务器数据）：
14:06:09.452+0800: 3794735.773: [Full GC (Ergonomics) [PSYoungGen: 215040K->81154K(218112K)] [ParOldGen: 261606K->261605K(262144K)] 476646K->342760K(480256K), [Metaspace: 83823K->83823K(1126400K)], 45.4329403 secs] [Times: user=125.24 sys=0.58, real=45.43 secs]
复制代码
到这儿，已经可以确定是由于 nacos 的 JVM 配置问题+es 问题的组合拳导致的此次故障。
需要优化的点
YGC 和 FGC 过于频繁，需要降低频率
CPU 占用率过高
sba 服务心跳检测时间短了点
解决方案
针对 FGC 频率过高问题，调整 nacos 的启动脚本，新增配置-XX:-UseAdaptiveSizePolicy，禁用 AdaptiveSizePolicy 策略
迁移 es 到单独的服务器上运行
调整 sba 的配置，将服务下线的心跳配置为 60s
JVM 优化过程
禁用 AdaptiveSizePolicy 之后，继续观察 nacos 的内存使用情况和 GC 情况，堆内存的 From 和 To 区已经正常，但是 YGC 和 FGC 的频率并没有下降多少。怀疑是每次 YGC 之后活下来的对象太多了，From 区 100M 也不够，于是每次执行完 jmap -heap PID 命令之后，立马再执行一次该命令，观察堆内存的增长速度。发现每次新生代大概增长 200-300M，老年代增长 3%左右。新生代仅有 1G，每次增长却有 200-300M，老年代增长速度过快，From 区还是小了点，于是调整 JVM 的启动参数，调整 Xms 和 Xmx 为 4g，指定 Xmn 为 3g，如下：
此次调整过后 YGC 间隔时间由 10s 变成了 40s，运行 3.5 天未发生 FGC，老年代使用率 66%。按这个速度，大约 5 天多一点会发生一次 FGC，这个频率就还算正常。
总结
ParallelGC 垃圾回收器默认开启 AdaptiveSizePolicy 有点坑，需要注意一下
es 这种服务最好使用单独的机器部署，比较吃 CPU 和内存。这里 es 的 CPU 占用率这么高还有一个坑，这里就不赘述了，下次再聊
YGC 和 FGC 频率不能太高，过高时需要调整 JVM 参数来降低频率，这个过程可能会比较繁琐，因为调整之后还要持续观察之后再次进行调整
还是有必要部署针对 JVM 的监控服务（比如 Prometheus），不然每次都需要手动执行命令观察 JVM 变化，有可能会错过关键信息
原文：https://www.cnblogs.com/yywf/p/17330932.html
如果感觉本文对你有帮助，点赞关注支持一下，想要了解更多 Java 后端，大数据，算法领域最新资讯可以关注我公众号【架构师老毕】私信 666 还可获取更多 Java 后端，大数据，算法 PDF+大厂最新面试题整理+视频精讲
评论