Javaメモリ、GCチューニングとそれにまつわるトラブル対応手順まとめ

GC周りでトラブルシューティングした際の経験や、Web等で調べたことをまとめてみる。

前提

JVMは、Sun Javaを想定。(他は使ったことないです。。。)
・Sun Java 1.5-1.6を想定。

目標

マイナーGC、Full GCそれぞれが頻発することなく、かつそれぞれの実行時間を1秒未満に抑えること。
マイナーGCは1秒未満どころではなく、もっと短くなるべき。どれくらいが理想かは?(0.1秒未満ぐらいを目指したい?)
連続した負荷状態(想定されるピークアクセス)でもOutOfMemoryErrorが発生しないこと。
理想的な状態は、上記に加えて、Full GCの発生が低頻度であること。
具体的には、できるだけマイナーGCで短命オブジェクト(1回使ったらもう使わないようなオブジェクト。逆にセッションオブジェクト等は長命オブジェクトとなる)を破棄させて、短命オブジェクトが、TenuringThresholdを超えるマイナーGCを経てNew領域からOld領域へ移動することをできるだけ抑えることがチューニング目標となる。(Old領域に行ってしまうとFull GCでしか掃除されないため、できるだけOld領域に移る前にNew領域で掃除させるということ)(実際のTenuringThresholdが、-XX:MaxTenuringThresholdで指定した値にできるだけ近い状態を維持するということ)

運用環境で是非設定しておくべきJava起動オプション

-server サーバーモードを有効化
-Xms Javaヒープ初期サイズ。一般的に、-Xmxと同値にする
-Xmx Javaヒープ最大サイズ
-Xmn(-XX:NewSize) New領域初期サイズ。一般的に、-XX:MaxNewSizeと同値にする
-XX:MaxNewSize New領域最大サイズ
-XX:PermSize Permanent領域初期サイズ。一般的に、-XX:MaxPermSizeと同値にする
-XX:MaxPermSize Permanent領域最大サイズ
-verbose:gc(-Xloggc:path_to_file) GCログ出力を有効化
-XX:+PrintGCTimeStamps GCログにタイムスタンプ(Java起動時からの経過時間)を出力
-XX:+PrintGCDetails GCログを詳細に出力(New領域とJavaヒープそれぞれがどれだけ減ったか出力される)
-XX:+PrintClassHistogram*1 SIGQUITシグナル受信時にヒープ統計情報を出力(出力時に強制的にFull GCが発生)。-verbose:gc(-Xloggc:path_to_file)と併用必須。なお、SIGQUITシグナルを送信するには、kill -3 を実行すればよい
-XX:+HeapDumpOnOutOfMemoryError OutOfMemoryError発生時にヒープダンプを出力(Sun Java 1.4.2_12以上、1.5.0_07以上、1.6以上)

大抵、運用環境で設定しておいた方がいいJava起動オプション

-XX:SurvivorRatio Eden領域のサイズをS0またはS1領域のサイズで割った値(S0とS1領域は同じサイズ)
-XX:MaxTenuringThreshold New領域において、オブジェクトがマイナーGCを何回超えて生き残ると、Old領域に移動するかのしきい値の最大値(実際のしきい値は、1からMaxTenuringThresholdの範囲で動的に決定される)
-XX:TargetSurvivorRatio Survivor領域がいっぱいと判断される使用率

チューニング(トラブル対応)のためのコマンド、ツール

1.GC発生状況、メモリリーク状況

-verbose:gc(-Xloggc:path_to_file)、-XX:+PrintGCTimeStamps、-XX:+PrintGCDetails
を設定しておくことでGCログが取得できる。取得したGCログは、GCViewer等でグラフ化できる。

2.ヒープ使用状況

jstatコマンドでリアルタイムに確認可能。
-gcutilオプションで、S0、S1、Eden、Old、Permanent領域ごとの使用率やマイナーGC、Full GCの発生回数、GCの実行時間累計が確認可能。
例.

jstat -gcutil -h10 <pid> 5000

jconsoleコマンドを使用すれば、GUIでリアルタイムに確認することも可能。

3.ヒープ統計情報

以下の方法で出力できる。

  • -verbose:gc(-Xloggc:path_to_file)、-XX:+PrintClassHistogramを設定しておき、kill -3 を実行
  • jmap -histo

ヒープ中のオブジェクトのインスタンス数、サイズ一覧が出力される。ヒープダンプの出力に比べて、取得時の負荷は小さく、運用環境でも使用可能だが、分析は大変。出力結果を分析可能なツール等も知りません。どこかにないかな?

4.ヒープダンプ

