Java stack and heap dump

对于大型 java 应用程序来说，再精细的测试都难以堵住所有的漏洞，即便我们在测试阶段进行了大量卓有成效的工作，很多问题还是会在生产环境下暴露出来，并且很难在测试环境中进行重现。JVM 能够记录下问题发生时系统的运行状态并将其存储在转储(dump)文件中，从而为我们分析和诊断问题提供了重要的依据。常见的转储文件包括 Java Dump， Heap dump 和 System dump。这里我们主要介绍 Java dump 在 JVM 故障诊断中的应用。

Java dump，也叫做 Thread dump，是 JVM 故障诊断中最重要的转储文件之一。JVM 的许多问题都可以使用这个文件进行诊断，其中比较典型的包括线程阻塞，CPU 使用率过高，JVM Crash，堆内存不足，和类装载等问题。作为一款轻量级（与 Heap dump 和 System dump 相比）的转储文件，Java dump 的确是我们诊断 JVM 问题的首选。本文将系统的介绍使用 Java dump 进行 JVM 故障诊断的方法和技巧，希望能够为大家提供一些帮助。

jstack Dump 日志文件中的线程状态
dump 文件里，值得关注的线程状态有：

    死锁，Deadlock（重点关注）
    执行中，Runnable  
    等待资源，Waiting on condition（重点关注）
    等待获取监视器，Waiting on monitor entry（重点关注）
    暂停，Suspended
    对象等待中，Object.wait() 或 TIMED_WAITING
    阻塞，Blocked（重点关注） 
    停止，Parked


产生时间

　　Java程序运行时，有时会产生JavaCore及HeapDump文件，它一般发生于Java程序遇到致命问题的情况下。

　　有时致命问题发生后，Java应用不会死掉，还能继续运行；

　　但有时致命问题发生，Java进程会死掉；

　　为了能够保留Java应用发生致命错误前的运行状态，JVM在死掉前产生两个文件，分别为JavaCore及HeapDump文件(是需要在启动参数中配置的-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\heapdump，不配置不生成dump文件)。


一、标准的SUN/Oracle JVM

当内存溢出时生成heapdump文件配置如下
-Xloggc:${目录}/temp_gc.log           （GC日志文件）
-XX:+HeapDumpOnOutOfMemoryError       （内存溢出时生成heapdump文件）
-XX:HeapDumpPath=${目录}              （heapdump文件存放位置）
如果要即时动态生成heapdump文件可以使用jmap命令，jdk6.0已取消了-XX:+HeapDumpOnCtrlBreak配置参数通过ctrl+break的方式。
jmap -dump:format=b,file=temp_heapdump.hprof <pid>

　　有何区别

　　JavaCore是关于CPU的，而HeapDump文件是关于内存的。

　　JavaCore文件主要保存的是Java应用各线程在某一时刻的运行的位置，即JVM执行到哪一个类、哪一个方法、哪一个行上。它是一个文本文件，打开后可以看到每一个线程的执行栈，以stack trace的显示。通过对JavaCore文件的分析可以得到应用是否“卡”在某一点上，即在某一点运行的时间太长，例如数据库查询，长期得不到响应，最终导致系统崩溃等情况。

　　HeapDump文件是一个二进制文件，它保存了某一时刻JVM堆中对象使用情况，这种文件需要相应的工具进行分析，如IBM Heap Analyzer这类工具。这类文件最重要的作用就是分析系统中是否存在内存溢出的情况。

　　怎么生成

　　这两个文件可以用手工的方式生成，当我们会遇到系统变慢或无响应的情况，这时就以采用手工的方式生成JavaCore及HeapDump文件。

　　在Unix/Linux上，产生这两个文件的方法如下：

    # ps -ef | grep java 
    user 4616 4582 0 17:30 pts/0 00:00:00 grep java 
    root 5580 1 0 Oct27 ? 00:02:27 /usr/bin/java -server -XX:PermSize=64M -XX:MaxPermSize=128m -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.util.logging.config.file=/usr/local/tomcat8090/conf/logging.properties -Djava.endorsed.dirs=/usr/local/tomcat8090/endorsed -classpath :/usr/local/tomcat8090/bin/bootstrap.jar -Dcatalina.base=/usr/local/tomcat8090 -Dcatalina.home=/usr/local/tomcat8090 -Djava.io.tmpdir=/usr/local/tomcat8090/temp org.apache.catalina.startup.Bootstrap start 
   # kill -3 5580 （目前已经不生成）

