【JVM】VM引数で指定するメモリの目安について知りたいです。

Question

お世話になります。

常駐プロセスとなるプログラムを稼働させ続けているのですが、
気になっている点が2点あります。
起動引数は以下を設定しています。

-Xms128m
-Xmx128m
-Xmn64m
-XX:MetaspaceSize=64m
-XX:MaxMetaspaceSize=128m

①S1領域
1回目のFGCが発生するまではかなりの時間がかかり、S1領域がずっと100%でした。
しかし、1度FGCが発生するとS1が0になり、その後FGCが頻発するようになりました。
これはXmxの値が小さいことが原因でしょうか？
※メモリ使用率については下記参照願います

②引数設定
プロセスを常駐させておくと、
GCは発生しているものの、継続的なメモリ上昇が見受けられ、
メモリリークのようなことが起きているように思われます。
これは引数設定に問題があるのでしょうか？
設定内容的には200m程度で収まる認識だったのですが、
タスクマネージャーから見ると240mに到達しており、現在も増えている状態です。

指摘事項などありましたら、
ご教示の程宜しくお願い致します。

jstatでメモリ使用率を表示したところ以下のようになりました。（抜粋）

  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
  0.00 100.00  62.50  99.84  96.52  90.35    170    1.020     0    0.000    10    0.049    1.068
  0.00 100.00  70.31  99.84  96.52  90.35    170    1.020     0    0.000    10    0.049    1.068
  0.00 100.00  79.69  99.84  96.52  90.35    170    1.020     0    0.000    10    0.049    1.068
  0.00 100.00  89.06  99.84  96.52  90.35    170    1.020     0    0.000    10    0.049    1.068
  0.00 100.00   3.08  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  13.85  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  21.54  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  29.23  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  38.46  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  47.69  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  55.38  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  64.62  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  72.31  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  81.54  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00  90.77  99.93  96.52  90.35    171    1.026     0    0.000    12    0.056    1.082
  0.00 100.00   5.41 100.00  96.52  90.35    172    1.051     0    0.000    12    0.056    1.107
  0.00 100.00  21.62 100.00  96.52  90.35    172    1.051     0    0.000    12    0.056    1.107
  0.00 100.00  37.84 100.00  96.52  90.35    172    1.051     0    0.000    12    0.056    1.107
  0.00 100.00  54.05 100.00  96.52  90.35    172    1.051     0    0.000    12    0.056    1.107
  0.00 100.00  64.86 100.00  96.52  90.35    172    1.051     0    0.000    12    0.056    1.107
  0.00 100.00  81.08 100.00  96.52  90.35    172    1.051     0    0.000    12    0.056    1.107
  0.00 100.00  97.30 100.00  96.52  90.35    172    1.051     0    0.000    12    0.056    1.107
  0.00   0.00   7.35  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300
  0.00   0.00  16.18  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300
  0.00   0.00  25.00  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300
  0.00   0.00  33.82  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300
  0.00   0.00  41.18  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300
  0.00   0.00  48.53  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300
  0.00   0.00  57.35  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300
  0.00   0.00  66.18  90.93  96.09  89.89    173    1.068     1    0.176    12    0.056    1.300

  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
  0.00   0.00  91.94  98.74  96.25  90.07    223    1.681    23    3.501    32    0.137    5.319
  0.00   0.00   4.84  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  11.29  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  19.35  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  29.03  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  38.71  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  46.77  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  54.84  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  64.52  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  72.58  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  82.26  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  88.71  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00  96.77  99.03  96.10  89.90    224    1.701    24    3.658    32    0.137    5.496
  0.00   0.00   8.06  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  16.13  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  22.58  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  32.26  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  40.32  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  48.39  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  58.06  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  66.13  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  75.81  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  83.87  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00  93.55  99.39  96.20  90.01    225    1.722    25    3.804    32    0.137    5.663
  0.00   0.00   3.23  99.74  96.27  90.09    226    1.741    26    3.950    32    0.137    5.829
  0.00   0.00  11.29  99.74  96.27  90.09    226    1.741    26    3.950    32    0.137    5.829
  0.00   0.00  20.97  99.74  96.27  90.09    226    1.741    26    3.950    32    0.137    5.829
  0.00   0.00  27.42  99.74  96.27  90.09    226    1.741    26    3.950    32    0.137    5.829
  0.00   0.00  37.10  99.74  96.27  90.09    226    1.741    26    3.950    32    0.137    5.829
  0.00   0.00  46.77  99.74  96.27  90.09    226    1.741    26    3.950    32    0.137    5.829

