【java】OutOfMemory発生時の調査方法

ヒープ領域設定などが適切に設定されていることが前提です。
これらを読む前に、まず-Xmsや-Xmxの値を見直してみてください。

メモリリークを理解する

通常、メモリリークはプログラム上のミスであることが大半です。
java7では、AutoCloseableまたはCloseableインターフェースの実装クラスはtry-with-resourcesという構文が利用でき、煩雑なfinally句を書く必要がなくなりました。反面、構文ミスによるリソースの閉じ忘れが発生することもあり・・・。

たとえば、

public class A implements AutoCloseable{
    public void close(){
        System.out.println("A was closed.");
    }
}

public class B implements AutoCloseable{
    private A a = null;

    public void close(){
        System.out.println("B was closed.");
    }
    public B(A a){
        this.a = a;
    }
}

というふたつのAutoCloseableを実装したクラスがあるとします。

public class Main {
    public static void main(String[] args){
        try(B b = new B(new A());){
            System.out.println("try");
        }
    }
}

呼び出し側がこのような構文ですと、結果は

try
B is closed.

A.javaのclose()が呼ばれていません。
このような問題を解決するには、

public class Main {
    public static void main(String[] args){
        try(A a = new A();
            B b = new B(a);){
            System.out.println("try");
        }
    }
}

このようにする必要があります。

try
B was closed.
A was closed.

結果はこの通りです。

これは一例ですが、思わぬところでリリースの解放忘れがある可能性があります。
開発時には問題が起きない場合も多いので、十分気を付けながらコーディングしていきたいものです。

GC LOGを調べる

javaVMでは、Garbage Collectionという機能が備わっており、開発者が意識しなくても、ある程度まで適切にメモリを管理してくれています。
OutOfMemoryエラーが発生するということは、GCを行っても解放されない領域があるということですから、このログを解析すれば、解決の糸口になります。

基本的には、GCのログとアプリケーションのログを時系列で比較検証することで、アプリケーション側のバグをチェックしていきます。

GC LOGの出力設定

GCログを出力するには、起動時に-verbose:gcオプションを付与します。今回はGCログを単独で取得したいので、あわせて-Xloggc:(出力先path)オプションを付与します。しかし、そのままではタイムスタンプが起動時からの経過時間となって、直観的な解析ができませんので、-XX:+PrintGCDateStampsを、また詳細情報の取得を行いたいので、-XX:+PrintGCDetailsを付与します。

オプション	説明
-verbose:gc	GCログを出力する
-Xloggc:(出力先path)	ログファイルの出力先を指定する
-XX:+PrintGCDateStamps	タイムスタンプを日付・時刻形式で出力する
-XX:+PrintGCDetails	GCの詳細情報を出力する

これでGCログが出力されるようになります。

GCログの解析

コマンド駆使して自力解析する方法もありますが、今回はGCViewerを利用して解析しましょう。

Changelog · chewiebug/GCViewer Wiki

こちらからダウンロードし、対象のログを読み込みます。
着目すべきは黒い縦の線で、これはFullGCが発動したタイミングを示しています。

FullGCはOLD領域がいっぱいになると行われるのですが、このOLD領域の遷移をよく観察します。

OLD領域が徐々に上がるケース
OLD領域が突然上がるケース

徐々に上がるケースでは、定常的に動いているオブジェクトのキャッシュ機構やクローズ漏れを疑います。
突然上がるケースでは、バッチやDBアクセスなどでメモリを使い切ったケースを疑います。

あとはアプリケーションのログファイルと突き合わせ、同じ時間に何が起こったのかを調べれば、異常箇所の特定が容易になります。

ヒープダンプを調べる

GCLOGの解析で解決に至らない場合は、ヒープダンプを調べましょう。

障害発生時（OutOfMemoryError）に自動的にヒープダンプを取るには、java起動時に以下のオプションを付与します。

-XX:+HeapDumpOnOutOfMemoryError

2018/02/15 +HeapDumpOnOutOfMemoryErrorの接頭記号が-になっておりました。記事をご参照頂いた方にはご迷惑をおかけしました。

ヒープダンプを任意に取得する場合は、java jdkに同梱されているjmapを実行します。
しかし、ヒープダンプを出力している間、アプリケーションが完全に停止するということに注意してください。本番環境では（ロードバランシングを行っていたとしても）なかなか実行するのは難しいでしょう。

任意のタイミングでヒープダンプを取得したい場合は、以下のコマンドを実行してください。

jmap -F -dump:format=b,file=(ファイル名) (pid)

実行できない場合は、環境変数を確認するか、フルパスで実行してください。

コマンド詳細は、oracle社のJava Platform, Standard Editionツール・リファレンス jmapを参照してください。

解析ツールはMemory Analyzerがよいでしょう。使い方は、furyu TECH BLOGさんがわかりやすく解説してくださっています。

さて、障害時のヒープダンプだけでも原因特定が出来たりするのですが、単にヒープ使用量が多いオブジェクトがあるというだけで断定はできません。アプリケーション側で必要な情報をキャッシュしているだけかもしれませんし、設定されているヒープ容量が足りないだけなのかもしれません。

キャッシュ機構については、独自実装でない限りは上限値の設定項目があると思います。まずはこれを見直します。

キャッシュが原因でない場合は、根本的にメモリ割り当てが足りていないのかもしれません。ヒープを見直します。

それも問題ない場合は、複数回に分けてヒープダンプを取り、起動時からの推移を確認します。
大抵の場合、起動時と異常時で大きく差異のあるオブジェクトがあるはずですので、この周辺を探っていくことで、問題を解決できる可能性が高いです。

まとめ

基本的な手順としては、GCログの精査からヒープダンプですが、もしヒープダンプが気軽に取得できる状況であれば、そちらから調査してみるほうが早いかもしれません。