JVM CMS垃圾回收问题

Question

我在一个应用程序的GC日志文件中看到了以下使用Concurrent Mark-Sweep收集器的症状：

4031.248: [CMS-concurrent-preclean-start]
4031.250: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4031.250: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 4036.346: [CMS-concurrent-abortable-preclean: 0.159/5.096 secs] [Times: user=0.00 sys=0.01, real=5.09 secs] 
4036.346: [GC[YG occupancy: 55964 K (118016 K)]4036.347: [Rescan (parallel) , 0.0641200 secs]4036.411: [weak refs processing, 0.0001300 secs]4036.411: [class unloading, 0.0041590 secs]4036.415: [scrub symbol & string tables, 0.0053220 secs] [1 CMS-remark: 16015K(393216K)] 71979K(511232K), 0.0746640 secs] [Times: user=0.08 sys=0.00, real=0.08 secs] 

预清理进程不断中止。我尝试将CMSMaxAbortablePrecleanTime从默认值5秒调整为15秒，但没有帮助。当前JVM选项如下...

Djava.awt.headless=true
 -Xms512m
 -Xmx512m
 -Xmn128m
 -XX:MaxPermSize=128m
 -XX:+HeapDumpOnOutOfMemoryError
 -XX:+UseParNewGC
 -XX:+UseConcMarkSweepGC
 -XX:BiasedLockingStartupDelay=0
 -XX:+DoEscapeAnalysis
 -XX:+UseBiasedLocking
 -XX:+EliminateLocks
 -XX:+CMSParallelRemarkEnabled
 -verbose:gc
 -XX:+PrintGCTimeStamps
 -XX:+PrintGCDetails
 -XX:+PrintHeapAtGC
 -Xloggc:gc.log
 -XX:+CMSClassUnloadingEnabled
 -XX:+CMSPermGenPrecleaningEnabled
 -XX:CMSInitiatingOccupancyFraction=50
 -XX:ReservedCodeCacheSize=64m
 -Dnetworkaddress.cache.ttl=30
 -Xss128k

看起来并发可中止的预清理(concurrent-abortable-preclean)从未有机会运行。我阅读过https://blogs.oracle.com/jonthecollector/entry/did_you_know，其中提出了启用CMSScavengeBeforeRemark的建议，但暂停的副作用似乎不是理想的选择。是否有人能提供任何建议？

此外，我想知道是否有人有学习CMS GC日志的好参考资料，特别是这一行：

[1 CMS-remark: 16015K(393216K)] 71979K(511232K), 0.0746640 secs]

不清楚这些数字指的是哪些内存区域。 编辑 找到了一个链接：http://www.sun.com/bigadmin/content/submitted/cms_gc_logs.jsp

- jlintz

---

cms标签用于指代内容管理系统，而不是并发标记和清除垃圾收集器。我将把它移除。 - Michael Myers

抱歉，关于此事我不小心了。谢谢！ - jlintz

将CMS初始化设置为50％似乎有点低：-XX：CMSInitiatingOccupancyFraction = 50也许增加它（或像“antispam”建议的那样使用默认值）会有不同的行为。此外，我的日志通常在CMS之前，期间和之后运行ParNew。 ParNew正在运行吗？ - Joshua Davis

Answer 1

[时间：用户=0.00系统=0.01，实际=5.09秒]

我会尝试调查为什么CMS-concurrent-abortable-preclean-start在5秒内既没有用户CPU时间也没有系统CPU时间。

我的建议是从“干净”的JVM CMS启动标志开始，例如

-Djava.awt.headless=true
-Xms512m
-Xmx512m
-Xmn128m
-Xss128k
-XX:MaxPermSize=128m
-XX:+UseConcMarkSweepGC
-XX:+HeapDumpOnOutOfMemoryError
-Xloggc:gc.log
-XX:+PrintGCTimeStamps
-XX:+PrintGCDetails
-XX:+PrintHeapAtGC

接着检查问题是否重现，并逐个调整参数。

- fglez

Answer 2

作为已经有人提到的第一步，应该增加CMSInitiatingOccupancyFraction。

作为第二步，我将使用标志“-XX：-PrintTenuringDistribution”，并确保没有从年轻代到老年代的过早晋升。这会导致从老年代到年轻代的引用，从而可能导致更长的可中止预清理阶段。 如果存在这样的过早晋升，请尝试调整eden和survior空间之间的比例。

- Gabi Kaltman

Answer 3

这里有一个很好的解释，涉及到了这种现象：

引用：

当系统负载轻时（也就是说不会进行小GC），预处理将会超时，完全GC将会失败，CPU被浪费。

它不会失败。它会变得不那么并行（即效率不高，并且工作较少时暂停时间更长）。

总而言之：这似乎是正常操作——线程只等待5秒钟进行小型GC，但如果没有发生，也没有什么大问题：JVM会选择另一种（效率低下）策略来继续GC。

- ppeterka

Answer 4

针对我正在使用的服务，我添加了：

-XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=80

这将配置JVM仅在80％填满后开始标记，值得一试。

- Carlos Saltos