Hatena::ブログ(Diary)

sardineの日記

アーカイブ
過去日記一覧 | カテゴリ別: ネット - プログラム - PC - 携帯電話 - ツール - FINAL FANTASY XI - はてな
 | 

2012-12-16 java.util.logging のバグに見る WeakReference 使用時の注意点

[] Java: java.util.logging のバグに見る WeakReference 使用時の注意点

Java の標準 API でよく知られている注意点のひとつに、「WeakReference 自体は強参照されるのでメモリリークしないように注意せよ」というのがある。

知っている人にとっては昔から既知の話題なんだけど、知らないと罠にはまってしまいがちなポイントでもある。

JDK の実装を担当するようなプログラマーであってもはまってしまうくらいなのだから。


WeakReference と注意点

java.lang.ref.WeakReference は、JVM が特別扱いする特殊なオブジェクトだ。もっと正確に言うと、WeakReference クラスのインスタンス変数が JVM で特別扱いされており、そのインスタンス変数だけは、通常の参照とは異なる「弱参照」になる。

通常の参照 (弱参照との対比で強参照とも呼ばれる) の場合、

List<String> list = new List<>();
list.add("レイトン教授");
System.out.println(list.get(0));

これを実行すると、コンソールに "レイトン教授" という文字列が出力される。なぜなら、2 行目で add した String オブジェクトに対する強参照が List に保持されているからだ。さらに、ローカル変数から List オブジェクトへの強参照がある間は、List 自体も回収されることがない。そのため、3 行目を実行する時点で、List から意図通りの String オブジェクトを取り出して、コンソールに出力することが、確実にできる。

対して、次の例のように弱参照では確実とは言えない

WeakReference ref = new WeakReference("成歩堂龍一");
System.out.println(ref.get());

WeakReference は、コンストラクタで渡したオブジェクトへの参照を保持し、get() を呼ぶとその参照を返す。したがって、この場合もコンソールに "成歩堂龍一" という文字列が出そうに見える。しかし、WeakReference が保持するのは常に弱参照なので、1 行目と 2 行目の間で GC が走ると、参照していたオブジェクトは GC で回収されてしまう可能性がある。その場合、get() は null を返すため、コンソールに出力されるのは "null" という文字列になるかもしれない。

以上のように、一見結果が不安定になるだけに見える弱参照だが、使い道はいろいろある。例えば、あるスレッド (java.lang.Thread オブジェクト) に対して何かしらのデータを関連付けたい場合、スレッドをキー、データを値として Map に登録したくなるが、そのままやってしまうと、Thread が強参照された状態となり、Map から明示的に削除するまで GC で回収されなくなってしまう。Thread オブジェクトはリソースを多く消費するので、それは避けたい……という場合に、弱参照を使うことが考えられる。その辺をうまく実装してカプセル化したのが java.util.WeakHashMap であり、また、java.lang.ThreadLocal であるが、詳細については Java SE API リファレンスを参照のこと。

java.util.logging にあったバグ

誤解してはいけないのは、WeakReference からの参照が弱参照となるのであって、WeakReference 自体を GC で回収してよいかどうかの判断は他の一般的なオブジェクトとまったく同じルールで行われる、ということだ。

java.util.logging.Logger は、ログ出力元を表すクラスだ。ツリー構造を持っており、例えば、"ayasato.mayoi" という名前の Logger は "ayasato" という名前の Logger の子になる。これを表現するため、Logger クラスは ArrayList を使って自分の子を保持するようになっている。当初、このインスタンス変数はこんな感じになっていた (実際には当時まだジェネリクスはなかったけど)。

List<Logger> kids = new ArrayList<Logger>();

一見何の問題もないが、実は問題大ありである。JVM に読み込まれたクラスはアンロードされることがあり、その場合 Logger も不要になる。わかりやすいのは、Tomcat 等の Servlet コンテナからアプリを削除した場合で、この場合、不要になったはずの Logger が親の kids に保持されたままになる。世に言うメモリリークというやつだ。

バグとして指摘されたため、当時の Sun は次のように修正した。

List<WeakReference<Logger>> kids = new ArrayList<WeakReference<Logger>>();

ほとんどのクラスでは、Logger を使う場合、次のように static final で宣言しているので、クラスがアンロードされれば kids から WeakReference を経由しての参照だけが残ることになり、Logger も GC で回収できるようになる、というわけだ。

public class Luke implements Future<EnglishGentleman> {
    private static final Logger LOG = LogManager.getLogger("luke");