　　首先，找出Java进程id ，然后再执行‘kill -3 进程号’的操作，等文件生成后再做一次同样的操作，再产生一组文件。

　　如何分析

　　JavaCore文件

　　两组文件在分析JavaCore时特别有效，因为它可以看出在先后两个时间点上，线程执行的位置，如果发现先后两组数据中同一线程都执行在同一位置，则说明此处可能有问题，因为程序运行是极快的，如果两次均在某一点上，说明这一点耗时是很大的，通过对这两个文件进行分析，查出原因，进而解决问题。

　　JavaCore文件的头部有一个“Current Thread Details”标记，它记录了JavaCore产生时系统运行的线程id，使用线程id在文件中查找线程的详细信息，该信息中记载了线程运行哪个类的时候造成的JavaCore。

    NULL ------------------------------------------------------------------------ 
    0SECTION TITLE   subcomponent dump routine 
    NULL =============================== 
    1TISIGINFOOUTOFMEMORY received 
    1TIDATETIME Date: 2011/12/07 at 15:59:42 
    1TIFILENAME Javacore filename:/usr/WebSphere/AppServer/profiles/WCSProdNode2/javacore19202086.1323298782.txt 
    NULL ------------------------------------------------------------------------ 
    0SECTION XHPI subcomponent dump routine 
    NULL   ============================== 
    1XHTIME Wed Dec 7 15:59:42 2011 
    1XHSIGRECV Unexpected   signal -1 received at   0x0 in <unknown>. Processing   terminated. 
    1XHFULLVERSION J2RE 1.4.2 IBM AIX build ca142ifx-20090918 (SR13   FP2) 
    NULL           
    1XHCURRENTTHD Current Thread   Details 
    NULL ---------------------- 
    2XHCURRSYSTHD "WebContainer :   5" sys_thread_t:0x45FB5328 
    3XHNATIVESTACK Native Stack 
    NULL ------------ 
    3XHSTACKLINEERR unavailable -   stack address not valid 
    ::: 
    ::: 
    0SECTION XM subcomponent   dump routine 
    NULL ============================ 
    NULL            
    1XMCURTHDINFO Current Thread Details 
    NULL ---------------------- 
    3XMTHREADINFO "WebContainer : 5" (TID:0x70A8E260, sys_thread_t:0x45FB5328, state:R, native ID:0x5CC0)   prio=5
    4XESTACKTRACE at   org.apache.taglibs.standard.tag.common.core.ImportSupport$ImportResponseWrapper.getString(Unknown   Source) 
    4XESTACKTRACE at   org.apache.taglibs.standard.tag.common.core.ImportSupport.acquireString(Unknown   Source) 
    4XESTACKTRACE at   org.apache.taglibs.standard.tag.common.core.ImportSupport.doEndTag(Unknown   Source) 
    4XESTACKTRACE at   com.ibm._jsp._part._jspx_meth_c_import_3(_part.java(Compiled Code)) 
    4XESTACKTRACE at   com.ibm._jsp._part._jspx_meth_c_otherwise_3(_part.java(Compiled   Code)) 
    4XESTACKTRACE at   com.ibm._jsp._part._jspx_meth_c_choose_4(_part.java(Compiled Code)) 
    4XESTACKTRACE at   com.ibm._jsp._part._jspService(_part.java:3237)

　　这样结合当时的日志文件可以找到问题产生的原因。不过，这种方法只能找到不是内存溢出的错误，对于在core文件头就有java/lang/outMemoryException的错误还是不知道是执行到哪个类的时候出现。

　　HeapDump文件

　　HeapDump文件是指定时刻的Java堆栈的快照，是一种镜像文件。Heap Analyzer工具通过分析HeapDump文件，哪些对象占用了太多的堆栈空间，来发现导致内存泄露或者可能引起内存泄露的对象。








