2014-04-19

Amazon EC2 の Amazon Linux インスタンスで、 Mule ESB 3.4.0 を動かしていたら、でくわしたメモリリーク。

原因は、OpenJDK 1.6.0_30。
ソケットの finalizer まわりにバグがあるみたい。

1.7.0_55 に変えたら、あっさり解消した。

障害の発生

Mule ESB が突然、再起動。
JVM の応答を監視しているラッパーが 30秒タイムアウトを検知して、強制的に Mule ESB を再起動した。

GCログ

手がかりが少なく、困っていた。
知人から、メモリリークの疑いと、GCログの取得するようにアドバイスがあった。

Mule ESB では、conf ファイルに以下を設定。

#
wrapper.java.additional.4=-verbose:gc
wrapper.java.additional.5=-XX:+PrintGCTimeStamps
wrapper.java.additional.6=-XX:+PrintGCDetails

※番号に注意。連番であること。

これで、メモリーリークが起きていること、３日間くらい稼働すると、Full GC が始まり、かつ、Tenured (old) 領域が、上限に張り付いたまま、メモリが解放されない現象を確認。

再現できなかった

しかし、テスト環境ではどうやっても再現しない。
できるだけ本番環境に近づけようと、いろいろテスト環境をいじってみた。

ここに相当時間を取られた。

再現した

データベースを、テスト環境では、Mule ESB と同じサーバーにインストールしていた。

これを本番環境と同じ RDS ( PostgreSQL 9.3.3 ) に変更した。

みごとに再現した。

アプリケーションのオブジェクトの生成や後始末をいろいろやってみる

問題が起きる時間に走るアプリケーションのオブジェクトの生成や後始末をいろいろ変えてみたがメモリリークは解消しない。

Amazon EC2 の　Amazon Linux インスタンスでは、デフォルトの JDK が、 1.6.0_30 で、そのままだったことに、ここで気が付く。

JDK のバージョンアップ

yum と alternatives コマンドは、ほんと楽ちん。
yum で 1.7 をインストールし、alternatives で、1.6 と 1.7 を切り替えながら、再現テスト。

見事に、 1.6 ではメモリリーク。1.7 では、リークなし。

一件、落着。

PostgreSQL のローカル接続がひとつの落とし穴だった

ローカルに接続する場合は、Unix ドメインソケット（ローカルなプロセス間通信）、別サーバー上のＤＢに接続する場合は、TCP/IPソケット（ネットワークソケット）。

OpenJDK 1.6.0_30 で発生したメモリーリークは、この、TCP/IPソケットのファイナライズに問題があるらしい。

教訓

テスト環境でも、RDS にするなど、もっと本番環境に近づけておくべきだった
メモリの状態をもっと確認すべきだった（本番環境とテスト環境で、top コマンド使うだけで、簡単に違いを発見できた）

開発日記