【JVM】查看GC日志

1.登录机器

ssh 10.7.198.2

2.进入日志目录

cd /var/sankuai/logs/

该目录的配置对应脚本文件run.sh

 

3.查看gc日志文件

ls

项目每次启动时会生成对应的gc日志文件，我们最近的一次是sc_c_operation-thriftserver.gc.log.201908061513文件

 

4.打印当前gc的情况

tail -f sc_c_operation-thriftserver.gc.log.201908061513

对应的脚本run.sh

 

 

对应的参数列表

-XX:+PrintGC 输出GC日志
-XX:+PrintGCDetails 输出GC的详细日志
-XX:+PrintGCTimeStamps 输出GC的时间戳（以基准时间的形式）
-XX:+PrintGCDateStamps 输出GC的时间戳（以日期的形式，如 2013-05-04T21:53:59.234+0800）
-XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
-Xloggc:../logs/gc.log 日志文件的输出路径

5.查看youngGC的情况

其含义大概如下：

418716.852（以上次发布时间的时间戳）: [GC（表示Young GC） (Allocation Failure) 418716.852: [ParNew: 744035K（年轻代垃圾回收前的大小）->51772K（年轻代回收后的大小）(755008K（年轻代总大小）), 0.0377154 secs（本次回收的时间）] 3094710K（整个堆回收前的大小）->2402447K（整个堆回收后的大小）(4110464K（堆总大小）), 0.0380713 secs（回收时间）] [Times: user=0.14（用户耗时） sys=0.00（系统耗时）, real=0.04 secs（实际耗时）]

 

6.查看发生FGC的情况

可以看到发生年轻代GC，年轻代回收了744035 - 51772 = 692263K。整个堆回收为3094710 - 2402447 = 692263K;

head -n 100 sc_c_operation-thriftserver.gc.log.201908061513 | grep "CMS"

结果如下：

 

可以看到CMS Initial Mark 触发时，old区大小为559M，而总含量为3344M，此时应该不足以发生full GC。

 

整个cms gc是从initial mark开始到remark结束，initial mark告诉你触发cms的old区大小，remark会告诉你cms后old区的使用情况

参考wiki：https://blog.youkuaiyun.com/ligeforrent/article/details/97044149

可以判断是因为metaspace内存超过了首次发生full gc的阈值导致的。

 

GC参数如下：

-XX:+UseConcMarkSweepGC
                    -XX:+UseParNewGC//使用ParNewGC
                    -XX:ParallelCMSThreads=4
                    -XX:+CMSClassUnloadingEnabled
                    -XX:+UseCMSCompactAtFullCollection
                    -XX:CMSFullGCsBeforeCompaction=1
                    -XX:CMSInitiatingOccupancyFraction=72"//在老年代到72%的时候，会触发一次CMS GC

 

配置了CMS却触发Full GC，有以下几种可能：

大对象分配时，年轻代不够，直接晋升到老年代，老年代空间也不够，触发 Full GC（老年代还剩800+M，显然不可能）
​内存碎片导致（由于CMS是基于标记清除算法的，所有会导致内存碎片，但通过grep -i "cms" gc.log，JVM尚未触发过CMS回收，所以也不存在内存碎片的说法）
​CMS GC失败导致（从gc.log并未找到concurrent mode failure的记录，排除）
​jmap -histo（人为执行该命令）