其中jmap是java自带的工具

查看整个JVM内存状态
jmap -heap [pid]
要注意的是在使用CMS GC 情况下，jmap -heap的执行有可能会导致JAVA 进程挂起

查看JVM堆中对象详细占用情况
jmap -histo [pid]

导出整个JVM 中内存信息
jmap -dump:format=b,file=文件名 [pid]

jhat是sun 1.6及以上版本中自带的一个用于分析JVM 堆DUMP 文件的工具，基于此工具可分析JVM HEAP 中对象的内存占用情况
jhat -J-Xmx1024M [file]
执行后等待console 中输入start HTTP server on port 7000 即可使用浏览器访问 IP：7000

eclipse Memory Analyzer
Eclipse 提供的一个用于分析JVM 堆Dump文件的插件。借助这个插件可查看对象的内存占用状况，引用关系，分析内存泄露等。
http://www.eclipse.org/mat/


[color=red]kill -3 [pid] （目前已经不生成）
在Linux 上找到Java所在的进程号，然后执行以上命令，线程的相关信息就输出到console


jstack
jstack 是sun JDK 自带的工具，通过该工具可以看到JVM 中线程的运行状况，包括锁等待，线程是否在运行
执行 jstack [pid] ,线程的所有堆栈信息

"http-8080-10" daemon prio=10 tid=x0a949bb60 nid=0x884  waiting for monitor entry [...]

"http-8080-10" 这个线程处于等待状态。 waiting for monitor entry 如果在连续几次输出线程堆栈信息都存在于同一个或多个线程上时，则说明系统中有锁竞争激烈，死锁，或锁饿死的想象。


“http-8080-11” daemon prio=10 tix=xxx nid=xxx in object.wait() [...]
java.lang.Thread.State:waiting (on object monitor)
该表示http-8080-11的线程处于对象的Wait 上，等待其他线程的唤醒，这也是线程池的常见用法。

“Low Memory Detector”daemon prio=10 tix=xx nid=xxx runnable [...] java.lang.Thread.State:runnable
表示“Low Memory Detector” 的线程处于Runable状态，等待获取ＣＰＵ的使用权.
[/color]


了分析java应用的内存泄漏，使用thread dump往往解决不了问题。使用jstat【eg：jstat -gcutil pid 1000 5】工具查看运行的java应用的heap size,perm size ,survivor ratio等，当时你无法知道是什么对象把堆填满了。

什么是 Java heap dump

     首先需要搞懂什么是java heap，java heap是分配给实例类和数组对象运行数据区，所有java线程在运行期间共享heap中的数据。Java heap dump相当于java应用在运行的时候在某个时间点上打了个快照(snapshot)。

触发 Java heap dump

    有以下方法出发heap dump

    使用$JAVA_HOME/bin/jmap -dump来触发，eg：jmap -dump:format=b,file=/home/longhao/heamdump.out
    使用$JAVA_HOME/bin/jcosole中的MBean，到MBean>com.sun.management>HotSpotDiagnostic>操作>dumpHeap中，点击 dumpHeap按钮。生成的dump文件在java应用的根目录下面。
    在应用启动时配置相关的参数 -XX:+HeapDumpOnOutOfMemoryError，当应用抛出OutOfMemoryError时生成dump文件。
    使用hprof。启动虚拟机加入-Xrunhprof:head=site，会生成java.hprof.txt文件。该配置会导致jvm运行非常的慢，不适合生产环境。

   

分析 Java heap dump

1：使用IBM HeapAnalyzer

     IBM HeapAnalyzer是一款免费的JVM内存堆的图形分析工具，它可以有效的列举堆的内存使用状况，帮助分析Java内存泄漏的原因。

     下载解压后有一个ha413.jar，执行: java -Xmx512m -jar ha413.jar /home/longhao/heapdump.out

   

