Java で完全に記述されたメモリ内データベースに取り組んでいます。システムにデータを供給する入力ソースがあります。これが抽出/ロード フェーズです。これを実行しているときに、JVM がハングしていることに気付きました。根本的な原因は、フル GC がトリガーされたことです。その後、アプリケーションがフリーズし、続いて OutOfMemory エラー (GC Overhead Limit Exceeded) が発生しました。
GC ログを調べると、古いものから新しいものまで、多くのガベージ コレクションが明らかになりました。驚くべきことの 1 つは、Desired Survivor のサイズがマイナスだったことです。なぜそうなのか理解しようとしていますか?誰もこれに遭遇したことがありますか?
環境:
- Windows7 Professional Service Pack1
- Dell Precision T7500、24 コア
- 64 ビット O/S 192 GB RAM
Sun JDK バージョン: 1.7.0_13-b20 (64 ビット)
JVM 設定:
- -Xmx100g
- -Xms100g
- -verbose:gc
- -Xloggc:C:/temp/logs/gc.log
- -XX:+PrintGCTimeStamps
- -XX:+PrintGCDetails
- -XX:+PrintTenuringDistribution
- -XX:MaxPermSize=256m
- -XX:+UseParallelOldGC
GC ログの抜粋 (これは完全なログではありません):
0.666: [GC の望ましいサバイバー サイズ 178913280 バイト、新しいしきい値 7 (最大 15) [PSYoungGen: 524289K->4431K(30583488K)] 524289K->4503K(100488576K)、0.0052536 秒] [時間: user=0.03 sys=0.00 =0.01秒]
0.671: [フル GC (システム) [PSYoungGen: 4431K->0K(30583488K)] [ParOldGen: 72K->4096K(69905088K)] 4503K->4096K(100488576K) [PSPermGen: 8852K->8847K(21248K)], 597.秒] [時間: user=0.08 sys=0.00, real=0.09 秒]
12.306: [GC の必要なサバイバー サイズ 178913280 バイト、新しいしきい値 7 (最大 15) [PSYoungGen: 26214464K->389676K(30583488K)] 26218560K->393868K(100488576K)、0.1907519 秒] [時間: user=0.6 =0.19秒]
19.845: [GC の望ましいサバイバー サイズ 178913280 バイト、新しいしきい値 7 (最大 15) [PSYoungGen: 26604140K->4369012K(30583488K)] 26608334K->4539738K(100488576K)、2.0671426 秒] [Times: 1 usersys.=2 real,6 sys.6 =2.07秒]
31.930: [GC の必要なサバイバー サイズ 178913280 バイト、新しいしきい値 7 (最大 15) [PSYoungGen: 30583476K->4368998K(30583488K)] 30764447K->5793376K(100488576K)、2.4316614 秒] [Times2.0 = 1 usersys.1,4 =2.43秒]
43.950: [GC 望ましいサバイバー サイズ 178913280 バイト、新しいしきい値 7 (最大 15) [PSYoungGen: 30583462K->4369018K(30583488K)] 32008283K->10474103K(100488576K)、3.0868838 秒] [Times: real、1.6 user sys3 = 1.7 =3.09秒]
57.851: [GC の望ましいサバイバー サイズ -954466304 バイト、新しいしきい値 6 (最大 15) [PSYoungGen: 30583482K->4369011K(16019904K)] 36688571K->19053916K(85924992K)、5.0616910 秒] [時間:=2.8 ユーザー 9.15 sys4実数=5.06秒]
67.849: [GC 望ましいサバイバー サイズ -954466304 バイト、新しいしきい値 5 (最大 15) [PSYoungGen: 16019891K->7854065K(23301696K)] 30706222K->22540396K(93206784K)、1.95740226 秒] [Times: user3.0 = 3実数=1.96秒]
74.940: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 4 (最大 15) [PSYoungGen: 19504945K->11650800K(23301696K)] 34191281K->27450594K(93206784K)、3.2089939 秒] [Times:1.41 user = 1.41 user]実数=3.21秒]
83.683: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 3 (最大 15) [PSYoungGen: 23301680K->11650785K(23301696K)] 39101518K->32434323K(93206784K)、4.8105989 秒] [Times: user = 1.8.0.6.0.2実数=4.81秒]
93.647: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 2 (最大 15) [PSYoungGen: 23301665K->10083445K(23301696K)] 44085203K->35191108K(93206784K)、3.9481522 秒] [Times:4.7 user = 2.7 sys5実数=3.95秒]
102.406: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 21734325K->10417779K(23301696K)] 46841988K->39667600K(93206784K)、4.703=1362 秒] [Times: sys=6.90]実数=4.70秒]
112.109: [GC の望ましいサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 22068659K->5501380K(23301696K)] 51318480K->45289996K(93206784K)、5.6499475 秒] [Times: 13.8 user = 13.9 sys5実数=5.65秒]
122.858: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 17152260K->5829244K(23301696K)] 56941300K->51036174K(93206784K)、3.9348524 秒]実数=3.93秒]
132.599: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 17480124K->4411050K(23301696K)] 62703442K->55124929K(93206784K)、3.2682313 秒] [時間: sys3 = 1.4.6 秒]実数=3.27秒]
141.869: [GC 望ましいサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 16061930K->5983419K(23301696K)] 66775809K->61080627K(93206784K)、3.1660854 秒] [Times:8.4 user sys3 = 8.9.9実数=3.17秒]
149.996: [GC の望ましいサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 17634299K->5335607K(23301696K)] 72731507K->65656597K(93206784K)、4.4767380 秒] [Times:2.4 user = 2.4 sys5、5実数=4.48秒]
154.473:[完全なGC [PSYounggen:5335607K-> 0K(23301696K)] [PAROLDGEN:60320990K-> 29187977K(69905088K)] 65656597K-> 2918777K(932067K [PS] PSPER] [PS] PSPERSE時間: user=518.19 sys=3.43, real=55.61 秒]
210.083: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 1942K->96K(23301696K)] 29189919K->29188073K(93206784K)、0.0512343 秒] [時間: user=0.50、sys=0。実数=0.05秒]
210.134:[完全なGC [PSyounggen:96K-> 0K(23301696K)] [PAROLDGEN:29187977K-> 29187816K(69905088K)] 29188073K-> 291887816K(9320684K)[PSPERMGEN:> 29188MGEN時間: user=236.31 sys=0.19, real=15.51 秒]
239.525: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 11650880K->4622965K(23301696K)] 40838696K->33810782K(93206784K)、1.2739696 秒] [Times:3.0 user = 3.0.0実数=1.27秒]
248.572: [GC の望ましいサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 16273845K->4009690K(23301696K)] 45461663K->37894227K(93206784K)、2.3307283 秒] [時間: ユーザー = 0.4 sys4実数=2.33秒]
256.854: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 15660570K->5707092K(23301696K)] 49545113K->43643553K(93206784K)、2.5595566 秒] [Times:6.0 user = 6.0.0 user]実数=2.56秒]
265.471: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 17357972K->4996932K(23301696K)] 55294440K->48690372K(93206784K)、2.8941178 秒] [Times:2.0 user = 2.0 user = 2.0実数=2.89秒]
275.795: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 16647812K->3781542K(23301696K)] 60342280K->52491436K(93206784K)、2.6240427 秒] [Times: user = 0.10 sys4、7.10実数=2.63秒]
284.083: [GC の必要なサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 15432422K->5815192K(23301696K)] 64142316K->58360954K(93206784K)、2.3724770 秒] [Times: user = 2.0 sys4、2.60実数=2.37秒]
291.659: [GC の望ましいサバイバー サイズ -954466304 バイト、新しいしきい値 1 (最大 15) [PSYoungGen: 17466072K->5357588K(23301696K)] 70011840K->63780322K(93206784K)、3.0063028 秒] [Times:20.0 user = 4.0 sys5実数=3.01秒]
299.322: [GC の望ましいサバイバー サイズ -1228210176 バイト、新しいしきい値 2 (最大 15) [PSYoungGen: 17008468K->6341939K(23301696K)] 75431206K->70078817K(93206784K)、4.1999305 秒] [Times3: sys = 5.15: 5.15 ユーザー実数=4.20秒]
303.523:[フルGC [PSyounggen:6341939K-> 0K(23301696K)] [PAROLDGEN:63736877K-> 38098305K(69905088K)] 70078817K-> 38083K [PSPESMGINED] PSPERSE
上記のログの 57.851 秒でわかるように、Desired Survivor サイズが負になっています。なぜそうなのかわかりません。
これはメモリリークのように見えますか?
どんな助けでも大歓迎です。また、ヒープ用のvisualvmのスナップショットを添付しています