使用HPjmeter分析GC log

1、启动HPjmeter：

HPJmeter本身就是一个jar包，可以通过java命令直接启动，就像运行其他jar包形式的java程序一样。

Java–jar%HPJMETER_PATH%HPjmeter.jar

这样，HPJmeter就启动了，但是如果我们要分析的dump文件很大的话，HPJmeter就需要很多内存，否则很容易crash。

所以在它启动时，我们应该加上一些参数：

Java -Xms512M -Xmx1024M -Xss8M -jar%HPJMETER_PATH%HPjmeter.jar

这次我们新加入了几个参数，其作用如下：

前两个参数保证打开较大的文件时不会crash，最后一个参数保证正常分析出memory leak怀疑点。

2、应用服务器生成GC log设置方法

GC日志记录了内存使用和回收状态，出现内存故障时，可作为分析排查手段。

设置-verbose:gc -Xloggc:/home/weblogic/bea/gc.vgc打印gc日志(HPJmeter直接识别的是vgc格式的日志，weblogic每次重启服务，会把上次的gc log覆盖掉)

启用GC监控的方法：增加java启动参数-verbose:gc

将GC日志输出到文件：不同JDK设置的参数不同，参考JDK官方文档
      SUN：-Xloggc:filename（例如：-Xloggc:/home/weblogic/bea/gc.vgc）
      IBM：-Xverbosegc:file=filename或-Xverbosegclog:filename
      HP：-Xverbosegc=filename

如何设置Java启动参数：有多种方式，以下各举一例

      Tomcat：在catalina.bat的“set JAVA_OPTS=%JAVA_OPTS% ”后设置

        WebLogic：在startWebLogic.cmd的“%JAVA_HOME%binjava %JAVA_VM% %MEM_ARGS% %JAVA_OPTIONS% ”后设置

      WebSphere：进入管理控制台，应用服务器->进程定义->Java虚拟机高级定义

3、分析GC log

使用-Xloggc:filename旗标的GC日志记录：
69.713: [GC 11536K->11044K(12016K), 0.0032621 secs]
69.717: [Full GC 11044K->5143K(12016K), 0.1429698 secs]
69.865: [GC 5958K->5338K(11628K), 0.0021492 secs]
69.872: [GC 6169K->5418K(11628K), 0.0021718 secs]
69.878: [GC 6248K->5588K(11628K), 0.0029761 secs]
69.886: [GC 6404K->5657K(11628K), 0.0017877 secs]
 

首先注意到的可能是每一项日志记录是写在一组方括号内的。其他GC算法，如并发收集器，可能将一些值分解为更细的信息。如果是这种情况，这些被分解的值会由包围在嵌入的一组方括号中的细节所替代，这使工具可以更容易地处理详细GC输出。

我们的研究首先从分析清单1中标记为69.713的记录开始。这个标记是JVM开始后的秒数和毫秒数的时间戳。在这个例子中，JVM在这个GC周期开始之前运行了69.713秒。从左到右的字段为：执行的收集的类型、GC之前的堆使用、总的堆能力和GC事件的持续时间。从这个描述中我们可以看出第一个GC事件是一个小的收集。在GC开始之前，使用了11536 Kb的堆空间。在完成时，使用了11044 Kb，堆能力为12016 Kb，而整个收集用了0.0032621秒。下一个事件，一个完全的GC，在69.717秒时或者上一个小GC事件之后0.003秒时开始。注意，如果将小GC事件的持续时间加到其开始时间上，就会看到它在完全的GC开始之前不到1毫秒结束。因此我们可以得出结论：小收集没有恢复足够的空间，这种失败触发了完全的GC。对应用程序来说，这像是一个持续了0.1462319秒的事件。让我们继续确定如何计算其他值。

GC日志记录的参数确定

我们通过确定每个GC日志记录中的值的参数来开始分析：

R(n) = T(n): [ <GC> HB->HE(HC), D]
n 清单中记录的索引，1是第一个，m是最后一个
R(n)  GC记录
T(n) 第n个GC发生的时间
HB  GC之前堆的数量
HE  GC之后使用的堆数量
HC 堆空间的总量
D  GC周期的持续时间

有了这些定义，我们现在可以推导出用于计算前面描述的值的公式。

gc打印出来的详情一般为：
[GC [DefNew: 8614K->781K(9088K), 0.0123035 secs] 118250K->113543K(130112K), 0.0124633 secs] 
这表示新生代大小整理前8614K，整理后还有781K（有可能为0，表示都清掉了），后面的9088表示总大小。
后面的就表示对整个堆空间而言。整理前118250K，整理后113543K，总大小为130112K。