jconsole結果

FGC頻発例（1度目までは時間がかかったが、次回以降で間隔が短い）

Answer 1

①S1領域

1回目のFGCが発生するまではかなりの時間がかかり、S1領域がずっと100%でした。
しかし、1度FGCが発生するとS1が0になり、その後FGCが頻発するようになりました。
これはXmxの値が小さいことが原因でしょうか？

ヤング世代の割り当てがヒープ全体のサイズと比較して1/2と大きいことが原因と考えられます。

以下のOracle公式ドキュメントに記載されていますが、Xmnがヒープと比較して大きすぎるとFGCばかり実行されてしまうようです。

Oracle公式ドキュメント

②引数設定

プロセスを常駐させておくと、
GCは発生しているものの、継続的なメモリ上昇が見受けられ、
メモリリークのようなことが起きているように思われます。
これは引数設定に問題があるのでしょうか？
設定内容的には200m程度で収まる認識だったのですが、
タスクマネージャーから見ると240mに到達しており、現在も増えている状態です。

「-Xmx128m」と「-XX:MaxMetaspaceSize=128m」で最大で256MBは使えるように設定されてるおり、240MBなら問題ないと思いますが認識合ってますか？

インスタンスやクラスを使用しなくなったらメモリが開放され、使用されるメモリが小さくなるものと勘違いされやすいですが、通常、最大サイズの範囲内で使用メモリが段々と増えていくことはそれほど珍しいことではありません。

例えば、クラスのアンロードは以下の条件を満たすと起こりえますが、条件を全て満たせば必ずされるわけではありません。（メモリに余裕がなくなれば話は別でしょうけど）

1. 番号リストヒープ中からそのクラスのインスタンスがなくなること。
2. そのクラスの static メソッドを実行中のスレッドがいないこと。
3. そのクラスをロードしたクラスローダーを現わす ClassLoader 派生型のインスタンスがヒープ中からなくなること。

Javaの場合、メモリリークで気をつけなければいけないことは、使用できる最大サイズまでメモリを使用した状態でFGCが頻繁に起きることです。FGCでメモリが開放できず、しかし、メモリが足りない場合、最終的にFGCにCPUのほとんどを持っていかれ、何も処理をできなくなり、MemoryOutOfErrorが起きます。
逆を言えば、最大サイズまでメモリ使用量が増えたとしてもGCが適切に適度に行われている分には問題ありません。

Comments

[ttdrop]

実行時のVM引数に関してですが、
現在実行しているのものが質問欄に提示した値となっていますが、
これまでに様々な値を使用して検証はしておりました。

> > ①S1領域
> > 1回目のFGCが発生するまではかなりの時間がかかり、S1領域がずっと100%でした。
> > しかし、1度FGCが発生するとS1が0になり、その後FGCが頻発するようになりました。
> > これはXmxの値が小さいことが原因でしょうか？

> ヤング世代の割り当てがヒープ全体のサイズと比較して1/2と大きいことが原因と考えられます。

上記に関してですが、1/2ではなく1/3,1/4など色々なパターンも試しましたが、
それでもS1が100に張り付き、S0が0のままとなって、移動が発生していないような事象が見受けられました。

> Javaの場合、メモリリークで気をつけなければいけないことは、使用できる最大サイズまでメモリを使用した状態でFGCが頻繁に起きることです。

Xms,Xmx,Xmnを全体的に小さくした際に上記のような事象が発生しておりました。。
FGCが1度発生するまでは結構な時間がかかりましたが、
その後OLD領域が0にならず、次第にFGCが増えていき、頻発するようになるということがありました。

