現場から学ぶWebアプリ開発のトラブルハック 第9回

JavaのGC頻度に惑わされた
年末年始の苦いメモリ

株式会社NTTデータ　基盤システム事業本部
茂呂 範
2007/12/27

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

今回の主な内容

【第1話】「大みそかだというのに……」 【第2話】“現場”での聞き込みが大事 【第3話】伝家の宝刀にご登場願おう 【第4話】「再現していません!!」 【第5話】犯人はお前だ！ Finalizer!! 【第6話】GCのやっていることは全部お見通しだ！ 【注意！】Finalizerが引き起こす3つのトラブル 【最後に】「先入観」「思い込み」「事実と推測を混同」

　Java言語を利用するようになって、システムを開発するうえで楽になった要素は何かというアンケートがあったとき、読者の皆さんならどのように回答するだろうか。私は迷わず、「メモリ管理」と回答する。

　同時に、Javaを利用してシステム開発を行う際に、注意していること、悩まされたことは何かとアンケートがあれば、「GC（ガベージ・コレクション）」と回答するだろう。

　多くのシステム開発の現場では、いまこの瞬間も、JavaのGCの挙動に悩まされ、GCの挙動をいかにコントロールするか、多くのシステムエンジニアが試行錯誤していると思う。今回は、そんなGCの挙動に惑わされたトラブルハックを紹介する。

【第1話】「大みそかだというのに……」

　ちょうど大みそかだったその日の早朝も、けたたましい電話の呼び出し音にたたき起こされた。電話に出ると、「Javaのシステムでメモリリークが起きている。助けてほしい」、と告げられた。「もう、大みそかだというのに……」と思っても仕方がない。

　「さっさと片付けるしかないか……」と、PrintClassHistogramオプションを使った前回のトラブルハックの経験もあり、そのときの資料を手にさっそうと現場へ向かった。

■ 移動中にシナリオを組み立てる

　移動中、頭の中でトラブルハックのシナリオを組み立てていた。まず、PrintClassHistogramオプション利用によりリークオブジェクトを特定する。その後のHPROFを用いたリークオブジェクト生成個所を特定する。

■ APサーバ内に複数のJava常駐プロセス

　現場に到着し、早速聞き込みを開始した。まずは、今回トラブルが発生したシステムを簡単に説明しよう。

　このシステムは、Webサーバ（Apache＋mod_jk）、AP（アプリケーション）サーバ（Tomcat）、DB（データベース）サーバ（PostgreSQL）から構成される、一見すると一般的なJavaのWebシステムだ。しかし、ほかのWebシステムと異なり、面白い特徴があった。それは、APサーバ内に複数のJava常駐プロセスが存在することだ。

　これらのJava常駐プロセスは、環境の制約により、独立したプロセスとして動作させる必要があった。さらにこれらのプロセスは、両手ほど存在し、互いに通信をしながら協調動作を行っていたのだ。

図1　システムのイメージ

【第2話】“現場”での聞き込みが大事

　トラブルハックの第一歩は、現場から情報を収集し、事実を再確認することだ。早速、プロジェクトメンバを集め、トラブルの経緯の確認を始めた。

■ 【Q1】問題が発生したときの状況は？

　APサーバ内のJava常駐プロセスのうち、ある特定の1種類のプロセスでメモリリークが発生している。このプロセスがメモリリークを引き起こすことで、APサーバ上の物理メモリを消費し、これをきっかけに運用管理端末に警告が上がり、問題として認識された。

■ 【Q2】いまはどういう対処を行っている？

　システム面では、早朝にAPサーバ再起動を行った。先ほど、怪しいJava常駐プロセスは特定が終わり、設計の見直しなどを行っているが、残念ながら目ぼしい成果は出ていない。製造担当者に確認を取っているが、ベースとなる部分はほとんど既存プログラムと同一であるというので、いま差分を洗っているところだ。

■ 【Q3】再起動までの猶予はどの程度ありそう？

　いま、過去の運用データを洗っているところだ。ざっくりと見た感じでは、持って2週間、余裕を見て1週間で再起動を行う必要があるだろう。メモリリークの量自体は大したことなさそうだが、リークしているJava常駐プロセスは、全部で5つ起動している。それだけに、影響が大きい。

■ 【Q4】最終的な着地点はどう考えている？

　今回のリリースが機能追加である以上、運用に負担を掛けることは避けたい。できれば、根本的な解決が望ましい。

■ 【Q5】最後に、突然顕在化した理由で思い当たることは？

　1週間ほど前に、機能追加を行った。実はメモリリークが発生しているJava常駐プロセスは、そのときの機能追加のために新規で作成されたJavaプログラムだ。それまでは何の問題もなく動いていたので、確実にそこだ。

■ 1週間前の機能追加とやらが

　話の後、該当するJavaプログラムのGCグラフが提示された。確認すると、ヒープ使用量が右肩上がりに上昇を続けており、明らかなメモリリークが発生していた。

図2　問題のGCグラフ

　Full GC（グラフ内では、黒い縦線）後もヒープサイズが減ることもなく、上昇を続けている以上、もはやメモリリーク以外に疑う必要はないだろう。

編集部注：Full GCについて詳しく知りたい読者は、連載第2回をご参照ください。

　このときは、どんな困難なメモリリークでも原因は解明できるだろうと思っていた。

1-2-3

Index
第9回　JavaのGC頻度に惑わされた年末年始の苦いメモリ
	Page1 【第1話】「大みそかだというのに……」 【第2話】“現場”での聞き込みが大事
	Page2 【第3話】伝家の宝刀にご登場願おう 【第4話】「再現していません!!」
	Page3 【第5話】犯人はお前だ！ Finalizer!! 【第6話】GCのやっていることは全部お見通しだ！ 【注意！】Finalizerが引き起こす3つのトラブル 【最後に】「先入観」「思い込み」「事実と推測を混同」

Java Solution全記事一覧

＠ITメールマガジン　新着情報やスタッフのコラムがメールで届きます（無料）