一个java crash的故障分析过程

 

一个应用在周五出现java进程消失，没有任何日志。先查看/var/log/message中无oom_killer信息，所以只能拿core。

该应用是一个集群，通知他们将出现crash的服务器上打开ulimit,等待生成core文件 。

今天周一，下午应用负责人紧急找我，说同时出几台crash了。开了ulimit参数的那台服务器coredump已经生成。

登录到该服务器上，先是gdb $JAVA_HOME/bin/java coredump_file

gdb) thread 1
[Switching to thread 1 (process 6838)]#0 0x00002aaab6cc75cd in Java_java_net_SocketOutputStream_socketWrite0 ()
from /usr/alibaba/install/jdk1.6.0_25/jre/lib/amd64/libnet.so
(gdb) bt
#0 0x00002aaab6cc75cd in Java_java_net_SocketOutputStream_socketWrite0 () from /usr/alibaba/install/jdk1.6.0_25/jre/lib/amd64/libnet.so
#1 0x00002aaaab041b0c in ?? ()
#2 0x0000000000000000 in ?? ()
(gdb)

因为JVM本身没有符号，短时间内看不出有用的信息。只知道process 6838在Java_java_net_SocketOutputStream_socketWrite0时退出，立即进入JAVA进程内部跟踪：

jstack $JAVA_HOME/bin/java coredump_file > a.txt

vi a.txt

找到 Thread 6838: (state = IN_NATIVE)
- java.net.SocketOutputStream.socketWrite0(java.io.FileDescriptor, byte[], int,
int) @bci=0 (Interpreted frame)

查看该线程的调用栈，一看吓了一跳，竟然有1600多行，其中有十多行代码重复了140多次，不用说，这段调用陷入了死循环。

查看该死循环的代码主要是velocity代码在rander一个模板，所以怀疑95%的可能是模板循环引用引起的，因为我不了解应用的具体实现，通知应该方查看信息提示的

模板调用，果然几分钟他们就发现了模板嵌套导致的死循环。

从拿到core到问题定位基本在五分钟内。所以即使看起来无踪可循的故障，只要获取关键信息，基本还是能反映问题的本质的。