jvm查看full gc频率

背景

先说一下基本情况，本次是对线上商品服务的JVM优化。商品服务的访问量非常高，单机QPS在3000左右，线上总共部署了15个商品服务节点。JVM堆内存大小是8G，其中给新生代分配了2G，老年代垃圾回收器采用CMS，新生代垃圾回收器是ParNew。

查看java进程

]#jps
24019 user.jar
25885 Jps
26958 Main

目标进程24019

监控jvm，每5秒打印一次

]# jstat -gc 24019 5000
 S0C    S1C     S0U      S1U      EC       EU        OC         OU       MC     MU     CCSC   CCSU      YGC     YGCT   FGC    FGCT     GCT   
53248.0 55808.0 23075.3  0.0   216064.0 181168.5  288256.0   179280.1  60072.0 58559.5 7080.0 6734.8     32    1.244   6      1.914    3.158
53248.0 55808.0 23075.3  0.0   216064.0 181168.5  288256.0   179280.1  60072.0 58559.5 7080.0 6734.8     32    1.244   6      1.914    3.158
53248.0 55808.0 23075.3  0.0   216064.0 181168.5  288256.0   179280.1  60072.0 58559.5 7080.0 6734.8     32    1.244   6      1.914    3.158
53248.0 55808.0 23075.3  0.0   216064.0 181168.5  288256.0   179280.1  60072.0 58559.5 7080.0 6734.8     32    1.244   6      1.914    3.158
53248.0 55808.0 23075.3  0.0   216064.0 181168.5  288256.0   179280.1  60072.0 58559.5 7080.0 6734.8     32    1.244   6      1.914    3.158

说明

S0C：第一个幸存区的大小
S1C：第二个幸存区的大小
S0U：第一个幸存区的使用大小
S1U：第二个幸存区的使用大小
EC：伊甸园区的大小
EU：伊甸园区的使用大小
OC：老年代大小
OU：老年代使用大小
MC：方法区大小
MU：方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
YGC：年轻代垃圾回收次数
YGCT：年轻代垃圾回收消耗时间
FGC：老年代垃圾回收次数
FGCT：老年代垃圾回收消耗时间
GCT：垃圾回收消耗总时间 

查看进程运行时间

]# ps -eo pid,tty,user,comm,lstart,etime | grep 24019
24019 ?        admin    java            Thu Dec 13 11:17:14 2018    01:29:43
进程id                   进程名          开始时间                     持续时间  

算频率

持续时间 /FGC

优化前的情况

首先我们使用 jstat 查看了 GC 的情况。又通过查看GC log，分析了GC 的详细状况。
使用 jstat -gcutil ${pid} 1000 每隔一秒打印一次 GC 统计信息。

可以看到，单次 Young GC 平均耗时是 60ms 左右，还是不错的，但是Young GC（YGC ）非常频繁，基本上每秒一次，有时还会一秒两次，在一秒两次的时候，Young GC对系统响应的压力就会比较明显。

jstat相关指标说明：

YGCT：Young GC 总时间，单位为秒
YGC：Young GC 次数
FGCT：Full GC 总时间，单位为秒
FGC：Full GC 次数
GCT：GC 总时间，是 YGCT 和 FGCT 之和

接着查看 GC log，打印 GC log 需要在 JVM 启动参数里添加如下参数：

-XX:+PrintGCDateStamps：打印 GC 发生的时间戳。
-XX:+PrintTenuringDistribution：打印 GC 发生时的代龄信息。
-XX:+PrintGCApplicationStoppedTime：打印 GC 停顿时长
-XX:+PrintGCApplicationConcurrentTime：打印 GC 间隔的服务运行时长
-XX:+PrintGCDetails：打印 GC 详情，包括 GC 前/内存等。
-Xloggc:…/gclogs/gc.log.date：指定 GC log 的路径

GC log如下：

从Log中，我们可以看到 gc 前有很多次 18ms 左右的停顿。

进一步分析和优化

直接查看 GC log 不太直观，可以借助一些可视化JVM分析工具来帮助我们分析，推荐一款不错的在线分析工具GCeasy，我们把 GC log 上传到https://gceasy.io 后， GCeasy 会根据GC log生成各个维度的图表，让我们更直观的分析JVM问题。

通过查看 GCeasy 生成的图表，我们可以发现JVM的吞吐量是 93%，即 JVM 运行业务代码的时长占 JVM 总运行时长的93%，这个吞吐量确实比较低，运行 100 分钟就有 7 分钟在执行 GC 操作。幸好这些 GC 中绝大多数都是 Young GC，单次GC时长较短时间可控并且频率均匀，所以商品服务还能正常运行。

解决这个问题，可以从三方面入手：减少对象的创建，增大新生代以及调整幸存区。

减少对象创建，本质上不算是JVM调优，而是代码优化，而且需要花大量的时间去撸代码，再逐步优化代码，周期会相当长。所以就暂时作罢了！

调整新生代比例

