当jvm出现致命错误时,会生成一个错误文件 hs_err_pid<pid>.log,其中包括了导致jvm crash的重要信息,可以通过分析该文件定位到导致crash的根源,从而改善以保证系统稳定。当出现crash时,该文件默认会生成到工作目录下,然而可以通过jvm参数指定生成路径(JDK6中引入):

-XX:ErrorFile=./hs_err_pid<pid>.log

该文件包含如下几类关键信息:

  • 日志头文件
  • 导致crash的线程信息
  • 所有线程信息
  • 安全点和锁信息
  • 堆信息
  • 本地代码缓存
  • 编译事件
  • gc相关记录
  • jvm内存映射
  • jvm启动参数
  • 服务器信息

下面用一个crash demo文件逐步解读这些信息,以便大家以后碰到crash时方便分析。

日志头文件

日志头文件包含概要信息,简述了导致crash的原因。而导致crash的原因很多,常见的原因有jvm自身的bug,应用程序错误,jvm参数配置不当,服务器资源不足,jni调用错误等。

现在参考下如下描述:

#
# A fatal error has been detected by the Java Runtime Environment:
#
# SIGSEGV (0xb) at pc=0x00007fb8b18fdc6c, pid=191899, tid=140417770411776
#
# JRE version: Java(TM) SE Runtime Environment (7.0_55-b13) (build 1.7.0_55-b13)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (24.55-b03 mixed mode linux-amd64 compressed oops)
# Problematic frame:
# J org.apache.http.impl.cookie.BestMatchSpec.formatCookies(Ljava/util/List;)Ljava/util/List;
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# If you would like to submit a bug report, please visit:
# http://bugreport.sun.com/bugreport/crash.jsp
#

这里一个重要信息是“SIGSEGV(0xb)”表示jvm crash时正在执行jni代码,而不是在执行java或者jvm的代码,如果没有在应用程序里手动调用jni代码,那么很可能是JIT动态编译时导致的该错误。其中SIGSEGV是信号名称,0xb是信号码,pc=0x00007fb8b18fdc6c指的是程序计数器的值,pid=191899是进程号,tid=140417770411776是线程号。

PS:除了“SIGSEGV(0xb)”以外,常见的描述还有“EXCEPTION_ACCESS_VIOLATION”,该描述表示jvm crash时正在执行jvm自身的代码,这往往是因为jvm的bug导致的crash;另一种常见的描述是“EXCEPTION_STACK_OVERFLOW”,该描述表示这是个栈溢出导致的错误,这往往是应用程序中存在深层递归导致的。

还有一个重要信息是:

# Problematic frame:

# J org.apache.http.impl.cookie.BestMatchSpec.formatCookies(Ljava/util/List;)Ljava/util/List;

这表示出现crash时jvm正在执行的代码,这里的“J”表示正在执行java代码,后面的表示执行的方法栈。除了“J”外,还有可能是“C”、“j”、“V”、“v”,它们分别表示:

  • C: Native C frame
  • j: Interpreted Java frame
  • V: VMframe
  • v: VMgenerated stub frame
  • J: Other frame types, including compiled Java frames

加上前面对SIGSEGV(0xb)”的分析,现在可以断定是JIT动态编译导致的该错误。

查阅资料发现:

此异常是由于jdk JIT compiler optimization 导致,bug id 8021898,官网描述如下:

The JIT compiler optimization leads to a SIGSEGV or an NullPointerException at a place it must not happen.

jdk1.7.0_25到1.7.0_55这几个版本都存在此bug,1.7.0_60后修复。可通过升级jdk解决此异常,可参考 http://bugs.java.com/view_bug.do?bug_id=8021898

到这里该问题已经分析出原因了,但是咱们可以再深入一步,分析下其它信息。

导致crash的线程信息

文件下面是导致crash的线程信息和该线程栈信息,描述信息如下:

Current thread (0x00007fb7b4014800):  JavaThread "catalina-exec-251" daemon [_thread_in_Java, id=205044, stack(0x00007fb58f435000,0x00007fb58f536000)]

siginfo:si_signo=SIGSEGV: si_errno=0, si_code=1 (SEGV_MAPERR), si_addr=0x0000003f96dc9c6c

