频繁操作本地缓存导致YGC耗时过长

某天,某位群友在JVM讨论群里发来一张GC log的图片。

其中主要的问题是YGC过长,每次耗时约为200ms。

YGC耗时过长

使用的JVM参数如下:

-Xmn2048m -Xms4096m -Xmx4096m -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:MetaspaceSize=128M -XX:MaxMetaspaceSize=128M

指定年轻代内存为2g,初始JVM内存为4g,最大JVM内存为4g。


这个问题引起了群友们的关注。

从GC log和JVM参数可以看出,GC算法使用默认的Parallel Scanvenge。

可以看到Eden区大小为1536M,两个Survivor区大小为256M。

得出-XX:SurvivorRatio = 6。

此外可以看到在GC时,desired survivor size 268435456 bytes = 256M,得出-XX:TargetSurvivorRatio = 100。

默认情况下,-XX:SurvivorRatio = 8,-XX:SurvivorRatio = 50。

然而并未设置这两个参数,一直怀疑是配置没有生效。

一时没有想到办法,有群友建议试着调整下 MaxGCPauseMills 或者 GCTimeRatio 参数。

然后效果都不好。


之后的某天,尝试使用jmap -heap pid打印应用的堆栈信息。

jmap查看应用堆栈信息

发现虽然写着SurvivorRatio = 8,但是E:S0:S1的比例并非是8:1:1。

于是开始寻找原因。

找到来自R大的回答:

http://hllvm.group.iteye.com/group/topic/35468

HotSpot VM里,ParallelScavenge系的GC(UseParallelGC / UseParallelOldGC)默认行为是SurvivorRatio如果不显式设置就没啥用。显式设置到跟默认值一样的值则会有效果。

因为ParallelScavenge系的GC最初设计就是默认打开AdaptiveSizePolicy的,它会自动、自适应的调整各种参数。

于是推荐群友尝试使用CMS,让这些配置固定下来,不做自适应调整。

但设置之后,发现YGC效果依旧不好。

jstat信息

显示发生4次YGC,耗时1.145s,平均耗时约286ms,情况反而更糟。


回头再次分析GC log。

发现日志中有这么一行。

new threshold 7 (max 15)

JVM中有个参数为晋升年龄阈值(-XX:MaxTenuringThreshold),默认值为15。

意思为在YGC时,超过该年龄的对象会被晋升到老年代。

但GC log中显示该阈值被修改成了7。

在年轻代对象晋升时,有一个判断条件如下:

动态年龄判断,大于等于某个年龄的对象超过了survivor空间一半,大于等于某个年龄的对象直接进入老年代。

得出,在某次YGC时,Survivor区中,年龄超过7的对象占用了Survivor空间一半以上。

而正常情况下,年轻代对象朝生夕死。

网络服务处理请求为毫秒级,YGC几秒甚至十几秒才发生一次。

多数年轻对象活不过1代。

于是,猜测该群友使用了本地缓存。


在得到肯定的回复后,详细询问了群友使用本地缓存的方法。

自行实现了一个本地缓存,类似于HashMap。

别的服务会每一分钟推送缓存数据用于同步。

在同步的时候不做diff操作,直接put。

举例:

缓存中保存Person类。

@Data
class Person {

    private String name;

    private Integer age;
}

缓存内容可能为:

{
    "jjs":{
        "age":27,
        "name":"jjs"
    }
}

缓存同步涉及两种操作:新增和覆盖

两种操作均直接使用put操作实现,无论当前缓存key是否已经存在。

这样的操作方法在业务上完全没有问题。

但对于GC而言,每次缓存同步需要new很多新的对象,并且这些对象都将一直存活,直到被覆盖,或者晋升到老年代。

这些缓存对象首先会被分配到年轻代,在YGC时候,这些对象都会被标记为存活。

得到YGC耗时过长原因一:

年轻代中有太多存活的对象,增加了标记时间。

此外,HashMap是数组加链表的结构,使用Node结构用于保存key、value。

HashMap的Node结构如下:

    static class Node<K,V> implements Map.Entry<K,V> {
        final int hash;
        final K key;
        V value;
        Node<K,V> next;
    }

每次put生成的node节点,很可能(hash冲突)被挂在已有node节点的next域上。

已有node为缓存,长期存活,很有可能位于老年代。

那么,就形成了老年代对象对年轻代对象的引用。

在YGC中,需要扫描Card Table中的dirty区域来识别被老年代对象引用的年轻代对象。

正常情况下,这种情形并不多。但在本文例子中,会大量存在。

得到YGC耗时过长原因二:

YGC又需要花费大量的时间在扫描Card Table上。

总结原因是操作本地缓存太频繁导致了YGC耗时过长。


回顾YGC的大致过程:

YGC / 图片来自Garbage Collection in the Java HotSpot Virtual Machine
  1. 从根节点开始扫描年轻代对象,直到扫描到下个引用为非年轻代对象。(可以避免YGC扫描整个堆。)
  2. 扫描老年代dirty区域,即可扫描到被老年代对象引用的年轻代对象。(老年代被分为不同的块,Card Table字节数组中每个字节表示老年代中的一块。新分配对象时,触发写屏障,存在有老年代对象引用年轻代对象时,将对应的卡表设置为dirty。)
  3. 将Eden和From区中的对象复制到To区。如果To区已满,则直接复制到老年代。

YGC耗时过长问题的排查还是应该从两个点出发:

  1. YGC时存活的年轻代对象太多。

  2. 老年代对象引用年轻代对象的情况太多。


解决方案:

修改代码需要一定的时间,群友采用了一种短期的办法。

修改了推送的周期。原来每一分钟推送一次。

YGC下降到18-25ms,但在缓存推送时,YGC时间仍然达到200ms。

两次缓存推送之间的对象都符合朝生夕死的弱分代假设,YGC时间正常。


后续修改思考/建议:

  • 分批推送缓存,并且在接到推送的缓存时做diff操作,尽量修改已有对象而非新建对象。此举可减少长寿对象生成。
  • 即使使用分批推送,在应用启动时,还是需要全量加载缓存。仍旧会面临应用刚启动时,YGC耗时过长的问题。
  • 重新规划应用。因为经常变化的数据并不适合放在缓存中。
  • 使用Redis缓存。Redis的响应时间为毫秒级,甚至只需几毫秒,并且无需考虑分布式下缓存同步问题。
  • 使用CMS垃圾回收算法。因为默认和Parallel Scanvenge算法配合的老年代回收算法是Serial Old或者Parallel Old。该算法需要标记清理压缩,STW时间较长。
最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 159,458评论 4 363
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,454评论 1 294
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 109,171评论 0 243
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 44,062评论 0 207
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,440评论 3 287
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,661评论 1 219
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,906评论 2 313
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,609评论 0 200
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,379评论 1 246
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,600评论 2 246
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 32,085评论 1 261
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,409评论 2 254
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 33,072评论 3 237
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,088评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,860评论 0 195
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,704评论 2 276
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,608评论 2 270

推荐阅读更多精彩内容