JVM崩溃Log日志分析
【welkin】
    Java的应用有时候会因为各种原因Crash,这时候会产生一个类似java_errorpid.log的错误日志。可以拿到了
    这个日志,怎样分析Crash的原因呢?下面我们来详细讨论如何分析java_errorpid.log的错误日志。
    一. 如何得到这个日志文件
    如果有一个严重的错误引起Java进程非正常退出,我们叫Crash,这时候会产生一个日志文件。缺省情况下,这个
    文件会产生在工作目录下。但是,可以在Java启动参数通过下面的设置,来改变这个文件的位置和命名规则。例如:
    java -XX:ErrorFile=/var/log/java/java_error_%p.log
    就将这个错误文件放在/var/log/java下,并且以java_error_pid.log的形式出现。
    二.产生错误的原因
    造成严重错误的原因有多种可能性。Java虚拟机自身的Bug是原因之一,但是这种可能不是很大。在绝大多数情况下,
    是由于系统的库文件、API或第三方的库文件造成的;系统资源的短缺也有可能造成这种严重的错误。在发生了Crash
    之后,如果无法定位根本原因,也应该迅速找到Work Around的方法。
    三.对日志文件的分析
    首先要检查日志的文件头:例如,下面是从一个客户发过来的错误日志的文件头
    -------------------------------------
    #
    # An unexpected error has been detected by HotSpot VirtualMachine:
    #
    # EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x0815e87e,pid=7268, tid=4360
    #
    # Java VM: Java HotSpot(TM) Server VM (1.4.2_13-b06 mixedmode)
    # Problematic frame:
    # V [jvm.dll+0x15e87e]
    #
    --------------------------------------
    文件头中有很多有用的信息,"EXCEPTION_ACCESS_VIOLATION "意味着Java应用Crash的时候,
    正在运行JVM自己的代码,而不是外部的Java代码或其他类库代码。这种情况很可能是JVM的Bug,但是
    也不一定。除了"EXCEPTION_ACCESS_VIOLATION",还有可能是别的信息,例如"SIGSEGV(0xb)",
    意味着JVM正在执行本地或JNI的代码;"EXCEPTION_STACK_OVERFLOW"意味着这是个栈溢出的错误。
    (**********看到这里我们知道我报错时正在运行JVM自己的代码,而不是外部的Java代码或其他类库代码*********)
    另外一个有用的信息就是:
    # Problematic frame:
    # V [jvm.dll+0x15e87e]
    它说明Crash的时候,JVM正在从哪个库文件执行代码。除了"V"以外,还有可能是"C"、"j"、"v"、"J"。具体的表示意思如下:
    FrameType Description:
    C: Native C frame
    j: Interpreted Java frame
    V: VMframe
    v: VMgenerated stub frame
    J: Other frame types, including compiled Java frames
    (**********看到这里我们知道我报错时是V: VMframe这种情况*********)
    文件头之后,是当前线程的DUMP信息,线程之后是JVM进程的DUMP信息,包括所有线程的状态、地址和ID。最后还有JVM状态,
    Heap状态,动态连接库等等的信息。这些烦乱的信息中,包含有非常有用的信息。下面我们根据几个具体的实例来分析Java虚拟
    机Crash的典型例子。
    四.内存回收引起的Crash
    内存回收引起的Crash有以下的特点:在日志文件头一般有" EXCEPTION_ACCESS _VIOLATION"和
    "# Problematic frame: # V[jvm.dll+...."的信息,意味着这是在JVM内部处理,而且多半是JVM的Bug。
    (**********看到这里我们知道我报错时意味着这是在JVM内部处理,而且多半是JVM的Bug*********)
    对于这类问题,最快的方法就是绕过它。
    另外,在Thread的DUMP信息最后,还能看到有关内存回收的行为例如:
    --------------- T H R E A D ---------------
    Current thread (0x00a56668): VMThread [id=4360]
    siginfo: ExceptionCode=0xc0000005, reading address 0x00000057
    Registers:
    ........
    Stack: [0x03cf0000,0x03d30000), sp=0x03d2fc18, freespace=255k
    Native frames: (J=compiled Java code, j=interpreted, Vv=VM code,C=native code)
    V [jvm.dll+0x15e87e]
    VM_Operation (0x063efbac): full generation collection, mode:safepoint, requested by thread 0x040f83f8
    ------------------------------------------------------------
    可以清楚的看到JVM正在做 "full generation collection"。另外还有可能看到,其他的回收行为:
    generation collection for allocation
    full generation collection
    parallel gc failed allocation
    parallel gc failed permanent allocation
    parallel gc system gc
    (***********这些错,俺都没碰到***********)
    对于内存回收的错误,一般采取改变回收的算法和参数的方法来绕过去。例如,来自客户的日志除了上面的
    日志信息,在日志中Heap信息中还能发现一些其他信息:
    --------------------------------------------------------------
    Heap
    def new generation total 22592K, used 19530K [0x10010000,0x11890000, 0x138f0000)
    eden space 20096K, 97% used [0x10010000, 0x11322bd8,0x113b0000)
    from space 2496K, 0% used [0x113b0000, 0x113b0000,0x11620000)
    to space 2496K, 0% used [0x11620000, 0x11620000, 0x11890000)
    tenured generation total 190696K, used 100019K [0x138f0000,0x1f32a000, 0x30010000)
    the space 190696K, 52% used [0x138f0000, 0x19a9cf38, 0x19a9d000,0x1f32a000)
    compacting perm gen total 38656K, used 38588K [0x30010000,0x325d0000, 0x34010000)
    the space 38656K, 99% used [0x30010000, 0x325bf038, 0x325bf200,0x325d0000)
    ----------------------------------------------------------------
    上面的信息能看出在Crash的时候,JVM的PermSize空间几乎已经消耗完了,并且回收算法在压缩Perm空间的时候出了错。
    因此,建议改变内存回收的算法,或扩大PermSize和MaxPermSize的数值。
    (*******这个倒是可以尝试*******)
    五.栈溢出引起的Crash
    Java代码引起的栈溢出,通常不会引起JVM的Crash,而是抛出一个Java异常:java.lang.StackOverflowError。
    但是在Java虚拟机中,Java的代码和本地C或C++代码公用相同的Stack。这样,在执行本地代码所造成的栈溢出,
    就有可能引起JVM的Crash了。
    栈溢出引起的Crash会在日志的文件头中看到"EXCEPTION_STACK_OVERFLOW"字样。另外,在当前线程的Stack
    信息中也能发现一些信息。例如下面的例子:
    -----------------------------------------------------------------------------------
    # An unexpected error has been detected by HotSpot Virtual     Machine:
    #
    # EXCEPTION_STACK_OVERFLOW (0xc00000fd) at pc=0x10001011, pid=296,tid=2940
    #
    # Java VM: Java HotSpot(TM) Client VM (1.6-internal mixed mode,sharing)
    # Problematic frame:
    # C [App.dll+0x1011]
    #
    --------------- T H R E A D ---------------
    Current thread (0x000367c0): JavaThread "main" [_thread_in_native,id=2940]
    :
    Stack: [0x00040000,0x00080000), sp=0x00041000, free space=4k
    Native frames: (J=compiled Java code, j=interpreted, Vv=VM code,C=native code)
    C [App.dll+0x1011]
    C [App.dll+0x1020]
    C [App.dll+0x1020]
    :
    C [App.dll+0x1020]
    C [App.dll+0x1020]
    ...<more frames>...
    Java frames: (J=compiled Java code, j=interpreted, Vv=VMcode)
    j Test.foo()V+0
    j Test.main([Ljava/lang/String;)V+0
    v ~StubRoutines::call_stub
    --------------------------------------------------------------------------------
    在上面的信息中,可以发现这是个栈溢出的错误。并且当前栈剩余的空间已经很小了(free space =4k)。
    因此建议将JVM的Stack的尺寸调大,主要设计两个参数:"-Xss"和"-XX:StackShadowPages=n"。