OutOfMemoryエラー発生!? GCがあるのに、なぜ？：現場から学ぶWebアプリ開発のトラブルハック（5）（1/2 ページ）
本連載は、現場でのエンジニアの経験から得られた、APサーバをベースとしたWebアプリ開発における注意点やノウハウについて解説するハック集である。現在起きているトラブルの解決や、今後の開発の参考として大いに活用していただきたい。（編集部）
今回の概要
本稿ではWebアプリケーションの開発プロジェクトで実際に直面したメモリに関するトラブル事例の中からjava.lang.OutOfMemoryErrorを題材としたTipsを紹介する。
帰宅直前に、突然電話が鳴り響く
業務を終えて帰宅しようとしたとある夜、突然電話が鳴る。相手は社内のプロジェクトのマネージャである。
「現在、テストを実施しているが、数分経つとOutOfMemoryErrorが発生してアプリケーションが落ちてしまう。再起動を掛けると、また順調に動くが、しばらく利用していると、同じようにOutOfMemoryErrorが発生する。メモリ不足のエラーなので、物理メモリを増やそうかと思っているが、物理メモリ増設の前に、アプリケーションという観点からメモリ不足を引き起こす問題がないか調査してほしい」
取りあえず、原因を探るために現場に急行した。
現場にてトラブルの詳細をヒアリング
現場に到着し、まずは現状分析のため、担当者に簡単にヒアリングを行った。ヒアリングした結果をまとめると、電話で得られた情報に加えて以下のような状況であった。
- OutOfMemoryError発生時に実行していた業務処理は毎回同じ
- 問題となっている業務処理は単体テスト時には快適に動作していた
- ほかの業務処理は問題なく動作している
7つ道具でGCログ解析を実施
大体の状況は把握したので、早速Webアプリの問題点を「見える化」する7つ道具を利用し、トラブル切り分けフローに従い、調査を開始した。
図1 トラブル切り分けフロー（フローに従って作業を進めようとしたところ、JavaVMに設定されたヒープ領域がデフォルト値であることに気が付いた。さすがに、これではメモリ不足が起きてしまうとにらんだが、事象の再現も兼ねて、デフォルト値のまま問題となっている業務処理に対して、多数のリクエストを投げてみた。すると予想どおり、あっさりOutOfMemoryErrorでアプリケーションが落ちてしまった。
そこで、ヒープ領域を1GByteに変更し、再度同じ負荷を掛けてみると、今度は十数分たってからOutOfMemoryErrorが発生した。GCログ（図2）を確認してみると、GCが発生しても、ヒープ領域のメモリ使用量（青線）が右肩上がりに増大しており、メモリが開放されていないことが分かった。
そこで、GC対象外となっているオブジェクトを探すため、HPROFを利用してオブジェクトプロファイリングを実施してみることにした（HPROFについて詳しく知りたい読者は、「HPROF プロファイラエージェント」をご参照ください）。
オブジェクトプロファイリングの実施
オブジェクトプロファイリングを実施した結果、リスト1のような結果が測定された（データは本稿のために作り直しています）。
| リスト1 改善前のオブジェクトプロファイリング結果（抜粋） |
percent live alloc'ed stack class
rank self accum bytes objs bytes objs trace name
1 33.06% 33.06% 32447816 811476 41182264 1353842 300133 char[]
2 26.41% 59.48% 25920000 1080000 38880000 1620000 315587 java.lang.String
3 12.84% 72.32% 12604768 555637 36750240 1620000 315539 byte[]
4 11.01% 83.33% 10800000 270000 10800000 270000 315579 jp.co.atmarkit.sample.model.User
5 4.39% 87.72% 4311360 269460 73627592 1622088 315374 char[]
|
オブジェクトプロファイリングした結果を確認してみると、Userオブジェクトは、オブジェクトに割り当てられたメモリ量(alloc'ed bytes／objs)と生存しているメモリ量（live bytes／objs）が一致しており、Userオブジェクトに対して、まったくGCが働いていないことが分かった。
そこで、問題となっている業務のソースコードを確認してみると、DBから取得したデータをHttpSessionにUserオブジェクトとして格納していた。セッションタイムアウトになる前であったため、GCがまったく働いていなかったのであろう。
このオブジェクトのスコープについて担当者に確認をしてみると、sessionスコープで扱う必要がないものであったため、requestスコープで取り扱うように修正し、その効果を確認した。
ソースコードを修正し、結果の確認
ソースコードを修正し、再測定したところ、OutOfMemoryErrorが発生しなくなり、一件落着となった。GCログは図3、オブジェクトプロファイリングはリスト2のように測定された。
| リスト2 改善後のオブジェクトプロファイリング結果（抜粋） |
percent live alloc'ed stack class
rank self accum bytes objs bytes objs trace name
1 7.19% 7.19% 1696184 42369 110282864 3627782 300133 char[]
2 5.70% 12.89% 1344000 56000 104256000 4344000 315530 java.lang.String
3 4.83% 17.72% 1139352 1410 584385000 723120 315732 char[]
4 3.97% 21.70% 937448 8471 480176632 4338737 315728 char[]
5 3.74% 25.43% 881608 8477 451229064 4338741 315712 char[]
6 2.43% 27.87% 574048 180 574048 180 316239 char[]
7 2.40% 30.27% 565600 2828 289538000 1447690 315730 char[]
8 2.37% 32.64% 560000 14000 28960000 724000 315522 jp.co.atmarkit.sample.model.User
|
オブジェクトに割り当てられたメモリ量（alloc'ed bytes/objs）と生存しているメモリ量（live bytes/objs）を見る限り、Userオブジェクトに対してGCが働いており、メモリリークが解消されている。
担当者に確認してみると、単体テスト時にOutOfMemoryErrorが発生しなかったのは、テスト実施時にDBに投入されていたデータ数が少なかったからのようである。検索結果のデータ数の見積もりをしていなかったため、テスト時のデータ量が少なく、問題が出ていなかったようだ。
今回の場合、DBから取得したデータをそのままsessionスコープで保持していたため、取得したデータ数が少ないと、問題は顕在化しにくい。
Copyright © ITmedia, Inc. All Rights Reserved.
注目のテーマ
ITmediaはアイティメディア株式会社の登録商標です。