JDK core dump分析

Java项目一般使用jstack, jmap等Java工具都可以分析进程bug，但是有时候jvm自身异常退出，此时往往没有hprof文件，而是生成了core文件，特别是在使用JNI技术的项目中，这时候就要用充分挖掘core文件中的有用信息了。

core dump介绍

当程序运行的过程中异常终止或崩溃，操作系统会将程序当时的内存状态记录下来，保存在一个文件中，这种行为就叫做Core Dump（中文有的翻译成“核心转储”)。我们可以认为 core dump 是“内存快照”，但实际上，除了内存信息之外，还有些关键的程序运行状态也会同时 dump 下来，例如寄存器信息（包括程序指针、栈指针等）、内存管理信息、其他处理器和操作系统状态和信息。core dump 对于编程人员诊断和调试程序是非常有帮助的，因为对于有些程序错误是很难重现的，例如指针异常，而 core dump 文件可以再现程序出错时的情景。

生成core dump

由于 core dump 文件会占据一定的磁盘空间，默认情况下，Linux 不允许生成 core dump 文件。例如，下面的命令显示，Linux 允许的最大 core dump 文件大小为 0：

$ ulimit -a | grep core
core file size          (blocks, -c) 0

可以通过下面设置，允许 Linux 生成 core dump 文件：

$ ulimit -c unlimited

注意到，这个设置只对当前登录回话有效。如果想要这个设置持久有效，可以把它写入到/etc/security/limits.conf文件中：

$ sudo vi /etc/security/limits.conf
* soft core unlimited
* soft hard unlimited

gdb

gdb JAVAHOMEJAVA_HOMEJAVAHOME/bin/java core-26492
进入gdb上下文后再执行bt命令，可以看到进程退出时的线程栈。

