garbage-collection - Concurrent Mark Sweep (CMS) GC 在 Minor Collection 运行时发生

Question

我们使用的是 Java 1.6 Hotspot JVM。 CMS GC 应该在 Old Gen 接近容量时运行。 Minor Collection 在 Young Gen 接近容量时运行。

但是，在一台服务器上，每次发生次要收集时，我们都会收到 CMS GC。在第二台服务器上，这不会发生(正常操作)。两台服务器上的 jvm 选项完全相同；这是在我们升级到 64 位网络服务器和 JRE 之后发生的。 JVM 选项如下:

<jvm-options>-Xms4096M -Xmx4096M</jvm-options>
<jvm-options>-server</jvm-options>
<jvm-options>-Xss256k</jvm-options>
<jvm-options>-XX:NewSize=392M</jvm-options>
<jvm-options>-XX:MaxNewSize=392M</jvm-options>
<jvm-options>-XX:+DisableExplicitGC</jvm-options>
<jvm-options>-XX:+UseParNewGC</jvm-options>
<jvm-options>-XX:+PrintClassHistogram</jvm-options>
<jvm-options>-XX:+PrintGCDateStamps</jvm-options>
<jvm-options>-XX:+UseConcMarkSweepGC</jvm-options>
<jvm-options>-XX:+PrintGCDetails</jvm-options>
<jvm-options>-XX:PermSize=80m</jvm-options>
<jvm-options>-XX:MaxPermSize=80m</jvm-options>
<jvm-options>-d64</jvm-options>
<jvm-options>-XX:+CMSIncrementalMode</jvm-options>
<jvm-options>-XX:+CMSIncrementalPacing</jvm-options>
<jvm-options>-XX:CMSIncrementalSafetyFactor=75</jvm-options>

CMSInitiatingOccupancyFraction 未设置，因此它是默认值。是什么原因造成的？两个 JVM 是否可以为未定义的 JVM 参数设置不同的默认值？

请查看下面的 GC 日志。第一行是 Minor Collection。几分之一秒后，CMS GC 在只有 10% 满时运行。

2013-02-28T13:49:55.446-0500: 1052247.742: [GC 1052247.742: [ParNew: 334791K->12629K(361280K), 0.0402234 secs] 687147K->366075K(4154176K) icms_dc=100 , 0.0409779 secs] [Times: user=0.28 sys=0.00, real=0.04 secs]
2013-02-28T13:49:55.505-0500: 1052247.801: [GC [1 CMS-initial-mark: 353445K(3792896K)] 366282K(4154176K), 0.0581835 secs] [Times: user=0.06 sys=0.01, real=0.06 secs]
2013-02-28T13:49:55.565-0500: 1052247.860: [CMS-concurrent-mark-start]
2013-02-28T13:49:56.713-0500: 1052249.009: [CMS-concurrent-mark: 0.796/1.148 secs] [Times: user=6.03 sys=0.04, real=1.15 secs]
2013-02-28T13:49:56.713-0500: 1052249.009: [CMS-concurrent-preclean-start]
2013-02-28T13:49:56.808-0500: 1052249.104: [CMS-concurrent-preclean: 0.094/0.095 secs] [Times: user=0.11 sys=0.00, real=0.10 secs]
2013-02-28T13:49:56.808-0500: 1052249.104: [CMS-concurrent-abortable-preclean-start] 
  CMS: abort preclean due to time 2013-02-28T13:50:01.892-0500: 1052254.188: [CMS-concurrent-abortable-preclean: 5.080/5.083 secs] [Times: user=5.98 sys=0.11, real=5.08 secs]
2013-02-28T13:50:01.911-0500: 1052254.207: [GC[YG occupancy: 56184 K (361280 K)]1052254.207: [Rescan (parallel) , 0.0413292 secs]1052254.249: [weak refs processing, 0.0001292 secs] [1 CMS-remark: 353445K(3792896K)] 409629K(4154176K), 0.0421145 secs] [Times: user=0.63 sys=0.02, real=0.04 secs]
2013-02-28T13:50:01.954-0500: 1052254.250: [CMS-concurrent-sweep-start]
2013-02-28T13:50:04.032-0500: 1052256.328: [CMS-concurrent-sweep: 2.078/2.078 secs] [Times: user=2.40 sys=0.03, real=2.08 secs]
2013-02-28T13:50:04.032-0500: 1052256.328: [CMS-concurrent-reset-start]
2013-02-28T13:50:04.050-0500: 1052256.346: [CMS-concurrent-reset: 0.018/0.018 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
2013-02-28T13:50:44.487-0500: 1052296.783: [GC 1052296.783: [ParNew: 333781K->12385K(361280K), 0.0377823 secs] 686314K->366061K(4154176K) icms_dc=100 , 0.0385722 secs] [Times: user=0.29 sys=0.00, real=0.04 secs]
2013-02-28T13:50:44.544-0500: 1052296.840: [GC [1 CMS-initial-mark: 353676K(3792896K)] 366257K(4154176K), 0.0562739 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
2013-02-28T13:50:44.601-0500: 1052296.897: [CMS-concurrent-mark-start]
2013-02-28T13:50:45.420-0500: 1052297.716: [CMS-concurrent-mark: 0.784/0.819 secs] [Times: user=5.79 sys=0.02, real=0.82 secs]
2013-02-28T13:50:45.420-0500: 1052297.716: [CMS-concurrent-preclean-start]
2013-02-28T13:50:45.517-0500: 1052297.813: [CMS-concurrent-preclean: 0.096/0.097 secs] [Times: user=0.12 sys=0.00, real=0.10 secs]
2013-02-28T13:50:45.518-0500: 1052297.813: [CMS-concurrent-abortable-preclean-start]
  CMS: abort preclean due to time 2013-02-28T13:50:50.524-0500: 1052302.820: [CMS-concurrent-abortable-preclean: 4.903/5.006 secs] [Times: user=5.39 sys=0.05, real=5.01 secs]
2013-02-28T13:50:50.543-0500: 1052302.839: [GC[YG occupancy: 49968 K (361280 K)]1052302.839: [Rescan (parallel) , 0.0695454 secs]1052302.909: [weak refs processing, 0.0001064 secs] [1 CMS-remark: 353676K(3792896K)] 403644K(4154176K), 0.0702712 secs]    

Answer 1

从您的日志来看，CMS 似乎一直在运行。通常 CMS 会延迟下一次年轻 GC 的初始标记(因为年轻空间在年轻 GC 之后具有最小的大小)。这就是为什么您在 ParNew 之后立即看到 CMS 初始标记的原因。

icms_dc=100 表明 CMS 甚至在 ParNew 之前就在不停地运行。

我见过一次(read more details) ，在我的案例中，CMS 是由达到占用阈值的永久空间触发的。检查你的 permspace 占用，有可能你应该增加它。

您还可以为永久空间配置不同的占用阈值(尽管我不确定它如何与 iCMS 一起使用)。

-XX:CMSInitiatingPermOccupancyFraction=N