一次Full GC排查

以前的一次full gc排查经历。

问题排查

之前偶然看 Grafana，发现应用在当天出现了两次比较明显的 GC 耗时尖峰，差不多白天一次，晚上一次。但是再看老年代，占用一直不高，曲线也没什么变化。

Pasted image 20261020224707

看起来不像老年代快满了，那这两次 GC 是哪里来的？

没有办法，进 Docker 容器看下 GC 日志：

1
2
3
4
5
[Full GC (System.gc())
    [CMS: 667220K->573688K(2097152K)]
    1847021K->573688K(3984640K),
    [Metaspace: 379950K->379950K(1402880K)],
    1.9782745 secs]

这下看到原因了：Full GC (System.gc())。

没想到群众里面有坏人，有人在偷偷调用 System.gc()！

在项目里搜索了一圈，没有找到相关调用，只好用 Arthas。因为触发时间不固定，所以把 Arthas 的输出保存到文件里，第二天再来查看：

1
2
stack java.lang.System gc -n 10 >> /tmp/arthas-gc.log &
quit

抓到了这样的调用栈：

1
2
3
4
thread_name=GC Daemon; id=20; is_daemon=true; priority=2

@java.lang.System.gc()
    at sun.misc.GC$Daemon.run(GC.java:109)

原来调用 System.gc() 的是 GC Daemon。

顺着调用栈看一下 JDK 8 的代码：

Pasted image 20261020225927

sun.misc.GC 里定义了一个 Daemon 内部类。它会读取 latencyTarget，再通过 maxObjectInspectionAge() 判断是不是太久没有进行相应的垃圾检查；达到阈值，就调用 System.gc()，否则继续等待。

但是很明显，这个不是我们最终想要的，还需要找到是在哪里调用了了这个GC.requestLatency。这里正常来说就是本机启一下服务，打个断点，看看堆栈是谁在创建，但是我不想看了，就咨询了一下chatgpt大人，它先让我看看当前的阈值：

1
ognl '@sun.misc.GC@currentLatencyTarget()'

得到结果：

1
@Long[36000000]

36,000,000 毫秒，也就是 10 小时。

然后 ChatGPT 大人就把怀疑对象指向了 Apache CXF：

Pasted image 20261026120845

结果还真是这个，Apache CXF 是一个服务框架，我们项目里的 WebService 用到了它。顺着这个线索，找到了 org.apache.cxf.common.logging.JDKBugHacks，看看它的类注释：

Pasted image 20261026121840

这个类主要是给一些 JDK 问题打补丁，部分实现借鉴了 Tomcat。罪魁祸首如下：

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
// Several components end up calling:
// sun.misc.GC.requestLatency(long)
//
// Those libraries / components known to trigger memory leaks due to
// eventual calls to requestLatency(long) are:
// - javax.management.remote.rmi.RMIConnectorServer.start()
try {
    if (!skipHack("org.apache.cxf.JDKBugHacks.gcRequestLatency")) {
        Class<?> clazz = Class.forName("sun.misc.GC");
        Method method = clazz.getDeclaredMethod("currentLatencyTarget");
        Long l = (Long) method.invoke(null);
        if (l != null && l.longValue() == 0) {
            //something already set it, move on
            method = clazz.getDeclaredMethod("requestLatency", Long.TYPE);
            method.invoke(null, Long.valueOf(36000000));
        }
    }
} catch (Throwable e) {
    //ignore
}

这个补丁的作用

这份代码主要处理的问题，是RMI创建的 GC Daemon 长期持有应用的类加载器，导致应用卸载后，相关的类和资源无法正常回收。

RMI 支持 JVM 之间的远程方法调用，里面用到了 DGC，也就是分布式垃圾回收。客户端拿到的是远程对象的引用，服务端不能直接检查客户端的堆，不知道这个引用是不是已经没人用了。

在 OpenJDK 8 的实现里，客户端通过虚引用和引用队列跟踪本地 LiveRef。当对应引用被 GC 处理后，客户端会通过 clean 调用通知服务端：不需要再为这个客户端保留远程对象了。

