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

肥え続けるTomcatと
胃を痛めるトラブルハッカー

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

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

今回の主な内容

知っているか？ メモリリークの本当の“恐怖”を 1カ月間かけて肥え続けるTomcatのヒープサイズ PrintClassHistogramオプションで、迷宮入りを防げ!! ObjectNameの上昇！ まさかのメモリリーク mod_jkのオプション1つでメモリリークが発生していた現実 PrintClassHistogramオプションの使いどころと注意点

　メモリリークと聞いて、良いイメージを思い浮かべる開発者は少ないだろう。経験したことのある人にとっては、思い出したくない過去の記憶がよみがえるかもしれない。もしかしたら、その単語を聞くだけで胃が痛くなる人もいるかもしれない。筆者もかつてはその1人であった。

　　前々回の記事では、WebサーバとTomcatの間の接続において、スレッド数の不整合により発生したトラブル事例を、前回はTomcatとDBサーバの間のトラブル事例を紹介した。今回もTomcat上で起きたトラブルの事例で、聞くだけでも嫌なメモリリークの解析を単純なパズルで解けるようにしてくれるJavaVMのオプション、-XX:+PrintClassHistogramを紹介する。

知っているか？ メモリリークの本当の“恐怖”を

　長時間システムを稼働し続けると、思わぬトラブルが発生することがある。代表的なものとしてメモリリークが挙げられる。システム内でメモリリークが発生していたとしても、一見しただけでは正常に動作しているように見えてしまい、見過ごしているかもしれない。しかし、その裏では徐々にメモリが消費され、気が付いたときにはメモリ不足により、システムが停止へと追い込まれる。

■ どうです？ 胃が痛くなってきませんか？

　中でも、長期間連続稼働して初めて現象として表れるメモリリークは、本当に厄介なケースだ。さまざまな政治的・技術的な理由により、再起動による回避という運用対処ができない場合、メモリリークを直すしか手段がない。その場合を想像してみてほしい。

1. まずは再現させないと。どれくらい運転すれば再現するのだろう？
2. 1週間動かしてみたけど、この状況は再現しているのかなあ……
3. もう3回目の再現試験だ。今度こそ再現してくれ！
4. ダメだ！ そもそも再現のための前提が間違っているのか!?
5. 何とかそれっぽい事象が起きたけど、当時の状況証拠が足りなくて結局再現したか判断できないよ……
6. 取りあえず、それっぽく直してみた。多分、これで大丈夫だよな？
7. 事象再発。どうやら、違うところを直していたらしい……
   （1ヘモドル）

　確かに、この状況は極端な例かもしれない。しかし、トラブルに対応する前に、こうならないという予測を、誰が立てられるだろうか。今回のトラブルハックでは、まさにこの状況が起きかけていた現場をひっくり返した逆転満塁ホームランの事例とその解析方法を紹介する。

1カ月間かけて肥え続けるTomcatのヒープサイズ

■ トラブルの電話って早朝に鳴るものですよね

　早朝に電話が鳴ると、大抵トラブル発生の連絡だ。その日も、とあるプロジェクトのマネージャから早朝に電話がかかってきた。電話の向こうでは、「メモリリーク！」「サービス停止!!」「●×☆仝＆々仝!?」との怒号が飛び交っている。とにもかくにも、状況確認も含めて、現場へ急行することにした。

　現場に到着し、担当者から状況を伺うと、次の情報を得られた。

• システム再起動によりサービスを再開した
• システム構成は、Apache・Tomcat・PostgreSQL構成である。Javaは1.4.2、Tomcatは5.0系を利用している
• 一次解析により、メモリリークが発生している可能性が高い
• しばらくは運用対処で乗り切るが、お客さまが本格対処を望まれている

　素晴らしいことに、すでにトラブル切り分けフローに従い、メモリリークが発生しているところまで突き止めていた。

■ 思わず本音が

　実際にGCログをGCViewerで視覚化した結果を確認すると、確かにメモリリークが発生していた。だが、そこには想像したくない目も覆いたくなるような世界が広がっていた。

編集部注：GCViewerについて詳しく知りたい読者は、連載第1回の 「その4：GCログ解析ツール」をご参照ください。

　まずは、GCログを見てほしい。

図1　1カ月かけて上昇するヒープサイズのGCViewr図（1）（画像をクリックすると拡大します）

図2　1カ月かけて上昇するヒープサイズのGCViewr図（2）（画像をクリックすると拡大します）

図3　1カ月かけて上昇するヒープサイズのGCViewr図（3）（画像をクリックすると拡大します）

図4　1カ月かけて上昇するヒープサイズのGCViewr図（4）（画像をクリックすると拡大します）

　ここで注目してほしいものは、横軸、すなわち起動時間だ。見えにくいかもしれないが、そこに記されていたものは、なんと25D、すなわち25日である。このグラフを確認した瞬間、「運用対処で逃げ続けたいですね」と思わず本音が漏れてしまった。

■ 作戦会議

　さて、この時点で取るべき作戦はいくつかある。それを簡単にまとめてみた。

表 取るべき作戦
作戦名	メリット	デメリット
試験環境で再現するまでガンバルぞ〜	・商用サービスに影響を与えることがないため、さまざまな情報取得・解析用ツールの導入や検証・試験を行える ・再現方法が明確である場合、高い負荷を掛け続けるなど、期間を短縮して再現させることができる	・再現方法が不明確の場合、再現したか否かの判断が難しく、また再現までの期間が見積もれずに、検証が長期化する恐れがある ・本番環境と同程度の環境でない場合、再現させることができない可能性がある
本番環境でトラップを仕掛けて再現を待つぞ〜	・再現方法が不明確でも、確実に前回事象発生時と同じ程度の期間で再現させることができる	・サービスに影響を与えるような大きな変更を加えることができないため、再現しても解析に必要な情報を取得できない場合がある

　試験環境での再現が王道だろう。25日かけて状況が悪化していたとはいえ、25日も再現に費やす必要はない。実際は、2〜3日程度連続運転すれば、事象は見えるだろう。しかし、現時点ではハッキリとした再現方法がなかった。

　もし再現に失敗すれば……。その恐怖を抑えつつ、プロジェクト側と再現試験の段取りを始めた。

■ 何度も失敗する再現試験。そして漂う絶望感

　再現試験の実施をプロジェクト側に任せ、しばらくは自席でリモートで解析する日々が続いた。そして、プロジェクトメンバから日々聞かされる再現失敗という報告に、頭を悩ませた。

　連続運転の末に発生したメモリリークであり、これまでのトラブルハックの経験から、リクエスト処理を契機にメモリリーク発生していると考えていた。しかし試験環境では、いくら高い負荷を掛けても、メモリリークが再現しなかったのだ。

　再現しなければ解析は始まらない。だが、再現させることができない。試験期間が足りないのか、負荷が足りないのか。現場からの報告も、日に日に覇気がなくなってきていた……。

1-2-3

Index
第8回　肥え続けるTomcatと胃を痛めるトラブルハッカー
	Page1 知っているか？ メモリリークの本当の“恐怖”を 1カ月間かけて肥え続けるTomcatのヒープサイズ
	Page2 PrintClassHistogramオプションで、迷宮入りを防げ!! ObjectNameの上昇！ まさかのメモリリーク
	Page3 mod_jkのオプション1つでメモリリークが発生していた現実 PrintClassHistogramオプションの使いどころと注意点

Java Solution全記事一覧

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