GC问题排查实战三-Parallel Scavenge和Parallel Old日志分析

年轻代GC的耗时问题

本篇开始一些比较细节的东西，不想说哪个垃圾回收器最好，没有最好，只有最合适以及根据不同情况调优，只想看看年轻代垃圾收集到底耗时耗在哪里，以便于出现问题的时候有解决思路，本次会用相同的例子压测，然后分别用Parallel Scavenge和Parallel Old,CMS,G1来进行垃圾回收，分析年轻代的一些耗时问题。

Parallel Scavenge和Parallel Old

参数

-Xms8192M -Xmx8192M -Xmn4096M -Xss1M -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintReferenceGC -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 -XX:MetaspaceSize=256M -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/data/app/log/gc/gc.log -XX:ErrorFile=/data/log/error/error.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/log/heap/heap_hprof.bin -Dfile.encoding=UTF-8

跑完后数据

gc日志数据

发现有耗时比较大的几次：

于是选第一次看看：

然后看了下日志，其中处理final引用对象用了48毫秒，然后发现有32K对象晋升，以及44%的对象经过复制到了to区，消耗应该在这些地方：

然后我们看第二次：

看看日志，发现也有56K对象晋升，也有50%复制，但是处理final引用的时间少了，所以时间稍微少了点：

我们再看后面一个看看是不是这些原因导致的时间久：

然后是日志，这次晋升的值有8K对象，49%的复制，但是所有的引用处理耗时很少了，所以这次时间花的少：

再看后面的这个，貌似复制的比前面少，为什么耗时比他多，以为可以看到晋升的多了130M+，也是要复制都老年代的，耗时呀

那我们找个耗时少的分析下，这次晋升还挺多，但是复制只有4%，引用处理几乎没怎么耗时，时间消耗少了好多：

再看下一个耗时很少的，验证下上面的结论：

safepoint相关数据

当然STW的时间也可能是因为safepoint的处理，为此我也打印了相关的耗时，可以看到基本都是vmop的耗时，也就是进行GC的STW，如果是有线程因为safepoint等待耗时的话spin ，sync的大量耗时就会出现，目前暂时没有：

晋升问题

为什么出现了晋升，好奇怪啊，没看到年龄到15呀，其实我们可以仔细看年龄信息，蓝色框的，其实他此刻的晋升阈值是2，说明有进行动态年龄处理了，把年龄是2的都晋升过去了，然后把阈值改为了2，具体的晋升逻辑是后面会说，是因为动态年龄调节机制：

暂时分析到这里，当然后面还有另外2个垃圾回收器的测试数据，后一篇说。

好了，今天就到这里了，希望对学习理解有帮助，大神看见勿喷，仅为自己的学习理解，能力有限。