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