ふわっと JVM のヒープ領域監視について考える

ども、かっぱです。

はじめに

• Java アプリケーションを運用する上では避けて通れないであろうヒープ領域の監視についてフワッと考えてみた
• JVM には幾つか領域があるがヒープ領域に焦点を当てる

参考

• http://www.whitemark.co.jp/tec/java/javaHeap.html
• http://www.whitemark.co.jp/tec/java/javagc.html
• http://d.hatena.ne.jp/ogin_s57/20120623/1340463194
• http://d.hatena.ne.jp/ogin_s57/20120709/1341836704
• https://docs.oracle.com/javase/jp/1.5.0/guide/management/agent.html
• http://chonaso.hatenablog.com/entry/20140507/1399395305
• http://www.slideboom.com/presentations/800440/20130727-%E6%B8%8B%E8%B0%B7Java-%232-Java%E3%82%A2%E3%83%97%E3%83%AA%E3%82%B5%E3%83%BC%E3%83%90-%E3%81%A8%E3%82%8A%E3%81%82%E3%81%88%E3%81%9A%E3%81%AE%E7%9B%A3%E8%A6%96
• http://www.syboos.jp/java/doc/full-gc-in-java-and-howto.html

上記の全ての記事がとても参考になった（というかむしろそのまま内容を拝借した感じになっている…）投稿者、作者の皆様に感謝。

JVM の構成

構成

以下のようなイメージ。

ヒープ領域

• Java が利用出来るメモリ領域

非ヒープ領域

• Permanent 領域

New 領域

• Eden : 最初にインスタンス化したオブジェクトが格納される
• From : Scavenge GC によってオブジェクトが格納される
• To : Scavenge GC によってオブジェクトが格納される

Old 領域

• New 領域の From と To のやりとり頻度が多い（Defaul 32 回）オブジェクトで利用される
• 空き領域が少なくなると Full GC によってオブジェクトは破棄される

Parament 領域

• アプリケーションのクラス、メソッドが格納される
• 大量のクラスや JSP を大量に利用する場合には領域を大きく確保しておく必要がある
• Old 領域同様に空き領域が少なくなると Full GC により空き領域を確保する

GC

ガーベージコレクション

以下のようなイメージ。

New 領域における Scavenge GC について

• Eden 領域が一杯になると Scavenge GC が実行されオブジェクトは To 領域へ移動して Eden 領域の空き容量を確保
• 再び Eden 領域が一杯になり Scavenge GC が実行されるとオブジェクトは To 領域へ移動、To 領域のオブジェクトは From 領域に移動
• From と To でオブジェクトの行き来が発生するが、この行き来が 32 回を超える(*1)と Old 領域にオブジェクトは移動する（MaxTenuringThreshold）
• 比較的短時間で終了する

(*1:「最大 32 回となり 32 回未満でも Old 領域にプロモートすることがある」とのコメントを頂きました)

Old 領域における Full GC について

• 主に Old 領域と Perament 領域を対象とした GC となる（New 領域でも発生する）
• Scavenge GC 及び Old 領域、Perament 領域を対象とする GC の為に処理時間が長い
• Full GC 実行中はシステム停止となってしまう…

監視項目（どこを見ておくべきなのか（何を主に見ておくべきなのか））

個人的な見解

• 各領域（New / Old / Parament）の使用率
• 各 GC の回数（特に Full GC）
• New の Eden 領域
• JVM に関係ないけどファイルのオープン数（Open Files Limits）
• メモリリーク =「Full GC が発生しても Old領域 の空き容量が回復しない状態」

（以下、引続き書く）

各種ツール（監視ツール、解析ツール）

jstat

jstat は JVM のパフォーマンス統計監視ツールで CentOS の場合には openjdk-devel をインストールする必要がある。

sudo yum install java-1.7.0-openjdk-devel.x86_64

例えば jps を使って Elasticsearch で利用している JVM のプロセス ID を確認して jstat で状態を確認するには以下のように実行する。

# sudo -u elasticsearch jps
2713 Jps
2363 Elasticsearch
# sudo -u elasticsearch jstat -gc 2365
2365 not found
# sudo -u elasticsearch jstat -gc 2363
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       PC     PU    YGC     YGCT    FGC    FGCT     GCT
8512.0 8512.0 8512.0  0.0   68160.0  58472.1   176960.0   13304.9   38912.0 38885.4      2    0.059   0      0.000    0.059

