2

Java 1.6 Hotspot JVM を使用しています。Old Gen が容量に近づくと、CMS GC が実行されます。マイナー コレクションは、Young Gen が定員に近づくと実行されます。

ただし、あるサーバーでは、マイナー コレクションが発生するたびに CMS GC を取得しています。2 番目のサーバーでは、これは発生しません (通常の操作)。jvm オプションは両方のサーバーでまったく同じです。これは、64 ビット Web サーバーと 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 は設定されていないため、デフォルト値です。何が原因でしょうか? 2 つの JVM は、未定義の JVM パラメーターに対して異なるデフォルト値を持つことができますか?

以下のGCログをご覧ください。最初の行はマイナー コレクションです。ほんの一瞬後、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]
4

2 に答える 2

1

From your logs it seems that CMS is running continuously. Normally CMS will delay initial-mark for next young GC (because young space have smallest size right after young GC). This is a reason why you are seeing CMS initial-mark right after ParNew.

icms_dc=100 suggest that CMS were running non-stop even before ParNew.

I have seen this once (read more details), in my case CMS were triggered by premanent space reaching occupancy threshold. Check your permspace occupation, there is a chance that you should increase it.

You could also configure different occupancy threshold for permanent space (though I'm not sure how it will work with iCMS).

-XX:CMSInitiatingPermOccupancyFraction=N
于 2013-03-01T11:31:38.697 に答える