以下の方法で出力できる。

  • -XX:+HeapDumpOnOutOfMemoryErrorを設定しておき、OutOfMemoryErrorが発生
  • -XX:+HeapDumpOnCtrlBreak*2を設定しておき、kill -3 を実行
  • jmap -heap:format=b (Java 1.5の場合)
  • jmap -dump:format=b,file=filename (Java 1.6の場合)

出力に時間もかかる(ヒープサイズ512MBで5-10分程度)し、負荷も大きいが、詳細なヒープ情報を取得可能。ダンプファイルはバイナリなので、以下のツールで分析する。

5.プロファイラ

オブジェクトの生成、GC等、JVMの挙動をトレースする。アプリケーションを動作させつつ、増加していくオブジェクトを探したり、スタックトレースを確認したり等の調査が可能。パフォーマンスが悪化するため、運用環境では通常使用できない。メモリリークやメモリの大量消費の調査の場合、まず問題の再現方法を突き止めた上で、開発/検証環境でプロファイラを使用して、再現方法を実施して、増加したオブジェクトを解析する。

6.スレッドダンプ

ヒープ、GCチューニングの観点ではないが、アプリケーションの応答がとまってしまったらとりあえず取得するのがよい。kill -3 で出力される。スレッドのデッドロックが発生していないか、大量の待ち行列が発生していないか等がわかる。

ケース別チューニング(トラブル対応)方法

1.OutOfMemoryError: PermGen space と出る場合

Permanent領域不足によるOutOfMemoryErrorが発生している。
対応としては、-XX:PermSize、-XX:MaxPermSizeを指定し、OutOfMemoryErrorが発生しないようにPermanent領域を広げてやればよい。ただし、基本的にPermanent領域は、クラス情報やメソッド情報が格納される領域であり、アプリケーション起動後はほとんど増減しない。jstatやjconsole等でPermanent領域の使用状況を確認し、もし増加が続くようであれば、Permanent領域のメモリリークが発生している可能性がある。
リーク箇所を発見するには、ヒープ統計情報やヒープダンプを数回取得して比較したり、アプリケーションログ等からOutOfMemoryError発生直前に実行されている処理がいつも同じでないか等を確認する。
例えば、DIコンテナは通常1アプリケーションで1つしか使用しないが、とある処理で新規にコンテナを生成するようになっていて、その処理が実行されるたびに大量のPermanent領域を消費し、ついにはOutOfMemoryErrorが発生した事例がある。

2.OutOfMemoryError: Java Heap Space と出る場合(OutOfMemoryErrorとしか出ないこともある)

ヒープ不足によるOutOfMemoryErrorが発生している。
とりあえずの対応としては、-Xms、-Xmxを指定し、OutOfMemoryErrorが発生しないようにヒープを広げてやればよい。
根本対応としてはまずは、GCログを取得し、ヒープでのメモリリークが発生していないか確認する必要がある。GCログをGCViewerExcel等でグラフ化して確認する。グラフがFull GCを跨って、右肩上がりになっている(右肩上がりになってFull GCでいったん下がるが、スタート時ほど下がっていない(複数回のFull GC発生時の下限値を結ぶ線が右肩上がりになっている))場合は、メモリリークが発生している可能性が高い。リーク箇所を発見するには、ヒープ統計情報やヒープダンプを数回取得して比較して、Full GCを経ても増加し続けているオブジェクトを探す。怪しいオブジェクトが見つかれば、NetBeans Profiler等を使用して、オブジェクトの使用箇所を探し、オブジェクト参照を追跡する。

3.ヒープチューニング方法

運用環境で、jstat -gcutilやjconsoleを使用してヒープの各領域の使用状況を確認しながら、Full GC実行時間を最小にするために、OutOfMemoryErrorが発生しないサイズでなるべく小さいサイズを-Xms、-Xmxに指定し、また、Full GC発生頻度を抑えるために、
-Xmn(-XX:NewSize)、-XX:MaxNewSize、-XX:SurvivorRatio、-XX:MaxTenuringThreshold、-XX:TargetSurvivorRatio
を調整して、なるべくNew領域でのマイナーGCでメモリを解放させて、Old領域へ移動される頻度、サイズを減らすようにする。
マイナーGCが発生していないのに、いきなりOld領域の使用率が上がった場合や、S0、S1、Eden領域がいきなり100%になった場合は、オブジェクトのサイズがS0、S1、Eden領域サイズよりも大きい。アクセスログと突き合わせて、使用率のあがるURLを特定し、コードを見たり、URLアクセス前後のヒープ統計情報、ヒープダンプを比較することで、サイズの大きいオブジェクトを特定する。もし、そのオブジェクトが短命オブジェクトの場合は、-Xmn(-XX:NewSize)、-XX:MaxNewSizeを増加させて、Old領域に行かないように調整する。とりあえずは、以下のような値からはじめて調整していく。