但是有可能出现客户端很长时间都不发生相关 GC的情况。因此，RMI DGC 会调用 GC.requestLatency(...)，给本地 GC 提一个延迟请求，尽量避免这种情况。

问题主要出在jdk本身，第一次注册请求时，如果 GC Daemon 还不存在，就需要创建这个线程。看一下这里 JDK 8 实现：

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
private static class Daemon extends Thread {

    private Daemon(ThreadGroup tg) {
        super(tg, "GC Daemon");
    }

    public static void create() {
        PrivilegedAction<Void> pa = new PrivilegedAction<Void>() {
            public Void run() {
                ThreadGroup tg =
                    Thread.currentThread().getThreadGroup();

                // 一直找到 root ThreadGroup
                for (ThreadGroup tgn = tg;
                     tgn != null;
                     tg = tgn, tgn = tg.getParent());

                Daemon d = new Daemon(tg);
                d.setDaemon(true);
                d.setPriority(Thread.MIN_PRIORITY + 1);
                d.start();

                GC.daemon = d;
                return null;
            }
        };

        AccessController.doPrivileged(pa);
    }
}

看起来只是普通地创建一个线程。但在 new Daemon(tg) 调用父类构造方法时，Thread 内部还会做一件事：继承创建者线程的上下文类加载器，也就是 TCCL（Thread Context ClassLoader）。相关逻辑如下：

1
2
3
4
5
6
7
8
Thread parent = currentThread();
SecurityManager security = System.getSecurityManager();

if (security == null || isCCLOverridden(parent.getClass())) {
    this.contextClassLoader = parent.getContextClassLoader();
} else {
    this.contextClassLoader = parent.contextClassLoader;
}

也就是说，在构造线程对象时，TCCL 的引用就已经传过去了，不用等到 start()。前面虽然把线程放到了根 ThreadGroup，但线程组和上下文类加载器是两回事，这样做不会自动把 TCCL 换成系统类加载器。

假设第一次触发创建的是一个 Web 应用线程，而它的 TCCL 正好是这个应用的类加载器，那么新建的 GC Daemon 也就拿到了同一个引用。

但如果应用在同一个 JVM 里卸载、重新部署，旧的应用类加载器本来应该可以回收，这个仍然存活的线程却还在抓着它。只看 TCCL 这条强引用链，就已经足以让它保持可达：

1
2
3
存活的 GC Daemon 线程（GC Root）
    └── contextClassLoader
            └── 旧 Web 应用的 ClassLoader

类加载器无法回收，它所加载的类也就无法随之卸载，相关静态字段引用的对象还可能继续留在堆里。这样多重新部署几次，就可能把好几代应用的类和相关对象一起留下来。Tomcat 的 gcDaemonProtection 就是针对这一类问题做防护。Tomcat 类加载器泄漏防护

这时候 Full GC 也没用，因为引用链还在，因此 CXF 的补丁实际不是为了fullgc，而是趁这个线程还没有创建，先换好上下文类加载器，提前把它创建出来。

把 JDKBugHacks.doHacks() 的外层逻辑和前面那段反射调用合在一起，流程相当于下面这样：

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
Thread current = Thread.currentThread();
ClassLoader original = current.getContextClassLoader();
try {
    // 先切换创建者线程的 TCCL
    current.setContextClassLoader(ClassLoader.getSystemClassLoader());

    if (sun.misc.GC.currentLatencyTarget() == 0) {
        // 再注册请求，触发 GC Daemon 的创建
        sun.misc.GC.requestLatency(36000000L);
    }
} finally {
    // 恢复创建者线程原来的 TCCL
    current.setContextClassLoader(original);
}

解决方案

因为我们没有使用RMI，可以通过 JVM 启动参数跳过这一项补丁：

1
-Dorg.apache.cxf.JDKBugHacks.gcRequestLatency=false

问题排查#

这个补丁的作用#

解决方案#

评论

问题排查

这个补丁的作用

解决方案