Fatal Error log format,JVM 致命错误日志格式
本文翻译自: http://www.oracle.com/technetwork/java/javase/felog-138657.html
本文内容基于 Java SE 6,HotSpot JVM。
当一个致命错误发生时,一个错误日志将被创建,存储了在致命错误发生时获取到的信息和状态。
注意:这个文件的格式可能随着版本的更新而改变。
C.1 致命错误日志位置
产品标志 -XX:ErrorFile=file
可以指定文件在哪里创建, file
表示了文件位置的完整路径。 file
里的子字符串 %%
将被转换为 %
, %p
将被转换为进程ID。
在下面的例子里,错误日志文件将被写到 /var/log/java
目录、被命名为 java_error Pid
.log : java -XX:ErrorFile=/var/log/java/java_error%p.log
。
如果 -XX:ErrorFile=file
标志没有指定,默认的文件名是 hs_err_ pid
.log,pid是进程ID。
另外,如果没有指定 -XX:ErrorFile=file
标志,系统尝试在进程的工作目录创建文件。万一不能在工作目录创建文件(空间不足、权限问题或其他问题),文件将在操作系统的临时目录里创建。在Solaris和Linux上临时目录是 /tmp
。在Windows上临时目录由环境变量 TMP
指定;如果那个环境变量没有指定,将使用 TEMP
环境变量。
C.2 致命错误日志描述
错误日志包含在致命错误发生时获取到的信息,如果可能,包括下面的信息:
- 操作异常或激起致命错误的信号
- 版本信息和配置信息
- 激起致命错误的线程细节和线程的栈痕迹trace
- 正在运行的线程列表和它们的状态
- 堆的概要信息
- 已加载的本地类库(native libraries)列表
- 命令行参数
- 环境变量
- 操作系统和CPU的细节
注意:在某些情况下,只有这些信息的子集会被输出到错误日志。这在致命错误非常严重以至于错误处理器没法回复并报告所有细节。
错误日志是一个文本文件保护下面的章节:
- 一个头提供了崩溃的简要描述。
- 一个章节描述了线程信息。
- 一个章节描述了进程信息。
- 一个章节描述了系统信息。
注意:这个致命错误日志描述的格式是基于Java SE 6。格式在不同的发布版之间可能不同。
C.3 头格式
头章节在每个致命错误日志文件的开头,包含了问题的简要描述。头也会被输出到标准输出,可能会出现了应用程序的输出日志里。
头包含一个到 HotSpot 虚拟机错误报告页面的链接,在那里用户可以提交bug报告。
下面的一个崩溃的头示例:
#
# An unexpected error has been detected by Java Runtime Environment:
#
# SIGSEGV (0xb) at pc=0x417789d7, pid=21139, tid=1024
#
# Java VM: Java HotSpot(TM) Client VM (1.6.0-rc-b63 mixed mode, sharing)
# Problematic frame:
# C [libNativeSEGV.so+0x9d7]
#
# If you would like to submit a bug report, please visit:
# http://bugreport.sun.com/bugreport/crash.jsp
#
示例显示了VM在一个意外信号上崩溃。下一行描述了信号类型,导致信号的程序计数器(PC),进程ID和线程ID,如下:
# SIGSEGV (0xb) at pc=0x417789d7, pid=21139, tid=1024
| | | | +--- thread id
| | | +------------- process id
| | +--------------------------- program counter
| | (instruction pointer)
| +--------------------------------------- signal number
+---------------------------------------------- signal name
下一行包含了VM版本(Client VM或Server VM),一个指示指明了应用程序是否运行在混合或解释模式下,一个指示表明是否允许类文件共享。
# Java VM: Java HotSpot(TM) Client VM (1.6.0-rc-b63 mixed mode, sharing)
接下来的信息是导致崩溃的函数帧,如下:
# Problematic frame:
# C [libNativeSEGV.so+0x9d7]
| +-- Same as pc, but represented as library name and offset.
| For position-independent libraries (JVM and most shared
| libraries), it is possible to inspect the instructions
| that caused the crash without a debugger or core file
| by using a disassembler to dump instructions near the
| offset.
+----------------- Frame type
在这个例子里,”C” 帧类型表示是一个本地 C 帧。下面的表展示了可能的帧类型:
帧类型描述C本地 C 帧j解释执行的 Java 帧VVM 帧vVM 生成的桩(stub)帧J其他帧类型,包括编译了的Java帧
内部错误将导致VM错误处理器生成一个类似的错误dump,然而,头格式是不同的。Examples of internal errors are guarantee() failure, assertion failure, ShouldNotReachHere(), and so forth。内部错误的头看起来是这样的:
#
# 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"
和一个长的十六进制字符串。这个十六进制字符串编码了检测到错误发生的源模块和行号。通常情况下这个 “错误字符串” 对HotSpot 虚拟机的开发工程师很有用。
错误字符串编码了行号,因此它可能随着代码改变和发表而改变。这个错误字符串只对产生它的VM有意义。
C.4 线程章节格式
这个章节包含了导致崩溃的线程的信息。如果有多个线程在同一时间崩溃,只有一个线程将被输出。
C.4.1 线程格式
线程章节的第一部分显示了激起致命错误的线程,如下:
Current thread (0x0805ac88): JavaThread "main" [_thread_in_native, id=21139]
| | | | +-- ID
| | | +------------- state
| | +-------------------------- name
| +------------------------------------ type
+-------------------------------------------------- pointer
线程指针指向Java VM内部线程结构。通常没有用处,除非正在调试一个活的Java VM或core文件。
下面的列表显示了可能的线程类型:
- JavaThread
- VMThread
- CompilerThread
- GCTaskThread
- WatcherThread
- ConcurrentMarkSweepThread
下面的表显示了重要的线程状态:
线程状态描述_thread_uninitialized线程未被创建。这仅在内存腐化时发生。_thread_new线程已被创建但还没有启动。_thread_in_native线程正在执行本地代码。错误很可能是本地代码bug。_thread_in_vm线程正在执行VM代码
_thread_in_Java
线程正在执行解释的或编译的Java代码
_thread_blocked
线程阻塞…_trans如果上面的状态以字符串 _trans
结尾,表示线程正在转换到不同状态。
输出里的线程ID是本地线程的标识符。
如果Java线程是一个守护线程,字符串 daemon
将被输出到线程状态。
C.4.2 信号信息
错误日志里接下来的信息描述了导致VM终结的意外信号。在Windows系统上输出如下:
siginfo: ExceptionCode=0xc0000005, reading address 0xd8ffecf1
在上面的例子里,异常码是 0xc0000005 (ACCESS_VIOLATION)
,异常在线程尝试读取地址 0xd8ffecf1
时出现。
在Solaris OS和Linux系统上信号数值(si_signo)和信号码(si_code)用于标识异常,如下:
siginfo:si_signo=11, si_errno=0, si_code=1, si_addr=0x00004321
C.4.3 寄存器上下文
错误日志里接下来的信息是致命错误发生时寄存器上下文。输出的精准的格式是依赖处理器的。下面的示例显示了Intel(IA32)处理器的输出:
Registers:
EAX=0x00004321, EBX=0x41779dc0, ECX=0x080b8d28, EDX=0x00000000
ESP=0xbfffc1e0, EBP=0xbfffc1f8, ESI=0x4a6b9278, EDI=0x0805ac88
EIP=0x417789d7, CR2=0x00004321, EFLAGS=0x00010216
寄存器的值与指令结合起来可能很有用。
C.4.4 机器指令
C.4.5 线程栈
如果可能,错误日志接下来的输出是线程栈。这包括栈的基地址和栈顶地址、当前栈的指针和线程未使用的当前可获取的栈的数量。如果可能,后续是栈的帧,最多输出100个帧。对于C/C++帧,库的名字也会被输出。很重要的一点是要注意到在一些知名错误条件下栈可能已经被损坏,在这种情况下,细节可能不可得。
Stack: [0x00040000,0x00080000), sp=0x0007f9f8, free space=254k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V [jvm.dll+0x83d77]
C [App.dll+0x1047]
j Test.foo()V+0
j Test.main([Ljava/lang/String;)V+0
v ~StubRoutines::call_stub
V [jvm.dll+0x80f13]
V [jvm.dll+0xd3842]
V [jvm.dll+0x80de4]
C [java.exe+0x14c0]
C [java.exe+0x64cd]
C [kernel32.dll+0x214c7]
Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j Test.foo()V+0
j Test.main([Ljava/lang/String;)V+0
v ~StubRoutines::call_stub
日志包含了两个线程栈:
-
第一个线程栈是本地帧,输出了本地线程,显示了所有函数调用。
-
第二个线程栈是Java帧,输出了包含内联了方法的Java帧,跳过了本地帧。取决于崩溃,可能没法输出本地线程栈,但可能输出Java帧。
C.4.6 更多细节
如果错误在VM线程或编译器线程里发生,更多的细节将被输出。例如,在VM线程的情况下,如果VM线程在致命错误发生时执行一个VM操作,VM操作将被输出。在下面的输出例子里,编译器线程激起一个致命错误,任务是编译任务,HotSpot客户端VM正在编译方法 hs101t004Thread.ackermann
:
Current CompileTask:
HotSpot Client Compiler:754 b
nsk.jvmti.scenarios.hotswap.HS101.hs101t004Thread.ackermann(IJ)J (42 bytes)
HotSpot服务器VM的输出对于编译任务有轻微的区别,但也包括完整的类名字和方法。
C.5 进程章节格式
进程章节输出在线程章节之后。它包含了整个进行的信息,包括线程列表和进程的内存使用。
C.5.1 线程列表
线程列表包含了VM知道的线程。这包括Java线程和一些VM内部线程,但不包括用户应用程序创建的、没有附加到VM的任何本地线程。输出格式如下:
=>0x0805ac88 JavaThread "main" [_thread_in_native, id=21139]
| | | | | +----- ID
| | | | +------------------- state
| | | | (JavaThread only)
| | | +--------------------------------- name
| | +------------------------------------------ type
| +---------------------------------------------------- pointer
+------------------------------------------------------ "=>" current thread
这是后续输出的一个例子:
Java Threads: ( => current thread )
0x080c8da0 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=21147]
0x080c7988 JavaThread "CompilerThread0" daemon [_thread_blocked, id=21146]
0x080c6a48 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=21145]
0x080bb5f8 JavaThread "Finalizer" daemon [_thread_blocked, id=21144]
0x080ba940 JavaThread "Reference Handler" daemon [_thread_blocked, id=21143]
=>0x0805ac88 JavaThread "main" [_thread_in_native, id=21139]
Other Threads:
0x080b6070 VMThread [id=21142]
0x080ca088 WatcherThread [id=21148]
线程类型和线程状态在 线程章节格式 描述。
C.5.2 VM 状态
接下来是VM状态,指示了虚拟机的整体状态。下面的表描述了一般的状态:
一般的VM状态描述not at a safepoint常规执行。at a safepointVM内的所有线程阻塞等待特定的VM操作完成。synchronizing特殊的VM操作要求VM 等待VM内的所有线程阻塞
VM状态在错误日志里单独一行输出,如下:
VM state:not at safepoint (normal execution)
C.5.3 互斥量和监视器
错误日志里接下来的信息是由当前线程持有的互斥量和监视器列表。这些互斥量是VM内部锁,而不是与Java对象关联的监视器。下面的例子显示了崩溃时被持有的VM锁看起来是怎样的。对于每个所,日志包含了所的名字、它的属主和VM内部互斥结构体的地址和它的OS锁。一般情况下这个信息对于那些非常熟悉HotSpot VM的人有用。属主线程可能交叉引用到线程列表。
VM Mutex/Monitor currently owned by a thread:
([mutex/lock_event])[0x007357b0/0x0000031c] Threads_lock - owner thread: 0x00996318
[0x00735978/0x000002e0] Heap_lock - owner thread: 0x00736218
C.5.4 堆汇总
接下来的信息是堆汇总。输出依赖于GC配置。在这个例子里使用串行收集器,禁止类数据共享,tenured代是空的。这可能表示致命错误发生得早或在启动阶段发生,且GC还没有提升任何对象到tenured代。示例如下:
Heap
def new generation total 576K, used 161K [0x46570000, 0x46610000, 0x46a50000)
eden space 512K, 31% used [0x46570000, 0x46598768, 0x465f0000)
from space 64K, 0% used [0x465f0000, 0x465f0000, 0x46600000)
to space 64K, 0% used [0x46600000, 0x46600000, 0x46610000)
tenured generation total 1408K, used 0K [0x46a50000, 0x46bb0000, 0x4a570000)
the space 1408K, 0% used [0x46a50000, 0x46a50000, 0x46a50200, 0x46bb0000)
compacting perm gen total 8192K, used 1319K [0x4a570000, 0x4ad70000, 0x4e570000)
the space 8192K, 16% used [0x4a570000, 0x4a6b9d48, 0x4a6b9e00, 0x4ad70000)
No shared spaces configured.
C.5.5 内存映射
日志里接下来的信息是崩溃时的虚拟内存区域列表。这个列表在大的应用程序里可能 长。内存映射在调试一些崩溃时很有用,因为它能告诉你实际使用了什么屏障,它们在内存中的位置,在堆的位置和监视页面。
内存映射的格式是操作系统特定的。在Solaris操作系统上,基地址和库的名字将被输出。在Windows系统上,每个库的基地址和结束地址将被输出。下面的输出示例在Linux/X86上生成,注意,例子里的很多行为了简介的目的都忽略了。
Dynamic libraries:
08048000-08056000 r-xp 00000000 03:05 259171 /h/jdk6/bin/java
08056000-08058000 rw-p 0000d000 03:05 259171 /h/jdk6/bin/java
08058000-0818e000 rwxp 00000000 00:00 0
40000000-40013000 r-xp 00000000 03:0a 400046 /lib/ld-2.2.5.so
40013000-40014000 rw-p 00013000 03:0a 400046 /lib/ld-2.2.5.so
40014000-40015000 r--p 00000000 00:00 0
Lines omitted.
4123d000-4125a000 rwxp 00001000 00:00 0
4125a000-4125f000 rwxp 00000000 00:00 0
4125f000-4127b000 rwxp 00023000 00:00 0
4127b000-4127e000 ---p 00003000 00:00 0
4127e000-412fb000 rwxp 00006000 00:00 0
412fb000-412fe000 ---p 00083000 00:00 0
412fe000-4137b000 rwxp 00086000 00:00 0
Lines omitted.
44600000-46570000 rwxp 00090000 00:00 0
46570000-46610000 rwxp 00000000 00:00 0
46610000-46a50000 rwxp 020a0000 00:00 0
46a50000-46bb0000 rwxp 00000000 00:00 0
46bb0000-4a570000 rwxp 02640000 00:00 0
Lines omitted.
上面内存映射的行格式如下:
40049000-4035c000 r-xp 00000000 03:05 824473 /jdk1.5/jre/lib/i386/client/libjvm.so
|<------------->| ^ ^ ^ ^ |<----------------------------------->|
Memory region | | | | |
| | | | |
Permission --- + | | | |
r: read | | | |
w: write | | | |
x: execute | | | |
p: private | | | |
s: share | | | |
| | | |
File offset ----------+ | | |
| | |
Major ID and minor ID of -------+ | |
the device where the file | |
is located (i.e. /dev/hda5) | |
| |
inode number ------------------------+ |
|
File name -------------------------------------------------------+
在内存映射输出里,每个库有两个虚拟内存区域:一个用于代码,一个用于数据。代码段的许可被标识为 r-xp(可读、可执行、私有)
,数据段的许可被标识为 rw-p(可读、可写、私有)
。
Java堆已经包含了堆的概要,但它对于验证
C.5.6 VM参数和环境变量
错误日志里接下来的信息是VM参数列表,后接环境变量列表。示例:
VM Arguments:
java_command: NativeSEGV 2
Environment Variables:
JAVA_HOME=/h/jdk
PATH=/h/jdk/bin:.:/h/bin:/usr/bin:/usr/X11R6/bin:/usr/local/bin:
/usr/dist/local/exe:/usr/dist/exe:/bin:/usr/sbin:/usr/ccs/bin:
/usr/ucb:/usr/bsd:/usr/etc:/etc:/usr/dt/bin:/usr/openwin/bin:
/usr/sbin:/sbin:/h:/net/prt-web/prt/bin
USERNAME=user
LD_LIBRARY_PATH=/h/jdk6/jre/lib/i386/client:/h/jdk6/jre/lib/i386:
/h/jdk6/jre/../lib/i386:/h/bugs/NativeSEGV
SHELL=/bin/tcsh
DISPLAY=:0.0
HOSTTYPE=i386-linux
OSTYPE=linux
ARCH=Linux
MACHTYPE=i386
注意环境变量的列表只是作用于Java VM的环境变量的一个子集。
C.5.7 信号处理器
在Solaris OS和Linux上,错误日志里接下来的信息是信号处理器列表。
Signal Handlers:
SIGSEGV: [libjvm.so+0x3aea90], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGBUS: [libjvm.so+0x3aea90], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGFPE: [libjvm.so+0x304e70], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGPIPE: [libjvm.so+0x304e70], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGILL: [libjvm.so+0x304e70], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGUSR1: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGUSR2: [libjvm.so+0x306e80], sa_mask[0]=0x80000000, sa_flags=0x10000004
SIGHUP: [libjvm.so+0x3068a0], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGINT: [libjvm.so+0x3068a0], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGQUIT: [libjvm.so+0x3068a0], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGTERM: [libjvm.so+0x3068a0], sa_mask[0]=0xfffbfeff, sa_flags=0x10000004
SIGUSR2: [libjvm.so+0x306e80], sa_mask[0]=0x80000000, sa_flags=0x10000004
C.6 系统章节格式
错误日志里最后的章节是系统信息。输出是操作系统特定的,但一般包括操作系统版本、CPU信息和内存配置的概要信息。
下面的示例显示Solaris 9 OS系统上的输出:
--------------- S Y S T E M ---------------
OS: Solaris 9 12/05 s9s_u5wos_08b SPARC
Copyright 2005 Sun Microsystems, Inc. All Rights Reserved.
Use is subject to license terms.
Assembled 21 November 2005
uname:SunOS 5.9 Generic_112233-10 sun4u (T2 libthread)
rlimit: STACK 8192k, CORE infinity, NOFILE 65536, AS infinity
load average:0.41 0.14 0.09
CPU:total 2 has_v8, has_v9, has_vis1, has_vis2, is_ultra3
Memory: 8k page, physical 2097152k(1394472k free)
vm_info: Java HotSpot(TM) Client VM (1.5-internal) for solaris-sparc,
built on Aug 12 2005 10:22:32 by unknown with unknown Workshop:0x550
在Solaris OS和Linux上,操作系统信息是包含在文件 /etc/*release
的。这个文件描述运行应用程序的系统类型,在某些情况下还包含补丁级别的字符串信息。有些系统更新不能反应在 /etc/*release
文件里。特别是在Linux系统(在其上用户可以重建系统的任意部分)上尤其如此。
在Solaris OS上 uname
系统调用用于获得内核的名字。线程库(T1或T2)也会被输出。
在Linux系统上 uname
系统调用也用于获取内核的名字。 libc
版本和线程库类型也会被输出,如:
uname:Linux 2.4.18-3smp #1 SMP Thu Apr 18 07:27:31 EDT 2002 i686
libc:glibc 2.2.5 stable linuxthreads (floating stack)
|<- glibc version ->|<-- pthread type -->|
原文还提到输出里的不同线程模型,由于我的Ubuntu上的
uname -a
命令不输出这些,就不翻译了。
在Solaris OS和Linux上,接下来的信息是 rlimit
信息,注意,VM默认的栈大小一般小于系统的限制。如:
rlimit: STACK 8192k, CORE 0k, NPROC 4092, NOFILE 1024, AS infinity
| | | | virtual memory (-v)
| | | +--- max open files (ulimit -n)
| | +----------- max user processes (ulimit -u)
| +------------------------- core dump size (ulimit -c)
+---------------------------------------- stack size (ulimit -s)
load average:0.04 0.05 0.02
接下来的信息指出了CPU架构和在VM启动时指定的能力,如下:
CPU:total 2 family 6, cmov, cx8, fxsr, mmx, sse | | |<----- CPU features ---->| | | | +--- processor family (IA32 only): | 3 - i386 | 4 - i486 | 5 - Pentium | 6 - PentiumPro, PII, PIII | 15 - Pentium 4 +------------ Total number of CPUs
接下来的信息是内存信息,如下:
unused swap space
total amount of swap space |
unused physical memory | |
total amount of physical memory | | |
page size | | | |
v v v v v
Memory: 4k page, physical 513604k(11228k free), swap 530104k(497504k free)
有些系统要求交换空间放宽到实际物理内存的两倍,其他系统可能没有这样的要求。一般的规则是,如果物理内存和交换空间都快满了,这是个怀疑由于不充足内存和崩溃的很好理由。
在Linux系统上,内核可能把大多数不用的物理内存转换为文件缓存。当需要更多内存时,内核将归还缓存内存给应用程序。这个由内核透明地处理,但它确实意味这错误处理器报告的未使用的物理内存可能接近于 0,而仍然有足够的物理内存可获得。
错误日志里SYSTEM章节里的最后信息是 vm_info
,是内嵌在 libjvm.so/jvm.dll
里的版本字符串。每个Java VM有一个独特的 vm_info
字符串。如果你怀疑致命错误日志是否由特定的Java JVM生成,检查版本字符串。