JBossがおかしい！あなたならどうしますか？
Java Advent Calendar 2011とJBoss Advent Calendar 2011の28日目のエントリです。タイトルはMySQLがおかしい！あなたならどうしますか？ – MySQL Casual Advent Calendar 2011のパクリです。素晴らしいエントリですね。
このエントリでは対象をJBossとJava VMに置き換えてお送りします。
JBossがおかしい！
(略)
まずはserver.log
このファイルがトラブルシューティングの基本になります。WARNかERRORレベルで出力されているものをチェックすれば大抵何が起きているのかはわかります。ほとんどの場合はエラーメッセージや例外メッセージでぐぐるとそれなりに情報は出てくるでしょう。
$ grep -nEe "WARN|ERROR" server.log | less $ grep -nEe "WARN|ERROR|Caused by" -e "^[._[:alnum:]]+(Exception|Error)" server.log | less
例外も引っ掛けたい場合は下のほう使って下さい。
server.logは以下の位置にあります。同じディレクトリにあるアクセスログとboot.logも役に立つのでトラブルのときは一緒に取得しておきましょう。
スレッドがハングしてる、もしくは暴走してCPU使ってる
スレッドダンプとGCログを取得して解析。
ログ見ても原因がわからない
DEBUGログ有効にしても原因がわかるようなログが出ない、そんな場合はBytemanを使いましょう。
Java VMがクラッシュした
どうせ古いJava VM使ってるんだろ？最新版使ってるとほとんどクラッシュしないよ？
というのはさておき、OpenJDKであれば自力で解析できるっちゃーできるんですが、解析のために必要な知識がかなり膨大なのであまり現実的な選択肢ではないと思います。クラッシュの調査とか対策とか修正を期待する場合はOracleのJava for BusinessとかRHELに含まれるOpenJDKなどのサポートつきのJava VM使って下さい。その場合はコアダンプ取るのにulimit -c unlimitedで制限解除しとくのを忘れずに。
Java VMの情報取得
Java VMの情報を取得するにはJConsoleとかもありますが、あれはGUIツールであり保存が効かない。生データを完全な形で保存するようにしましょう。
Java VMについてくるツール群を利用してまずはプロセスIDを調べ、各種ツールで情報を収集します。
プロセスIDを調べる
$ jps -mlv
mlvオプションを付けたことない人は一度付けて実行してみるよろし。
基本的なVMの情報を取得
$ jinfo <pid>
ヒープサマリ取得
$ jmap -heap <pid>
ヒストグラム取得
$ jmap -histo:live <pid>
ヒープダンプ取得
$ jmap -dump:live,format=b,file=heap.bin <pid>
ヒープダンプはメモリ内容を全部ディスクに書き出す、というようなことをするので、取得にちょっと負荷と時間がかかるので注意。
スレッドダンプを取得
$ jstack <pid>
ランタイムでJMXからGCログを有効化
良い子はちゃんとJava VMオプションで事前に有効化しておきましょう。ランタイムからだと-Xloggc:
- "com.sun.management:type=HotSpotDiagnostic" MBean
- setVMOption(String, String) operation
PrintGCDetails, trueとかセットする。-verbose:gcオプションに相当するものは"java.lang:type=Memory" MBeanにVerbose attributeとかあるけどこのオプションは実は必要ないんだよね。
とりあえず全部とっとくシェルスクリプト
ぶっちゃけこういうの一個作っておけば上の覚えておかなくてもいいんじゃねーの。
#!/bin/sh PID=$1 if [ -z $PID ]; then echo "Usage: $0 <pid>" exit 1 fi DATE=`date +%Y%m%d%H%M%S` DUMPFILE=dumpj-$DATE.txt { date echo "============ jinfo $PID ============" jinfo $PID echo "============ jmap -heap $PID ============" jmap -heap $PID echo "============ jmap -histo:live $PID ============" jmap -histo:live $PID echo "============ jmap -dump:live,format=b,file=heap-$DATE.bin $PID ============" jmap -dump:live,format=b,file=heap-$DATE.bin $PID # Take thread dump every 5 sec for 3 min MAX_COUNT=36 INTERVAL=5 COUNT=0 while [ $COUNT -lt $MAX_COUNT ] do COUNT=`expr $COUNT + 1` echo "============ jstack $PID loop $COUNT ============" jstack $PID echo "============ top -b -n 1 -H -p $PID ==========" top -b -n 1 -H -p $PID sleep $INTERVAL done } > $DUMPFILE
