Java GC全集(十一):过早提升速率问题和解决方案

本文来自于HeapDump性能社区! !有性能问题,上HeapDump性能社区!
正文:

过早提升(Premature Promotion)

提升速率(promotion rate), 用于衡量单位时间内从年轻代提升到老年代的数据量。一般使用 MB/sec 作为单位, 和分配速率类似。

JVM会将长时间存活的对象从年轻代提升到老年代。根据分代假设, 可能存在一种情况, 老年代中不仅有存活时间长的对象,也可能有存活时间短的对象。这就是过早提升:对象存活时间还不够长的时候就被提升到了老年代。

major GC 不是为频繁回收而设计的, 但 major GC 现在也要清理这些生命短暂的对象, 就会导致GC暂停时间过长。这会严重影响系统的吞吐量。

如何测量提升速率

可以指定JVM参数 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps , 通过GC日志来测量提升速率. JVM记录的GC暂停信息如下所示:

0.291: [GC (Allocation Failure)
[PSYoungGen: 33280K->5088K(38400K)]
33280K->24360K(125952K), 0.0365286 secs]
[Times: user=0.11 sys=0.02, real=0.04 secs]
0.446: [GC (Allocation Failure)
[PSYoungGen: 38368K->5120K(71680K)]
57640K->46240K(159232K), 0.0456796 secs]
[Times: user=0.15 sys=0.02, real=0.04 secs]
0.829: [GC (Allocation Failure)
[PSYoungGen: 71680K->5120K(71680K)]
112800K->81912K(159232K), 0.0861795 secs]
[Times: user=0.23 sys=0.03, real=0.09 secs]

从上面的日志可以得知: GC之前和之后的 年轻代使用量以及堆内存使用量。这样就可以通过差值算出老年代的使用量。GC日志中的信息可以表述为:

Event Time Young decreased Total decreased Promoted Promotion rate
(事件) (耗时) (年轻代减少) (整个堆内存减少) (提升量) (提升速率)
--- --- --- --- --- ---
1st GC 291ms 28,192K 8,920K 19,272K 66.2 MB/sec
2nd GC 446ms 33,248K 11,400K 21,848K 140.95 MB/sec
3rd GC 829ms 66,560K 30,888K 35,672K 93.14 MB/sec
Total 829ms 76,792K 92.63 MB/sec

根据这些信息, 就可以计算出观测周期内的提升速率。平均提升速率为 92 MB/秒, 峰值为 140.95 MB/秒

请注意, 只能根据 minor GC 计算提升速率。 Full GC 的日志不能用于计算提升速率, 因为 major GC 会清理掉老年代中的一部分对象。

提升速率的意义

和分配速率一样, 提升速率也会影响GC暂停的频率。但分配速率主要影响 minor GC, 而提升速率则影响 major GC 的频率。有大量的对象提升,自然很快将老年代填满。 老年代填充的越快, 则 major GC 事件的频率就会越高。

v2-df2149a5d93253177a396370eadf8e44_1440w.png

此前说过, full GC 通常需要更多的时间, 因为需要处理更多的对象, 还要执行碎片整理等额外的复杂过程。

示例

让我们看一个过早提升的示例。 这个程序创建/获取大量的对象/数据,并暂存到集合之中, 达到一定数量后进行批处理:

public class PrematurePromotion {
private static final Collection<byte[]> accumulatedChunks
= new ArrayList<>();
private static void onNewChunk(byte[] bytes) {
accumulatedChunks.add(bytes);
if(accumulatedChunks.size() > MAX_CHUNKS) {
processBatch(accumulatedChunks);
accumulatedChunks.clear();
}
}
}

Demo 程序 受到过早提升的影响。下文将进行验证并给出解决办法。

过早提升的影响

一般来说,过早提升的症状表现为以下形式:

  • 短时间内频繁地执行 full GC。
  • 每次 full GC 后老年代的使用率都很低, 在10-20%或以下。
  • 提升速率接近于分配速率。