OutOfMemoryは発生していなかったのですが（その前に止めてしまったのかもしれません）
やはり処理のどこかに参照が残ってたりして正しく破棄できていないということでしょうか。。

[LineOfLightning]

S1が100に貼り付き、S0が0のままというのは最初から最後までずっとそうなのでしょうか？
S0が全く使われていないであれば、「-XX:TargetSurvivorRatio」、または「-XX:MaxTenuringThreshold」の値がおかしいのかもしれません。

[LineOfLightning]

また、メモリの最大使用量まで割り当てられてる状態でFGCが頻発しているときのjstatやjconsoleを提示して頂くことは可能でしょうか？
または、その状態で放置して以下のいずれかのエラーが出ることを確認することは可能でしょうか？
・OutOfMemoryError: PermGen space
・OutOfMemoryError: Java Heap Space

[ttdrop]

> S1が100に貼り付き、S0が0のままというのは最初から最後までずっとそうなのでしょうか？

上記の通りです。。

> S0が全く使われていないであれば、「-XX:TargetSurvivorRatio」、または「-XX:MaxTenuringThreshold」の値がおかしいのかもしれません。

-XX:TargetSurvivorRatio=50
-XX:MaxTenuringThreshold=12
として起動してみましたが、変わらずです。不適切な値という事でも無さそうなのですが..
YGCが発生してもS1だけが100%張り付いた状態で、S0へ移動されていないように見えます。

S0C S1C S0U S1U EC EU OC OU MC MU YGC
0.0 1024.0 0.0 1024.0 8192.0 2048.0 23552.0 17677.1 47360.0 45623.0 39
0.0 1024.0 0.0 1024.0 8192.0 3072.0 23552.0 17677.1 47360.0 45623.0 39
0.0 1024.0 0.0 1024.0 8192.0 4096.0 23552.0 17677.1 47360.0 45623.0 39
0.0 1024.0 0.0 1024.0 8192.0 6144.0 23552.0 17677.1 47360.0 45623.0 39
0.0 1024.0 0.0 1024.0 8192.0 0.0 23552.0 19291.3 47360.0 45628.1 40
0.0 1024.0 0.0 1024.0 8192.0 1024.0 23552.0 19291.3 47360.0 45628.1 40
0.0 1024.0 0.0 1024.0 8192.0 2048.0 23552.0 19291.3 47360.0 45628.1 40
0.0 1024.0 0.0 1024.0 8192.0 4096.0 23552.0 19291.3 47360.0 45628.1 40
0.0 1024.0 0.0 1024.0 8192.0 5120.0 23552.0 19291.3 47360.0 45628.1 40
0.0 1024.0 0.0 1024.0 8192.0 6144.0 23552.0 19291.3 47360.0 45628.1 40
0.0 1024.0 0.0 1024.0 8192.0 1024.0 23552.0 18310.9 47360.0 45607.1 41
0.0 1024.0 0.0 1024.0 8192.0 1024.0 23552.0 18310.9 47360.0 45607.1 41
0.0 1024.0 0.0 1024.0 8192.0 2048.0 23552.0 18310.9 47360.0 45607.1 41
0.0 1024.0 0.0 1024.0 8192.0 3072.0 23552.0 18310.9 47360.0 45607.1 41
0.0 1024.0 0.0 1024.0 8192.0 4096.0 23552.0 18310.9 47360.0 45607.1 41

[ttdrop]

> メモリの最大使用量まで割り当てられてる状態でFGCが頻発しているときのjstatやjconsoleを提示して頂くことは可能でしょうか？

過去に実施したものをキャプチャとして残していたので、質問欄に画像として添付致しました。

> または、その状態で放置して以下のいずれかのエラーが出ることを確認することは可能でしょうか？
> ・OutOfMemoryError: PermGen space
> ・OutOfMemoryError: Java Heap Space

引数設定などを同じものを設定して再現するか試してみます。

