写点什么

深入 JVM 彻底剖析 ygc 越来越慢的原因(上)

2016 年 5 月 04 日

今天一个同学问我:“我排查问题时总是遇到,jmap -heap 或 -histo 不能用,是不是我们机器配置有啥问题哇? ”

分享下这个 case 的解决过程。

登上同学说的那台不能用的机器,执行 jstack,报错:get_thread_regs failed for a lwp,这个问题以前碰到过,但忘了当时是什么原因了,执行其他的jmap -histo什么也卡着不动。

既然 jstack 没法弄,就 pstack 看看进程到底什么状况吧,于是 pstack [pid] 看,发现有一个线程的堆栈信息有点奇怪:

\#0 0x00000038e720cd91 in sem_wait ()对系统函数不太懂,但总觉得sem_wait这个有点奇怪,于是 Google 之,基本明白了这个是由于进程在等信号,这个时候通常会 block 住其他所有的线程,于是立刻 ps 看了下进程的状态,果然进程的状态变成了 T,那上面碰到的所有现象都很容易解释了,于是执行:kill -CONT [pid],一切恢复正常。

继续查为什么进程状态会变成 T,问问题的同学告诉了下我他在机器上执行过的一些命令,我看到其中一个很熟悉的命令:jmap -heap,看过我之前文章的同学估计会记得我很早以前分享过,在用 cms gc 的情况下,执行jmap -heap有些时候会导致进程变 T,因此强烈建议别执行这个命令,如果想获取内存目前每个区域的使用状况,可通过jstat -gcjstat -gccapacity来拿到。

到此为止,问题终于搞定,以后碰到 jstack/jmap 等不能用的时候,可以先看看进程的状态,因此还是那句话,执行任何一句命令都要清楚它带来的影响。

手头还有另外一个 case,折腾了一个多星期了还是没太有头绪,case 的现象是 ygc 越来越慢,但可以肯定不是由于 cms gc 碎片问题造成的,感兴趣的同学可以拿这个 case 去玩玩,如果能告诉我原因就更好了:),执行下面的代码,启动参数可以为“-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xms512m -Xmx512m -Xmn100m -XX:+UseConcMarkSweepGC:”

复制代码
 
复制代码
import com.thoughtworks.xstream.XStream;
public class XStreamTest {
public static void main(String[] args) throws Exception {
while(true){
XStream xs = new XStream();
xs.toString();
xs = null;
}
}
}

应该就可以看到 ygc 的速度从 10+ms 一直增长到 100+ms 之类的…

针对这个 case,有位同学看到这个后周末时间折腾了下,把原因给分析出来了,分析过程很赞。非常感谢这位同学(阿里的一位同事,花名叫彦贝),在征求他的同意后,我把他写的整个问题的分析文章转载到这里。

上分析工具 VisualVM

在解决很多问题的时候,工具起的作用往往是巨大,很多时候通过工具分析,很快便能找到原因,但是这次并没有,下图是 VisualVM 观察到 Heap 上的 GC 图表。

从图标中可以看出,Perm 区空间基本水平,但是 Old 区空间成增长态势与 YGCT 时间增长的倍率基本一直。熟悉 YGC 的朋友都知道 YGC 主要分为标记和收回两个阶段,YGCT 也是基于这 2 个阶段统计的。由于每次回收的空间大小差不多,所以怀疑是标记阶段使用的时间比较长,下面回顾一下 JVM 的垃圾标记方式。

JVM 垃圾回收的标记方法:枚举根节点

在 Java 语言里面,可作为 GC Roots 的节点主要在全局性的引用(例如常量或类静态属性)与执行上下文(例如栈帧中的本地变量表)中。如果要使用可达性分析来判断内存是否可回收的,那分析工作必须在一个能保障一致性的快照中进行——这里“一致性”的意思是整个分析期间整个执行系统看起来就像被冻结在某个时间点上,不可以出现分析过程中,对象引用关系还在不断变化的情况,这点不满足的话分析结果准确性就无法保证。这点也是导致 GC 进行时必须“Stop The World”的其中一个重要原因,即使是号称(几乎)不会发生停顿的 CMS 收集器中,枚举根节点时也是必须要停顿的。

