这是一个创建于 1270 天前的主题，其中的信息可能已经有所发展或是发生改变。
问题描述
一个线上 16 个节点的服务，突然有两个节点 young gc 时间异常。从原先的 10ms 飙升到 1000+ms，到后面的 3s 以上。 目前解决方法是先把这两个节点给剔除了，但是没有下线；
应用配置和状态
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
内存监控
提问
想请教一下这种 young gc 时间突然上升的，而且是个别节点的出现的问题该如何排查？正常节点的 young gc 频率和异常节点大致相同，但是时间相差巨大。
第 1 条附言 · 2021-06-02 17:31:44 +08:00
这个问题的重点难道不是 young gc 的时间为什么这么异常吗，dump 下来之后去掉 unreachable object 整个堆也就 150M 的不可回收对象，说明内存分配和回收是没有问题的。
但是正常节点 young gc 只用 20ms，两个异常节点每次却要 > 1s 的时间。
gc 的原因和间隔在 gceasy 的分析链接里面都有。我不纠结 gc 的原因，就是最常见的 allocation failure
但是正常节点 young gc 只用 20ms，两个异常节点每次却要 > 1s 的时间。
gc 的原因和间隔在 gceasy 的分析链接里面都有。我不纠结 gc 的原因，就是最常见的 allocation failure
 |
1
henta 2021-06-02 17:07:52 +08:00
我说一个可能的原因吧，redis 并发拉取没有加锁，具体分析等大神来
|
 |
2
fkname 2021-06-02 17:13:02 +08:00
jstat -gccause pid 1000 每秒查询是否存在 gc 和 gc 原因
|
 |
3
ccde8259 2021-06-02 19:31:48 +08:00 via iPhone
由于 CMS 有两次 STW，STW 时间是否异常？进入 SafePoint 耗时是否异常？
其次 MaxAbortablePrecleanTime 是 5 秒，Preclean 阶段耗时是否异常？是否可以适当压缩 Preclean 阶段耗时？ |
 |
4
linbiaye 2021-06-02 19:37:54 +08:00
看图没有泄漏，隔离了之后请求到其它节点也没引起异常，如果确认其他节点配置都一样，java 版本都一样，由于请求引起的可能性很小。排查一下异常节点系统，是不是系统内存吃紧，引起了 swap?
|
 |
5
hyperdak288 2021-06-02 19:58:28 +08:00
有个 trick 的套路，因为 parnew 和 cms 的 gclog 实在太少，可以用 G1 来打印更 detail 的日志方便找到可能出现问题的阶段
|
 |
6
limuyan44 2021-06-02 20:00:11 +08:00
换 g1，看哪个阶段出了问题，不过通常都是直接甩锅给 swap 。
|
 |
7
RichardYyf OP 我这边差不多有结论了，明天验证一下。另外想看下各位 V 友对于这个问题的讨论。目前为止讨论好少。。Java 相关的技术贴热度居然这么低🤣
|
 |
8
rapperx2 2021-06-03 09:29:46 +08:00
看不懂，无法讨论，下一位！
|
 |
9
ledkk 2021-06-03 10:33:29 +08:00  1
ygc 耗时高有很多种原因，常见的是年轻代的对象被年老代引用，每次统计是不是可以在 ygc 阶段回收的时候，都需要去年老代看引用的根对象是不是引用计数为 0，这段时间可能会导致耗时比较高。
|
 |
10
zhongpingjing 2021-06-03 14:06:25 +08:00
没有思路，期待大佬的分析结果
@RichardYyf |
|
11
RichardYyf OP @ledkk 大佬一语中的，目前判断是在某个很短的时间内，内存分配率忽然提高，GC 没有做好自适应准备，导致有几百兆的对象进入到老年代，存在跨代引用，增加了 young gc 时扫描处理时间。现在我个人感觉疑惑的是，GC 后面做好自适应准备后，每次 young gc 之后新生代的对象几乎都被回收了，1.6g -> 10m 左右，为啥 jvm 不会去把 card table 里面的跨代引用记录给删了。还要每次都去扫描呢？
|
|
12
RichardYyf OP 目前来看可能这几百兆对象的突然晋升可能大部分都存在这个跨代引用。HotSpot 使用 CardTable 记录老年代对年轻代的引用。把老年代分成一个个内存块，每一块对应在 CardTable 中都是 1 bit 。当值为 1 时，表示这个内存块中有对年轻代的引用，需要加入到 GC Roots 中。这可能更加剧了扫描的耗时。我个人有个疑问，为啥 young gc 扫描之后，不会去更新 card table 里面的跨代引用情况。我在一篇[国外的文章]( http://blog.ragozin.info/2011/06/understanding-gc-pauses-in-jvm-hotspots.html) 中找到了对整个 young gc 过程的详细解析，里面评论去有人提出过我的类似疑问，但是我没有搞懂回答中的后半句话。“There are two activities related to card table happen during young GC. Reference scanning tasks are clearing cards as memory is being scanned. Though if reference to object is rewritten (due to its relocation), card is marked dirty again. Every live object form young space is being relocated, so right after young GC, every memory page containing references to survived young objects is marked as dirty.”
|
|
13
RichardYyf OP 好吧稍微开窍了，这句话是说，Reference scanning task 会 reset card table，但是在当存活对象被移动到 survivor space 的时候，引用关系被重置，存在有引用这些存活年轻对象的老年区对象的内存页会被重新标记。
这个机制没有毛病。但是和我遇到的情况相印证就觉得有点奇怪。。 |
|
14
ledkk 2021-06-03 20:11:22 +08:00 1
从你发的截图看，年轻代增长很快，且每次 ygc 后都能回收大部分数据，但对应的老年代的空间上涨并不是特别快。这说明年轻代的这些对象基本都是临时对象，达不到常驻内存的条件，你们的 ygc 的耗时比较高。这种情况很可能是由于使用了类似本地缓存的模块，使用了 LRU 相关的策略，缓存的命中率并不高，新产生的年轻代的对象不停的往缓存中扔，缓存快速 LRU 淘汰，从而产生了年轻代被年老代引用的情况。
cardtable 内部只是存储了一块内存是否引用年轻代的标识，实际还是需要针对这块内存进行引用计数，判断年轻代的对象是否可回收 |
|
15
linbiaye 2021-06-07 14:49:49 +08:00
解决了吗？比较关注为啥就是两个特定的节点有问题。
|
Select Language