写点什么

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

2016 年 5 月 11 日

阿里 JVM 团队的同学帮助从 JVM 层面继续深入的剖析了下前面那个 ygc 越来越慢的 case,分析文章相当的赞,思路清晰,工具熟练,JVM 代码熟练,请看这位同学(阿里 JVM 团队:寒泉子)写的文章,我转载到这。

Demo 分析

虽然这个 demo 代码逻辑很简单,但是其实这是一个特殊的 demo,并不简单,如果我们将 XStream 对象换成 Object 对象,会发现不存在这个问题,既然如此那有必要进去看看这个 XStream 的构造函数(请大家直接翻 XStream 的代码,这里就不贴了)。

这个构造函数还是很复杂的,里面会创建很多的对象,上面还有一些方法实现我就不贴了,总之都是在不断构建各种大大小小的对象,一个 XStream 对象构建出来的时候大概好像有 12M 的样子。

那到底是哪些对象会导致 ygc 不断增长呢,于是可能想到逐步替换上面这些逻辑,比如将最后一个构造函数里的那些逻辑都禁掉,然后我们再跑测试看看还会不会让 ygc 不断恶化,最终我们会发现,如果我们直接使用如下构造函数构造对象时,如果传入的 classloader 是 AppClassLoader,那会发现这个问题不再出现了,代码如下:

复制代码
public static void main(String[] args) throws Exception {
int i=0;
while (true) {
XStream xs = new XStream(null,null, new ClassLoaderReference(XStreamTest.class.getClassLoader()),null, new DefaultConverterLookup());
xs.toString();
xs=null;
}
}

是不是觉得很神奇,由此可见,这个 classloader 至关重要。

不得不说的类加载器

这里着重要说的两个概念是初始类加载器和定义类加载器。举个栗子说吧,AClassLoader->BClassLoader->CClassLoader,表示 AClassLoader 在加载类的时候会委托 BClassLoader 类加载器来加载,BClassLoader 加载类的时候会委托 CClassLoader 来加载,假如我们使用 AClassLoader 来加载 X 这个类,而 X 这个类最终是被 CClassLoader 来加载的,那么我们称 CClassLoader 为 X 类的定义类加载器,而 AClassLoader 和 BClassLoader 分别为 X 类的初始类加载器,JVM 在加载某个类的时候对这三种类加载器都会记录,记录的数据结构是一个叫做 SystemDictionary 的 hashtable,其 key 是根据 ClassLoader 对象和类名算出来的 hash 值,而 value 是真正的由定义类加载器加载的 Klass 对象,因为初始类加载器和定义类加载器是不同的 classloader,因此算出来的 hash 值也是不同的,因此在 SystemDictionary 里会有多项值的 value 都是指向同一个 Klass 对象。

那么 JVM 为什么要分这两种类加载器呢,其实主要是为了快速找到已经加载的类,比如我们已经通过 AClassLoader 来触发了对 X 类的加载,当我们再次使用 AClassLoader 这个类加载器来加载 X 这个类的时候就不需要再委托给 BClassLoader 去找了,因为加载过的类在 JVM 里有这个类加载器的直接加载的记录,只需要直接返回对应的 Klass 对象即可。

Demo 中的类加载器是否会加载类

我们的 demo 里发现构建了一个 CompositeClassLoader 的类加载器,那到底有没有用这个类加载器加载类呢,我们可以设置一个断点在 CompositeClassLoader 的 loadClass 方法上,可以看到会进入断点。
可见确实有类加载的动作,根据类加载委托机制,在这个 Demo 中我们能肯定类是交给 AppClassLoader 来加载的,这样一来 CompositeClassLoader 就变成了初始类加载器,而 AppClassLoader 会是定义类加载器,都会在 SystemDictionary 里存在,因此当我们不断 new XStream 的时候会不断 new CompositeClassLoader 对象,加载类的时候会不断往 SystemDictionary 里插入记录,从而使 SystemDictionary 越来越膨胀,那自然而然会想到如果 GC 过程不断去扫描这个 SystemDictionary 的话,那随着 SystemDictionary 不断膨胀,那么 GC 的效率也就越低,抱着验证下猜想的方式我们可以使用 perf 工具来看看,如果发现 cpu 占比排前的函数如果都是操作 SystemDictionary 的,那就基本验证了我们的说法,下面是 perf 工具的截图,基本证实了这一点。

SystemDictionary 为什么会影响 GC 过程

想象一下这么个情况,我们加载了一个类,然后构建了一个对象 (这个对象在 eden 里构建) 当一个属性设置到这个类里,如果 gc 发生的时候,这个对象是不是要被找出来标活才行,那么自然而然我们加载的类肯定是我们一项重要的 gc root,这样 SystemDictionary 就成为了 gc 过程中的被扫描对象了,事实也是如此,可以看 vm 的具体代码(代码在:SharedHeap::process_strong_roots,感兴趣的同学可以直接翻这部分代码)。

看上面的SH_PS_SystemDictionary_oops_do task就知道了,这个就是对 SystemDictionary 进行扫描。

但是这里要说的是虽然有对 SystemDictionary 进行扫描,但是 ygc 的过程并不会对 SystemDictionary 进行处理,如果要对它进行处理需要开启类卸载的 vm 参数,CMS 算法下,CMS GC 和 Full GC 在开启 CMSClassUnloadingEnabled 的情况下是可能对类做卸载动作的,此时会对 SystemDictionary 进行清理,所以当我们在跑上面 demo 的时候,通过jmap -dump:live,format=b,file=heap.bin命令执行完之后,ygc 的时间瞬间降下来了,不过又会慢慢回去,这是因为 jmap 的这个命令会做一次 gc,这个 gc 过程会对 SystemDictionary 进行清理。