由于目前的主流 JVM 使用的都是准确式 GC,所以当执行系统停顿下来之后,并不需要一个不漏地检查完所有执行上下文和全局的引用位置,虚拟机应当是有办法直接得到哪些地方存放着对象引用。在 HotSpot 的实现中,是使用一组成为 OopMap 的数据结构来达到这个目的,在类加载完成的时候,HotSpot 就把对象内什么偏移量上是什么类型的数据计算出来,在 JIT 编译过程中,也会在特定的位置记录下栈里和寄存器里哪些位置是引用。这样 GC 在扫描时就就可以直接得知这些信息了。
上面这段引用自《深入理解 Java 虚拟机》,用个图简单表示一下,当然图也是源于书中:

基于对 GC Roots 的怀疑,猜测 Old 区中存在越来越多的 gc root 节点,那什么样的对象是 root 节点呢?不懂的我赶紧 google 了一下。

(不要看我红色圈出来了,第一次看到这几个嫌疑犯时我也拿不准是哪个)

为了进一步验证是 Old 区的 GC Roots 造成 YGCT 增加的,我们来做一次 full gc,干掉 Old 区。代码如下:

复制代码
public class SlowYGC {
public static void main(String[] args) throws Exception {
int i= 0;
while (true) {
XStream xs = new XStream();
xs.toString();
xs = null;
if(i++ % 10000 == 0)
{
System.gc();
}
}
}
}

可以看出 Full GC 后 YGCT 锐减到初始状态。那是 Full GC 到底回收了哪些对象?进入到下一步,增加 VM 参数。

增加 VM 参数

为了看到 Full GC 前后对象的回收情况,我们增加下面 2 个 VM 参数

-XX:+PrintClassHistogramBeforeFullGC
-XX:+PrintClassHistogramAfterFullGC

重新运行上面的代码,可以观察到下面的日志:

(点击放大图像)

上图左边是FGC 前的对象情况,右边是FGC 后的情况,结合我之前给出的GC Root 候选人中的Monitor 锁,相信你很快就找到20026 个 Ljava.util.concurrent.ConcurrentHashMap$Segment对象几乎被全部回收了,ConcurrentHashMap 中正是通过 Segment 来实现分段锁的。那什么逻辑会导致出现大量的 Segment 锁对象。继续看 Full GC 日志com.thoughtworks.xstream.core.util.CompositeClassLoader这个对象也差不多在 FGC 的时候全军覆没,所以怀疑是 ClassLoader 引起的锁竞争,下面在 ClassLoader 的源码中继续查找。

ClassLoader 中的 ConcurrentHashMap

这里有个拿锁的动作,跟进去看看呗。

为了验证走到这块逻辑下了一个断点。剩下的就是 putIfAbsent 方法(这里就不详细分析实现了)有兴趣的同学可以看看源码中 CAS 和 tryLock 的使用。

至此基本分析和定位出了 YGCT 原因,在去看看 Xstream 的构造函数。

可以看出每次new XstreamI()的同时会 new 一个新的 ClassLoader,基本上证明了上述怀疑和猜测。

推导一下按照上述分析,应该是所有自定义的 ClassLoader 都会 YGCT 变长的时间问题,于是手写一个 ClassLoader 验证一下。Java 代码如下:

复制代码
public class TestClassLoader4YGCT {
public static void main(String[] args) throws Exception{
while(true)
{
Object obj = newObject();
obj.toString();
obj = null;
}
}
private static Object newObject() throws Exception
{
ClassLoader classLoader = new ClassLoader() {
@Override
public Class
<!--?--> loadClass(String s) throws ClassNotFoundException {
try{
String fileName = s.substring(s.lastIndexOf(“.”) + 1)+ “.class”;
InputStream inputStream = getClass().getResourceAsStream(fileName);
if(inputStream == null){
return super.loadClass(s);
}
byte[] b = new byte[inputStream.available()];
inputStream.read(b);
return defineClass(s,b,0,b.length);
}catch (Exception e)
{
System.out.println(e);
return null;
}
}
};
Class
<!--?--> obj = classLoader.loadClass(“jvmstudy.classload.TestClassLoader4YGCT”);
return obj.newInstance();
}
}
复制代码
VM 参数 -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xms512m -Xmx512m -Xmn100m -XX:+UseConcMarkSweepGC

