性能问答>应用集群个别实例 young gc 时间突然飙升>
16回复
11月前

应用集群个别实例 young gc 时间突然飙升



问题描述

一个线上16个节点的服务,突然有两个节点young gc 时间异常。从原先的10ms飙升到1000+ms,到后面的3s以上
目前解决方法是先把这两个节点给剔除了,但是没有下线;
image.png


gc-log 分析链接

应用配置和状态

JVM参数

-Xms4g -Xmx4g -Xmn2g -XX:MetaspaceSize=256m -XX:MaxMetaspaceSize=256m -XX:SurvivorRatio=8 -XX:+UseConcMarkSweepGC -XX:+UseCMSCompactAtFullCollection -XX:CMSMaxAbortablePrecleanTime=5000 -XX:+CMSClassUnloadingEnabled -XX:CMSInitiatingOccupancyFraction=80 -XX:+DisableExplicitGC -verbose:gc -Xloggc:/data/logs/app-gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Dfile.encoding=UTF-8 -Djava.awt.headless=true -XX:+UseCompressedOops -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/logs/app.dump -XX:MaxDirectMemorySize=256m -XX:+UseCMSInitiatingOccupancyOnly -XX:+ExplicitGCInvokesConcurrent

容器配置

  • 4C8g

内存监控

image.png

提问

想请教一下这种 young gc 时间突然上升的,而且是个别节点的出现的问题该如何排查?

3337 阅读
请先登录,再评论

大概看了下,我觉得可以基本确定的是,大量对象晋升到老年代导致的年轻代暂停时间变长(从 Interactive Graphs 可知),晋升给年轻代复制算法带来的影响比较大,除了在晋升时候做更多的逻辑判断外,这些晋升的对象就呆在老年代变成活的了(从日志分析可知,这些对象其实大部分是短暂的),晋升后因为这些对象存活(除非来一次FGC,但是没有发生),所以加重了老年代到年轻代的代际引用处理时间,年轻代时间再也缩短不了了。应该去想办法重点找出到底是哪些对象晋升上去了。

311月前
回复 Richard_Yi:

这个就有待继续研究和理解了

11月前回复
回复 鸠摩:

card table 存在就是为了记录跨代引用,目前来看就是这几百兆对象的突然晋升可能大部分都存在这个跨代引用。HotSpot 使用 CardTable 记录老年代对年轻代的引用。把老年代按照 4KB 的大小分块,每一块对应在 CardTable 中都是1 bit。当值为1时,表示这4KB 的内存中有对年轻代的引用,需要加入到 GC Roots 中。这可能更加剧了扫描的耗时。我个人有个疑问,为啥 young gc 扫描之后,不会去更新card table 里面的跨代引用情况。。

11月前回复
回复 Richard_Yi:

其他机子,gc日志有这个突然500M晋升到老年代情况吗,我感觉确实这个500M是关键,增加了扫描老年代的时间。看你那边运行其实很稳定都只有young gc没有cms gc,要么别让它晋升(可以试试调大XX:MaxTenuringThreshold和年轻代大小),要么能触发cms gc,不然500m就一直在(不过后面为啥会有9s的时间不清楚)

11月前回复
查看更多

两个问题节点的情况是相似的。正常节点old gen 也有从400 -> 800 -> 1600的内存变化,但是gc时间一直是正常的。

另外提供一个信息,这是一个文件服务,提供文件上传(频次低)和查询功能。

两个异常节点:
1:https://gceasy.io/my-gc-report.jsp?p=c2hhcmVkLzIwMjEvMDYvMy8tLTEwLjEzMC45LjEzMi1hcHAtZ2NfMjAyMS0wNi0wMy0xMC4wMS4wNC45MDMudHh0LS0yLTktMTg=&channel=WEB

2. https://gceasy.io/my-gc-report.jsp?p=c2hhcmVkLzIwMjEvMDYvMy8tLTEwLjEzMC4xMy4xMjQtYXBwLWdjXzIwMjEtMDYtMDMtMTAuMDUuMzQuMS50eHQtLTItOS0xOA==&channel=WEB

正常节点:https://gceasy.io/diamondgc-report.jsp?oTxnId_value=889d7cfc-a71f-46ce-832c-c03c6e99143a

111月前
回复 鸠摩:

正常节点Old Gen有过CMS GC,但是在这之前ygc的时间也很正常。正常节点 old gen 也是一次性陡增的(不知道是因为年龄晋升还是因为分配担保)。我怀疑是不是这两个异常节点晋升的对象有问题,一直存在着对新生代新生对象的引用。https://gceasy.io/my-gc-report.jsp?p=c2hhcmVkLzIwMjEvMDYvNC8tLTEwLjEzMC4xNC4xODktYXBwLWdjXzIwMjEtMDYtMDMtMTAuMTAuMjkuMzMwLnR4dC0tMi04LTMw&channel=WEB
image.png

11月前回复
回复 Richard_Yi:

正常节点的看不了呀,正常节点Old Gen有对象晋升后有没有过CMS GC

11月前回复
回复 Richard_Yi:

拿了一个问题节点做测试,手动 jmap -histo:live ,full gc 之后这个节点的young gc就正常了。image.png

11月前回复

2g的新生代,younggc时间突然变长,首先考虑是不是机器cpu资源争抢? 问题发生时是不是cpu占用很高导致gc线程拿不到cpu资源,如果是虚拟机要考虑宿主机cpu的占用

111月前
回复 ferdi:

监控看了,没有发生资源抢占。容器资源也都是隔离的,没有超配,同一宿主机上不会有竞争。

image.png

11月前回复