本文记录一次频繁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区大小