GC 日志

(点击放大图像)

结论

当大量new 自定义的ClassLoader 来加载时,会产生大量ClassLoader 对象以及parallelLockMap(ConcurrentHashMap)对象,导致产生大量的Segment 分段锁对象,大大增加了GC Roots 的数量,导致YGC 中的标记时间变长。如果能直接看到YGCT 的详细使用情况,这个结论会显得更加严谨。这只是我自己的一个推导,并不一定是正确答案。


感谢魏星对本文的审校。

给InfoQ 中文站投稿或者参与内容翻译工作,请邮件至 editors@cn.infoq.com 。也欢迎大家通过新浪微博( @InfoQ @丁晓昀),微信(微信号: InfoQChina )关注我们。

2016 年 5 月 04 日 17:4813985

评论

发布
暂无评论
发现更多内容

架构师训练营 12 周笔记

郎哲158

使用Angular8和百度地图api开发《旅游清单》

徐小夕

Java angular.js 前端 angular

第12周总结

饭桶

Learun FrameWork,.Net Core3.1工作流引擎平台

力软.net/java开发平台

.net core 工作流引擎

Week 12 作業

Christy LAW

智慧公安大数据分析研判系统开发,合成作战平台建设

WX13823153201

三金本体挖矿模式系统开发丨三金本体平台源码设计

系统开发咨询1357O98O718

三金本体挖矿模式源码

vivo 全球商城:从 0 到 1 代销业务的融合之路

vivo互联网技术

架构 分布式 商城项目 商城

「奇淫技巧」如何写最少的代码

Kerwin

Java 代码设计 代码技巧

Java并发编程:多线程并发内存模型

码农架构

Java并发

Forsage系统开发(模式分析)

系统开发咨询1357O98O718

Forsage系统开发案例介绍

年终盘点 | 七年零故障支撑双11的消息中间件 RocketMQ,怎么做到的?

阿里巴巴中间件

消息中间件 双十一

架构1期 第十二周作业

haha

第12周作业

饭桶

5分钟完成业务实时监控系统搭建,是一种什么样的体验?

阿里巴巴中间件

体验 监控

BMEX交易所系统软件开发|BMEX交易所APP开发

开發I852946OIIO

系统开发

有道逻辑英语-时态新发现笔记

Leo

学习 前端进阶训练营 笔记 时态

第十二周 作业

熊桂平

极客大学架构师训练营

第十二周 架构方法学习总结 —— 数据应用

兵长

区块链钱包系统开发方案丨多币种钱包系统开发详情

系统开发咨询1357O98O718

区块链钱包开发

LeetCode题解:433. 最小基因变化,BFS,JavaScript,详细注释

Lee Chen

算法 LeetCode 前端进阶训练营

Week 12 學習總結

Christy LAW

OKO疯矿链系统开发案例(源码)

系统开发咨询1357O98O718

OKO疯矿链系统开发

TRONex波场智能合约系统开发详解丨TRONex波场链系统开发(源码)

系统开发咨询1357O98O718

系统开发 TRONex波场智能合约 APP开发

智天下APP系统开发|智天下软件开发

开發I852946OIIO

系统开发

架构师训练营 12 周作业

郎哲158

ETH场外交易系统开发流程丨ETH场外交易开发源码案例

系统开发咨询1357O98O718

ETH场外交易系统开发

与前端训练营的日子 --Week07

SamGe

学习

COMP矿池矿机系统开发案例分析

系统开发咨询1357O98O718

COMP矿池矿机系统开发介绍

如何降低微服务测试成本?我的经验之谈

阿里巴巴中间件

减肥为什么会失败,有可能是因为你仍然在摄入容易消化的食用糖。

叶小鍵

科普 减肥、廋身 盖里·陶比斯 加工食用糖

InfoQ 极客传媒开发者生态共创计划线上发布会

InfoQ 极客传媒开发者生态共创计划线上发布会

深入JVM彻底剖析ygc越来越慢的原因(上)-InfoQ