系统CPU Load飙升排查之debug日志打印隐含大对象序列化导致的系统性能急剧下降

机器健康情况

    这段时间某台机器持续load报警，查看load监控和JVM GC回收都不太正常，于是怀疑是业务增长导致，但是看了tcp连接监控监控，发现业务并没有明显增长，如下图:

首先查看CPU，机器都是24核以上，内存配置48G，垃圾收集使用G1，停顿时间200ms

近一个月的load监控如下：

近一个月的内存使用

图上可看出，这太机器可用内存已经不多了。

再看CPU使用率，最高可达到75%：

GC情况如下：

次数：

时间：

好像GC也不太正常，一次YGC最长时间可300ms左右。

再看FULL GC

次数：

时间：

full gc一次最长可达300s，这不能不怀疑这台机器有问题。但是集群中其他机器full gc次数比较少，于是觉得这台机器性能可能比较差，为了快速解决问题，于是扩展了一台机器（实体机），32核，64G内存，操作系统 centos，我知道，这可能是治标的办法，但可为治本赢得时间。

确实，申请了这太性能很高的机器后，情况得到缓解，但是过几天发现，这台机器也FULL GC 了，虽繁不频繁（可能只是机器性能好而已）监控如下：

基于以上分析的启示

1 FULL GC比较频繁并且一次FULL GC时间比较长

2 系统的Load比较高

3 业务量并没有增长

所以，扩展机器的确不能治本，而应该寻找代码问题，彻底治本。但是如何治本呢？既然不知道是什么原因导致，不妨假设是GC导致load过高，而从GC的表现，尤其是FULL GC来看，这一假设基本是合理的。

FULL GC分析

首先查看JVM参数配置：

export TOMCAT_USER="tomcat"
export JAVA_OPTS="-Xms56g -Xmx56g   -server -XX:+DisableExplicitGC   -verbose:gc -XX:+UseG1GC -XX:+PrintFlagsFinal -XX:+PrintReferenceGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -X
X:+PrintAdaptiveSizePolicy -XX:+PrintGCApplicationStoppedTime -XX:InitiatingHeapOccupancyPercent=20 -XX:G1ReservePercent=15 -XX:G1HeapRegionSiz
e=32m -XX:ConcGCThreads=8 -XX:MaxGCPauseMillis=200 -XX:G1HeapWastePercent=1 -XX:+UnlockDiagnosticVMOptions -XX:+G1SummarizeConcMark -Xloggc:$CA
TALINA_BASE/logs/gc.log"
chown -R tomcat:tomcat $CATALINA_BASE/logs
chown -R tomcat:tomcat $CATALINA_BASE/cache
chown -R tomcat:tomcat $CATALINA_BASE/conf
chown -R tomcat:tomcat $CATALINA_BASE/work
chown -R tomcat:tomcat $CATALINA_BASE/temp
export JAVA_OPTS="$JAVA_OPTS -Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=127.0.0.1:10336"

关键参数内存56G，显然已经不小了。所以排除内存不足引发FULL GC。

2 看gc日志

然后再查看问题比较明显的机器2018-6-30 的gc日志（gc.log.2018-06-30.gz），搜索Full GC:

首先，解压压缩的文件

sudo zcat gc.log.2018-06-30.gz > ~/temp.log

然后在~目录下搜索Full GC日志：

strings temp.log |grep 'Full GC'

结果：

2018-06-30T16:25:46.379+0800: 336421.977: [Full GC (Allocation Failure) 2018-06-30T16:25:53.193+0800: 336428.791: [SoftReference, 1273 refs, 0.0003157 secs]2018-06-30T16:25:53.193+0800: 336428.792: [WeakReference, 12369 refs, 0.0013254 secs]2018-06-30T16:2