以上表示导致出错的线程是0x00007fb7b4014800(指针),线程类型是JavaThread,JavaThread表示执行的是java线程,关于该线程其它类型还可能是:

  • VMThread:jvm的内部线程
  • CompilerThread:用来调用JITing,实时编译装卸class 。 通常,jvm会启动多个线程来处理这部分工作,线程名称后面的数字也会累加,例如:CompilerThread1
  • GCTaskThread:执行gc的线程
  • WatcherThread:jvm周期性任务调度的线程,是一个单例对象。 该线程在JVM内使用得比较频繁,比如:定期的内存监控、JVM运行状况监控,还有我们经常需要去执行一些jstat 这类命令查看gc的情况
  • ConcurrentMarkSweepThread:jvm在进行CMS GC的时候,会创建一个该线程去进行GC,该线程被创建的同时会创建一个SurrogateLockerThread(简称SLT)线程并且启动它,SLT启动之后,处于等待阶段。CMST开始GC时,会发一个消息给SLT让它去获取Java层Reference对象的全局锁:Lock

后面的”catalina-exec-251″表示线程名,带有catalina前缀的线程一般是tomcat启动的线程,“daemon”表示该线程为守护线程,再后面的“[_thread_in_Java”表示线程正在执行解释或者编译后的Java代码,关于该描述其它类型还可能是:

  • _thread_in_native:线程当前状态
  • _thread_uninitialized:线程还没有创建,它只在内存原因崩溃的时候才出现
  • _thread_new:线程已经被创建,但是还没有启动
  • _thread_in_native:线程正在执行本地代码,一般这种情况很可能是本地代码有问题
  • _thread_in_vm:线程正在执行虚拟机代码
  • _thread_in_Java:线程正在执行解释或者编译后的Java代码
  • _thread_blocked:线程处于阻塞状态
  • …_trans:以_trans结尾,线程正处于要切换到其它状态的中间状态

最后的“id=205044”表示线程ID,stack(0x00007fb58f435000,0x00007fb58f536000)表示栈区间。

“siginfo:si_signo=SIGSEGV: si_errno=0, si_code=1 (SEGV_MAPERR), si_addr=0x0000003f96dc9c6c”这部分是导致虚拟机终止的非预期的信号信息:其中si_errno和si_code是Linux下用来鉴别异常的,Windows下是一个ExceptionCode。

所有线程信息

再下面是线程信息:

Java Threads: ( => current thread )
0x00007fb798015800 JavaThread "catalina-exec-280" daemon [_thread_blocked, id=206093, stack(0x00007fb58d718000,0x00007fb58d819000)]
0x00007fb7a4016800 JavaThread ”catalina-exec-279″ daemon [_thread_blocked, id=206091, stack(0x00007fb58d819000,0x00007fb58d91a000)]
… …(省略) Other Threads:
0x00007fb8b4231000 VMThread [stack: 0x00007fb854eb6000,0x00007fb854fb7000] [id=192015]
0x00007fb8b4321000 WatcherThread [stack: 0x00007fb835e6c000,0x00007fb835f6d000] [id=192414]

信息和上面介绍的类似,其中[_thread_blocked表示线程阻塞。

安全点和锁信息

再下面是安全点和锁信息:

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

安全线信息为正常运行,其它可能得描述还有:

  • not at a safepoint:正常运行状态
  • at safepoint:所有线程都因为虚拟机等待状态而阻塞,等待一个虚拟机操作完成
  • synchronizing:一个特殊的虚拟机操作,要求虚拟机内的其它线程保持等待状态

锁信息为未被线程持有,Mutex是虚拟机内部的锁,而Monitor则是synchronized锁或者其它关联到的Java对象。

堆信息

再下面是堆信息:

Heap
par new generation total 2293760K, used 1537284K [0x00000006f0000000, 0x0000000790000000, 0x0000000790000000)
eden space 1966080K, 78% used [0x00000006f0000000, 0x000000074dc97aa8, 0x0000000768000000)
from space 327680K, 0% used [0x0000000768000000, 0x00000007680a9580, 0x000000077c000000)
to space 327680K, 0% used [0x000000077c000000, 0x000000077c000000, 0x0000000790000000)
concurrent mark-sweep generation total 1572864K, used 49449K [0x0000000790000000, 0x00000007f0000000, 0x00000007f0000000)
concurrent-mark-sweep perm gen total 262144K, used 49857K [0x00000007f0000000, 0x0000000800000000, 0x0000000800000000) Card table byte_map: [0x00007fb8b8fa8000,0x00007fb8b9829000] byte_map_base: 0x00007fb8b5828000

堆信息包括:新生代、老生代、永久代信息。这里标识了使用CMS垃圾收集器。

下面的“Card table”表示一种卡表,是jvm维护的一种数据结构,用于记录更改对象时的引用,以便gc时遍历更少的table和root。

本地代码缓存

再下面是本地代码缓存信息:

Code Cache  [0x00007fb8b1000000, 0x00007fb8b1a60000, 0x00007fb8b4000000)
total_blobs=3580 nmethods=3111 adapters=421 free_code_cache=38857Kb largest_free_block=39469312

这是一块用于编译和保存本地代码的内存;注意是本地代码,它和PermGen(永久代)是不一样的,永久代是用来存放jvm和java类的元数据的。

编译事件

再下面是本地代码编译信息:

Compilation events (10 events):
Event: 110587.798 Thread 0x00007fb8b425a800 3338 java.util.HashSet::remove (20 bytes)
Event: 110587.804 Thread 0x00007fb8b425a800 nmethod 3338 0x00007fb8b168a9d0 code [0x00007fb8b168ab60, 0x00007fb8b168afa8]
... ...(省略)
Event: 112147.387 Thread 0x00007fb8b425a800 3342 org.apache.http.impl.cookie.BestMatchSpec::formatCookies (116 bytes)
Event: 112147.465 Thread 0x00007fb8b425a800 nmethod 3342 0x00007fb8b18fcd50 code [0x00007fb8b18fd1a0, 0x00007fb8b18ff338]

可以看到,一共编译了10次;其中包含org.apache.http.impl.cookie.BestMatchSpec::formatCookies的编译;这和前面的结论相吻合。

gc相关记录

再下面是gc执行记录:

GC Heap History (10 events):
Event: 110665.975 GC heap before
{Heap before GC invocations=255 (full 31):
par new generation total 2293760K, used 1966777K [0x00000006f0000000, 0x0000000790000000, 0x0000000790000000)
eden space 1966080K, 100% used [0x00000006f0000000, 0x0000000768000000, 0x0000000768000000)
from space 327680K, 0% used [0x0000000768000000, 0x00000007680ae480, 0x000000077c000000)
to space 327680K, 0% used [0x000000077c000000, 0x000000077c000000, 0x0000000790000000)
concurrent mark-sweep generation total 1572864K, used 49237K [0x0000000790000000, 0x00000007f0000000, 0x00000007f0000000)
concurrent-mark-sweep perm gen total 262144K, used 49856K [0x00000007f0000000, 0x0000000800000000, 0x0000000800000000)
Event: 110665.981 GC heap after
Heap after GC invocations=256 (full 31):
par new generation total 2293760K, used 693K [0x00000006f0000000, 0x0000000790000000, 0x0000000790000000)
eden space 1966080K, 0% used [0x00000006f0000000, 0x00000006f0000000, 0x0000000768000000)
from space 327680K, 0% used [0x000000077c000000, 0x000000077c0ad6f8, 0x0000000790000000)
to space 327680K, 0% used [0x0000000768000000, 0x0000000768000000, 0x000000077c000000)
concurrent mark-sweep generation total 1572864K, used 49237K [0x0000000790000000, 0x00000007f0000000, 0x00000007f0000000)
concurrent-mark-sweep perm gen total 262144K, used 49856K [0x00000007f0000000, 0x0000000800000000, 0x0000000800000000)
}
... ...(省略)

可以看到gc次数为10次(full gc),然后后面描述了每次gc前后的内存信息;看一看到并没有内存不足等问题。

jvm内存映射

再下面是jvm加载的库信息:

Dynamic libraries:
00400000-00401000 r-xp 00000000 08:02 39454583 /home/service/jdk1.7.0_55/bin/java
00600000-00601000 rw-p 00000000 08:02 39454583 /home/service/jdk1.7.0_55/bin/java
013cd000-013ee000 rw-p 00000000 00:00 0 [heap]
6f0000000-800000000 rw-p 00000000 00:00 0
3056400000-3056416000 r-xp 00000000 08:02 57409539 /lib64/libgcc_s-4.4.7-20120601.so.1
3056416000-3056615000 ---p 00016000 08:02 57409539 /lib64/libgcc_s-4.4.7-20120601.so.1
3056615000-3056616000 rw-p 00015000 08:02 57409539 /lib64/libgcc_s-4.4.7-20120601.so.1
353be00000-353be20000 r-xp 00000000 08:02 57409933 /lib64/ld-2.12.so
353c01f000-353c020000 r--p 0001f000 08:02 57409933 /lib64/ld-2.12.so
353c020000-353c021000 rw-p 00020000 08:02 57409933 /lib64/ld-2.12.so
... ...(省略)

这些信息是虚拟机崩溃时的虚拟内存列表区域。它可以告诉你崩溃原因时哪些类库正在被使用,位置在哪里,还有堆栈和守护页信息。以列表中第一条为例介绍下:

  • 00400000-00401000:内存区域
  • r-xp:权限,r/w/x/p/s分别表示读/写/执行/私有/共享
  • 00000000:文件内的偏移量
  • 08:02:文件位置的majorID和minorID
  • 39454583:索引节点号
  • /home/service/jdk1.7.0_55/bin/java:文件位置

jvm启动参数

再下面是jvm启动参数信息:

VM Arguments:
jvm_args: -Djava.util.logging.config.file=/home/service/tomcat7007-account-web/conf/logging.properties -Xmx4096m -Xms4096m -Xmn2560m -XX:SurvivorRatio=6 -XX:PermSize=256m -XX:MaxPermSize=256m -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:/home/work/webdata/logs/tomcat7007-account-web/develop/gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/work/webdata/logs/tomcat7007-account-web/develop/ -Dtomcatlogdir=/home/work/webdata/logs/tomcat7007-account-web/develop -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=7407 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Djava.endorsed.dirs=/home/service/tomcat7007-account-web/endorsed -Dcatalina.base=/home/service/tomcat7007-account-web -Dcatalina.home=/home/service/tomcat7007-account-web -Djava.io.tmpdir=/home/service/tomcat7007-account-web/temp
java_command: org.apache.catalina.startup.Bootstrap start
Launcher Type: SUN_STANDARD Environment Variables:
JAVA_HOME=/home/service/jdk1.7.0_55
PATH=/opt/zabbix/bin:/opt/zabbix/sbin:/home/service/jdk1.7.0_55/bin:/home/work/bin:/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/sbin:/home/work/bin
SHELL=/bin/bash

上面是jvm参数,下面是系统的环境配置。

服务器信息

再下面是服务器信息:

/proc/meminfo:
MemTotal: 65916492 kB
MemFree: 14593468 kB
Buffers: 222452 kB
Cached: 28502452 kB
SwapTotal: 0 kB
SwapFree: 0 kB
... ...(省略)
/proc/cpuinfo:
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 62
model name : Intel(R) Xeon(R) CPU E5-2420 v2 @ 2.20GHz
stepping : 4
... ...(省略)

上面是内存信息,主要关注下swap信息,看看有没有使用虚拟内存;下面是cpu信息。

 

JVM致命错误日志(hs_err_pid.log)分析(转载)的更多相关文章

  1. JVM致命错误日志(hs_err_pid.log)分析

    当jvm出现致命错误时,会生成一个错误文件 hs_err_pid<pid>.log,其中包括了导致jvm crash的重要信息,可以通过分析该文件定位到导致crash的根源,从而改善以保证 ...

  2. JVM致命错误日志(hs_err_pid.log)解读

    JVM致命错误日志(hs_err_pid.log)解读 摘自:https://blog.csdn.net/u013938484/article/details/51811400 2016年07月02日 ...

  3. JVM致命错误日志详解

    目录 文件描述 文件位置 文件头 错误信息记录 JVM运行信息 崩溃原因 错误信息 线程描述 线程信息 信号信息 计数器信息 机器指令 内存映射信息 线程堆栈 其他信息 进程描述 线程列表 虚拟机状态 ...

  4. 详细分析MySQL事务日志(redo log和undo log) 表明了为何mysql不会丢数据

    innodb事务日志包括redo log和undo log.redo log是重做日志,提供前滚操作,undo log是回滚日志,提供回滚操作. undo log不是redo log的逆向过程,其实它 ...

  5. 详细分析MySQL事务日志(redo log和undo log)

    innodb事务日志包括redo log和undo log.redo log是重做日志,提供前滚操作,undo log是回滚日志,提供回滚操作. undo log不是redo log的逆向过程,其实它 ...

  6. 【PHP】善用php-fpm的慢执行日志slow log,分析php性能问题

    (转)善用php-fpm的慢执行日志slow log,分析php性能问题  众所周知,mysql有slow query log,根据慢查询日志,我们可以知道那些sql语句有性能问题.作为mysql的好 ...

  7. 【MySQL (六) | 详细分析MySQL事务日志redo log】

    Reference:  https://www.cnblogs.com/f-ck-need-u/archive/2018/05/08/9010872.html 引言 为了最大程度避免数据写入时 IO ...

  8. apache与nginx日志文件的区别(转载)

    apache与nginx日志文件的区别 转载:http://www.xfcodes.com/apache/log/3270.htm 导读:apache与nginx日志文件的区别,在apache与ngi ...

  9. jvm系列(九):Java GC 分析

    Java GC就是JVM记录仪,书画了JVM各个分区的表演. 什么是 Java GC Java GC(Garbage Collection,垃圾收集,垃圾回收)机制,是Java与C++/C的主要区别之 ...

随机推荐

  1. 07.LoT.UI 前后台通用框架分解系列之——强大的文本编辑器

    LOT.UI分解系列汇总:http://www.cnblogs.com/dunitian/p/4822808.html#lotui LoT.UI开源地址如下:https://github.com/du ...

  2. [SGU495] Kids and Prizes (概率dp)

    题目链接:http://acm.sgu.ru/problem.php?contest=0&problem=495 题目大意:有N个盒子,里面都放着礼物,M个人依次去选择盒子,每人仅能选一次,如 ...

  3. [转]永久告别Android的背景选择器Selector!无需切很多图了!

    package com.zoke.custom.autobg; import android.content.Context; import android.content.res.TypedArra ...

  4. 自定义控件,上图下字的Button,图片任意指定大小

    最近处在安卓培训期,把自己的所学写成博客和大家分享一下,今天学的是这个自定义控件,上图下字的Button安卓自带,但是苦于无法设置图片大小(可以在代码修改),今天自己做了一个,首先看一下效果图,比较实 ...

  5. 【问题解决方案】下载GitHub里的单个文件

    背景:在不把整个项目弄下来的情况下 步骤:raw --> 右击 --> 链接另存为... 参考:如何用浏览器从 github 上下载某项目中的单个文本文件

  6. CF809E Surprise me!(莫比乌斯反演+Dp(乱搞?))

    题目大意: 给你一棵树,树上的点编号为\(1-n\).选两个点\(i.j\),能得到的得分是\(\phi(a_i*a_j)*dis(i,j)\),其中\(dis(i,j)\)表示\(a\)到\(b\) ...

  7. 你不可不知的Java引用类型之——WeakReference源码详解

    定义 WeakReference是弱引用,该引用不会影响垃圾回收器对对象的回收,不会影响对象的生命周期. 说明 当虚拟机在某个时间点决定要回收一个弱可达(weakly-reachable)对象时,会自 ...

  8. 安装Androidsdudio时

    安装Androidsdudio时,Androidsdudio的路劲可以任意选择,但Androidsdk的路劲就默认到c盘里.然后安装后就可以直接用了

  9. linux 系统全盘恢复

    恢复备份 一.准备 1. 从 u盘启动,进入 live-cd 系统,配置好网络和镜像源,更新一下仓库的数据库. sudo pacman -Syy 2. 安装 timeshift 这个软件. sudo ...

  10. Linux基础命令---验证组文件grpck

    grpck grpck指令可以验证组文件“/etc/group”和“/etc/gshadow”的完整性.检查的内容包括:正确的字段数.唯一有效的组名称.有效的组标识符.成员和管理员的有效列表.“/et ...