ちなみにこの時のVM引数は下記になります。
-Xms128m
-Xmx128m
-Xmn64m
-XX:MetaspaceSize=64m
-XX:MaxMetaspaceSize=128m

[LineOfLightning]

コメント欄のjstatを見たところ、S1がたったの1024KB = 1MBのままというのが気になりますね。
仮にS1が1MBしかないと、それ以上のサイズを持ったものは、S1やS0には入れられないので、当然いきなりOLDにいれることになります。

以下の3つのオプションを指定しないで同様の現象が起きるか確認してください。
-Xmn
-XX:MetaspaceSize
-XX:MaxMetaspaceSize

[ttdrop]

引数を以下で実行致しました。
-Xms128m
-Xmx128m

S1領域は8192.0と先ほどより増えましたが、
それでも100%使用してしまっているようです。

jstat -gc -h10 8408 1000
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT CGC CGCT GCT
0.0 8192.0 0.0 8192.0 73728.0 35840.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 35840.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 35840.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 36864.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 37888.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 38912.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 39936.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 40960.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 41984.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109
0.0 8192.0 0.0 8192.0 73728.0 43008.0 49152.0 12043.5 45084.0 43824.9 5836.0 5384.4 8 0.093 0 0.000 6 0.016 0.109

[LineOfLightning]

すみません。
そのjstatだと、最中にYGCが一回も発生していないのでS1からS0へ移動できないのかどうかがわからないので、YGCが発生しているタイミングのものをお願いします。

ただ、S1Cが100%になってしまうところを見ると、Survivor領域が足りない可能性がありますね。

[ttdrop]

失礼致しました。
下記YGC9→10のものになります。

jstat -gcutil -h10 17968 10000
S0 S1 E O M CCS YGC YGCT FGC FGCT CGC CGCT GCT
0.00 100.00 77.78 24.66 97.66 93.07 9 0.092 0 0.000 6 0.015 0.107
0.00 100.00 92.59 24.66 97.66 93.07 9 0.092 0 0.000 6 0.015 0.107
0.00 100.00 8.20 31.62 97.25 93.11 10 0.099 0 0.000 6 0.015 0.114
0.00 100.00 19.67 31.62 97.25 93.11 10 0.099 0 0.000 6 0.015 0.114

Survivor領域が足りていないのは私もそう思ったのですが、
試しにXms1024m,Xmm1024,-XX:SurvivorRatio=2などと設定しても同事象でした。

[LineOfLightning]

調べた結果、S0が0のままなのは問題ないようです。
以下のサイトを端的に説明するとjstatがJava 9より採用されたG1と合致していないため、S0が0のままに見えるだけなそうです。
もし、もう少し正確な値を見たい場合は、オプションで「-XX:+PrintHeapAtGC」を指定するといいそうです。

https://discuss.elastic.co/t/gc-s1-always-used-100-never-less-than-100/111076/3

後は、本当にメモリの最大サイズ付近でFGCが頻発するかどうかですね。
メモリの割当量が少な過ぎるとFGCが頻発してしまうのは当たり前なので、多めの値を取ってる状態且つ、メモリの最大割当まで使用してる状態でFGCを行ってもメモリが枯渇したままであれば、メモリリークの可能性が高いです。

また、もし、良ければ-XX:+PrintHeapAtGCでFGCが頻発しているあたりのログを見せて頂けると助かります。

[ttdrop]

> jstatがJava 9より採用されたG1と合致していないため、S0が0のままに見えるだけなそうです。

そうだったのですね..
頂いたサイトを拝見しましたが、確かに同じような事象でした。

また、-XX:+PrintHeapAtGCを指定して出力との記載がありましたが、
Java9以降でこれがサポートされていないのか、私のEclipse環境でも使用することが出来ませんでした..

Eclipseコンソール（抜粋）
--------------------------------------------------------------
Unrecognized VM option 'PrintHeapAtGC'
[0.004s][warning][gc] -Xloggc is deprecated. Will use -Xlog:gc:C:\home\gc.log instead.
--------------------------------------------------------------

https://stackoverflow.com/questions/44878699/unable-to-start-solr-with-java-9
https://github.com/sunspot/sunspot/issues/872