修改 VM 代码验证

很遗憾 hotspot 目前没有对 ygc 的每个 task 做一个时间的统计,因此无法直接知道是不是SH_PS_SystemDictionary_oops_do这个 task 导致了 ygc 的时间变长,为了证明这个结论,我特地修改了一下代码,在上面的代码上加了一行:GCTraceTime t(“SystemDictionary_OOPS_DO”,PrintGCDetails,true,NULL);然后重新编译,跑我们的 demo,测试结果如下:

复制代码
2016-03-14T23:57:24.293+0800: [GC2016-03-14T23:57:24.294+0800: [ParNew2016-03-14T23:57:24.296+0800: [SystemDictionary_OOPS_DO, 0.0578430 secs]
: 81920K->3184K(92160K), 0.0889740 secs] 81920K->3184K(514048K), 0.0900970 secs] [Times: user=0.27 sys=0.00, real=0.09 secs]
2016-03-14T23:57:28.467+0800: [GC2016-03-14T23:57:28.468+0800: [ParNew2016-03-14T23:57:28.468+0800: [SystemDictionary_OOPS_DO, 0.0779210 secs]
: 85104K->5175K(92160K), 0.1071520 secs] 85104K->5175K(514048K), 0.1080490 secs] [Times: user=0.65 sys=0.00, real=0.11 secs]
2016-03-14T23:57:32.984+0800: [GC2016-03-14T23:57:32.984+0800: [ParNew2016-03-14T23:57:32.984+0800: [SystemDictionary_OOPS_DO, 0.1075680 secs]
: 87095K->8188K(92160K), 0.1434270 secs] 87095K->8188K(514048K), 0.1439870 secs] [Times: user=0.90 sys=0.01, real=0.14 secs]
2016-03-14T23:57:37.900+0800: [GC2016-03-14T23:57:37.900+0800: [ParNew2016-03-14T23:57:37.901+0800: [SystemDictionary_OOPS_DO, 0.1745390 secs]
: 90108K->7093K(92160K), 0.2876260 secs] 90108K->9992K(514048K), 0.2884150 secs] [Times: user=1.44 sys=0.02, real=0.29 secs]

我们会发现 YGC 的时间变长的时候,SystemDictionary_OOPS_DO的时间也会相应变长多少,因此验证了我们的说法。

有同学提到如果 Demo 代码改成不 new XStream,而是直接 new CompositeClassLoader 或 CustomClassLoader 则不会出问题,按照上面的分析也很容易解释,就是因为如果直接 new CustomClassLoader 的话,并没触发 loadClass 这动作,而 new XStream 的话在构造器里就在 loadClass。

有同学提到在 JDK 8 中跑这个 case 不会出现问题,原因是:jdk8 在对 SystemDictionary 扫描时做了优化,增加了一层 cache,大大减少了需要扫描的入口数。


感谢魏星对本文的审校。

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

2016 年 5 月 11 日 17:055241

评论

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

【可下载】2020年底收官!为大家整理了物联网行业全面研究报告、行业洞察、白皮书……

IoT云工坊

人工智能 大数据 5G 物联网 智能家居

训练营第四周作业

大脸猫

极客大学架构师训练营

网络时间协议介绍以及服务器同步网络时间

MySQL从删库到跑路

ntp 时间同步

基于f2从零实现移动端可视化编辑器

徐小夕

Java H5 数据可视化 h5编辑器 H5制作

python+requests进行get、post方法接口测试

测试人生路

Python 接口测试

极客大学架构师训练营第一期第八周总结

睡不着摇一摇

架构师一期

第八周课后练习

高兵

成为架构师 - 架构师训练营第 04周

陈永龙Vincent

作业-第4周

arcyao

架构师训练营第 8 周作业

netspecial

极客大学架构师训练营

架构师训练营第 8 周学习总结

netspecial

极客大学架构师训练营

第八章作业

alpha

极客大学架构师训练营

第四周作业

Jack

家谱链亮相高交会,点亮“区块链+文化”融合发展之路

13530558032

高交会:高新企业源中瑞在此出展区块链BAAS技术

WX13823153201

作业-第4周总结

arcyao

《Web应用安全权威指南》.pdf

田维常

【JAVA】TreeSet, LinkedHashSet和HashSet差异对比

莫问

“懂行”的价值循环与蝴蝶风暴

脑极体

【Mycat】Mycat核心开发者带你轻松掌握Mycat路由转发!!

冰河

分布式 微服务 分库分表 中间件 mycat

面试官最常用小心思:说说你的项目并发量多大?负载均衡怎么做?

小Q

Java Linux 学习 面试 并发

家谱链亮相高交会,点亮“区块链+文化”融合发展之路

WX13823153201

家谱链亮相高交会

《身边的金钱心理学》

石云升

JVM真香系列:图解垃圾回收器

田维常

JVM 垃圾回收

第八周总结

alpha

极客大学架构师训练营

高交会:高新企业源中瑞在此出展区块链BAAS技术

13530558032

腾讯强推Redis成长手册!原理+应用+集群+拓展+源码五飞

小Q

Java redis 学习 架构 面试

训练营第四周总结

大脸猫

极客大学架构师训练营

目标检测-darknet 之模型初始化

Dreamer

架构师训练营第 1 期 - 第八周总结

Todd-Lee

极客大学架构师训练营

架构师训练营 第四周作业

文江

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

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

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