通过jinfo工具在full GC前后做heap dump

上一篇：[url=http://rednaxelafx.iteye.com/blog/1048958]通过JMX控制在full GC前后做heap dump[/url]

想像一个Java进程在远程服务器上突然遇到频繁full GC的状况。我们只是想动态的改变[b]HeapDumpBeforeFullGC[/b]与[b]HeapDumpAfterFullGC[/b]参数来获取full GC前后的heap dump，并不想在侵入到Java程序内去通过代码做这个工作。这种场景里jinfo就能派上用场了——它已经把相关的JMX操作给封装好了。
（提醒：如果找不到打出来的heap dump的话，请设置[b]HeapDumpPath[/b]。这个参数指定heap dump的目录。
[b]-XX:HeapDumpPath=[/b][i]path/to/your/heap/dumps/dir[/i]）

上一篇其实已经提到了，通过jinfo -flag同样可以设置标记为manageable的VM参数。参考jinfo的帮助文档：
[quote]

$ jinfo -help
Usage:
    jinfo [option] <pid>
        (to connect to running process)
    jinfo [option] <executable <core>
        (to connect to a core file)
    jinfo [option] [server_id@]<remote server IP or hostname>
        (to connect to remote debug server)

where <option> is one of:
    -flag <name>         to print the value of the named VM flag
    -flag [+|-]<name>    to enable or disable the named VM flag
    -flag <name>=<value> to set the named VM flag to the given value
    -flags               to print VM flags
    -sysprops            to print Java system properties
    <no option>          to print both of the above
    -h | -help           to print this help message

[/quote]

于是上一篇的实验可以用jinfo来做一次。

同样是在当前目录下放一个.hotspotrc文件来显示GC日志：

+PrintGCDetails

然后开groovysh来执行三次System.gc()。其中，第一次System.gc()之后在命令行调用下列命令：

$ jps
18711 Jps
18650 GroovyStarter
$ jinfo -flag +HeapDumpBeforeFullGC 18650
$ jinfo -flag +HeapDumpAfterFullGC 18650

然后在第二次System.gc()之后再调用：

$ jinfo -flag -HeapDumpBeforeFullGC 18650
$ jinfo -flag -HeapDumpAfterFullGC 18650

那么可以观察到Groovy Shell的运行状况是：

$ groovysh
[GC [PSYoungGen: 14016K->1344K(16320K)] 14016K->1344K(53696K), 0.0072690 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[GC [PSYoungGen: 15360K->2288K(30336K)] 15360K->4824K(67712K), 0.0183850 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 
Groovy Shell (1.7.7, JVM: 1.6.0_25)
Type 'help' or '\h' for help.
----------------------------------------------------------------------------------------------------------------------------
groovy:000> System.gc()
[GC [PSYoungGen: 26693K->2288K(30336K)] 29229K->8748K(67712K), 0.0262440 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] 
[Full GC (System) [PSYoungGen: 2288K->0K(30336K)] [PSOldGen: 6460K->8725K(37376K)] 8748K->8725K(67712K) [PSPermGen: 16933K->16933K(34176K)], 0.1172670 secs] [Times: user=0.11 sys=0.01, real=0.12 secs] 
===> null
groovy:000> System.gc()
[GC [PSYoungGen: 2932K->256K(30336K)] 11658K->8981K(67712K), 0.0017600 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Heap Dump: Dumping heap to java_pid18650.hprof ...
Heap dump file created [18535501 bytes in 0.317 secs]
, 0.3208840 secs][Full GC (System) [PSYoungGen: 256K->0K(30336K)] [PSOldGen: 8725K->8918K(37376K)] 8981K->8918K(67712K) [PSPermGen: 17045K->17045K(38464K)], 0.1131950 secs] [Times: user=0.11 sys=0.00, real=0.11 secs] 
[Heap DumpDumping heap to java_pid18650.hprof.1 ...
Heap dump file created [18440786 bytes in 0.318 secs]
, 0.3179790 secs]===> null
groovy:000> System.gc()
[GC [PSYoungGen: 1016K->160K(30336K)] 9935K->9078K(67712K), 0.0020120 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Full GC (System) [PSYoungGen: 160K->0K(30336K)] [PSOldGen: 8918K->9028K(37376K)] 9078K->9028K(67712K) [PSPermGen: 17077K->17077K(36928K)], 0.1111340 secs] [Times: user=0.11 sys=0.00, real=0.11 secs] 
===> null
groovy:000> quit
Heap
 PSYoungGen      total 30336K, used 2427K [0x00000000edc00000, 0x00000000efbe0000, 0x0000000100000000)
  eden space 28032K, 8% used [0x00000000edc00000,0x00000000ede5ef68,0x00000000ef760000)
  from space 2304K, 0% used [0x00000000ef760000,0x00000000ef760000,0x00000000ef9a0000)
  to   space 2304K, 0% used [0x00000000ef9a0000,0x00000000ef9a0000,0x00000000efbe0000)
 PSOldGen        total 37376K, used 9028K [0x00000000c9400000, 0x00000000cb880000, 0x00000000edc00000)
  object space 37376K, 24% used [0x00000000c9400000,0x00000000c9cd12b0,0x00000000cb880000)
 PSPermGen       total 36928K, used 17142K [0x00000000c4200000, 0x00000000c6610000, 0x00000000c9400000)
  object space 36928K, 46% used [0x00000000c4200000,0x00000000c52bdbb0,0x00000000c6610000)

效果是：第二次System.gc()的时候，我们得到了两份HPROF格式的heap dump，而第一次与第三次都没有。

这样就可以很方便的在遇到full GC频繁的时候获取那么一两组heap dump来分析，而不需要在VM启动的时候就指定这两个参数——那样的话dump出来的文件就多了orz