メモリを多めに取っている且つ最大割り当てまで行くまでに時間がかかる可能性がありますが、
一旦プログラムを動かし続けてみることにします。

[LineOfLightning]

> また、-XX:+PrintHeapAtGCを指定して出力との記載がありましたが、
> Java9以降でこれがサポートされていないのか、私のEclipse環境でも使用することが出来ませんでした..
すみません。使えなくなっていたんですね。
以下のOracle公式ドキュメントを参考に「-verbose:gc」と一緒に「-XX:+PrintGCDetails」や「-XX:+PrintGCTimeStamps」を使用してみてください。

https://docs.oracle.com/javase/jp/9/tools/java.htm#GUID-3B1CE181-CD30-4178-9602-230B800D4FAE__BABFAFAE

[ttdrop]

ありがとうございます。
メモリを大きく取って、とやってみたのですが、
メモリの上昇値がわずかであるため、FGCが走るまでに時間がかかりすぎたため、
メモリを少なめにしたところ、途中でプロセスが停止しました。
OutOfMemoryなどのログは出ていません...
コンソールがいきなり止まったような状態になりました。

gc.logは後ろの方を抜粋すると、↓のような感じでした。

[917.602s][info][gc,phases,start] GC(14121) Phase 1: Mark live objects
[917.632s][info][gc,stringtable ] GC(14121) Cleaned string and symbol table, strings: 24352 processed, 0 removed, symbols: 152966 processed, 0 removed
[917.632s][info][gc,phases ] GC(14121) Phase 1: Mark live objects 30.205ms
[917.632s][info][gc,phases,start] GC(14121) Phase 2: Prepare for compaction
[917.635s][info][gc,phases ] GC(14121) Phase 2: Prepare for compaction 3.198ms
[917.635s][info][gc,phases,start] GC(14121) Phase 3: Adjust pointers
[917.648s][info][gc,phases ] GC(14121) Phase 3: Adjust pointers 12.144ms
[917.648s][info][gc,phases,start] GC(14121) Phase 4: Compact heap
[917.650s][info][gc,phases ] GC(14121) Phase 4: Compact heap 2.490ms
[917.654s][info][gc,heap ] GC(14121) Eden regions: 0->0(6)
[917.654s][info][gc,heap ] GC(14121) Survivor regions: 0->0(1)
[917.654s][info][gc,heap ] GC(14121) Old regions: 24->24
[917.654s][info][gc,heap ] GC(14121) Humongous regions: 0->0
[917.654s][info][gc,metaspace ] GC(14121) Metaspace: 46768K->46768K(100352K)
[917.654s][info][gc ] GC(14121) Pause Full (G1 Evacuation Pause) 23M->23M(24M) 52.973ms
[917.655s][info][gc,cpu ] GC(14121) User=0.11s Sys=0.00s Real=0.05s
[917.655s][info][gc,task ] GC(14123) Using 2 workers of 4 for full compaction
[917.655s][info][gc,start ] GC(14123) Pause Full (G1 Evacuation Pause)
[917.655s][info][gc,phases,start] GC(14123) Phase 1: Mark live objects
[917.691s][info][gc,stringtable ] GC(14123) Cleaned string and symbol table, strings: 24352 processed, 0 removed, symbols: 152966 processed, 0 removed
[917.691s][info][gc,phases ] GC(14123) Phase 1: Mark live objects 35.582ms
[917.691s][info][gc,phases,start] GC(14123) Phase 2: Prepare for compaction
[917.694s][info][gc,phases ] GC(14123) Phase 2: Prepare for compaction 3.550ms
[917.694s][info][gc,phases,start] GC(14123) Phase 3: Adjust pointers
[917.708s][info][gc,phases ] GC(14123) Phase 3: Adjust pointers 13.340ms
[917.708s][info][gc,phases,start] GC(14123) Phase 4: Compact heap
[917.712s][info][gc,phases ] GC(14123) Phase 4: Compact heap 4.624ms
[917.716s][info][gc,heap ] GC(14123) Eden regions: 0->0(6)
[917.716s][info][gc,heap ] GC(14123) Survivor regions: 0->0(1)
[917.716s][info][gc,heap ] GC(14123) Old regions: 24->24
[917.716s][info][gc,heap ] GC(14123) Humongous regions: 0->0
[917.716s][info][gc,metaspace ] GC(14123) Metaspace: 46768K->46768K(100352K)
[917.716s][info][gc ] GC(14123) Pause Full (G1 Evacuation Pause) 23M->23M(24M) 61.738ms
[917.717s][info][gc,cpu ] GC(14123) User=0.11s Sys=0.00s Real=0.06s
[917.717s][info][gc,marking ] GC(14122) Concurrent Mark Abort
[917.717s][info][gc ] GC(14122) Concurrent Cycle 115.387ms
[917.717s][info][gc,start ] GC(14124) Pause Young (Normal) (G1 Evacuation Pause)
[917.717s][info][gc,task ] GC(14124) Using 4 workers of 4 for evacuation
[917.717s][info][gc,phases ] GC(14124) Pre Evacuate Collection Set: 0.0ms
[917.717s][info][gc,phases ] GC(14124) Evacuate Collection Set: 0.3ms
[917.717s][info][gc,phases ] GC(14124) Post Evacuate Collection Set: 0.1ms
[917.717s][info][gc,phases ] GC(14124) Other: 0.1ms
[917.718s][info][gc,heap ] GC(14124) Eden regions: 0->0(6)
[917.718s][info][gc,heap ] GC(14124) Survivor regions: 0->0(1)
[917.718s][info][gc,heap ] GC(14124) Old regions: 24->24
[917.718s][info][gc,heap ] GC(14124) Humongous regions: 0->0
[917.718s][info][gc,metaspace ] GC(14124) Metaspace: 46768K->46768K(100352K)
[917.718s][info][gc ] GC(14124) Pause Young (Normal) (G1 Evacuation Pause) 23M->23M(24M) 0.731ms
[917.718s][info][gc,cpu ] GC(14124) User=0.00s Sys=0.00s Real=0.00s

