本文记录一次频繁GC的剖析

问题

查看我的项目日志发现GC频繁,简直几秒钟一次

查看GC日志

[GC (Allocation Failure) [PSYoungGen: 6816K->320K(8192K)] 82693K->76229K(187904K), 0.0032930 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] [GC (Allocation Failure) [PSYoungGen: 6464K->224K(8192K)] 82373K->76165K(187904K), 0.0067897 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] [GC (Allocation Failure) [PSYoungGen: 6368K->192K(8192K)] 82309K->76149K(187904K), 0.0052315 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] [GC (Allocation Failure) [PSYoungGen: 6336K->1152K(8192K)] 82293K->77117K(187904K), 0.0026567 secs] [Times: user=0.05 sys=0.00, real=0.00 secs] [GC (Allocation Failure) [PSYoungGen: 7296K->1184K(8192K)] 83261K->77157K(187904K), 0.0049316 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] [GC (Allocation Failure) [PSYoungGen: 7202K->1056K(8192K)] 83175K->77037K(187904K), 0.0053079 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] [GC (Allocation Failure) [PSYoungGen: 7181K->912K(8192K)] 83162K->76901K(187904K), 0.0045949 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [GC (Allocation Failure) [PSYoungGen: 7056K->544K(8192K)] 83045K->76557K(187904K), 0.0066989 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 

GC日志打印YGC日志十分频繁,几秒钟一次。
PSYoungGen 是应用Parallel Scavenage垃圾收集器的年老代
从日志上能够看到 7056K->544K(8192K) 年老代总大小十分小只有8M,这就是产生频繁YGC的起因,当new了一个新对象,Young区内存不够调配时,就会触发一次YGC。
那么为什么Young区会这么小呢?

Jstat

通过jstat -gc 2668 10000 7 查看GC状况

$   jstat -gc 2668 10000 7 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT2048.0 1024.0  0.0   704.0   5632.0   5504.2   179712.0   80893.3   55552.0 53214.6 6912.0 6470.5   9573   69.553   6      0.593   70.1462048.0 2048.0  0.0   1184.1  5120.0   911.5    179712.0   80973.3   55552.0 53214.6 6912.0 6470.5   9577   69.573   6      0.593   70.1672048.0 2048.0 1024.0  0.0    5120.0   1978.0   179712.0   81005.3   55552.0 53214.6 6912.0 6470.5   9580   69.596   6      0.593   70.1892048.0 2048.0  0.0   224.0   5120.0   3156.5   179712.0   81069.3   55552.0 53214.6 6912.0 6470.5   9583   69.614   6      0.593   70.2072048.0 2048.0 1216.1  0.0    5120.0   4161.0   179712.0   81125.3   55552.0 53214.6 6912.0 6470.5   9586   69.632   6      0.593   70.2252048.0 2560.0 1984.0  0.0    4608.0   2132.9   179712.0   81213.3   55552.0 53214.6 6912.0 6470.5   9590   69.660   6      0.593   70.2533584.0 3584.0 2144.0  0.0    4096.0   2305.9   179712.0   81381.3   55552.0 53214.6 6912.0 6470.5   9594   69.683   6      0.593   70.276

EC eden区大小
EU eden区已应用空间大小
S0C 示意 Survival 0 区容量
S1C 示意 Survival 1 区容量
S0U 示意 Survival 0 区已应用空间大小
S1U 示意 Survival 1 区已应用空间大小
相干参数看考文档(java8):https://docs.oracle.com/javase/8/docs/technotes/tools/windows/jstat.html#BEHHGFAE

从下面能够看到,eden区、S0区和S1区大小始终在变动而且并不一定相等,那么为什么堆区大小始终在变动呢?

查了一下发现jvm有个参数UseAdaptiveSizePolicy开启了,该参数是默认开启的,查看jvm参数:

$ java -XX:+PrintFlagsFinal -version | grep UseAdaptiveSizePolicy     bool UseAdaptiveSizePolicy                     = true                                {product}

那么能够确定起因基本上是jvm因为开启了UseAdaptiveSizePolicy参数,jvm主动调整堆大小,因为Young区被调整太小导致频繁产生YGC,咱们能够通过调整启动参数来防止这种状况。

从新设置启动参数

-XX:+PrintGCDetails -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -Xmn100M 

-XX:+PrintGCDetails 启用日志
-XX:-UseAdaptiveSizePolicy 敞开主动跳转堆区大小
-XX:SurvivorRatio=8 设置eden区和survivor区大小比8
-Xmn100M 置Young区大小