2：jhat

     jhat(Java Head Analyse Tool )是用来分析java堆的命令，可以将堆中的对象以html的形式显示出来，包括对象的数量，大小等等，并支持对象查询语言OQL，分析相关的应用后，可以通过http://localhost:7000来访问分析结果。

     示例: $JAVA_HOME/bin/jhat -J-Xmx512m /home/longhao/dump.out

3：Eclipse MemoryAnalyzer

     Eclipse Memory Analyzer是一个快速并且功能强大的Java heap分析器，能够帮助你查找内存泄漏和减少内存消耗。在File>Acquire Heap Dump>configure>HPROF jmap dump provider设置一下分析应用的JDK，点击相关应用列表来生成heap dump并分析。

     在socket，nio中的有些API中，申请的内存是直接想OS要的，在堆中分析内存是查看不到的，可以通过-XX:MaxDirectMemorySize=来设置应用向OS直接申请的最大内存数。






1.jmap –heap pid
查看内存
查看指定java进程内的所有对象情况，统计信息
得到运行java程序的内存分配的详细情况。例如实例个数，大小等
命名行格式
jmap [ option ] pid
jmap [ option ] executable core
jmap [ option ] [server-id@]remote-hostname-or-IP

-dump:[live,]format=b,file=<filename> 使用hprof二进制形式,输出jvm的heap内容到文件=. live子选项是可选的，假如指定live选项,那么只输出活的对象到文件.
-finalizerinfo 打印正等候回收的对象的信息.
-heap 打印heap的概要信息，GC使用的算法，heap的配置及wise heap的使用情况.
-histo[:live] 打印每个class的实例数目,内存占用,类全名信息. VM的内部类名字开头会加上前缀”*”. 如果live子参数加上后,只统计活的对象数量.
-permstat 打印classload和jvm heap长久层的信息. 包含每个classloader的名字,活泼性,地址,父classloader和加载的class数量. 另外,内部String的数量和占用内存数也会打印出来.
-F 强迫.在pid没有相应的时候使用-dump或者-histo参数. 在这个模式下,live子参数无效.
-h | -help 打印辅助信息
-J 传递参数给jmap启动的jvm.

[wls81@CNSH-stg4-080 ~]$ jmap -heap 1345
Attaching to process ID 1345, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 20.45-b01

using parallel threads in the new generation. –新生代采用并行线程处理方式
using thread-local object allocation.
Concurrent Mark-Sweep GC –同步并行垃圾回收

