Subscribed unsubscribe Subscribe Subscribe

HashMapでOutOfMemoryErrorが発生するケース

Java

HashMapの同期化をしていないと無限ループになるという話はこことかここで説明されているのでかなり有名かと思います。

今回不運にも遭遇したのは、同期化をしていなくてOutOfMemoryError(以下、OOM)が起きてしまうというケース。かなり特殊かもしれないですが、同じ問題で悩む人が今後いればと思い、記録しておきます。

再現方法

早速再現方法を。以下のようなコードを実行すると、たまにOOMが起きてしまいます。HashMapに異なるデータをputをし続けてデータが増加し続けるという単純なリークではありませんよ!
ここで行っていることは、

  • HashMapにデータを追加(キーは0-3000までのランダムな数字)するスレッド×2
  • 追加されたデータを全て削除するスレッド×1

を同時に実行しているだけです。キーは0-3000で固定なので、どんどんHashMapの中身が増加し続けるということはありません。

import java.util.HashMap;
import java.util.Map;
import java.util.Random;

public class HashMapTest {

	public static void main(String[] args) {

		final Map<Integer, Object> target = new HashMap<Integer, Object>();

		Runnable r1 = new Runnable() {

			@Override
			public void run() {
				while (true) {
					Random ran = new Random();
					int nextInt = ran.nextInt(3000);
					target.put(new Integer(nextInt), nextInt);
				}
			}
		};

		Runnable r2 = new Runnable() {

			@Override
			public void run() {
				while (true) {
					try {
						Integer[] all = new Integer[3000];
						target.keySet().toArray(all);

						for (Integer key : all) {
							target.remove(key);
						}

					} catch (Exception e) {
					} catch (Error e) {
						e.printStackTrace();
					}
				}
			}
		};

		Thread t1 = new Thread(r1);
		Thread t2 = new Thread(r1);
		Thread t3 = new Thread(r2);

		t1.start();
		t2.start();
		t3.start();
	}
}

問題はどこか?

根本的な問題はHashMapを同期化していないことなのですが、なぜOOMが起きているのか一見謎です。OOM発生時のスタックトレースは以下のような内容で、HashMap.keySet().toArray()の内部で配列のコピー時に大量にメモリを消費しOOMになってそう...という風に読めます。しかし、この配列はHashMapのキーなので最大でも3000個しかないはずだが…?

java.lang.OutOfMemoryError: Java heap space
	at java.lang.reflect.Array.newArray(Native Method)
	at java.lang.reflect.Array.newInstance(Array.java:52)
	at java.util.Arrays.copyOf(Arrays.java:2760)
	at java.util.Arrays.copyOf(Arrays.java:2734)
	at java.util.AbstractCollection.finishToArray(AbstractCollection.java:198)
	at java.util.AbstractCollection.toArray(AbstractCollection.java:173)
	at HashMapTest$2.run(HashMapTest.java:31)
	at java.lang.Thread.run(Thread.java:680)

ヒープの状態を見てみる

OOMに遭遇した場合は、VM再起動の前にヒープの情報を取得しておくのが鉄則です*1
そこでjmap -histoでクラスヒストグラムを出して調べてみます。jpsコマンドでjavaプロセスIDを調べてから、jmap -histo で各クラスのインスタンス数とそのバイト数をチェックすることができます。

$ jps
2167 
3134 Jps
3133 HashMapTest

$ jmap -histo 3133

 num     #instances         #bytes  class name
----------------------------------------------
   1:             4       63879760  [Ljava.lang.Integer;
   2:          8123        1110360  <methodKlass>
   3:          8123        1067064  <constMethodKlass>
   4:           599         695336  <constantPoolKlass>
   5:         13228         664376  <symbolKlass>
   6:           574         487472  <constantPoolCacheKlass>
   7:           599         437112  <instanceKlassKlass>
   8:          1408         414488  [I
   9:          2573         232040  [C
  10:           817         130224  [B

結果、なんとjava.lang.Integerの配列が約63MBと巨大になっていることがわかりました。
HashMap.keySet().toArray(all)で引数で渡しているオブジェクトもInteger配列です。やはりここがOOMの発生元のようです。しかし、引数で渡している配列がなぜヒープに残り続けているのかこれだけでは不明です。

実は無限ループの副作用?

ここからはJavaのクラスライブラリのソースを追うしかありません。HashMapのソースをデバッガで追っていくと、HashMap.keySet().toArray()の奥で呼ばれるjava.util.AbstractCollection#finishToArray(T[] r, Iterator it)がどうも怪しいです。while (it.hasNext()) でHashMap#size()以上の数でもガンガンループを繰り返している様子。そうなると、newCapには現在の配列数の1.5倍の値が入ります。
このnewCapはArrays.copyOf(r, newCap);で渡されています。つまり、無限ループが内部で発生し、配列のサイズが1.5倍ずつ拡張され続ける
という現象が内部で起こっているようです。無限ループで1.5倍ずつ拡張されているため、ヒストグラムを取得すると配列のサイズがヒープ内に残っているように見えたわけですね。

    private static <T> T[] finishToArray(T[] r, Iterator<?> it) {
	int i = r.length;
        while (it.hasNext()) {
            int cap = r.length;
            if (i == cap) {
                int newCap = ((cap / 2) + 1) * 3;
                if (newCap <= cap) { // integer overflow
		    if (cap == Integer.MAX_VALUE)
			throw new OutOfMemoryError
			    ("Required array size too large");
		    newCap = Integer.MAX_VALUE;
		}
		r = Arrays.copyOf(r, newCap);

そもそもCPU100%になっていて無限ループ問題に気づくのでは?

最近のサーバだとCPUはマルチコアがほとんどです。その場合、今回のように1スレッドだけ無限ループだとCPUが100%に張り付く現象にはなりません。特にすでにサービス提供中の環境だと実際の処理も混じってくるので、単にアクセス数が多いように見えなくて気づかないというものあります。
問題の検知を早めるには、エラーログの監視が有効です。実際のプロジェクトでも、java.util.ConcurrentModificationExceptionが事前に発生していました。この例外を検知したなら、HashMapの同期漏れを疑ったほうがいいです。放っておくと無限ループやOOMに陥る可能性があります。

解決方法

一応解決方法を書いておくと、HashMapをきちんと同期化することです。例えば、再現コードのnew HashMapをnew ConcurrentHashMapにすればOKです。

まとめ

  • HashMap.keySet().toArray()を使用している場合、同期化をミスるとOOMが発生するケースがあります。
  • OOMが起きても慌てずに落ち着いてヒープの情報を取得しましょう。再現性が低い場合はチャンスを逃さないように!
  • エラーログはちゃんと監視すること!サインはどこかで現れています。ConcurrentModificationExceptionがあれば危険信号。

*1:メモリに関するトラブルシュートは[http://samuraism.jp/diary/2008/11/03/1225722480000.html:title]がオススメです