增大新生代比例。只需要修改JVM参数即可，说起来简单，但需要多次调整并压测，最终找到一个平衡点，在保证FullGC的频次和耗时都在合理的范围之内，把Young GC的频次降到最低。
有人可能会问：增大新生代比例，会不会导致Young GC的耗时明显增大？虽然降低了GC频次，但是单次GC的耗时却明显增加了，岂不是得不偿失？
首先，我们需要先明确，目前主流的新生代收集器大多采用标记-复制算法，ParNew也一样。研究表明，绝大多数应用场景，新生代中98%的对象生命周期很短，在毫秒级别，基本上被使用一次后就会变成垃圾对象，会在下一次GC时被清理掉。在很多JVM中将堆内存分为一块较大的Eden空间和两块较小的Survivor空间(下图的S0和S1)，新生对象存放在Eden区。当发生Young GC时，将Eden和当前Survivor中存活的对象一次性复制到另外一块Survivor中，最后整体清理Eden和当前的Survivor空间。每次Young GC时两块Survivor区互相更换。HotSpot虚拟机默认Eden和两块Survivor的大小比例是8:1:1，也就是说每次新生代中可用内存为整个新生代容量的90%（80%+10%），只有10%的内存会被“浪费”。

现在我们清楚了ParNew回收器采用了标记-复制算法。现在来分析一下ParNew回收器GC耗时和新生代大小的关系。我们知道标记-复制算法分为两个阶段，标记阶段和复制阶段。为了简化问题我们暂且认为标记阶段只扫描新生代的存活对象，其实该阶段还需要扫描部分老年代对象。假设我们要把新生代扩容1.5倍。

• 扩容前：新生代容量为2G，假设某对象A的存活时间为600ms，Young GC间隔500ms，那么本次GC时间 = 扫描新生代时间 + 复制对象时间（Eden和当前Survivor复制到另一个Survivor）。

• 扩容后：新生代容量为3G ，对象A的生命周期为600ms，但是由于新生代扩容了1.5倍，所以Young GC间隔理论上增加到了750ms。此时发生Young GC，对象A已经用完了生命周期，成为了垃圾对象，就不需要把对象A复制到另一个Survivor区了。那么本次GC时间 = 1.5 × 扫描新生代时间，没有增加复制时间。

所以，当扩大新生代容量时，实际上每次GC需要复制的存活对象并不会按照扩容比例递增。容量扩大到1.5倍，增加的存活对象会远小于1.5倍。虽然标记阶段消耗的时间提高到了1.5倍，但是复制阶段耗时并没有明显提高。更重要的是，对于虚拟机来说，复制对象的成本要远高于扫描标记的成本，所以，单次Young GC时间更多取决于存活对象的数量，而非Eden区的大小。如果堆内存中存在大量短生命周期的对象（大部分场景是这样的），那么扩容新生代后，Young GC时间不会显著增加。

分代调整

此外，观察了各代龄的对象数量情况后，对代龄设置也做了调整。

前文提到，当发生Young GC时，会将Eden和当前的Survivor中存活的对象一次性复制到另外一块Survivor中，最后整体清理Eden和当前的Survivor空间。每次Young GC时两块Survivor区会互相更换。存活对象在两块Survivor区之间每交换一次，对象年龄就会增长一岁。直到达到MaxTenuringThreshold设置的年龄（默认是15岁）时，相应的对象就会被转移到老年代。所以为了减少复制成本，MaxTenuringThreshold要尽量合理，不能设置太大，否则有些长寿对象在每次GC时都会在两个Survivor区之间来回复制，无疑是增加了复制阶段的耗时。

看上图，在15个分代中，7岁以上的对象80%都会被转移到老年代（769.02除以980.48 ≈ 80% ）。于是我们把 MaxTenuringThreshold 的值调整为 7，将年龄超过7岁的对象直接转移到老年代。这样就减少了长寿对象在两个 survivor 区之间来回复制带来的性能开销。

偏向锁停顿

我们看到GC log里有很多18ms左右的停顿，虽然每次停顿时间不算长，但频繁的停顿对性能消耗还是比较明显。
这个问题曾经遇到过几次，基本都是偏向锁导致。JDK1.8 之后 JVM 对锁进行了优化，增加了偏向锁。所谓的偏向，就是偏心，偏向锁会偏向于当前已经占有锁的线程 。适合锁竞争不激烈的场景（某个同步块并发不高，很少会出现多线程同时竞争锁的场景）。大概过程如下，获得锁的线程再次获得锁时，会判断偏向锁是否指向自己，如果指向自己，该线程将不用再次获得锁，就可以直接进入同步块，以此来优化性能。当其他线程请求相同的锁时，偏向模式结束。偏向锁的实现就是将对象头的标记设置为偏向，并将线程ID写入对象头。

在竞争激烈的场景，偏向锁会增加系统负担， 因为每次都要加一次是否偏向的判断。关键是遇到锁竞争时，取消锁的过程需要等待全局安全点（safe point），会导致所有线程暂停，即会发生Stop-The-World。所以在锁竞争激烈的场景下，最好提前关闭掉偏向锁。
在JVM中默认会开启偏向锁，所以我们只需要关闭偏向锁即可：

-XX:-UseBiasedLocking

最后

经过一轮调整和压测，最终新生代调整到了2.9G，整个堆内存保持8G不变，MaxTenuringThreshold调成了7。新生代增大了将近1.5倍，Young GC 的频率减少了大概1/3。GC 的吞量提高了3.8%，达到了96.8%，。Young GC 平均耗时稍有上升，从60ms上升到了71ms，基本符合预期。另外Full GC 的频率和耗时也在可接受的范围。

调优是个复杂、细致的活儿，要因地制宜。不同的机器、不同的应用、不同的业务场景和不同的访问量级，调优的方式都不同，没有一个固定的模式。做JVM调优之前，建议先了解JVM运行原理，内存模型，GC过程，相关GC回收器回收机制，回收算法。先把基础知识打扎实，再加上耐心和决心才能够真正做好JVM优化，成为JVM高手。

参考

https://club.perfma.com/article/1846118