要演示这种情况稍微有点麻烦, 所以我们使用特殊手段, 让对象提升到老年代的年龄比默认情况小很多。指定GC参数 -Xmx24m -XX:NewSize=16m -XX:MaxTenuringThreshold=1, 运行程序之后,可以看到下面的GC日志:

2.176: [Full GC (Ergonomics)
[PSYoungGen: 9216K->0K(10752K)]
[ParOldGen: 10020K->9042K(12288K)]
19236K->9042K(23040K), 0.0036840 secs]
2.394: [Full GC (Ergonomics)
[PSYoungGen: 9216K->0K(10752K)]
[ParOldGen: 9042K->8064K(12288K)]
18258K->8064K(23040K), 0.0032855 secs]
2.611: [Full GC (Ergonomics)
[PSYoungGen: 9216K->0K(10752K)]
[ParOldGen: 8064K->7085K(12288K)]
17280K->7085K(23040K), 0.0031675 secs]
2.817: [Full GC (Ergonomics)
[PSYoungGen: 9216K->0K(10752K)]
[ParOldGen: 7085K->6107K(12288K)]
16301K->6107K(23040K), 0.0030652 secs]

乍一看似乎不是过早提升的问题。事实上,在每次GC之后老年代的使用率似乎在减少。但反过来想, 要是没有对象提升或者提升率很小, 也就不会看到这么多的 Full GC 了。

简单解释一下这里的GC行为: 有很多对象提升到老年代, 同时老年代中也有很多对象被回收了, 这就造成了老年代使用量减少的假象. 但事实是大量的对象不断地被提升到老年代, 并触发 full GC。

解决方案

简单来说, 要解决这类问题, 需要让年轻代存放得下暂存的数据。有两种简单的方法:

一是增加年轻代的大小, 设置JVM启动参数, 类似这样: -Xmx64m -XX:NewSize=32m, 程序在执行时, Full GC 的次数自然会减少很多, 只会对 minor GC的持续时间产生影响:

2.251: [GC (Allocation Failure)
[PSYoungGen: 28672K->3872K(28672K)]
37126K->12358K(61440K), 0.0008543 secs]
2.776: [GC (Allocation Failure)
[PSYoungGen: 28448K->4096K(28672K)]
36934K->16974K(61440K), 0.0033022 secs]

二是减少每次批处理的数量, 也能得到类似的结果. 至于选用哪个方案, 要根据业务需求决定。在某些情况下, 业务逻辑不允许减少批处理的数量, 那就只能增加堆内存,或者重新指定年轻代的大小。

如果都不可行, 就只能优化数据结构, 减少内存消耗。但总体目标依然是一致的: 让临时数据能够在年轻代存放得下。
在本系列文章中,介绍了JVM中垃圾收集的实现原理,以及如何高效地利用GC。
第一篇:什么是垃圾回收?

第二篇:Java 中的垃圾收集原理解析

第三篇:GC算法基础篇

第四篇:GC 算法实现篇——串行GC

第五篇:GC 算法实现篇——并行GC

第六篇:GC 算法实现篇——并发标记-清除

第七篇:GC 算法实现篇——垃圾优先算法

第八篇:GC 调优基础篇

第九篇:GC 调优工具篇

第十篇:GC调优实战篇—高分配速率(High Allocation Rate)

第十一篇:GC 调优的实战篇—过早提升(Premature Promotion)

第十二篇:GC 调优的实战篇—Weak, Soft 及 Phantom 引用

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 215,012评论 6 497
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,628评论 3 389
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 160,653评论 0 350
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,485评论 1 288
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,574评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,590评论 1 293
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,596评论 3 414
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,340评论 0 270
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,794评论 1 307
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,102评论 2 330
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,276评论 1 344
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,940评论 5 339
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,583评论 3 322
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,201评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,441评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,173评论 2 366
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,136评论 2 352

推荐阅读更多精彩内容