アプリケーション開始時に連続フルGCを実行する理由

Question

アプリケーション（TomcatにデプロイされたWebアプリケーション）の起動中に連続フルGCが起動する理由は何ですか？

JDK 1.6

メモリの設定
-Xms1024M -Xmx1024M -XX:PermSize=200M -XX:MaxPermSize=512M -XX:+UseParallelOldGC

jmapの出力は、システムが起動時に多数のオブジェクトを割り当て、それらあまりに参照を維持しているように見えます

Heap Configuration: 
    MinHeapFreeRatio = 40 
    MaxHeapFreeRatio = 70 
    MaxHeapSize  = 1073741824 (1024.0MB) 
    NewSize   = 2686976 (2.5625MB) 
    MaxNewSize  = 17592186044415 MB 
    OldSize   = 5439488 (5.1875MB) 
    NewRatio   = 2 
    SurvivorRatio = 8 
    PermSize   = 209715200 (200.0MB) 
    MaxPermSize  = 536870912 (512.0MB) 

0.194: [GC [PSYoungGen: 10489K->720K(305856K)] 10489K->720K(1004928K), 0.0061190 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]  
0.200: [Full GC (System) [PSYoungGen: 720K->0K(305856K)] [ParOldGen: 0K->594K(699072K)] 720K->594K(1004928K) [PSPermGen: 6645K->6641K(204800K)], 0.0516540 secs] [Times: user=0.10 sys=0.00, real=0.06 secs]  
6.184: [GC [PSYoungGen: 262208K->14797K(305856K)] 262802K->15392K(1004928K), 0.0354510 secs] [Times: user=0.18 sys=0.04, real=0.03 secs]  
9.549: [GC [PSYoungGen: 277005K->43625K(305856K)] 277600K->60736K(1004928K), 0.0781960 secs] [Times: user=0.56 sys=0.07, real=0.08 secs] 
11.768: [GC [PSYoungGen: 305833K->43645K(305856K)] 322944K->67436K(1004928K), 0.0584750 secs] [Times: user=0.40 sys=0.05, real=0.06 secs] 
15.037: [GC [PSYoungGen: 305853K->43619K(305856K)] 329644K->72932K(1004928K), 0.0688340 secs] [Times: user=0.42 sys=0.01, real=0.07 secs] 
19.372: [GC [PSYoungGen: 273171K->43621K(305856K)] 302483K->76957K(1004928K), 0.0573890 secs] [Times: user=0.41 sys=0.01, real=0.06 secs] 
19.430: [Full GC (System) [PSYoungGen: 43621K->0K(305856K)] [ParOldGen: 33336K->54668K(699072K)] 76957K->54668K(1004928K) [PSPermGen: 36356K->36296K(204800K)], 0.4569500 secs] [Times: user=1.77 sys=0.02, real=0.46 secs] 
19.924: [GC [PSYoungGen: 4280K->128K(305856K)] 58949K->54796K(1004928K), 0.0041070 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
19.928: [Full GC (System) [PSYoungGen: 128K->0K(305856K)] [ParOldGen: 54668K->54532K(699072K)] 54796K->54532K(1004928K) [PSPermGen: 36300K->36300K(204800K)], 0.3531480 secs] [Times: user=1.19 sys=0.10, real=0.35 secs] 
20.284: [GC [PSYoungGen: 4280K->64K(305856K)] 58813K->54596K(1004928K), 0.0040580 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
20.288: [Full GC (System) [PSYoungGen: 64K->0K(305856K)] [ParOldGen: 54532K->54532K(699072K)] 54596K->54532K(1004928K) [PSPermGen: 36300K->36300K(204800K)], 0.2360580 secs] [Times: user=1.01 sys=0.01, real=0.24 secs] 
20.525: [GC [PSYoungGen: 4280K->96K(305856K)] 58813K->54628K(1004928K), 0.0030960 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
20.528: [Full GC (System) [PSYoungGen: 96K->0K(305856K)] [ParOldGen: 54532K->54533K(699072K)] 54628K->54533K(1004928K) [PSPermGen: 36300K->36300K(204800K)], 0.2311320 secs] [Times: user=0.88 sys=0.00, real=0.23 secs] 
20.760: [GC [PSYoungGen: 4280K->96K(305856K)] 58814K->54629K(1004928K), 0.0034940 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
20.764: [Full GC (System) [PSYoungGen: 96K->0K(305856K)] [ParOldGen: 54533K->54533K(699072K)] 54629K->54533K(1004928K) [PSPermGen: 36300K->36300K(204800K)], 0.2381600 secs] [Times: user=0.85 sys=0.01, real=0.24 secs] 
21.201: [GC [PSYoungGen: 5160K->354K(305856K)] 59694K->54888K(1004928K), 0.0019950 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
21.204: [Full GC (System) [PSYoungGen: 354K->0K(305856K)] [ParOldGen: 54533K->54792K(699072K)] 54888K->54792K(1004928K) [PSPermGen: 36300K->36300K(204800K)], 0.2358570 secs] [Times: user=0.98 sys=0.01, real=0.24 secs] 
21.442: [GC [PSYoungGen: 4280K->64K(305856K)] 59073K->54856K(1004928K), 0.0022190 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
21.444: [Full GC (System) [PSYoungGen: 64K->0K(305856K)] [ParOldGen: 54792K->54792K(699072K)] 54856K->54792K(1004928K) [PSPermGen: 36300K->36300K(204800K)], 0.2475970 secs] [Times: user=0.95 sys=0.00, real=0.24 secs] 
21.773: [GC [PSYoungGen: 11200K->741K(305856K)] 65993K->55534K(1004928K), 0.0030230 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
21.776: [Full GC (System) [PSYoungGen: 741K->0K(305856K)] [ParOldGen: 54792K->54376K(699072K)] 55534K->54376K(1004928K) [PSPermGen: 36538K->36537K(204800K)], 0.2550630 secs] [Times: user=1.05 sys=0.00, real=0.25 secs] 
22.033: [GC [PSYoungGen: 4280K->96K(305856K)] 58657K->54472K(1004928K), 0.0032130 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
22.036: [Full GC (System) [PSYoungGen: 96K->0K(305856K)] [ParOldGen: 54376K->54376K(699072K)] 54472K->54376K(1004928K) [PSPermGen: 36537K->36537K(204800K)], 0.2507170 secs] [Times: user=1.01 sys=0.01, real=0.25 secs] 
22.289: [GC [PSYoungGen: 4280K->96K(305856K)] 58657K->54472K(1004928K), 0.0038060 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
22.293: [Full GC (System) [PSYoungGen: 96K->0K(305856K)] [ParOldGen: 54376K->54376K(699072K)] 54472K->54376K(1004928K) [PSPermGen: 36537K->36537K(204800K)], 0.2640250 secs] [Times: user=1.07 sys=0.02, real=0.27 secs] 
22.560: [GC [PSYoungGen: 4280K->128K(305856K)] 58657K->54504K(1004928K), 0.0036890 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
22.564: [Full GC (System) [PSYoungGen: 128K->0K(305856K)] [ParOldGen: 54376K->54377K(699072K)] 54504K->54377K(1004928K) [PSPermGen: 36537K->36536K(204800K)], 0.2585560 secs] [Times: user=1.08 sys=0.01, real=0.25 secs] 
22.823: [GC [PSYoungGen: 4533K->96K(305856K)] 58910K->54473K(1004928K), 0.0020840 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
22.825: [Full GC (System) [PSYoungGen: 96K->0K(305856K)] [ParOldGen: 54377K->54377K(699072K)] 54473K->54377K(1004928K) [PSPermGen: 36536K->36536K(204800K)], 0.2505380 secs] [Times: user=0.99 sys=0.01, real=0.25 secs] 
23.077: [GC [PSYoungGen: 4530K->32K(305856K)] 58908K->54409K(1004928K), 0.0016220 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
23.079: [Full GC (System) [PSYoungGen: 32K->0K(305856K)] [ParOldGen: 54377K->54378K(699072K)] 54409K->54378K(1004928K) [PSPermGen: 36536K->36536K(204800K)], 0.2320970 secs] [Times: user=0.95 sys=0.00, real=0.23 secs] 
24.424: [GC [PSYoungGen: 87133K->800K(305856K)] 141512K->55179K(1004928K), 0.0038230 secs] [Times: user=0.01 sys=0.01, real=0.01 secs] 
24.428: [Full GC (System) [PSYoungGen: 800K->0K(305856K)] [ParOldGen: 54378K->54950K(699072K)] 55179K->54950K(1004928K) [PSPermGen: 37714K->37712K(204800K)], 0.4105190 secs] [Times: user=1.25 sys=0.17, real=0.41 secs] 
24.866: [GC [PSYoungGen: 4280K->256K(305856K)] 59231K->55206K(1004928K), 0.0041370 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
24.870: [Full GC (System) [PSYoungGen: 256K->0K(305856K)] [ParOldGen: 54950K->54789K(699072K)] 55206K->54789K(1004928K) [PSPermGen: 37720K->37719K(204800K)], 0.4160520 secs] [Times: user=1.12 sys=0.19, real=0.42 secs] 
29.041: [GC [PSYoungGen: 262208K->12901K(275136K)] 316997K->67691K(974208K), 0.0170890 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 

Answer 1

を下回っています。ヤングGCのコレクションを見ると、たとえば次のようになります。 [PSYoungGen: 87133K->800K(305856K)]これは、ほとんどのオブジェクトが削除されていることを示しています（ライブヒープのサイズは87Mから800Kになります）。しかし、次のFull GCは、それらがゴミではなく、古い世代に昇進していることを示唆しています。フルGCログ（例： [ParOldGen: 54950K->54789K(699072K)]は、ライブヒープがあまり減少しないことを示しています（約0.2％）。これは、ライブの古いヒープ内のオブジェクトのほとんどが依然として強く参照されていることを意味します。あなたのシステムには2つの問題の1つがあると思います。あなたはメモリリークがあり、必要のないオブジェクトにぶら下がっています。 2.システムには多くのメモリが必要です。

メモリリークの場合は、プロファイラを使用して、作成されているオブジェクトの種類とその作成元を調べて、問題を試して分析することができます。

Answer 2

私は最終的に問題を発見しました、いくつかのライブラリがSystem.gcを呼び出すようです（私はまだどのライブラリと理由が分かりませんでした）。私はDisableExplicitGCオプションを追加し、問題はなくなりました。