$ gdb /data/soft/jdk/bin/java core.11668
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-80.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /data/soft/jdk1.8.0_141/bin/java...Missing separate debuginfo for /data/soft/jdk1.8.0_141/bin/java
Try: yum --enablerepo='*debug*' install /usr/lib/debug/.build-id/c9/0f19ee0af98c47ccaa7181853cfd14867bc931.debug
(no debugging symbols found)...done.
[New LWP 14367]
...
[New LWP 14355]
[New LWP 11685]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Missing separate debuginfo for /data/soft/jdk1.8.0_141/jre/lib/amd64/server/libjvm.so
Try: yum --enablerepo='*debug*' install /usr/lib/debug/.build-id/43/a2bc419314aa566cd5ba54779ae18b47022cad.debug
Missing separate debuginfo for /data/soft/jdk1.8.0_141/jre/lib/amd64/libverify.so
Try: yum --enablerepo='*debug*' install /usr/lib/debug/.build-id/b3/de2701fa3aef182d8e7b2db8d294a91af1eb7c.debug
Missing separate debuginfo for /data/soft/jdk1.8.0_141/jre/lib/amd64/libmanagement.so
Try: yum --enablerepo='*debug*' install /usr/lib/debug/.build-id/ee/7e746ef83f2c2fbe8ea0cb42706b63cd74de3f.debug
Missing separate debuginfo for /data/soft/jdk1.8.0_141/jre/lib/amd64/libinstrument.so
Try: yum --enablerepo='*debug*' install /usr/lib/debug/.build-id/13/552fe85b2af551ab806735bc5e5f2a5e00fbb1.debug
Core was generated by `/data/soft/jdk/bin/java -Djava.util.logging.config.file=/data/home/aics/taskbot'.
Program terminated with signal 6, Aborted.
#0  0x00007f50d652b1d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56        return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
(gdb) bt
#0  0x00007f50d652b1d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x00007f50d652c8c8 in __GI_abort () at abort.c:90
#2  0x00007f50397417f4 in tensorflow::internal::LogMessageFatal::~LogMessageFatal() () from /data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545395060637-0/libtensorflow_framework.so
#3  0x00007f5039721cf0 in tensorflow::monitoring::CollectionRegistry::Register(tensorflow::monitoring::AbstractMetricDef const*, std::function<void (tensorflow::monitoring::MetricCollectorGetter)> const&) ()from /data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545395060637-0/libtensorflow_framework.so
#4  0x00007f501520951f in ?? () from /data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545633543384-0/libtensorflow_jni.so
#5  0x00007f50151334db in ?? () from /data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545633543384-0/libtensorflow_jni.so
#6  0x00007f50d6efd1e3 in call_init (env=0x7f50d00c4460, argv=0x7ffe7bc01488, argc=21, l=<optimized out>) at dl-init.c:82
#7  _dl_init (main_map=main_map@entry=0x7f50249fa900, argc=21, argv=0x7ffe7bc01488, env=0x7f50d00c4460) at dl-init.c:131
#8  0x00007f50d6f018f6 in dl_open_worker (a=a@entry=0x7f503b2f7b98) at dl-open.c:560
#9  0x00007f50d6efcff4 in _dl_catch_error (objname=objname@entry=0x7f503b2f7b88, errstring=errstring@entry=0x7f503b2f7b90, mallocedp=mallocedp@entry=0x7f503b2f7b80, operate=operate@entry=0x7f50d6f01540 <dl_open_worker>, args=args@entry=0x7f503b2f7b98) at dl-error.c:177
#10 0x00007f50d6f00feb in _dl_open (file=0x7f5024008550 "/data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545633543384-0/libtensorflow_jni.so", mode=-2147483647, caller_dlopen=<optimized out>, nsid=-2, argc=21, argv=0x7ffe7bc01488, env=0x7f50d00c4460) at dl-open.c:650
#11 0x00007f50d68b8fbb in dlopen_doit (a=a@entry=0x7f503b2f7da0) at dlopen.c:66
#12 0x00007f50d6efcff4 in _dl_catch_error (objname=0x7f5024ae73e0, errstring=0x7f5024ae73e8, mallocedp=0x7f5024ae73d8, operate=0x7f50d68b8f60 <dlopen_doit>, args=0x7f503b2f7da0) at dl-error.c:177
#13 0x00007f50d68b95bd in _dlerror_run (operate=operate@entry=0x7f50d68b8f60 <dlopen_doit>, args=args@entry=0x7f503b2f7da0) at dlerror.c:163
#14 0x00007f50d68b9051 in __dlopen (file=<optimized out>, mode=<optimized out>) at dlopen.c:87
#15 0x00007f50d5e2a24e in os::dll_load(char const*, char*, int) () from /data/soft/jdk1.8.0_141/jre/lib/amd64/server/libjvm.so
#16 0x00007f50d5c2198c in JVM_LoadLibrary () from /data/soft/jdk1.8.0_141/jre/lib/amd64/server/libjvm.so
#17 0x00007f50d4ac7df8 in Java_java_lang_ClassLoader_00024NativeLibrary_load () from /data/soft/jdk1.8.0_141/jre/lib/amd64/libjava.so

jstack

之前从来没想过，居然还可以使用java工具来分析core文件

使用jstack可以查看到进程core_dump时的线程执行栈
/data/soft/jdk/bin/jstack /data/soft/jdk/bin/java core.26492

Thread 15040: (state = IN_NATIVE)- java.lang.ClassLoader$NativeLibrary.load(java.lang.String, boolean) @bci=0 (Interpreted frame)- java.lang.ClassLoader.loadLibrary0(java.lang.Class, java.io.File) @bci=328, line=1941 (Interpreted frame)- java.lang.ClassLoader.loadLibrary(java.lang.Class, java.lang.String, boolean) @bci=48, line=1824 (Interpreted frame)- java.lang.Runtime.load0(java.lang.Class, java.lang.String) @bci=57, line=809 (Interpreted frame)- java.lang.System.load(java.lang.String) @bci=7, line=1086 (Interpreted frame)- org.tensorflow.NativeLibrary.load() @bci=212, line=101 (Interpreted frame)- org.tensorflow.TensorFlow.init() @bci=0, line=66 (Interpreted frame)- org.tensorflow.TensorFlow.<clinit>() @bci=0, line=70 (Interpreted frame)- org.tensorflow.Graph.<clinit>() @bci=0, line=258 (Interpreted frame)

jmap

$ /data/soft/jdk/bin/jmap /data/soft/jdk/bin/java core.14652
结果如下：

Attaching to core core.14652 from executable /data/soft/jdk/bin/java, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.141-b15
0x0000000000400000      7K      /data/soft/jdk/bin/java
0x00007fbc261fb000      41K     /lib64/libonion.so
0x00007fbc25ec8000      139K    /lib64/libpthread.so.0
0x00007fbc25cb2000      100K    /data/soft/jdk1.8.0_141/bin/../lib/amd64/jli/libjli.so
0x00007fbc25aae000      18K     /lib64/libdl.so.2
0x00007fbc256ec000      2063K   /lib64/libc.so.6
0x00007fbc260e4000      151K    /lib64/ld-linux-x86-64.so.2
0x00007fbc246f5000      16615K  /data/soft/jdk1.8.0_141/jre/lib/amd64/server/libjvm.so
0x00007fbc243f3000      1114K   /lib64/libm.so.6
0x00007fbc240ea000      42K     /lib64/librt.so.1
0x00007fbc1fdf1000      64K     /data/soft/jdk1.8.0_141/jre/lib/amd64/libverify.so
0x00007fbc1fbc5000      220K    /data/soft/jdk1.8.0_141/jre/lib/amd64/libjava.so
0x00007fbc1f9aa000      121K    /data/soft/jdk1.8.0_141/jre/lib/amd64/libzip.so
0x00007fbbed321000      49K     /data/soft/jdk1.8.0_141/jre/lib/amd64/libmanagement.so
0x00007fbbed10a000      113K    /data/soft/jdk1.8.0_141/jre/lib/amd64/libnet.so
0x00007fbbeca48000      90K     /data/soft/jdk1.8.0_141/jre/lib/amd64/libnio.so
0x00007fbbec500000      251K    /data/soft/jdk1.8.0_141/jre/lib/amd64/libsunec.so
0x00007fbbec2ea000      86K     /lib64/libgcc_s.so.1
0x00007fbb78e4c000      50874K  /data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545634810127-0/libtensorflow_jni.so
0x00007fbb944f4000      15740K  /data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545634810127-0/libtensorflow_framework.so
0x00007fbb941d7000      972K    /lib64/libstdc++.so.6
0x00007fbb69848000      50874K  /data/home/aics/taskbot-tomcat/temp/tensorflow_native_libraries-1545641641135-0/libtensorflow_jni.so

看起来内存占用情况还好，没有特别的内存，但是不知道为什么libtensorflow_jni.so占用了两个50874K的堆。

转成hprof后分析

/data/soft/jdk/bin/jmap -dump:format=b,file=dump.hprof /data/soft/jdk/bin/java core.14652
转换之后就可以很方面的使用MAT或VisualVM进行JVM堆内存分析

常见问题

Missing separate debuginfo for: 执行命令debuginfo-install glibc-2.17-157.tl2.2.x86_64 libgcc-4.8.5-4.el7.x86_64 libstdc+±4.8.5-4.el7.x86_64

这里一般按照错误中的提示来执行命令，不过jvm相关的我也没有安装成功，也许是要使用OpenJDK才有调试信息包吧

参考

linux下core dump【总结】
在 Linux 生成 core dump 文件
如何抓获JVM crash的幕后黑手？（一）
https://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/tooldescr016.html#BABBAIJC
https://docs.oracle.com/javase/7/docs/technotes/tools/share/jmap.html