はじめに
JVMの基礎知識についてはこちらの記事で紹介した。
【JVM】OOM(Out Of Memory)障害対応のための必要な知識
これから具体的なOOMの解決方法について触れていく。
アウトプット編
ここからは実際にOOMの問題にぶち当たっ時に、解決するためのアクションを学んで行くことにする。
ここでは具体的に使えるツールの紹介なども行って行く。（使い方はリンクを貼ってあるのでそちらを参照）
今回対応した問題の詳しい事象
今回起きていた問題の事象をまとめると、
javaのプロセスが週に1度落ちると言う事象だった。
sarコマンドでメモリ使用率を確認してみたところ、落ちる直前に100%付近まで使用されていた。
JVMのクラッシュログにはOOMと言う文言が記載されていた。
以下では調査方針や調査方法、注意する点など多くをまとめているが、
私が調査しているときは、調査方法もよくわからず、大事な情報を見逃していたり、
誤ったデータを変に解釈していたりした。
なのでここに記載するやり調査方法は、現状の私が考えるベストな方法だ。
※ もっとこうするべきなど詳しい方がいましたらご指摘ください。
調査の方針
以下の順番で調査をして行くといいかもしれない。
1.hs_err_.logを確認し問題の切り分け（ここでかなり絞れる）
2.gcログからヒープの状況を確認
3.Javaヒープに問題があるなら、ヒープダンプから問題を特定
4.非ヒープに問題があるなら、スレッド数から問題を特定
5.上記以外の理由でメモリ使用率が上がっているならOOM Killerを疑う
最初に行っておくと、OOMの問題に対応する際は、非線形的に問題が絡み合っていたりするので、
冷静に仮説を立てて地道に検証して行く鋼のメンタルが必要だ。
1.hs_err_.logを確認し問題の切り分け（ここでかなり絞れる）
このログを見る事でOOMの問題をだいぶ絞ることが出来る。
その後に仮説検証を繰り返して行くことで、原因にたどり着くスピードも格段に早くなると思うので、
一番注意して確認してほしい。（私は最初その事を知らずに戦ってました）
ちなみにこのログはJVMがクラッシュした時に出力されるログである。
JVMの起動オプションに何も設定しないと、カレントディレクトリに出力される仕様になっている。
出力先を指定したい場合は、以下の起動オプションを設定する事で決定できる。
java -XX:ErrorFile=/var/log/java/java_error%p.log
hs_err_.logを読み解く
それではhs_err_.logを読んで問題を特定して行く。
logファイルの中身を開くと以下のような記述がある。
その記述によって問題をある程度絞ることが出来るので参考にしてほしい。
・ Javaヒープに問題がある
Exception in thread "main": java.lang.OutOfMemoryError: Java heap space
Java heap space indicates that an object could not be allocated in the Java heap
とある。javaヒープ領域にオブジェクトを割り当てることが出来なかったよ！と言う解釈でいい
つまり、javaヒープ領域の容量が少ない。→容量を増やせば問題が解決される。
the message might be an indication that the application is unintentionally holding references to objects
ともある。あるオブジェクトがずっと参照されていて、GC削除対象にならずにメモリが徐々になくなっているよ！と言う解釈でいい
つまり、これはメモリリークのこと
→ ヒープダンプを取得し、徐々に増えているオブジェクトを特定し、ソースを回収する事で問題が解決される。
以下の3.Javaヒープに問題があるなら、ヒープダンプから問題を特定を参照
・ Permanentヒープに問題がある
Exception in thread "main": java.lang.OutOfMemoryError: PermGen space
PermGen space indicates that the permanent generation is full.
とある。Permanent領域が足りないとよ！と言う解釈でいい
つまり、-XX:MaxPermSize optionなどで十分な領域を確保してあげる必要がある。
また、staticな変数や、最初にクラスローダーにロードされるクラスがこの領域に格納される。
・ Javaヒープに問題がある。
Exception in thread "main": java.lang.OutOfMemoryError: Requested array size exceeds VM limit
Requested array size exceeds VM limit indicates that the application (or APIs used by that application) attempted to allocate an array that is larger than the heap size.
とある。配列をJavaヒープ領域に割り当てられなかったよ！という解釈でいい
つまり、javaヒープ領域の容量が少ない。→容量を増やせば問題が解決される。
もしくは、ヒープダンプを取得し、徐々に増えているオブジェクトを特定し、ソースを回収する事で問題が解決される。
以下の3.Javaヒープに問題があるなら、ヒープダンプから問題を特定を参照
・ Cヒープに問題がある
Exception in thread "main": java.lang.OutOfMemoryError: request <size> bytes for <reason>. Out of swap space?
the HotSpot VM code reports this apparent exception when an allocation from the native heap failed and the native heap might be close to exhaustion.
とある。メモリがネイティブヒープ（Cヒープ）に割り当てられなかったよ！とい解釈でいい
ちなみに私が対応したのはこの問題でした。
この問題に当たった時は、基本的にスレッド数に原因があるとみていい。
なので4.非ヒープに問題があるなら、スレッド数から問題を特定を参照
詳しくは以下のサイトが参考になる。
※ 最近になって思ったが、あるツールで問題起きてるなら、ネット記事ではなくその仕様書を読んだ方がいい
英語なので読むのに時間がかかるかも知れないが有益な情報が得られる。
https://docs.oracle.com/javase/7/docs/webnotes/tsg/TSG-VM/html/memleaks.html
ここまでの情報で、ある程度問題が絞れたと思う。
ここからその問題を仮説から事実へと転換していく。
2.gcログからヒープの状況を確認
インプット編にも記載したが、-verbose:gcを起動オプションに設定する事で、
gcログは取得できる。
このログを見れば、マイナーGCやメジャーGCが走った結果どのようにヒープ領域が変動しているかがわかる。
可視化して見るにはGCViewerがとても役に立つ。
ツールの使用方法や見方はこちらの記事が役に立つ
https://qiita.com/i_matsui/items/aabbdaa169c6ae51ecb3
3.Javaヒープに問題があるなら、ヒープダンプから問題を特定
Memory Analyzerを使ってヒープダンプの結果を可視化し比較する事で、
本当にJavaヒープに問題があるかわかってくる。
Memory Analyzerの使い方などは以下の記事がとても役に立つ。
※ 記事というか仕様書？
https://www.ibm.com/developerworks/community/wikis/home?lang=ja#!/wiki/PD%20Professional/page/5.%20Memory%20Analyzer%E3%82%92%E4%BD%BF%E7%94%A8%E3%81%97%E3%81%9Fheapdump%E8%A7%A3%E6%9E%90%E6%96%B9%E6%B3%95
具体的な方法は、
・ヒープダンプを取得する。（インプット編に記載した）
※ 実行時、1時間後、2時間後など経過がわかるようにヒープダンプを取得すると比較しやすい
※ また落ちた時のヒープダンプがあるなら最後にメモリを多く使用していたオブジェクトがわかる
・基本的に検証環境でのヒープダンプなのでscpでヒープダンプをローカルへ
・Memory Analyzerでヒープダンプを読み込み
・Dominator Treeを確認し、使用率が高いオブジェクトを確認。
※ Retained Heapという欄がヒープに使用している大きさなので、ここが多くなっていくほど、
Javaヒープの領域が減っていくという事である。
どのオブジェクトが問題かわかったらソースを改修していく。
ただヒープ領域が足りないなら増やせば良い。
4.非ヒープに問題があるなら、スレッド数から問題を特定
スレッドダンプを比較をすることで、スレッド数の比較ができる。
# pid確認
jcmd -l
# スレッドダンプを取得
jstack <pid> > threaddump.txt
また、jconsoleを使うことで、スレッド数の推移を可視化できるので、
時間に比例してスレッドが増えているのかなどがわかる。
使ったことはないが、こちらもすごく便利そうなので紹介しておく。
https://github.com/irockel/tda
以下のコマンドでスレッド数とメモリ使用率がわかるので、時間の経過と共に増えているかが比較できる。
ps auxww -L | grep -e java -e PID | grep -v grep
こちらの記事を参考にした。
http://d.hatena.ne.jp/rx7/20101219/p1
お願い：もっと他にいいやり方があると思っています。知っている方は教えてください。
5.上記以外の理由でメモリ使用率が上がっているならOOM Killerを疑う
Linuxの仕様 ~キャッシュ~
Linuxの思想の一つに空いているメモリを積極的に使用する仕組みがある。
これの厄介なところは、psコマンドで表示されない。
例えば、ps aux でプロセスのメモリー使用率を見ると、javaのプロセスが、30%メモリを使っている。
しかし、sar -r 1 でメモリ全体の使用率を見ると、90%程度にいっていたりする。
※ sarコマンドの見方をしっかり理解していれば、簡単に気づくことができる。
https://it.alohakeakua.net/?p=104
この状況が起きている場合は、キャッシュに使われている可能性が高い。
ちなみに私の時もページキャッシュにメモリが60%程度も使用されていた。
# ページキャッシュをすべて削除
# echo 1 > /proc/sys/vm/drop_caches
上記の方法でページキャッシュを削除できるが、必要なキャッシュも削除してしまうので微妙。
最悪、cronで定期実行すれば、ページキャッシュにメモリが使われる問題は解決される。
もちろんなぜページキャッシュがされるかの原因調査もするべきだ。
大量にログ出力（I/Oが発生）しているところなど疑えば良い。
以下の記事が参考になる
https://tech.mercari.com/entry/2015/07/16/170310
Linuxの仕様 ~OOM Killer~
そう。Linuxには殺人鬼が潜んでいる。
Linuxにはメモリーの容量が足りなくなってくると、panicを起こさないために、
メモリを使用しているプロセスを強制的にkillするという仕様がある。
OOM killerによってプロセスをkillした場合は、以下のファイルにどのプロセスをkillしたか出力される。
less /var/log/messages
02:53:58 xxxxx1 kernel: Out of memory: Killed process 28036, UID 80, (xmllint).
また、JVMがクラッシュした時にでるログ、hs_err_.logのpidと、
/var/log/messages配下にkillしたpidが一致していたら、OOM Killerによってkillされたことがわかる。
以下の記事が参考になる。
https://blog.ybbo.net/2013/07/10/oom-killer%E3%81%AB%E3%81%A4%E3%81%84%E3%81%A6/
調査の際に注意する事
・ローカル環境と検証環境など環境差異があると再現などできないことがある。
LinuxなどOSの違いによって、挙動も変わってくる
(javaのプロセス以外に問題がある可能性があるから)
・バッチ処理のヒープダンプを取得する時は、タイミングに気をつける。
例えば、定期的に実行されるjavaプロセスのヒープダンプを負荷が高い時にとると、
もちろんオブジェクトの数も多くうまく比較ができない。
なので比較する際は、同じ状態・条件でヒープダンプを取得し、比較するべき。
・仮説や方針のない調査をしない
これが一番大事なことだと思う。
調べていくうちに、気になっていろんなところを調べたり、グラフをなんか眺めていたりする。
ほぼ無意味なのでやめたほうがいい。私はたまにしてしまう。
まとめ
OOMの問題が起きた際の具体的な問題のみき分け方と、解決方法についてまとめた。
私と同じようにOOMの問題に苦しんでいる人の役に立ってもらえれば嬉しい。
また、私も調べたことをまとめただけなので、ここで紹介した以外の方法や、
視点はもっとあると思う。知っているならぜひ教えて欲しい。