gdb で Java VM の core を確認する。
元ネタ、http://icedtea.classpath.org/people/adinn/unwinder/file/f50e52519fb9/
java calling convention
プログラム中で関数をコールする際にどのレジスタに引数をセットするのかや、スタックのどこに戻り先のアドレスをセットしておくのかなど calling convention (呼出規約)として決められています。
同様に Java VM においても、Java プログラム中でメソッドをコールする場合に Java VM での calling convention (呼出規約)があり、これは x86-64 の呼び出し規約とはまったく違います。
そのため、gdb で java VM の core ファイルを開くと x86-64 のネイティブな箇所のスタックは表示されても、Java のスタックに関しては ?? の表記となり正しくスタックの情報が表示されません。
OpenJDK Unwinder を利用すると、Java VM のスタックまで gdb で表示する事が可能になります。
OpenJDK Unwinder
(gdb) source dbg8.py
Installing openjdk unwinder
(gdb) bt
#0 0x00007f17a5f2970d in read () at /lib64/libpthread.so.0
#1 0x00007f17a372b7b8 in () at /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/jre/lib/amd64/libjava.so
#2 0x00007f17a372ae28 in () at /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/jre/lib/amd64/libjava.so
#3 0x00007f178d017774 in [native] java.io.FileInputStream.readBytes(byte,int,int) () at java/io/FileInputStream.java
#4 0x00007f178d007a40 in [interpreted: bc = 4] java.io.FileInputStream.read(byte,int,int) ()
at java/io/FileInputStream.java:255
#5 0x00007f178d007a40 in [interpreted: bc = 39] java.io.BufferedInputStream.read1(byte,int,int) ()
at java/io/BufferedInputStream.java:286
#6 0x00007f178d007a40 in [interpreted: bc = 49] java.io.BufferedInputStream.read(byte,int,int) ()
at java/io/BufferedInputStream.java:346
#7 0x00007f178d007a40 in [interpreted: bc = 135] sun.nio.cs.StreamDecoder.readBytes() ()
at sun/nio/cs/StreamDecoder.java:285
#8 0x00007f178d007a40 in [interpreted: bc = 112] sun.nio.cs.StreamDecoder.implRead(char,int,int) ()
at sun/nio/cs/StreamDecoder.java:327
#9 0x00007f178d007a40 in [interpreted: bc = 180] sun.nio.cs.StreamDecoder.read(char,int,int) ()
at sun/nio/cs/StreamDecoder.java:179
#10 0x00007f178d007a40 in [interpreted: bc = 7] java.io.InputStreamReader.read(char,int,int) ()
at java/io/InputStreamReader.java:184
#11 0x00007f178d007a40 in [interpreted: bc = 145] java.io.BufferedReader.fill() () at java/io/BufferedReader.java:162
#12 0x00007f178d007ffd in [interpreted: bc = 44] java.io.BufferedReader.readLine(boolean) ()
at java/io/BufferedReader.java:325
#13 0x00007f178d007d80 in [interpreted: bc = 2] java.io.BufferedReader.readLine() ()
at java/io/BufferedReader.java:389
#14 0x00007f178d007d80 in [interpreted: bc = 27] sleep.keyin() () at sleep.java:33
#15 0x00007f178d007ffd in [interpreted: bc = 9] sleep.main(java.lang.String) () at sleep.java:14
#16 0x00007f178d0004e7 in StubRoutines (1) ()
#17 0x00007f17a4be3b4a in JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*) (result=0x7f17a633dce0, m=<optimized out>, args=<optimized out>, __the_thread__=0x7f179c009000)
at /usr/src/debug/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/openjdk/hotspot/src/share/vm/runtime/javaCalls.cpp:406
#18 0x00007f17a4bf51ea in jni_invoke_static(JNIEnv*, JavaValue*, jmethodID, JNI_ArgumentPusher*, Thread*, JNICallType, jobject) (env=env@entry=0x7f179c009258, result=result@entry=0x7f17a633dce0, method_id=method_id@entry=0x7f179c0d9980, args=args@entry=0x7f17a633dd30, __the_thread__=__the_thread__@entry=0x7f179c009000, call_type=JNI_STATIC, receiver=0x0, this=<optimized out>)
at /usr/src/debug/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/openjdk/hotspot/src/share/vm/prims/jni.cpp:1330
#19 0x00007f17a4c08ee6 in jni_CallStaticVoidMethod(JNIEnv*, jclass, jmethodID, ...) (env=0x7f179c009258, cls=<optimized out>, methodID=0x7f179c0d9980)
at /usr/src/debug/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/openjdk/hotspot/src/share/vm/prims/jni.cpp:2524
#20 0x00007f17a5af99e9 in ()
at /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/jre/bin/../lib/amd64/jli/libjli.so
#21 0x00007f17a5f22e25 in start_thread () at /lib64/libpthread.so.0
#22 0x00007f17a562734d in clone () at /lib64/libc.so.6
(gdb)
ふつーに gdb で bt を行うと以下のように途中から ?? となります。
(gdb) bt
#0 0x00007f17a5f2970d in read () from /lib64/libpthread.so.0
#1 0x00007f17a372b7b8 in read (__nbytes=8192, __buf=0x7f17a633b2f0, __fd=0) at /usr/include/bits/unistd.h:44
#2 handleRead (fd=0, buf=buf@entry=0x7f17a633b2f0, len=len@entry=8192)
at /usr/src/debug/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/openjdk/jdk/src/solaris/native/java/io/io_util_md.c:156
#3 0x00007f17a372ae28 in readBytes (env=0x7f179c009258, this=0x7f17a633d3d8, bytes=0x7f17a633d3d0, off=0, len=8192,
fid=<optimized out>)
at /usr/src/debug/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/openjdk/jdk/src/share/native/java/io/io_util.c:109
#4 0x00007f178d017774 in ?? ()
#5 0x00007f17a0406570 in ?? ()
#6 0x00007f179c009000 in ?? ()
#7 0x00007f17a0407260 in ?? ()
#8 0x00007f179c009000 in ?? ()
#9 0x00007f17a633d360 in ?? ()
#10 0x0000000000000000 in ?? ()
(gdb)
jstack では
jstack の “-m” オプションで __libc_read など、ネイティブなスタックも表示可能です。
とは言え、使い慣れている gdb で確認したいと思う方は多いのではないでしょうか?。
$ jstack -m /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/bin/java ./core.6688
... 中略...
----------------- 6689 -----------------
0x00007f17a5f2970d __libc_read + 0x2d
0x00007f17a372ae28 readBytes + 0x188
0x00007f178d017774 * java.io.FileInputStream.readBytes(byte[], int, int) bci:0 (Interpreted frame)
0x00007f178d007a40 * java.io.FileInputStream.read(byte[], int, int) bci:4 line:255 (Interpreted frame)
0x00007f178d007a40 * java.io.BufferedInputStream.read1(byte[], int, int) bci:39 line:284 (Interpreted frame)
0x00007f178d007a40 * java.io.BufferedInputStream.read(byte[], int, int) bci:49 line:345 (Interpreted frame)
0x00007f178d007a40 * sun.nio.cs.StreamDecoder.readBytes() bci:135 line:284 (Interpreted frame)
0x00007f178d007a40 * sun.nio.cs.StreamDecoder.implRead(char[], int, int) bci:112 line:326 (Interpreted frame)
0x00007f178d007a40 * sun.nio.cs.StreamDecoder.read(char[], int, int) bci:180 line:178 (Interpreted frame)
0x00007f178d007a40 * java.io.InputStreamReader.read(char[], int, int) bci:7 line:184 (Interpreted frame)
0x00007f178d007a40 * java.io.BufferedReader.fill() bci:145 line:161 (Interpreted frame)
0x00007f178d007ffd * java.io.BufferedReader.readLine(boolean) bci:44 line:324 (Interpreted frame)
0x00007f178d007d80 * java.io.BufferedReader.readLine() bci:2 line:389 (Interpreted frame)
0x00007f178d007d80 * sleep.keyin() bci:27 line:29 (Interpreted frame)
0x00007f178d007ffd * sleep.main(java.lang.String[]) bci:9 line:14 (Interpreted frame)
0x00007f178d0004e7 <StubRoutines>
0x00007f17a4be3b4a _ZN9JavaCalls11call_helperEP9JavaValueP12methodHandleP17JavaCallArgumentsP6Thread + 0xf0a
0x00007f17a4bf51ea _ZL17jni_invoke_staticP7JNIEnv_P9JavaValueP8_jobject11JNICallTypeP10_jmethodIDP18JNI_ArgumentPusherP6Thread.isra.201 + 0x30a
0x00007f17a4c08ee6 jni_CallStaticVoidMethod + 0x186
0x00007f17a5af99e9 JavaMain + 0xa29
gdb 実行環境のセットアップ
RHEL 7.4 の環境では、以下を追加インストールしました。
# yum install java-1.8.0-openjdk-debuginfo-1.8.0.131-11.b12.el7.x86_64
# yum install xz-devel-5.2.2-1.el7.x86_64
# yum install python-devel-2.7.5-58.el7.x86_64
- gdb の make
OpenJDK unwinder は、gdb 7.10 からサポートされた Python の frame unwinder の機能を利用しています。
RHEL 7.4 同梱の gdb は gdb-7.6.1 と古く、新しい版の gdb が必要です。
以下のようにダウンロードとコンパイルを行います。
# mkdir /work
# cd /work
# wget https://ftp.gnu.org/gnu/gdb/gdb-7.12.tar.xz
# tar xvf gdb-7.12.tar.xz
# cd /work/gdb-7.12
# ./configure --with-python --with-lzma
# make
- libjvm.so.debug へのパスを調整する
新しく make した gdb が libjvm.so.debug を見つけられないのでシンボリックリンクを張ります。
# ln -s /usr/lib/debug/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/jre/lib/amd64/server
/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/jre/lib/amd64/server/.debug
- OpenJDK Unwinder を持ってくる。
http://icedtea.classpath.org/people/adinn/unwinder/file/f50e52519fb9/
(私は、dbg8.py の表示された内容をコピペして dbg8.py にしました。)
gdb の実行
$ /work/gdb-7.12/gdb/gdb --data-directory=/work/gdb-7.12/gdb/data-directory /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.131-11.b12.el7.x86_64/bin/java ./core.6688
...中略 ...
(gdb) source dbg8.py
Installing openjdk unwinder
(gdb) thread 1
(gdb) bt
最初に記載した Java フレームも含めたスタック情報が表示されます。
gdb の実行に関してハマった箇所
- import gdb のエラー
(gdb) source dbg8.py
Traceback (most recent call last):
File "dbg8.py", line 21, in
import gdb
ImportError: No module named gdb
(gdb)
python で import する gdb が見つかっていないので gdb 起動時に "--data-directory=/work/gdb-7.12/gdb/data-directory" と明示すればOK
- gdb.error: No type named nmethod.
(gdb) source dbg8.py
Installing openjdk unwinder
Traceback (most recent call last):
File "dbg8.py", line 52, in
class Types(object):
File "dbg8.py", line 66, in Types
nmethodp_t = gdb.lookup_type('nmethod').pointer()
gdb.error: No type named nmethod.
(gdb)
gdb が libjvm.so.debug ファイルを見つけられてません。
strace などで gdb がどのディレクトリを検索しているかを確認して、そこに libjvm.so.debug を置くか、上での libjvm.so.debug のパスの調整のようにシンボリックリンクを張れば OK
- lzma のワーニングがうざい。
xz-devel-5.2.2-1.el7.x86_64 をインストールしていない環境で gdb を作成すると、gdb 起動時に以下の warning がレポートされます。
xz-devel をインストール後、gdb を make すれば OK。
warning: Cannot parse .gnu_debugdata section; LZMA support was disabled at compile time