-Xmn(-XX:NewSize)、-XX:MaxNewSize -Xmxサイズの1/4 - 1/3程度
-XX:SurvivorRatio 2 - 8程度
-XX:MaxTenuringThreshold 32程度
-XX:TargetSurvivorRatio 80 - 90程度
4.マイナーGC実行時間が1秒を超える場合

New領域が大きすぎる可能性があるので、-Xmn(-XX:NewSize)、-XX:MaxNewSizeを減らす。CPUが複数ある(マルチコアを含む)場合は、-XX:+UseParallelGC オプションでパラレルGCを有効にする。

-XX:+UseParallelGC マイナーGCをマルチスレッドで実行
5.Full GC実行時間が1秒を超える場合

まずは、メモリリークが発生していないか確認する。確認方法は、2.OutOfMemoryError: Java Heap Space と出る場合 を参照。
メモリリークが発生していない場合は、Old領域が大きすぎる可能性があるので、-Xms、-Xmxを減らす。減らしすぎて、OutOfMemoryErrorを発生させないように注意する。やり方は、3.ヒープチューニング方法 を参照。

メモリリークが発生しておらず、これ以上減らすとOutOfMemoryErrorが発生するOld領域サイズなのに、Full GC実行時間が1秒を超える場合は、以下の対応案が考えられる。

(1)アプリケーションでメモリを使いすぎていないか確認し、使いすぎている場合は修正する
メモリを多く消費する処理を特定するには、運用環境で、jstat -gcutilやjconsoleを使用してヒープの各領域の使用状況を監視し、使用率がドカッとあがったときに実行された処理を、アクセスログから突き止める。(ある程度絞れれば、あとは開発/検証環境で突き止める)あとは、コード解析を行い、修正する。

(2)セッションタイムアウト時間の確認
セッションタイムアウト時間が不必要に長すぎないか確認し、長い場合は短くする。

(3)コンカレントGCの使用
Full GCをできるだけアプリケーションをとめずに並行実行するコンカレントGCを使用する。以下のJava起動オプションを設定する。
※-Xms -Xmx -XX:NewSize -XX:MaxNewSize、-XX:SurvivorRatio、-XX:MaxTenuringThreshold、-XX:TargetSurvivorRatioは設定されている前提。

-XX:+UseConcMarkSweepGC コンカレントGCの有効化
-XX:+CMSParallelRemarkEnabled Full GCのRemarkフェイズをマルチスレッドで実行
-XX:+UseParNewGC マイナーGCをマルチスレッドで実行
6.アプリケーションの応答が停止(フリーズ)した場合

スレッドダンプを取得する。

7.StackOverflowError と出る場合

StackTraceを確認し、メソッドの不要な再帰呼び出し等が行われていないか確認する。あるいは、以下のJava起動オプションを設定し、スタックサイズを増やしてみる。

  HotSpot VMの場合 非HotSpot VMの場合
-Xss (Java/ネイティブ)スレッドのスタックサイズ ネイティブスレッドのスタックサイズ
-Xoss 効果なし*3 Javaスレッドのスタックサイズ
参考URL

JVMオプション一覧
http://blogs.sun.com/watt/resource/jvm-options-list.html


PrintClassHistogramオプション
http://www.atmarkit.co.jp/fjava/rensai4/troublehacks08/troublehacks08_3.html


UseConcMarkSweepGCオプション
http://www.atmarkit.co.jp/fjava/rensai4/troublehacks02/troublehacks02_2.html


2時間集中 Java トラブル解決ドリル
http://mediacast.sun.com/users/okazaki/media/20070327_javatroubleshooting.pdf


侍によるGCログ解析、メモリリーク箇所確認方法
jmapによるヒープダンプ取得とEclipse Memory Analyzerによる解析
http://yusuke.homeip.net/diary/2008/11/10/1226316240000.html


Tomcat@Windowsのcatalina.out出力、スレッドダンプ出力方法
http://yusuke.homeip.net/diary/2006/09/21/1158846052527.html

*1:Java 1.5.0_05にはバグがあって、PrintClassHistogramオプションは、UseConcMarkSweepGCオプションと併用しなければ、kill -3 を行ってもヒープ統計情報が出力されないので注意

*2:HeapDumpOnCtrlBreakオプションは、Sun Java 1.4.2_17以上か、1.5.0_14以上が必要。なお、1.6はオプションが廃止されている。Ctrl+Breakまたは、SIGQUITシグナルを送れば、スレッドダンプと一緒にヒープダンプが出力される

*3:HotSpot VMの場合、Javaスレッドは一意のネイティブスレッドに関連付けられるため -Xossは効果がない。