(转）FULL GC分析过程分享

 

 

http://www.taobaotest.com/blogs/2294
在性能测试过程中,FULL GC频繁是比较常见的问题，FULL GC 产生的原因有很多，这里主要针对meta压测过程中分析FULL GC问题的一些思路进行分享，供大家参考
1.如何发现是否发生FULL GC和FULL GC是否频繁
使用JDK自带的轻量级小工具jstat
语法结构：
Usage: jstat -help|-options
jstat -<option> [-t] [-h<lines>] <vmid> [<interval> [<count>]]

参数解释：
Options — 选项，我们一般使用 -gcutil 查看gc情况
vmid — VM的进程号，即当前运行的java进程号
interval– 间隔时间，单位为秒或者毫秒
count — 打印次数，如果缺省则打印无数次
比如 /opt/taobao/java/bin/jstat –gcutil pid 5000

输出结果：
S0 S1 E O P YGC YGCT FGC FGCT GCT
0.00 90.63 100.00 58.82 3.51 183 2.059 0 0.000 2.059
0.00 15.48 7.80 60.99 3.51 185 2.092 1 0.305 2.397
0.00 15.48 18.10 47.90 3.51 185 2.092 2 0.348 2.440
S0 — Heap上的 Survivor space 0 区已使用空间的百分比
S1 — Heap上的 Survivor space 1 区已使用空间的百分比
E — Heap上的 Eden space 区已使用空间的百分比
O — Heap上的 Old space 区已使用空间的百分比
P — Perm space 区已使用空间的百分比
YGC — 从应用程序启动到采样时发生 Young GC 的次数
YGCT– 从应用程序启动到采样时 Young GC 所用的时间(单位秒)
FGC — 从应用程序启动到采样时发生 Full GC 的次数
FGCT– 从应用程序启动到采样时 Full GC 所用的时间(单位秒)
GCT — 从应用程序启动到采样时用于垃圾回收的总时间(单位秒)
通过FGC我们可以发现系统是否发生FULL GC和FULL GC的频率

2. FULL GC分析和问题定位
a. GC log收集和分析
(1)在JVM启动参数增加："-verbose:gc -Xloggc:<file_name> -XX:+PrintGCDetails -XX:+PrintGCDateStamps"
PrintGCTimeStamp只能获得相对时间，建议使用PrintGCDateStamps获得full gc 发生的绝对时间
(2)如果采用CMS GC,仔细分析jstat FGC输出和GC 日志会发现， CMS的每个并发GC周期则有两个stop-the-world阶段——initial mark与final re-mark，使得CMS的每个并发GC周期总共会更新full GC计数器两次，initial mark与final re-mark各一次

b. Dump JVM 内存快照
/opt/taobao/java/bin/jmap -dump:format=b,file=dump.bin pid
这里有一个问题是什么时候进行dump?
一种方法是前面提到的用jstat工具观察，当OLD区到达比较高的比例如60%，一般会很快触发一次FULL GC,可以进行一次DUMP,在FULL GC发生以后再DUMP一次，这样比较就可以发现到底是哪些对象导致不停的FULL GC
另外一种方法是通过配置JVM参数
-XX:+HeapDumpBeforeFullGC -XX:+HeapDumpAfterFullGC分别用于指定在full GC之前与之后生成heap dump

c. 利用MAT((Memory Analyzer Tool)工具分析dump文件
关于MAT具体使用方法网上有很多介绍，这里不做详细展开，这里需要注意的是：
(1) MAT缺省只分析reachable的对象，unreachable的对象（将被收集掉的对象）被忽略，而分析FULL GC频繁原因时unreachable object也应该同时被重点关注。如果要显示unreachable的对象细节必须用mat 1.1以上版本并且打开选项“keep unreachable object”
(2) 通常dump文件会好几个G，无法在windows上直接进行分析，我们可以先把dump文件在linux上进行分析，再把分析好的文件拷贝到windows上，在windows上用MAT打开分析文件。