JavaのGUIアプリケーション(ネイティブライブラリ使用)をしばらく実行していると、だんだん重くなり、JavaヒープメモリをJDKのjconsoleツールで調べると、上限に張り付きFull GCが頻繁に発生してますが、グラフが下がらないという状況がありました。
同じくJDKのjvisualvmツールでヒープに占めるオブジェクトを調査すると(「サンプラ」タブの「メモリー」ボタンを押し、ヒープヒストグラムを表示)、あるクラスのインスタンスが100万個以上と同数のjava.lang.ref.Finalizerが存在しています。
ロジック的なメモリリークではなく、GCのファイナライズに関して問題が生じているようです。問題のクラスは、ネイティブライブラリを使用していおり、jconsoleでFinalizerスレッドのダンプを見ると、そのクラスのfinalizeでネイティブ呼び出しをしています。
参考: ファイナライズの仕組みについて解説している記事がありました。
普通にGCで到達不能になっても、Finalizerスレッドでfinalizeが呼ばれるまではインスタンスを保持する必要があり、finalize呼び出しでJNI経由のネイティブコードを実行していると、短時間に大量にオブジェクトを生成した場合にFinalizerスレッドが追いつかないということがあるのかもしれません。
調査・解析に使用したツールなどのメモ
今回の問題を調査するにあたって、Java標準機能で間に合ってしまいました。
jconsole
調査対象のJavaアプリケーションを実行後、JDK標準ツールのjconsoleを実行します。起動後、接続するJavaプログラムを選択すると、CPU使用率、メモリ使用量、スレッド数、スレッドのスタックトレースなどがGUI上で確認できます。
GCの発生回数と累計時間もモニタできるので、まず最初にアプリケーションの状況を見るときはこれが便利です。
jconsoleからは、java.util.loggingのログレベルを制御することもできるので、アプリケーション実行途中でログ詳細を出したい、ということも可能です。結構便利です。なお、log4jの場合もlog4jライブラリに含まれているMBeanを初期化で設定しておけば、同様にログレベルを変更することができます。
jvisualvm
調査対象のJavaアプリケーションを実行後、JDK標準ツールのjvisualvmを実行します。jconsoleと同様、接続するJavaプログラムを選択すると、CPU使用率、メモリ使用量、スレッドなどの情報がGUI上で確認できます。jconsoleと機能が大分かぶっていますが、今回の調査では[サンプラ]タブの[メモリー]サンプリングでヒープヒストグラムをモニタしました。ヒープ使用量の多いクラス順に表示してくれるものです。
jvisualvmに別途Visual GCプラグインを入れると、世代別GCの動きがグラフィカルに見える楽しい機能があります。[ツール]メニュー>[プラグイン]で、[使用可能なプラグイン]タブからVisual GCをインストールします。