    // ...
}

ところが、これでもまだ問題があった。これが今回のメインのお題だが、Logger は確かに回収されるようになったものの、インスタンス変数 kids に格納されている WeakReference オブジェクト自体はいつまでたっても回収されないままだったのだ。

最終的には、JDK 6u19 でこの問題も改善され、kids 内の WeakReference が無効 (get() メソッドを呼ぶと null を返す状態) になったら kids から削除するという動作が追加された。

どんな影響があったか

最終的に修正される前のバージョン (JDK 6u18) で実際に起きた例を紹介する。ちょっとややこしいので、うまく説明できるか自信がないが……。

ある通信系ライブラリを使った常駐プログラムを、長期間起動したままにしていたところ、ある日突然 OutOfMemoryError が発生した。詳細なログが残っておらず、JDK 付属のコマンドを使って調べてみたところヒープにはまだ数十 MB の空きがあったため、PermGen 領域の不足や GC に長時間かかったために OutOfMemoryError が投げられたのではないか、とも考えられたが、調査を進めた結果、java.util.logging.Logger にある前述のバグが原因でヒープが不足していたことがわかった。

使用していた通信系ライブラリでは JMX を使用しており、TCP コネクションをそれぞれ別個の MBean として登録・公開する仕様になっていた。つまり、通信開始時に MBean を登録し、通信終了時に登録解除するようになっていて、JConsole 等のツールを使っていつでもコネクションの状態を確認できるようになっていた。

一方、JDK/JRE に含まれている JMX 関連のクラスは内部で java.util.logging.Logger を使用しており、MBean の登録・解除を行う際にもログ出力を行うようになっていたが、その使い方がちょっと変わっていた。Logger のインスタンスを自分で保持せずに、必要になる都度取得する、という書き方になっていたのだ。イメージでいうとこんな感じ。

LogManager.getLogger("javax.management.mbeanserver").debug("MBean が登録されたよ!");

getLogger を呼び出したのが初回の場合、親に当たる "javax.management" の Logger が先に作られ、その後作られた "javax.management.mbeanserver" の Logger が、WeakReference でラップした上で親の kids に追加される。

GC が起きなければ、このロジックがもう一度実行されても、Logger のインスタンスは作成済みなので、そのインスタンスが再利用されて終わる。ところが、途中で GC によって "javax.management.mbeanserver" の Logger が回収されていると、同じ名前の Logger を再度作成される。そして、WeakReference も新しく作った上で、何も考えずに親の kids に add されてしまう。

親の kids には前回作った WeakReference がゴミとして残っているが、かまうことなく kids の 2 個目の要素として追加されてしまうのだ。これが何度も繰り返されると、親の kids には無効な WeakReference が大量に積まれていく。

運の悪いことに、この kids というインスタンス変数は、java.util.ArrayList だった。ArrayList は配列を使って実装された List で、要素が追加されて配列の長さが足りなくなると、約 1.5 倍の長さの新しい配列を作って、古い配列に格納されていた内容を丸ごと移し替える、という方法で容量を増やしていく。要素数が増えていくとこの 1.5 倍というのび自体が馬鹿にならない。

例えば、ある時点で配列の長さが 10 万だったとする。参照型の配列は、まぁだいたい要素 1 あたり 4 バイトなので、長さ 10 万の配列なら 40 万バイト必要である。ここで ArrayList に要素が追加されて容量の拡張が必要になると、長さ 15 万の新しい配列が作成されるわけだが、その瞬間、新旧の配列が同時にヒープ上に存在する。すでに持っている旧の配列とは別に、新しい配列の分 (長さ 15 万 × 4 バイト = 60 万バイト) を確保できなければダメなのだ。僕の環境では、これが原因で、まだヒープに空き容量がありそうに見えるのに、「通信を開始しようとする→MBeanを登録しようとする→ログを出そうとする→親 Logger の kids の容量を増やそうとする→新しい配列を作ろうとして OutOfMemoryError が発生→通信開始失敗」という結果になってしまっていた。

一度失敗すると、以降は同じことの繰り返しとなり、通信を開始しようとするたびに OutOfMemoryError で失敗……。

最終的には、JDK のリリースノートにこの件のバグが載っていることに気付き、バージョンを上げてみたところ、メモリリークは発生しなくなった。

結論

WeakReference の使い方には要注意。プロでさえ間違える。

トラックバック - http://d.hatena.ne.jp/sardine/20121216
 | 
TP 1499229% です!