亲宝软件园·资讯

展开

JVM致命错误日志详解

☆★傲天★☆ 人气:2
[toc] 最近一段时间生产环境频繁出问题,每次都会生成一个hs_err_pid*.log文件,因为工作内容的原因,之前并没有了解过相关内容,趁此机会学习下,根据项目的使用情况,此文章针对JDK 8进行分析,不过因为素材问题,文章中引用的文件内容为JDK 7生成的文件,此处应该不影响,因为官方文档中关于此部分说明使用的是JDK 6生成的文件。我们将按照内容在文件中出现的顺序进行介绍。 *PS:本人水平有限,工作中也没有太多机会进行此类知识的应用,文章内容绝大多数来自于官方文档,某些内容在官网中并没有涉及,相应的介绍不一定准确,希望各位大佬不吝赐教* > JDK 8 > 官方文档下载地址:[https://www.oracle.com/java/technologies/javase-jdk8-doc-downloads.html](https://www.oracle.com/java/technologies/javase-jdk8-doc-downloads.html) > 致命错误日志文档:https://img.qb5200.com/download-x/docs/technotes/guides/troubleshoot/felog.html#fatal_error_log_vm > JDK 7 > 官方文档地址:[https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/](https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/) > 致命错误日志文档:[https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/webnotes/tsg/TSG-VM/html/felog.html](https:/https://img.qb5200.com/download-x/docs.oracle.com/javase/7https://img.qb5200.com/download-x/docs/webnotes/tsg/TSG-VM/html/felog.html) ## 文件描述 错误日志是在JVM遇到致命错误时生成的日志文件,可能包括以下信息: * 引发致命错误的异常操作或信号 * 版本和配置信息 * 引发致命错误的线程详细信息和线程堆栈记录 * 正在运行的线程及其状态的列表 * 有关堆的概要信息 * 加载的本机库的列表 * 命令行参数 * 环境变量 * 操作系统和 CPU 的详细信息 > 当问题严重到错误处理器无法收集并报告所有信息时,可能只有一部分信息会写入错误日志。 文件总共分为一下几个章节: * 简单描述崩溃信息的文件头 * 线程描述部分 * 进程描述部分 * 系统信息部分 ## 文件位置 致命错误日志文件位置可以通过 `-XX:ErrorFile`进行指定,例如: ```bash java * -XX:ErrorFile=/var/log/java/java_error%p.log ``` 以上设置表示文件会放在`/var/log/java`目录下,`%p`表示进程的PID。如果不设置`XX:ErrorFile`属性,日志默认生成在执行java命令的目录下,文件名默认为`hs_err_pid%p.log`,如果该目录因为某种情况无法写入(空间不足,权限不足等),在linux系统下默认写到`/tmp`目录下,windows系统下默认使用环境变量中`TMP`对应的目录,如果没有则使用`TEMP`对应的目录(TMP和TEMP均为windows默认的环境变量,且默认值一样)。 ## 文件头 文件头在错误日志的最开头,主要是对问题的简单描述。这部分内容同样会打印到标准输出,可能也会打印到应用程序的控制台上。示例如下: ```xml # # A fatal error has been detected by the Java Runtime Environment: # # SIGSEGV (0xb) at pc=0x00007f80e0cd095c, pid=48, tid=140189843019520 # # JRE version: Java(TM) SE Runtime Environment (7.0_80-b15) (build 1.7.0_80-b15) # Java VM: Java HotSpot(TM) 64-Bit Server VM (24.80-b11 mixed mode linux-amd64 compressed oops) # Problematic frame: # V [libjvm.so+0x65395c] jni_SetByteArrayRegion+0x19c # # Core dump written. Default location: /apps/gateway/project/bin/core or core.48 # # If you would like to submit a bug report, please visit: # http://bugreport.java.com/bugreport/crash.jsp # ``` ### 错误信息记录 前两行主要描述了信号类型、发起信号的程序计数器、进程ID和线程ID,如下所示: ```xml # SIGSEGV (0xb) at pc=0x00007f80e0cd095c, pid=48, tid=140189843019520 | | | | | | | | | +--- 线程ID | | | +----------- 进程ID | | +-------------------------------- 程序计数器对应的指针 | +-------------------------------------------- 信号值(十六进制) +--------------------------------------------------- 信号名称 ``` 信号名称是操作系统自身的一种信息,CentOS 7下共有以下35种,可在/usr/include/bits/signum.h中查看其具体的声明 信号名称 | 信号值 | 含义 -|-|- SIGHUP | 1 | Hangup (POSIX). SIGINT | 2 | Interrupt (ANSI). SIGQUIT | 3 | Quit (POSIX). SIGILL | 4 | Illegal instruction (ANSI). SIGTRAP | 5 | Trace trap (POSIX). SIGABRT | 6 | Abort (ANSI). SIGIOT | 6 | IOT trap (4.2 BSD). SIGBUS | 7 | BUS error (4.2 BSD). SIGFPE | 8 | Floating-point exception (ANSI). SIGKILL | 9 | Kill, unblockable (POSIX). SIGUSR1 | 10 | User-defined signal 1 (POSIX). SIGSEGV | 11 | Segmentation violation (ANSI). SIGUSR2 | 12 | User-defined signal 2 (POSIX). SIGPIPE | 13 | Broken pipe (POSIX). SIGALRM | 14 | Alarm clock (POSIX). SIGTERM | 15 | Termination (ANSI). SIGSTKFLT | 16 | Stack fault. SIGCLD | SIGCHLD | Same as SIGCHLD (System V). SIGCHLD | 17 | Child status has changed (POSIX). SIGCONT | 18 | Continue (POSIX). SIGSTOP | 19 | Stop, unblockable (POSIX). SIGTSTP | 20 | Keyboard stop (POSIX). SIGTTIN | 21 | Background read from tty (POSIX). SIGTTOU | 22 | Background write to tty (POSIX). SIGURG | 23 | Urgent condition on socket (4.2 BSD). SIGXCPU | 24 | CPU limit exceeded (4.2 BSD). SIGXFSZ | 25 | File size limit exceeded (4.2 BSD). SIGVTALRM | 26 | Virtual alarm clock (4.2 BSD). SIGPROF | 27 | Profiling alarm clock (4.2 BSD). SIGWINCH | 28 | Window size change (4.3 BSD, Sun). SIGPOLL | SIGIO | Pollable event occurred (System V). SIGIO | 29 | I/O now possible (4.2 BSD). SIGPWR | 30 | Power failure restart (System V). SIGSYS | 31 | Bad system call. SIGUNUSED | 31 | - ### JVM运行信息 接下来两行描述了JVM相关版本信息及运行配置信息,内容如下: ``` # JRE version: Java(TM) SE Runtime Environment (7.0_80-b15) (build 1.7.0_80-b15) # Java VM: Java HotSpot(TM) 64-Bit Server VM (24.80-b11 mixed mode linux-amd64 compressed oops) ``` 上述文件内容可以得知以下几点: * JRE版本号为1.7u80 * JVM版本号为24.80-b11 * JVM运行在Server模式下。对应的是Client模式,Client JVM适合需要快速启动和较小内存空间的应用,它适合交互性的应用,比如GUI;而Server JVM则是看重执行效率的应用的最佳选择,更适合服务端应用。 * JVM运行在混合模式下,即mixed mode,是JVM默认的运行模式。其他模式还有解释模式(interpreted mode)和编译模式(compiled mode),解释模式会强制JVM以解释方式执行所有的字节码,编译模式下JVM在第一次使用时会把所有的字节码编译成本地代码,这两种模式各有优劣,单独使用时都会有部分性能上的损失,所以默认使用混合模式即可,混合模式下对于字节码中多次被调用的部分,JVM会将其编译成本地代码以提高执行效率;而被调用很少(甚至只有一次)的方法在解释模式下会继续执行,从而减少编译和优化成本。 ### 崩溃原因 接下来两行描述了引发崩溃问题的函数帧 ```xml # Problematic frame: # V [libjvm.so+0x65395c] jni_SetByteArrayRegion+0x19c | | | +-- 类似于程序计数器, 以库名和偏移量表示。 | 对于与位置无关的库(JVM和其他库),可以不通过 | 调试器或通过反汇编程序转存偏移量周围结 | 构的core文件来定位引起崩溃的指令。 +----------------- 帧类型 ``` 帧类型包括以下几种: 帧类型 | 描述 - | - C | Native C frame j | Interpreted Java frame V | VMframe v | VMgenerated stub frame J | Other frame types, including compiled Java frames 关于例子中描述的`jni_SetByteArrayRegion+0x19c`这部分目前没有找到相关的资料,官方给的示例中并没有这一部分,根据字面含义来看,此部分应该表示的是崩溃时正在通过JNI方式调用SetByteArrayRegion方法。 ### 错误信息 接下来的错误信息部分根据不同错误显示不一样的内容,在官方给的资料中提供了一份关于内部错误的错误信息,示例如下: ```xml # An unexpected error has been detected by HotSpot Virtual Machine: # Internal Error (4F533F4C494E55583F491418160E43505000F5), pid=10226, tid=16384 # Java VM: Java HotSpot(TM) Client VM (1.6.0-rc-b63 mixed mode) ``` 以上示例中提供的内容没有信号名称和信号值,只包含了`Internal Error`和一个十六进制的字符串,该字符串对出现问题的模块和行号进行了编码,通常情况下只对JVM工程师有用。 因为我们生产环境上出现的问题和示例中的问题种类不一样,所以我们拿到了这样一段信息: ```xml # Core dump written. Default location: /apps/gateway/project/bin/core or core.48 # If you would like to submit a bug report, please visit: # http://bugreport.java.com/bugreport/crash.jsp ``` 这段信息中记录了core dump文件的位置和官方的BUG反馈页面地址,针对具体问题则需要查看core dump文件了。 ## 线程描述 这一部分描述崩溃时正在运行的线程信息,如果有多个线程同时崩溃,只会打印其中一个线程的信息。 ### 线程信息 ``` Current thread (0x00007f80dc8ce000): JavaThread "RcvThread: com.*.*.*.remote.internal.RemoteTCPConnection[qmid=*,fap=10,peer=/*.*.*.9,localport=*,ssl=no]" daemon [_thread_in_native_trans, id=90,stack(0x00007f807dbb5000,0x00007f807dcb6000)] ``` 第一部分展示了引发致命错误的线程,以上为生产的实际信息,因为敏感信息,内容中部分字段使用`*`进行了脱敏。各部分说明如下: ``` Current thread (0x0805ac88): JavaThread "main" [_thread_in_native, id=21139, stack(0x7dbb5000, 0x7dcb6000)] | | | | | | | | | | | +--------- 栈区间 | | | | +---------------------- ID | | | +--------------------------------- 状态 | | +---------------------------------------------- 名称 | +-------------------------------------------------------- 类型 +---------------------------------------------------------------------- 指针 ``` 线程指针指的是JVM内部的线程结构,一般只在实时调试JVM或core文件时才会有用。线程类型包括以下几种: * `JavaThread` * `VMThread` * `CompilerThread` * `GCTaskThread` * `WatcherThread` * `ConcurrentMarkSweepThread` `daemon`标识进程为守护进程,该项不一定会存在。 接下来的线程状态中常见的有以下几种: Thread State | Description - | - _thread_uninitialized | 线程未创建,仅在内存崩溃时出现。 _thread_new | 线程已被创建,但是没有启动。 _thread_in_native | 线程正在执行本地代码,可能因为本地代码的BUG导致此问题。 _thread_in_vm | 线程正在执行虚拟机代码。 _thread_in_Java | 线程正在执行编译或解释后的Java代码。 _thread_blocked | 线程被阻塞。 ..._trans | 以上状态如果后边带有`_trans`,表示线程正在切换状态。 ### 信号信息 ``` siginfo:si_signo=SIGSEGV: si_errno=0, si_code=0 (SEGV0), si_addr=0x0000000000000000 ``` 信号信息描述了导致JVM终止的异常信号信息,此部分信息根据操作系统不同会有所区别,上边的例子是linux服务器下生成的内容,在windows下内容如下: ``` siginfo: ExceptionCode=0xc0000005, reading address 0xd8ffecf1 | | | +--------- 线程异常时读取的地址 +------------------------------------ 异常码 ``` ### 计数器信息 ``` Registers: RAX=0x00007f80e2109e00, RBX=0x00007f80dc8ce000, RCX=0x0000000000001a70, RDX=0x00007f80e14c87f0 RSP=0x00007f807dca4710, RBP=0x00007f807dca4780, RSI=0x00007f807dcb47f8, RDI=0x00007f80dc8ce1e8 R8 =0x00007f807dca47a0, R9 =0x000000000000005a, R10=0x0000000000000000, R11=0x0000000000000000 R12=0x00007f807dcb47f8, R13=0x0000000000001a70, R14=0x0000000000000000, R15=0x00007f80e14c8800 RIP=0x00007f80e0cd095c, EFLAGS=0x0000000000010206, CSGSFS=0xffff000000000033, ERR=0x0000000000000007 TRAPNO=0x000000000000000e ``` 此部分内容为程序崩溃时程序计数器中的内容,这一部分的打印格式和服务器的处理器类型有关,以上为我手中文件的内容,这一部分内容与下一部分结合来看会比较有用(实际上也没看懂)。 ### 机器指令 ``` Top of Stack: (sp=0x00007f807dca4710) 0x00007f807dca4710: 0000000000007ffe 00007f807dca47a0 0x00007f807dca4720: 00007f807dcb5700 00007f807dcb5680 ...... 0x00007f807dca48f0: 2020202020202020 2020202020202020 0x00007f807dca4900: 2020202020202020 1c00000020202020 Instructions: (pc=0x00007f80e0cd095c) 0x00007f80e0cd093c: ff 0f 1f 00 48 8b 05 59 b3 7b 00 48 89 da 48 c1 0x00007f80e0cd094c: ea 04 8b 00 21 d0 48 8b 15 cf 6f 7b 00 48 03 02 0x00007f80e0cd095c: c7 00 01 00 00 00 e9 b6 fe ff ff 66 0f 1f 84 00 0x00007f80e0cd096c: 00 00 00 00 45 85 ed 74 40 84 c9 74 77 48 8b 05 ``` 以上是博主文件的内容,因为篇幅原因中间部分隐藏了,这一部分内容包含了系统崩溃时程序计数器栈顶的32个指令。这些信息可以通过反编译程序编译出崩溃地址附近的指令。需要注意的是A32和AMD64架构的指令长度不一致,所以并不一定能够反编译出这部分指令。 ### 内存映射信息 ``` Register to memory mapping: RAX=0x00007f80e2109e00 is an unknown value RBX=0x00007f80dc8ce000 is a thread RCX=0x0000000000001a70 is an unknown value RDX=0x00007f80e14c87f0:

加载全部内容

相关教程
猜你喜欢
用户评论