[LineOfLightning]

ログを見る限り、確かにFULL GCが頻発しており、実行前と実行後でほとんど変わってない(23MB -> 23MB)ことが見て取れますね。

ただ、ヒープサイズの最大が24MBはあまりに小さすぎると思いますがどうでしょうか？

無理やりヒープサイズを小さくしてハングアップさせても意味がありません。
何故なら、全くメモリリークしていなくてもメモリの割当が小さければFGCが頻発します。

GCを効率的に行うにはヒープにある程度の空きが必要です。
JVMは必要に応じてメモリをOSに要求し、一度、メモリを確保した後、GCを行っても確保したメモリを手放すことはありません。GCで開放されてもJVMに割り当てられたままです。JVMが自分で再利用するだけです。

JVMのメモリ管理は我々が考えているよりずっと複雑です。
同じ処理の繰り返しなのでメモリの使用量は最初の一回以外全く増えないはずだ、メモリ使用量が増えるのはメモリリークのせいだなんて思い込むのは危険です。

メモリリークが起きていると信じている理由はどこにありますか？

線形的にメモリ使用量がずっと増え続けてますか？
最初のうちはメモリ使用量が段々と増え、ある程度時間が経ったらほとんどメモリ使用量増えなくなってませんか？

繰り返しになりますが、もし、ヒープサイズ(Xmx)に余裕をもたせて、それでもFGCが頻発するようでしたら、メモリリークの可能性が高いです。
余裕をもたせた結果、FGCは頻発しない。または、ヒープサイズの最大まで全然達する気配がないのであれば、それは問題なくメモリが管理されてるということです。

[ttdrop]

確かに上昇比率としては、徐々にゆるやかになっていくグラフとなっています。。
メモリリークが起きているという根拠はなく、むしろ起きていないという前提でいました。

> 同じ処理の繰り返しなのでメモリの使用量は最初の一回以外全く増えないはずだ、メモリ使用量が増えるのはメモリリークのせいだなんて思い込むのは危険です。

