HotSpot Compiler
Java VM は、最初は実行対象のコードをインタープリタとして実行し動作していますが、頻繁に実行される箇所(Server VM で-XX:CompileThreshold=10000 以上)をネイティブなマシン語にコンパイルする事で実行を高速化しています。
Java VM がクラッシュしてしまう原因として、この HotSpot コンパイラの不具合により、対象のメソッドをコンパイルしようとして SIGSEGV + core dump で異常終了となるケースがあります。
※ 個人的な感想ですが、Java VM の古い版 Java 1.4 などの頃はこればっかりでした。最近の Java VM ではあまり経験はありません。
hs_error_log
core dump とともに通常 hs_error_log or hs_err_pid1234.log など hs error ログファイルが出力されます。
このログファイル中に、HotSpot コンパイラが何のメソッドをコンパイルしようとして異常終了に至ったのなど重要な情報が記録されています。
標準出力には以下のようにエラーが吐かれて終了しています。
# ulimit -c unlimited
# /usr/libexec/tomcat/server start
# A fatal error has been detected by the Java Runtime Environment:
#
# SIGSEGV (0xb) at pc=0x00007f5073f646c0, pid=15045, tid=139983466055424
#
# JRE version: OpenJDK Runtime Environment (7.0_141-b02) (build 1.7.0_141-mockbuild_2017_06_13_12_10-b00)
# Java VM: OpenJDK 64-Bit Server VM (24.141-b02 mixed mode linux-amd64 compressed oops)
# Derivative: IcedTea 2.6.10
# Distribution: Red Hat Enterprise Linux Server release 7.3 (Maipo), package rhel-2.6.10.5.el7-x86_64 u141-b02
# Problematic frame:
# V [libjvm.so+0x8446c0]
#
# Core dump written. Default location: /usr/share/tomcat/core or core.15045
#
# An error report file with more information is saved as:
# /tmp/jvm-15045/hs_error.log
#
# If you would like to submit a bug report, please include
# instructions on how to reproduce the bug and visit:
# http://icedtea.classpath.org/bugzilla
#
中止 (コアダンプ)
hs error ログファイルの以下の箇所から HotSpot コンパイラが、何のメソッドをコンパイルしようとしてクラッシュに至ったのかが分かります。
# vi /tmp/jvm-15045/hs_error.log
... 中略 ...
Current CompileTask:
C2: 205800 155 org.apache.tomcat.util.buf.ByteChunk::recycle (21 bytes)
...
テストのために無理やり core を出力させていますので、通常このメソッドで core dump に至る事はありません。
上記のような出力結果から CompileTask: 欄のメソッドが対象のメソッドです。
問題への対処
このような HotSpot コンパイラの不具合を回避するには、コンパイル対象のメソッドを HotSpot コンパイラの対象外にする事で回避できます。
Java を起動する時のカレントワーキングディレクトリに .hotspot_compiler ファイルを作成します。
Java VM は起動時に、このファイルを読み、その後指定のメソッドは HotSpot コンパイル対象になる事はありません。
# vi .hotspot_compiler
exclude org/apache/tomcat/util/buf/ByteChunk recycle
なぜ HotSpot コンパイラが SIGSEGV で異常終了したのかに関しては、ほとんどが Java VM の不具合です。
しかしながら、同じ異常終了の事象を別の環境で再現する事は非常に困難です。
そのため Java VM のサポート窓口へ問い合わせしても、今までに事例の無い新しい問題であった場合は、すぐに原因が明確となって修正される事は期待できません。
その時点で最新の Java VM で再発するかを見極めて、最新版でも発生する場合には今後修正されることに期待を込めて core ファイル、リンクされているライブラリ、hs error ログなどをサポート窓口へ提供することになると思います。
運用環境では、それよりも先に、まず .hotspot_compiler を設定しての問題回避ですね。
core ファイルから対象メソッド名の確認
"hs error ファイル取得し忘れた"、"もう消してしまった" 、など手元に java core ファイルしか無い不幸な状況に陥ることがあります。
この場合でも core ファイルから対象のクラス名、メソッド名を確認することが可能です。
以下、RHEL 7.4 Java 1.7.0_141 環境で確認
$ gdb /usr/lib/jvm/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/jre-abrt/bin/java /usr/share/tomcat/core.15045
... 中略 ...
(gdb) bt
#0 0x00007f50747b01f7 in raise () from /lib64/libc.so.6
#1 0x00007f50747b18e8 in abort () from /lib64/libc.so.6
#2 0x00007f5073f18de9 in os::abort (dump_core=<optimized out>) at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/os/linux/vm/os_linux.cpp:1635
#3 0x00007f50740a7bcf in VMError::report_and_die (this=this@entry=0x7f5070c49bd0)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/utilities/vmError.cpp:1074
#4 0x00007f5073f21ff7 in JVM_handle_linux_signal (sig=11, info=0x7f5070c49e30, ucVoid=0x7f5070c49d00, abort_if_unrecognized=<optimized out>)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/os_cpu/linux_x86/vm/os_linux_x86.cpp:531
#5 <signal handler called>
#6 0x00007f5073f646c0 in Phase::Phase (this=0x0, pnum=Phase::Compiler)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/opto/phase.cpp:83
#7 0x00007f5073b78711 in Compile::Compile (this=0x0, ci_env=0x7f5070c4ba40, compiler=0x7f506c072730, target=0x7f503c0ba4f0, osr_bci=-1, subsume_loads=<optimized out>,
do_escape_analysis=true, eliminate_boxing=true) at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/opto/compile.cpp:683
#8 0x00007f5073ae3d30 in C2Compiler::compile_method (this=0x7f506c072730, env=0x7f5070c4ba40, target=0x7f503c0ba4f0, entry_bci=-1)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/opto/c2compiler.cpp:137
#9 0x00007f5073b7f788 in CompileBroker::invoke_compiler_on_method (task=task@entry=0x7f506c1595c0)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/compiler/compileBroker.cpp:1761
#10 0x00007f5073b80b00 in CompileBroker::compiler_thread_loop ()
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/compiler/compileBroker.cpp:1597
#11 0x00007f5074059cfa in JavaThread::thread_main_inner (this=this@entry=0x7f506c0a8800)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/runtime/thread.cpp:1687
#12 0x00007f507405a07f in JavaThread::run (this=0x7f506c0a8800)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/runtime/thread.cpp:1667
#13 0x00007f5073f17de2 in java_start (thread=0x7f506c0a8800) at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/os/linux/vm/os_linux.cpp:910
#14 0x00007f5074f57e25 in start_thread () from /lib64/libpthread.so.0
#15 0x00007f507487334d in clone () from /lib64/libc.so.6
(gdb)
上記、コンパイルスレッドのフレーム #8 のように C2Compiler::compile_method 関数があるはずです。
この第3引数に target = 0x7f503c0ba4f0 としてコンパイル対象のメソッドが指定されています。
この target から、クラス名、メソッド名を確認していきます。
(gdb) frame 8
#8 0x00007f5073ae3d30 in C2Compiler::compile_method (this=0x7f506c072730, env=0x7f5070c4ba40, target=0x7f503c0ba4f0, entry_bci=-1)
at /usr/src/debug/java-1.7.0-openjdk-1.7.0.141-2.6.10.5.el7.x86_64/openjdk/hotspot/src/share/vm/opto/c2compiler.cpp:137
137 Compile C(env, this, target, entry_bci, subsume_loads, do_escape_analysis, eliminate_boxing);
(gdb)
(gdb) p ({ciMethod}0x7f503c0ba4f0)->_name
$1 = (ciSymbol *) 0x7f503c0ba590
(gdb) p ({ciSymbol}0x7f503c0ba590)->_symbol
$2 = (Symbol *) 0x7f506c4fdb10
(gdb) p &({Symbol}0x7f506c4fdb10)->_body
$3 = (signed char (*)[1]) 0x7f506c4fdb1a
(gdb) x/s 0x7f506c4fdb1a
0x7f506c4fdb1a: "recycle"
(gdb)
メソッド名 "recycle" でした。
(gdb) p ({ciMethod}0x7f503c0ba4f0)->_holder
$21 = (ciInstanceKlass *) 0x7f503c0ba5a0
(gdb) p ({ciInstanceKlass}0x7f503c0ba5a0)->_name
$22 = (ciSymbol *) 0x7f503c0ba630
(gdb) p ({ciSymbol}0x7f503c0ba630)->_symbol
$23 = (Symbol *) 0x7f506c529af0
(gdb) p &({Symbol}0x7f506c529af0)->_body
$24 = (signed char (*)[1]) 0x7f506c529afa
(gdb) x/s 0x7f506c529afa
0x7f506c529afa: "org/apache/tomcat/util/buf/ByteChunk"
(gdb)
クラス名 "org/apache/tomcat/util/buf/ByteChunk" でした。
なんとも、手探り感満載の確認となってしまいましたが面倒なので、簡単な Python スクリプトを書きました。
https://github.com/takimai39/gdb-java
(gdb) source target.py
(gdb) target 0x7f503c0ba4f0
exclude org/apache/tomcat/util/buf/ByteChunk recycle
(gdb)
何かのお役に立てましたら幸いです。