jvm内存很大，cms报错concurrent mode failure

最近上线一个定时任务：根据条件查询数据，然后生成excel，当成邮件中的附件发送给指定用户。在这个定时任务执行的时候，从gc的日志部分如下：

2016-10-12T15:10:56.017+0800: 2130.042: [GC2016-10-12T15:10:56.017+0800: 2130.042: [ParNew: 605431K->65838K(613440K), 0.0397940 secs] 1115602K->592670K(2029056K), 0.0400670 secs]

[Times: user=0.19 sys=0.01, real=0.04 secs]

2016-10-12T15:10:56.173+0800: 2130.198: [GC2016-10-12T15:10:56.173+0800: 2130.198: [ParNew: 611182K->68096K(613440K), 0.0386650 secs] 1138014K->610941K(2029056K), 0.0390110 secs]

[Times: user=0.20 sys=0.01, real=0.04 secs]

2016-10-12T15:10:56.313+0800: 2130.338: [GC2016-10-12T15:10:56.313+0800: 2130.338: [ParNew: 613440K->68096K(613440K), 0.0391930 secs] 1156285K->627219K(2029056K), 0.0394650 secs]

[Times: user=0.21 sys=0.01, real=0.04 secs]

2016-10-12T15:10:56.475+0800: 2130.500: [GC2016-10-12T15:10:56.475+0800: 2130.500: [ParNew: 613440K->65122K(613440K), 0.0415260 secs] 1172563K->640188K(2029056K), 0.0418330 secs]

[Times: user=0.24 sys=0.01, real=0.04 secs]

2016-10-12T15:10:56.655+0800: 2130.680: [GC2016-10-12T15:10:56.655+0800: 2130.680: [ParNew: 610466K->68096K(613440K), 0.0363720 secs] 1185532K->659268K(2029056K), 0.0366540 secs]

[Times: user=0.21 sys=0.01, real=0.04 secs]

从这部分日志中就可以年轻代gc使用的垃圾收集器为ParNew，并且收集频率相当高，一秒就执行了很多次，显然是很不合理的。从中可以想到有以下几种情况：

1、大量新对象生成

2、年轻代空间较小

 

然后我们又观察了一下老年代的情况，发现老年代被占用空间迅速增长，而且很快就把老年代空间占满了。这时候gc日志也有错误出现了，如下：

2016-10-12T15:14:34.289+0800: 2348.314: [Full GC2016-10-12T15:14:34.289+0800: 2348.314: [CMS2016-10-12T15:14:35.172+0800: 2349.197: [CMS-concurrent-mark: 1.151/1.181 secs] [Times:

 user=3.36 sys=0.05, real=1.18 secs]

 (concurrent mode failure): 1415615K->1415468K(1415616K), 5.3406530 secs] 2029055K->1492615K(2029056K), [CMS Perm : 159147K->159147K(262144K)], 5.3409430 secs] [Times: user=6.19 s

ys=0.01, real=5.34 secs]

发生了concurrent mode failure，此错误就是在CMS GC的过程中，又有对象需要放到old区，但是old区空间不足了，放不下了就报了此错误。

从以上情况能够看出，年轻代的对象很快的进入了old区，而且数量还比较大，在old区进行gc的时候，又有很多年轻代要进入old区，但是old区空间已经满足不了要求了。

 

这时候我们查看了系统运行时，jvm的参数，如下：

-XX:CMSFullGCsBeforeCompaction=0 -XX:CMSInitiatingOccupancyFraction=80 -XX:+DisableExplicitGC -XX:ErrorFile=/var/sankuai/logs/waimai-bizdata-task.vmerr.log.2016

10121435 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/sankuai/logs/waimai-bizdata-task.heaperr.log.201610121435 -XX:InitialHeapSize=2147483648 -XX:MaxHeapSize=2147483648

-XX:MaxNewSize=697933824 -XX:MaxPermSize=268435456 -XX:MaxTenuringThreshold=6 -XX:NewSize=697933824 -XX:OldPLABSize=16 -XX:OldSize=1395867648 -XX:PermSize=134217728 -XX:+PrintComm

andLineFlags -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSCompactAtFullCollection -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+

UseParNewGC

可以看到-XX:MaxTenuringThreshold=6（默认值是15），即对象经历多少次年轻代回收之后仍存活，就会放入老年代中，且-XX:NewSize=697933824年轻代总共有600多M。

再看一下堆内存-XX:MaxHeapSize=2147483648，总共是2G的空间，明显比较小，使用CMS收集器的话，最好有大的内存和强力的CPU，内存最好大于3G。

通过CMSInitiatingOccupancyFraction<=((Xmx-Xmn)-(Xmn-Xmn/(SurvivorRatior+2)))/(Xmx-Xmn)*100这个公式的计算，大致得出CMSInitiatingOccupancyFraction<=53。

通过以上分析，发现以下问题：

1、堆内存偏小，应该设置大一些，如6G

2、-XX:MaxTenuringThreshold设置也应该大一些（这里有必要说一下，虽然显示这个参数值被修改了，但这个参数并没有被设置，而是设置的其他参数默认修改了这个参数，所以使用CMS的一些参数时，要特别注意，最好打印一下被修改的参数，这样能够清楚具体什么参数被修改了，-XX:NewSize也是一样的）

3、XX:CMSFullGCsBeforeCompaction此值最好设置为1，XX:CMSInitiatingOccupancyFraction此值设置偏大了一点

 

根据以上分析，对一些参数做了修改之后，重新运行程序，只是减缓了出错的时间点，但是依然发生同样的问题。

这时我们利用jmap -dump:live,format=b,file=out [pid]命令打印了一下程序的堆内存，然后使用mat进行分析。这里有个插曲，由于dump下来的文件比较大，mat加载时一直报错java heap space，从中能够看出mat内存不够。mat在界面上无法修改使用的内存，需要在他的配置文件MemoryAnalyzer.ini中修改-Xmx1024m为你需要的内存大小。

 

这时候等mat把dump文件加载之后，发现以下对象比较多

 

 

发现这个对象是生成excel的，后来上网查了一下，发现是因为使用了XSSFWorkbook，这个对象会把所有数据都放在内存中，占用着内存，所以内存使用量很大。在POI3.8之后，提供了SXSSFWorkbook，这个是支持流处理，通过限制内存中可访问的记录行数来实现低内存利用，当达到限定值时，新一行数据的加入会引起老一行的数据刷新到硬盘，比如内存中限制行数为100，当行号达到101时，行号为0的记录会被刷新到硬盘，并从内存删除，以此类推。

SXSSFWorkbook对象生成时，可以指定内存中限制的行数，以rowAccessWindowSize属性来标识，默认的就是100。

 

使用SXSSFWorkbook这个生成excel之后，在运行程序就正常了，gc也不是很频繁了，比较平稳。