Heap Configuration:
   MinHeapFreeRatio = 40 –最小堆使用比例,小于40增加
   MaxHeapFreeRatio = 70 –最大堆可用比例，大于70缩小
   MaxHeapSize      = 2147483648 (2048.0MB) –最大堆空间大小
   NewSize          = 21757952 (20.75MB)-新生代初始值
   MaxNewSize       = 43581440 (41.5625MB)- 新生代最大值
   OldSize          = 65404928 (62.375MB)
   NewRatio         = 7 -新域与旧域之比，如-XX：NewRatio = 7就表示新域与旧域之比为1：7
   SurvivorRatio    = 8 -新域中Eden区与两个Survivor区的比值
   PermSize         = 21757952 (20.75MB)
   MaxPermSize      = 268435456 (256.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
   capacity = 39256064 (37.4375MB)
   used     = 10106616 (9.638420104980469MB)
   free     = 29149448 (27.79907989501953MB)
   25.745362550866027% used
Eden Space:
   capacity = 34930688 (33.3125MB)
   used     = 8710216 (8.306709289550781MB)
   free     = 26220472 (25.00579071044922MB)
   24.935712689083022% used
From Space:
   capacity = 4325376 (4.125MB)
   used     = 1396400 (1.3317108154296875MB)
   free     = 2928976 (2.7932891845703125MB)
   32.28389855587121% used
To Space:
   capacity = 4325376 (4.125MB)
   used     = 0 (0.0MB)
   free     = 4325376 (4.125MB)
   0.0% used
concurrent mark-sweep generation:    --OG大小和使用情况
   capacity = 2103902208 (2006.4375MB)
   used     = 621060520 (592.2894668579102MB)
   free     = 1482841688 (1414.1480331420898MB)
   29.519457588781616% used
Perm Generation:  
   capacity = 221929472 (211.6484375MB)
   used     = 141924728 (135.34996795654297MB)
   free     = 80004744 (76.29846954345703MB)
   63.9503742882784% used


2.Jmap -dump:format=b,file=dumpFileName pid
dump命令

1.jstat -gc pid
Jstat 一般用来查看堆内存的实时情况

这是一个比较实用的一个命令，可以观察到classloader，compiler，gc相关信息。可以时时监控资源和性能
jstat -gc 22225 2000 20  没个2秒显示一次，一共显示20次
命令格式
-class：统计class loader行为信息
-compile：统计编译行为信息
-gc：统计jdk gc时heap信息
-gcutil：统计gc时，heap情况
-gccapacity：统计不同的generations（不知道怎么翻译好，包括新生区，老年区，permanent区）相应的heap容量情况
-gccause：统计gc的情况，（同-gcutil）和引起gc的事件
-gcnew：统计gc时，新生代的情况
-gcnewcapacity：统计gc时，新生代heap容量
-gcold：统计gc时，老年区的情况
-gcoldcapacity：统计gc时，老年区heap容量
-gcpermcapacity：统计gc时，permanent区heap容量


S0C：年轻代中第一个survivor（幸存区）的容量 (字节)
S1C：年轻代中第二个survivor（幸存区）的容量 (字节)
S0U：年轻代中第一个survivor（幸存区）目前已使用空间 (字节)
S1U：年轻代中第二个survivor（幸存区）目前已使用空间 (字节)
EC：年轻代中Eden（伊甸园）的容量 (字节)
EU：年轻代中Eden（伊甸园）目前已使用空间 (字节)
OC：Old代的容量 (字节)
OU：Old代目前已使用空间 (字节)
PC：Perm(持久代)的容量 (字节)
PU：Perm(持久代)目前已使用空间 (字节)
YGC：从应用程序启动到采样时年轻代中gc次数
YGCT：从应用程序启动到采样时年轻代中gc所用时间(s)
FGC：从应用程序启动到采样时old代(全gc)gc次数
FGCT：从应用程序启动到采样时old代(全gc)gc所用时间(s)
GCT：从应用程序启动到采样时gc用的总时间(s)

2.jstat -gcutil pid
S0：年轻代中第一个survivor（幸存区）已使用的占当前容量百分比
S1：年轻代中第二个survivor（幸存区）已使用的占当前容量百分比
E：年轻代中Eden（伊甸园）已使用的占当前容量百分比
O：old代已使用的占当前容量百分比
P：perm代已使用的占当前容量百分比


jstack –l pid

stack –l pid > 111.log  生成线程快照到文件中
虚拟机自带的一种堆栈跟踪工具，生成虚拟机当前的线程快照。查看没有响应的线程出现的原因。
-l 长列表. 打印关于锁的附加信息,例如属于java.util.concurrent的ownable synchronizers列表.

jstack能得到运行java程序的java stack和native stack的信息。可以轻松得知当前线程的运行情况，注：这个和thread dump是同样的结果。但是thread dump是用kill -3 pid命令，还是服务器上面少用kill为妙

linux的kill -3指令可以帮我们输出当前进程中所有线程的状态，如哪些线程在运行，哪些在等待，因为什么等待，代码哪一行等待。

kill -3 会将信息输出至控制台，所以使用时，被kill -3的进程最好是nohup启动的。

kill -3并不会影响程序运行，不用担心他把程序杀死了。执行kill -3 后 目前已经失效，jdk不在生成dump文件


jstack除了在正常运行的系统能连接上去以外，在系统已经不能正常提供JMX服务了，但进程还活着的时候，也能连接上去。
使用jstack命令的帮助可以看到，该工具的功能也很强大：
主要分为两个功能：

a．  针对活着的进程做本地的或远程的线程dump；

b．  针对core文件做线程dump。

比如，下面就是一个针对进程做的线程dump：

jstack除了进程活着的时候可以做dump，如果进程crash了，那么系统应该会留下core文件，jstack工具依然能够对core文件做线程dump，
jstack java.core







iostat







查看IO相关信息