地味にハマったのが root ユーザーの状態で jps を実行すると以下のように Elasticsearch のプロセスを見つける事が出来ない。

# jps
2780 Jps
2363 -- process information unavailable

jps コマンドや jstat コマンドはデフォルトで /tmp/hsperfdata_${ユーザー名} 以下に出力される ${PID} ファイル名が付いたファイルを参照するが、Elasticsearch の場合には以下のような状態になっている。

# ls -l tmp/hsperfdata_elasticsearch/
total 32
-rw------- 1 elasticsearch elasticsearch 32768 Mar 28 17:23 2363

ということで elasticsearch ユーザーで実行することで jps や jstat で Elasticsearch のプロセスを見つけることが出来て状態を確認することも出来たところで…前後してしまったが jstat の出力オプションについて以下のようにドキュメントより転載。

出力オプションに関してはプラットフォーム毎に異なるので各プラットフォームで利用可能な出力オプションを確認するには -options を実行して確認する。例えば、x86_64 な CentOS 6.x 上で確認すると以下のように出力される。

# jstat -options
-class
-compiler
-gc
-gccapacity
-gccause
-gcnew
-gcnewcapacity
-gcold
-gcoldcapacity
-gcpermcapacity
-gcutil
-printcompilation

Elasticsearch が稼働している環境で各出力オプションを試してみる。

# sudo -u elasticsearch jps
1145 Elasticsearch
1570 Jps

# sudo -u elasticsearch jstat -class 1145
Loaded  Bytes  Unloaded  Bytes     Time
  6687 12891.6        0     0.0       4.30

# sudo -u elasticsearch jstat -compiler 1145
Compiled Failed Invalid   Time   FailedType FailedMethod
     672      0       0     3.80          0

# sudo -u elasticsearch jstat -gc 1145
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       PC     PU    YGC     YGCT    FGC    FGCT     GCT
8704.0 8704.0  0.0   4026.3 69952.0  20325.1   174784.0   29543.6   35264.0 35087.9      7    0.129   0      0.000    0.129

# sudo -u elasticsearch jstat -gccapacity 1145
 NGCMN    NGCMX     NGC     S0C   S1C       EC      OGCMN      OGCMX       OGC         OC      PGCMN    PGCMX     PGC       PC     YGC    FGC
 87360.0 340736.0  87360.0 8704.0 8704.0  69952.0   174784.0   707840.0   174784.0   174784.0  21248.0 169984.0  35264.0  35264.0      7     0

# sudo -u elasticsearch jstat -gccause 1145
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT    LGCC                 GCC
  0.00  46.26  30.21  16.90  99.50      7    0.129     0    0.000    0.129 Allocation Failure   No GC

# sudo -u elasticsearch jstat -gcnew 1145
 S0C    S1C    S0U    S1U   TT MTT  DSS      EC       EU     YGC     YGCT
8704.0 8704.0    0.0 4026.3  6   6 4352.0  69952.0  22320.2      7    0.129

# sudo -u elasticsearch jstat -gcnewcapacity 1145
  NGCMN      NGCMX       NGC      S0CMX     S0C     S1CMX     S1C       ECMX        EC      YGC   FGC
   87360.0   340736.0    87360.0  34048.0   8704.0  34048.0   8704.0   272640.0    69952.0     7     0

# sudo -u elasticsearch jstat -gcold 1145
   PC       PU        OC          OU       YGC    FGC    FGCT     GCT
 35264.0  35088.4    174784.0     29543.6      7     0    0.000    0.129

# sudo -u elasticsearch jstat -gcoldcapacity 1145
   OGCMN       OGCMX        OGC         OC       YGC   FGC    FGCT     GCT
   174784.0    707840.0    174784.0    174784.0     7     0    0.000    0.129

# sudo -u elasticsearch jstat -gcpermcapacity 1145
  PGCMN      PGCMX       PGC         PC      YGC   FGC    FGCT     GCT
   21248.0   169984.0    35264.0    35264.0     7     0    0.000    0.129

# sudo -u elasticsearch jstat -gcutil 1145
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT
  0.00  46.26  39.41  16.90  99.50      7    0.129     0    0.000    0.129

# sudo -u elasticsearch jstat -printcompilation 1145
Compiled  Size  Type Method
     679    191    1 java/util/EnumSet noneOf

各出力オプション毎の項目についてはドキュメントを参照するとして　-gc オプションを実行した際の各項目は下記の通り。（ドキュメントより抜粋）

元記事はこちら

「ふわっと JVM のヒープ領域監視について考える」