JavaのGC頻度に惑わされた年末年始の苦いメモリ：現場から学ぶWebアプリ開発のトラブルハック（9）（2/3 ページ）

本連載は、現場でのエンジニアの経験から得られた、APサーバをベースとしたWebアプリ開発における注意点やノウハウについて解説するハック集である。現在起きているトラブルの解決や、今後の開発の参考として大いに活用していただきたい。（編集部）

[茂呂範，株式会社NTTデータ] PC用表示関連情報

LINE

Hatena

前のページへ | 次のページへ

【第3話】伝家の宝刀にご登場願おう

　さて、これまでの経緯を簡単にまとめてみよう。

1週間前の機能追加により、新しくJava常駐プロセスがAPサーバ内に追加された
機能追加前までは、問題はまったくなかった
機能追加後からは、メモリ使用量が時間とともに増加していることが分かった
GCログより、新規の追加したJava常駐プロセス内でメモリリークが発生していた

図3　トラブルのイメージ

■おさらい：PrintClassHistogramオプションとは？

　ここまで事象が特定されていれば、伝家の宝刀PrintClassHistogramオプションにご登場願おう。ここで簡単におさらいすると、PrintClassHistogramは、Javaヒープ内に存在するインスタンスの個数と総サイズを、クラスごとの統計情報として出力するオプションだ。

　クラスごとに、この統計情報を時系列に追うことで、どのクラスがメモリリークしている原因かを容易に特定できる。その上オーバヘッドも少なく、環境への変更も最低限で済むため、サービス中の商用環境でも利用できる使い勝手のよいJavaVMのデバッグオプションだ。詳しくは、前回を参照いただきたい。

　PrintClassHistogramオプションを紹介すると、現場からは安堵（あんど）の声が漏れた。そして、早速PrintClassHitogramオプションを利用して、試験環境にて再現試験を行うことになった。

　そして、年越し3日間の連続稼働の後、驚くべき事実を目の当たりにすることになる。

【第4話】「再現していません!!」

　年明けのある朝、現場に到着すると、プロジェクトメンバがGCグラフを手に駆け付けてきた。

図4　メモリリーク再現試験：失敗

　再現試験のGCグラフは、何の問題もないGCグラフだった。再現失敗か、何か見落としがあったのか。

　「あ!!」

　そのとき、プロジェクトメンバの1人が大きな声で叫んだ。指さしていたのは、同じくGCグラフだったが、そのグラフでは商用環境に近い動作をしていたのだ!!

図5　メモリリーク再現試験：近い動作6日分

　確認を行うと、このGCグラフは、メモリリーク検証用のPrintClassHistogramオプションを意図的に設定しなかったJava常駐プロセスだという。

　きな臭いにおいが漂い始めている。

■Javaプログラムでは一切利用されていなかったRMI

　さらにこのとき、この再現試験の裏で行っていたJavaプログラムのソースコードレビューを担当していた同僚が、面白い事実に気が付いた。それは、既存プログラムはすべて、何らかの形でRMI（Remote Method Invocation）を利用していたが、新規に追加したJavaプログラムでは一切RMIを利用していなかったのだ。

編集部注：RMIについて詳しく知りたい読者は、「Weｂアプリケーション実現の本質を知ろう」の「分散オブジェクト RMI ＆ CORBA」をご参照ください。

　すぐさま、RMIを利用しているJava常駐プロセスのGCグラフを確認すると、以下のようなものだった。なお、背景が黒くなっているが、誤植でも何でもない。RMIを利用すると、1分に1回Full GCが発生するため、黒い線が重なってこのように見えてしまうのだ。