垃圾收集器长时间停顿,表现在 Web 页面上可能是页面响应码 500 之类的服务器错误问题,如果是个支付过程可能会导致支付失败,将造成公司的直接经济损失,程序员要尽量避免或者说减少此类情况发生。
提升失败(promotion failed)
在 Minor GC 过程中,Survivor Unused 可能不足以容纳 Eden 和另一个 Survivor 中的存活对象, 那么多余的存货对象将被移到老年代, 称为过早提升(Premature Promotion)。 这会导致老年代中短期存活对象的增长, 可能会引发严重的性能问题。
再进一步,如果老年代没有足够的空间放下这些存活对象,或者老年代有足够的空间,但是由于碎片较多,这时如果新生代要转移到老年带的对象比较大,所以,必须尽可能提早触发老年代的CMS回收来避免这个问题(promotion failed时老年代CMS还没有机会进行回收,又放不下转移到老年带的对象,因此会出现下一个问题concurrent mode failure,需要stop-the-wold GC- Serail Old)。
提升失败日志:
2016-01-07T18:54:26.948+0800: 18782.967: [GC2016-04-07T18:54:26.948+0800: 18782.967: [ParNew (promotion failed)
Desired survivor size 117833728 bytes, new threshold 10 (max 10)
- age 1: 6141680 bytes, 6141680 total
- age 2: 6337936 bytes, 12479616 total
- age 3: 549120 bytes, 13028736 total
- age 4: 87768 bytes, 13116504 total
- age 5: 221384 bytes, 13337888 total
- age 6: 934168 bytes, 14272056 total
- age 7: 146072 bytes, 14418128 total
- age 8: 626064 bytes, 15044192 total
- age 9: 398000 bytes, 15442192 total
- age 10: 429616 bytes, 15871808 total
: 1969227K->1929200K(2071808K), 0.7452140 secs]2016-01-07T18:54:27.693+0800: 18783.713: [CMS: 1394703K->632845K(2097152K), 4.0993640 secs] 3301676K->632845K(4168960K), [CMS Perm : 77485K->77473K(159744K)], 4.8450240 secs] [Times: user=5.18 sys=0.56, real=4.84 secs]
Heap after GC invocations=5847 (full 7):
par new generation total 2071808K, used 0K [0x00000006e9c00000, 0x0000000776400000, 0x0000000776400000)
eden space 1841664K, 0% used [0x00000006e9c00000, 0x00000006e9c00000, 0x000000075a280000)
from space 230144K, 0% used [0x0000000768340000, 0x0000000768340000, 0x0000000776400000)
to space 230144K, 0% used [0x000000075a280000, 0x000000075a280000, 0x0000000768340000)
concurrent mark-sweep generation total 2097152K, used 632845K [0x0000000776400000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 77473K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
}
解决方案:
- 针对一些大的朝生熄灭的对象,Surivor空间存放不下,就会存放到老年代,针对这种情况,可以扩大Survivor空间。
- 老年代空间碎片,无法放下大对象,就在进行一定次数的Full GC(标记清除)的时候进行一次标记整理算法。
并发模式失败(concurrent mode failure)
由于cms的无法处理浮动垃圾(Floating Garbage)引起的。这个跟cms的机制有关。cms的并发清理阶段,用户线程还在运行,因此不断有新的垃圾产生,而这些垃圾不在这次清理标记的范畴里头,cms无法在本次gc清除掉,这些就是浮动垃圾。由于这种机制,cms年老代回收的阈值不能太高,否则就容易预留的内存空间很可能不够(因为本次gc同时还有浮动垃圾产生
),从而导致concurrent mode failure发生。可以通过-XX:CMSInitiatingOccupancyFraction的值来调优。
日志:
2016-02-21T13:53:07.974+0800: 171467.254: [GC [1 CMS-initial-mark: 1436199K(1560576K)] 1512927K(2504320K), 0.0618140 secs] [Times: user=0.06 sys=0.00, real=0.07 secs]
2016-02-21T13:53:08.036+0800: 171467.316: [CMS-concurrent-mark-start]
2016-02-21T13:53:08.377+0800: 171467.657: [CMS-concurrent-mark: 0.340/0.340 secs] [Times: user=2.11 sys=0.15, real=0.34 secs]
2016-02-21T13:53:08.377+0800: 171467.657: [CMS-concurrent-preclean-start]
2016-02-21T13:53:08.385+0800: 171467.665: [CMS-concurrent-preclean: 0.008/0.008 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2016-02-21T13:53:08.385+0800: 171467.665: [CMS-concurrent-abortable-preclean-start]
{Heap before GC invocations=88667 (full 45):
par new generation total 943744K, used 914399K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 100% used [0x0000000757000000, 0x000000078a340000, 0x000000078a340000)
from space 104832K, 72% used [0x000000078a340000, 0x000000078ecf7d98, 0x00000007909a0000)
to space 104832K, 0% used [0x00000007909a0000, 0x00000007909a0000, 0x0000000797000000)
concurrent mark-sweep generation total 1560576K, used 1436199K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
2016-02-21T13:53:09.535+0800: 171468.815: [GC2016-02-21T13:53:09.535+0800: 171468.815: [ParNew
Desired survivor size 53673984 bytes, new threshold 6 (max 6)
- age 1: 7100568 bytes, 7100568 total
- age 2: 4676456 bytes, 11777024 total
- age 3: 8773736 bytes, 20550760 total
- age 4: 7709744 bytes, 28260504 total
- age 5: 10891960 bytes, 39152464 total
- age 6: 11735032 bytes, 50887496 total
: 914399K->75616K(943744K), 0.0414860 secs] 2350599K->1517225K(2504320K), 0.0417710 secs] [Times: user=0.32 sys=0.05, real=0.05 secs]
Heap after GC invocations=88668 (full 45):
par new generation total 943744K, used 75616K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 0% used [0x0000000757000000, 0x0000000757000000, 0x000000078a340000)
from space 104832K, 72% used [0x00000007909a0000, 0x0000000795378128, 0x0000000797000000)
to space 104832K, 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)
concurrent mark-sweep generation total 1560576K, used 1441609K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
}
2016-02-21T13:53:10.202+0800: 171469.482: [CMS-concurrent-abortable-preclean: 1.772/1.817 secs] [Times: user=4.94 sys=0.06, real=1.81 secs]
2016-02-21T13:53:10.204+0800: 171469.483: [GC[YG occupancy: 497152 K (943744 K)]2016-02-21T13:53:10.204+0800: 171469.483: [Rescan (parallel) , 1.3691900 secs]2016-02-21T13:53:11.573+0800: 171470.853: [weak refs processing, 0.1009300 secs]2016-02-21T13:53:11.674+0800: 1714
70.954: [class unloading, 0.0153470 secs]2016-02-21T13:53:11.689+0800: 171470.969: [scrub symbol table, 0.0110770 secs]2016-02-21T13:53:11.700+0800: 171470.980: [scrub string table, 0.0016360 secs] [1 CMS-remark: 1441609K(1560576K)] 1938761K(2504320K), 1.5079530 secs] [Ti
mes: user=13.01 sys=0.08, real=1.51 secs]
2016-02-21T13:53:11.712+0800: 171470.992: [CMS-concurrent-sweep-start]
{Heap before GC invocations=88668 (full 45):
par new generation total 943744K, used 914528K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 100% used [0x0000000757000000, 0x000000078a340000, 0x000000078a340000)
from space 104832K, 72% used [0x00000007909a0000, 0x0000000795378128, 0x0000000797000000)
to space 104832K, 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)
concurrent mark-sweep generation total 1560576K, used 1441606K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
2016-02-21T13:53:11.775+0800: 171471.055: [GC2016-02-21T13:53:11.775+0800: 171471.055: [ParNew (promotion failed)
Desired survivor size 53673984 bytes, new threshold 6 (max 6)
- age 1: 4030872 bytes, 4030872 total
- age 2: 5959704 bytes, 9990576 total
- age 3: 4628680 bytes, 14619256 total
- age 4: 8773080 bytes, 23392336 total
- age 5: 7707144 bytes, 31099480 total
- age 6: 10890224 bytes, 41989704 total
: 914528K->907344K(943744K), 1.0312010 secs]2016-02-21T13:53:12.807+0800: 171472.086: [CMS2016-02-21T13:53:14.455+0800: 171473.735: [CMS-concurrent-sweep: 1.684/2.743 secs] [Times: user=3.69 sys=0.36, real=2.74 secs]
(concurrent mode failure): 1451903K->475795K(1560576K), 3.9644230 secs] 2356134K->475795K(2504320K), [CMS Perm : 78413K->78413K(159744K)], 4.9959570 secs] [Times: user=5.65 sys=0.34, real=5.00 secs]
Heap after GC invocations=88669 (full 46):
par new generation total 943744K, used 0K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)
eden space 838912K, 0% used [0x0000000757000000, 0x0000000757000000, 0x000000078a340000)
from space 104832K, 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)
to space 104832K, 0% used [0x00000007909a0000, 0x00000007909a0000, 0x0000000797000000)
concurrent mark-sweep generation total 1560576K, used 475795K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)
concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)
}
解决方案:
- CMS并发清理阶段,用户线程在年轻代中产生大量对象,大量年轻代中的对象要提升到老年代,老年代的清理速度赶不上年轻代的提升速度,就会造成
concurrent mode failure
,针对这个问题,- 扩大年轻代的空间,提升年轻代的晋升阈值
- 扩大老年代的空间存放年轻代要晋升的对象,设置 CMS 垃圾收集在老年代占比达到多少时启动来减少问题发生频率(越早启动问题发生频率越低,但是会降低吞吐量,具体得多调整几次找到平衡点)
- CMS并发清理阶段,年轻代提升上来的大对象,老年代碎片化严重,存放不下,针对这个问题,
- 一定次数的Full GC(标记清除)的时候进行一次标记整理算法。
总结:
promotion failed
造成Full GC,也可能会进一步造成concurrent mode failure
注意要尽量避免
concurrent mode failure
,因为这样会是CMS
收集器转化为Serial Old
收集器,Serial Old
收集器虽然会压缩老年代空间,但是这个收集器整个过程都是STOP THE World