今回の概要 本稿ではWebアプリケーションの開発プロジェクトで実際に直面したメモリに関するトラブル事例の中からjava.lang.OutOfMemoryErrorを題材としたTipsを紹介する。



帰宅直前に、突然電話が鳴り響く

業務を終えて帰宅しようとしたとある夜、突然電話が鳴る。相手は社内のプロジェクトのマネージャである。

「現在、テストを実施しているが、数分経つとOutOfMemoryErrorが発生してアプリケーションが落ちてしまう。再起動を掛けると、また順調に動くが、しばらく利用していると、同じようにOutOfMemoryErrorが発生する。メモリ不足のエラーなので、物理メモリを増やそうかと思っているが、物理メモリ増設の前に、アプリケーションという観点からメモリ不足を引き起こす問題がないか調査してほしい」

取りあえず、原因を探るために現場に急行した。

現場にてトラブルの詳細をヒアリング

現場に到着し、まずは現状分析のため、担当者に簡単にヒアリングを行った。ヒアリングした結果をまとめると、電話で得られた情報に加えて以下のような状況であった。

OutOfMemoryError発生時に実行していた業務処理は毎回同じ

問題となっている業務処理は単体テスト時には快適に動作していた

ほかの業務処理は問題なく動作している

7つ道具でGCログ解析を実施

大体の状況は把握したので、早速Webアプリの問題点を「見える化」する7つ道具を利用し、トラブル切り分けフローに従い、調査を開始した。

フローに従って作業を進めようとしたところ、JavaVMに設定されたヒープ領域がデフォルト値であることに気が付いた。さすがに、これではメモリ不足が起きてしまうとにらんだが、事象の再現も兼ねて、デフォルト値のまま問題となっている業務処理に対して、多数のリクエストを投げてみた。すると予想どおり、あっさりOutOfMemoryErrorでアプリケーションが落ちてしまった。

そこで、ヒープ領域を1GByteに変更し、再度同じ負荷を掛けてみると、今度は十数分たってからOutOfMemoryErrorが発生した。GCログ（図2）を確認してみると、GCが発生しても、ヒープ領域のメモリ使用量（青線）が右肩上がりに増大しており、メモリが開放されていないことが分かった。

そこで、GC対象外となっているオブジェクトを探すため、HPROFを利用してオブジェクトプロファイリングを実施してみることにした（HPROFについて詳しく知りたい読者は、「HPROF プロファイラエージェント」をご参照ください）。

図2 改善前のGCログ （画像をクリックすると拡大します）

オブジェクトプロファイリングの実施

オブジェクトプロファイリングを実施した結果、リスト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のように測定された。

図3 改善後のGCログ （画像をクリックすると拡大します）

リスト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スコープで保持していたため、取得したデータ数が少ないと、問題は顕在化しにくい。

1|2 次のページへ