仰る通りです。メモリの上昇に関して過剰反応していました。
また、本来の運用とは遠い値までヒープを下げる等、再現性に欠けておりました。

一度、本来系の設定値で連続稼働させ、長い目でどうなっているのか確認したいと思います。
色々とアドバイスを頂きありがとうございますｍｍ

Answer 2

メモリリークのようなことが起きているように思われます。

これは引数設定に問題があるのでしょうか？

右肩上がりにヒープ使用量が上がっているアプリケーションは、プログラム中に解放漏れのオブジェクトがあることを疑うべきです。

まずはヒープ使用量をツール(jconsole等)を使って確かめてください。
OutOfMemoryError の調べ方という記事もメモリリークの調査をする上で参考になると思います。

VM引数で指定するメモリの目安

まずはメモリリークを直してください。

直した仮定で話を勧めますが、その場合のヒープ使用量は同じ高さの波状になるはずです。
その状態でアプリケーションにおいて一番メモリを使用する操作（容量の大きいオブジェクトを大量にインスタンス化するなどの処理が含まれる操作）を行ってください。

その操作を行うことでOutOfMemoryErrorになるようであれば、問題が再発しなくなるまで割り当てるメモリを増やしてください。再発しなくなればそれが目安です。

ただ、大抵の場合はデフォルトのヒープサイズで足りるはずなので、事情がない限り割り当てるメモリは変更しないのが妥当です。

また、割り当てるメモリを変える前にメモリを無駄に多く消費している部分がプログラム中にないかを確認してください。あればその修正を行ってください。

Comments

[ttdrop]

ご回答ありがとうございます。
jconsoleで表示した結果を添付致しました。
ヒープはYGC発生時に下がっており、問題ないように見えます。

クラスのロード数が増える一方という状態になっていますが、
こちらが原因となっているのでしょうか。
metaspaceのサイズ指定でGCされる認識でいましたが。。

[ttdrop]

連投で申し訳ありません。
非ヒープ使用率が右肩あがりとなっていたため、ここのせいかもしれません。
（一度手動でGC実行してしまいましたが、それ以外に下がっている箇所が無さそうです。）

[BluOxy]

添付ありがとうございます。どうやらヒープメモリではなかったようですね。
jstatにMetaspace使用率が96%と書いてあるので、アプリケーション内のクラス数が多すぎるように見えます。このとき、MaxMetaspaceSizeのデフォルトサイズは無制限の認識なのでサイズを変えても効果はないと思います。

なので、次に試すべきことはいずれかの2つが挙げられます。
①下記URLを参考にEclipse MATで分析し、ロードされたクラスの中に意図したものがあるかどうかチェックし、問題を解消する
https://stackoverflow.com/questions/29423390/how-to-diagnose-a-java-8-metaspace-leak

②メモリを増設する

[ttdrop]

現在Eclipse MATで調べていますが、
・java.util.zip.ZipFile
・java.lang.Class
・java.lang.Thread
といったクラスがリーク疑惑対象として表示されましたが、
あまり原因と思われる箇所ではありませんでした。
（イマイチ使いこなせていないのでもう少し詳しく調べてみてはいます）
また、今回稼働させているプロセスは一連の短い処理を大量に繰り返し実施しているものになり、
アプリケーション内のクラスファイルは大した数ではないはずなのです...

[BluOxy]

中身を知らないため抽象的な意見になりますが、一連の短い処理の中から怪しい部分を見つけて、それをコメントアウトなどで一時的に無効にすることで非ヒープ使用率が高くなる箇所を特定できると思います。

[BluOxy]

例えば、ClassPoolから動的にクラスをロードするような処理がプログラム中（外部ライブラリ含め）に組み込まれている可能性が挙げられます。

他にもMetaspaceによるメモリリークが起きたときのチューニング方法という文献が見つかったので、こちらも参考になるかもしれません。
https://software.fujitsu.com/jp/manual/manualfiles/m170006/b1ws1303/01z200/b1303-00-11-06-01.html