深入 JVM 彻底剖析 ygc 越来越慢的原因（上）

今天一个同学问我：“我排查问题时总是遇到，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 -gc或jstat -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 ）关注我们。