Java 8年轻gc成本超过1s，如何减少新一代gc时间

Question

框架:Spring+mybatis+dubbo+RocketMQ。

下面是JVM参数：

-server-xmx5g-xms5g-xn1g-xx:metaspacesize=512m-xx:maxmetaspacesize=512m-xss256k-xx:survivorratio=8-xx:+printgcdetails-xloggc:/opt/apps/logs/gc.log-xx:+printgcdatestamps-xx:+printgcapplicationstoppedtime-xx:+printsafepointstatistics-xx:printsafepointstatisticscount=1-xx:+printreferencegc

我花了两个星期的时间来研究这个问题，但还是找不出是什么原因造成的。首先，我打开了GC日志和安全点日志，怀疑安全点可能是原因。但是我发现旋转时间+阻挡时间很短。只有年轻gc发生时，vmop时间与年轻gc停止时间几乎相同。

然后检查FinalRefence集合，并添加PrintReferenceGC。也很短。

这是gc日志

Answer 1

从年轻集合之后的剩余堆占用情况可以看出，应用程序的活动集大小（包括年轻和老对象）似乎小于300MB。您的堆总大小为5GB，因此有很多喘息的空间。

而且由于有呼吸的空间和年轻的停顿时间是一个问题，你可以尝试缩小年轻一代，这可能会稍微增加的持续率，但CMS老一代收集器应该能够跟上这一点。

根据您提供的GC日志：

2019-09-20T07:56:55.968+0800: 40869.330: [GC (Allocation Failure) 2019-09-20T07:56:55.969+0800: 40869.331: [ParNew2019-09-20T07:56:56.006+0800: 40869.368: [SoftReference, 0 refs, 0.0000588 secs]2019-09-20T07:56:56.006+0800: 40869.368: [WeakReference, 114 refs, 0.0000369 secs]2019-09-20T07:56:56.006+0800: 40869.368: [FinalReference, 22 refs, 0.0000404 secs]2019-09-20T07:56:56.006+0800: 40869.368: [PhantomReference, 0 refs, 0 refs, 0.0000298 secs]2019-09-20T07:56:56.006+0800: 40869.368: [JNI Weak Reference, 0.0000626 secs]: 842095K->3179K(943744K), 0.0378130 secs] 1170641K->331912K(5138048K), 0.0394628 secs] [Times: user=0.70 sys=0.42, real=0.04 secs] 
2019-09-20T07:58:44.545+0800: 40977.907: [GC (Allocation Failure) 2019-09-20T07:58:44.545+0800: 40977.908: [ParNew2019-09-20T07:58:45.798+0800: 40979.160: [SoftReference, 0 refs, 0.0000641 secs]2019-09-20T07:58:45.798+0800: 40979.160: [WeakReference, 116 refs, 0.0000436 secs]2019-09-20T07:58:45.798+0800: 40979.160: [FinalReference, 14 refs, 0.0000217 secs]2019-09-20T07:58:45.798+0800: 40979.160: [PhantomReference, 0 refs, 0 refs, 0.0000293 secs]2019-09-20T07:58:45.798+0800: 40979.160: [JNI Weak Reference, 0.0000510 secs]: 842091K->3159K(943744K), 1.2526309 secs] 1170824K->331976K(5138048K), 1.2541209 secs] [Times: user=6.73 sys=0.66, real=1.26 secs]