Javaを用いたプログラムで、運用開始後に原因不明の障害が発生する場合は多々あります。
原因不明のメモリリーク、CPUの一時的な極端な上昇といった現象は、アプリケーションのログからはなかなか原因が突き止められない場合があります。
こういった事象に対応するために、GCログの出力と、OutOfMemory発生時のヒープダンプ出力をあらかじめ仕込んでおくと、原因の早期発見が期待できます。
今回は、Javaアプリケーションの起動設定について、GCログとヒープダンプの出力設定をおこなう方法について紹介します。
環境情報
- Java 1.8.0_281
GCログの出力設定
GCログの出力設定は、Javaの起動オプションとして設定します。
設定オプションは以下になります。
-verbose:gc |
GCログを出力する。 |
-Xloggc |
GCログの出力先を設定する。 例)-Xloggc:./gc.log-%t
ファイル名に設定できる変数要素としては以下の2つがあります。 %t=ログファイルを作成した日時 %p=JavaプロセスのID |
-XX:+UseGCLogFileRotation |
GCログのローテーションをおこないます。 |
-XX:+PrintGCDateStamps |
GCログに時間のタイムスタンプを表示します。 |
-XX:+PrintGCDetails |
GCログの詳細を出力します。 |
-XX:NumberOfGCLogFiles |
GCログのローテーションをおこなう際、ローテーションするファイルの数を定義します。 |
-XX:GCLogFileSize |
1つのログファイルのファイルサイズを定義します。 定義したファイルサイズに到達したタイミングで、ローテーションがおこなわれます。 定義したファイルサイズに到達したタイミングで、ローテーションがおこなわれます。
M=メガ k=キロ(最小は7K) |
設定例としては以下になります。
実行するプログラムは「GcSample」となり、10キロのGCログファイルを最大5ファイルでローテーションをおこなっています。
GCログファイルにはログファイルを出力した日時を設定するために「%t」オプションを定義していますが、以下はWindowsのバッチファイル例なので、”%%”と記載してエスケープしています。
java -Xms256m -Xmx256m -verbose:gc -Xloggc:./gc.log-%%t -XX:+UseGCLogFileRotation -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10k GcSample
この定義でログファイルを出力した場合は、以下のような定義となります。
gc.log-2021-02-11_15-52-26.0 gc.log-2021-02-11_15-52-26.1 gc.log-2021-02-11_15-52-26.2 gc.log-2021-02-11_15-52-26.3 gc.log-2021-02-11_15-52-26.4.current ← 出力中ファイル
5ファイルでローテーションされています。
出力されたファイルはGCViewerなどのビューアで参照するのが一般的になります。
ヒープダンプ(HeadDump)の出力設定
GCログを設定しておくことも大事なのですが、GCログだけではOutOfMemoryが発生した場合の、リーク箇所などについては詳細を判断することはできません。
ヒープダンプを設定しておくと、OutOfMemory発生時にヒープダンプ(HeadDump)が出力されるので、詳細の原因調査が可能となります。
-XX:+HeapDumpOnOutOfMemoryError |
OutOfMemoryが発生した場合にヒープダンプを出力します。 |
-XX:HeapDumpPath |
ヒープダンプの出力先フォルダ、および、ファイル名を指定します。 ファイル名を指定しない場合は、「java_pidxxx.hprof」といったファイル名になります。 xxxはプロセスIDです。 |
-XX:OnOutOfMemoryError |
OutOfMemoryが発生した場合に実行するコマンドを定義することができます。 実行するコマンドは、シングルクォーテーションで囲んで定義します。
例)-XX:OnOutOfMemoryError=”cmd string.” |
OutOfMemoryが発生してヒープダンプを出力した際、指定したフォルダにダンプファイルを出力するのですが、同名ファイルが存在する場合は上書きしてくれません。
つまり、同じプロセスIDのJavaプロセスで複数回のOutOfMemoryが発生した場合、一番最初のヒープダンプだけが残ります。
一番最初のヒープダンプを残すのではなく、一番最後のヒープダンプを残したい場合は、OnOutOfMemoryErrorオプションを使います。
以下の例では、ヒープダンプが発生したタイミングで出力したダンプファイルをバックアップフォルダに移動をおこないます。
この定義をおこなうことで、ヒープダンプ出力先フォルダにはダンプファイルは残らず、バックアップフォルダに最後のヒープダンプが残ることになります。
java -Xms10m -Xmx10m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./ -XX:OnOutOfMemoryError="D:/gc/gc-move.bat" GcSample
OnOutOfMemoryErrorオプションに定義したgc-move.batの中身は以下になります。
backというフォルダに、出力したヒープダンプファイルを強制上書きコピーしています。
move /Y java*.hprof ./back/
OnOutOfMemoryErrorオプションに定義したコマンドは、ヒープダンプが出力された後に実行されるようです。
①:OutOfMemoryが発生
↓
②:ヒープダンプを出力
↓
③:OnOutOfMemoryErrorオプションに定義したコマンドを実行
このような動きであることを考慮して、OnOutOfMemoryErrorオプションに定義したコマンドを検討する必要があります。
仮に、最初のヒープダンプファイル・最後のヒープダンプファイル、という事ではなく、ヒープダンプの履歴を取りたい(全てのヒープダンプファイルを残しておきたい)場合は、上記例の「gc-move.bat」を修正すれば、様々な定義をおこなうことができます。
しかし、ヒープダンプファイルはプロセスのヒープ情報をそのままダンプしているので、かなりサイズが大きいファイルとなります。
そのため、ダンプファイルの履歴をとることはおすすめはしません。