《Java 并发编程·性能诊断与事故》13.2 并发标记与业务线程

把 G1 的并发标记拆成写屏障、并发线程和停顿三段:用 SATB 预写屏障解释为什么改引用也要记账,用 ConcGCThreads=1 与 6 的对照日志证明标记线程只是把同一份 CPU 工作摊到更多核上,再用 JFR 的 jdk.GCPhaseConcurrent 聚合各阶段耗时,给出业务线程侧的观测口径。

承接的问题

13.1 解决的是「分配太快」。分配速率降下来之后,GC 次数会变少,但另一种抖动会浮出来:Young GC 的日志很干净,单次一两毫秒,业务线程却每隔几秒出现一次几十毫秒的尾延迟,日志里同一时刻还多出一行 Concurrent Mark Cycle。

构造一个场景。libraryd-conc 的 300 MB 热点数据常驻在 G1 的老年代,压测时分配速率 100 MB/s,-Xmx512m。监控面板上 Young GC 平均 1.5 毫秒,看起来没问题;但 Concurrent Mark Cycle 每两三秒来一次,一次持续 60–80 毫秒。值班同学的疑问是:并发标记不是「并发」吗,为什么业务线程还会被影响?

答案有两层。第一层,并发标记确实不暂停业务线程,但它要 CPU——标记线程和应用线程抢同一批核。第二层,标记期间的引用修改必须记账,这笔账记在业务线程的写操作上,也就是写屏障。这一节把这两笔成本都量出来。

本机口径:

Apple M1 Pro,10 核,32 GB,macOS 26.3 (25D125)
Temurin 25.0.5+8

写作时 load average 是 86.62 85.05 72.03。所有计时都是单次运行、随调度波动、不作基准。本机 JDK 25 默认 GC 已核实为 G1(java -XX:+PrintFlagsFinal -version | grep UseG1GC 输出 true {product} {ergonomic}),下面显式写 -XX:+UseG1GC,并关掉自适应 IHOP 的干扰:

java -Xmx512m -XX:+UseG1GC -XX:ConcGCThreads=1 \
  -XX:InitiatingHeapOccupancyPercent=15 \
  -Xlog:gc*:file=g1-c1.log:uptime,level,tags \
  -cp classes MarkLoadProbe 22 100 300

写屏障:为什么「改一个引用」也要记账

并发标记要回答的问题是「哪些对象还活着」。标记线程从 GC Roots 出发遍历对象图,这期间业务线程还在改引用。如果不管,会出现两种漏标:

  • 标记线程刚扫过对象 A,业务线程把 A 的字段从 B 改成 C,然后删掉指向 B 的引用。B 在标记开始时是活的,但标记线程没扫到它,B 引用的整棵子树会被误回收。
  • 标记线程还没扫到 A,业务线程把 A 的字段改成 C。等标记线程扫 A 时读到的是 C,看起来没问题,但如果 C 已标、A 未标,C 的子树不会被重扫——这个组合叫「漏标三色问题」。

工业界有两种屏障来堵这两个口子。

SATB(Snapshot At The Beginning),G1 和 Shenandoah 的默认模式用它。它维护的是「标记开始那一刻的快照」:只要一个引用在标记期间被覆盖,就把旧值记进线程本地的 SATB 缓冲区,标记线程之后会把缓冲区里的旧值当作根继续扫。上面第一种漏标就被堵住了——B 虽然被删,但它的旧值已经进了日志。

// SATB 预写屏障,发生在 store 之前
void satb_pre_write(oop* field, oop new_value) {
    oop old = *field;
    if (marking_in_progress && old != null && !is_marked(old)) {
        satb_buffer_enqueue(old);      // 记录旧值
    }
    *field = new_value;
}

增量更新(Incremental Update),早期的 CMS 用它。它在 store 之后把新值或脏卡片记下来,remark 阶段重新扫描这些根。它堵的是第二种漏标。G1 不走这条路,但 G1 还有第二套屏障:跨 region 引用的卡片标记(post-write barrier),用来维护 RSNet。

// G1 的 post-write barrier(简化)
void g1_post_write(oop* field, oop new_value, HeapRegion* region) {
    if (new_value != null && crosses_region_boundary(field, new_value)) {
        if (!UseCondCardMark || card_is_clean(field)) {
            mark_card_dirty(field);    // 记脏卡,供 Remark/Refinement 重扫
        }
    }
}

两个屏障合起来,意味着每一次引用字段写入都可能付出额外代价:一次判断、一次日志入队或一次卡片写。这个代价不在 GC 线程上,而在业务线程里,随写操作次数线性增长。所以「并发标记不影响业务」这个说法只在暂停维度成立,在指令维度不成立。

G1 的相关参数在本机可以查到:

java -XX:+PrintFlagsFinal -version | grep -E "G1SATBBufferSize|G1SATBBufferEnqueueingThresholdPercent|G1ConcRefinementThreads|UseCondCardMark"
     uint G1ConcRefinementThreads                  = 9        {product} {ergonomic}
     uint G1SATBBufferEnqueueingThresholdPercent   = 60       {product} {default}
   size_t G1SATBBufferSize                         = 1024     {product} {default}
     bool UseCondCardMark                          = false    {product} {default}

SATB 缓冲区每个线程默认 1024 个槽,填到 60% 就入队到全局队列;G1ConcRefinementThreads=9 是处理脏卡的后台线程数,和 ConcGCThreads(标记线程)不是一回事,别混着调。

并发标记的 CPU 份额:ConcGCThreads 对照

先做一个能持续产生并发周期的负载:常驻 300 MB(30 万个 1 KB 数组),再以每秒 100 MB 的速度分配短命对象,堆固定 512 MB,IHOP 手动压到 15%。这样每两三秒就会走一次完整的并发周期。

import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.Locale;

public final class MarkLoadProbe {

    static volatile long sink;

    public static void main(String[] args) throws Exception {
        int seconds = Integer.parseInt(args[0]);
        int rateMBps = Integer.parseInt(args[1]);
        int liveMB = Integer.parseInt(args[2]);

        List<byte[]> live = new ArrayList<>(liveMB * 1024);
        for (int i = 0; i < liveMB * 1024; i++) {
            live.add(new byte[1000]);
        }
        System.out.printf(Locale.ROOT, "liveMB=%d heapMaxMB=%d rateMBps=%d%n",
                liveMB, Runtime.getRuntime().maxMemory() / 1048576, rateMBps);

        byte[][] ring = new byte[512][];
        int opBytes = 2048 + 16;
        long opsPerSec = rateMBps * 1_048_576L / opBytes;
        long tickNanos = 10_000_000L;
        long opsPerTick = Math.max(1, opsPerSec / 100);

        long end = System.nanoTime() + seconds * 1_000_000_000L;
        long[] lat = new long[(int) opsPerSec * 2];
        int latCount = 0;
        int second = 0;
        long secondStart = System.nanoTime();
        long opsThisSecond = 0;
        int idx = 0;
        long nextTick = System.nanoTime();

        System.out.println("sec,ops,p50us,p99us,maxUs,over1ms,allocMBps");
        while (System.nanoTime() < end) {
            for (long k = 0; k < opsPerTick; k++) {
                long t0 = System.nanoTime();
                byte[] b = new byte[2048];
                b[0] = (byte) idx;
                ring[idx & 511] = b;
                sink += b[0];
                idx++;
                lat[latCount++] = System.nanoTime() - t0;
                opsThisSecond++;
            }
            nextTick += tickNanos;
            long sleep = nextTick - System.nanoTime();
            if (sleep > 0) {
                Thread.sleep(sleep / 1_000_000L, (int) (sleep % 1_000_000L));
            }
            long now = System.nanoTime();
            if (now - secondStart >= 1_000_000_000L) {
                long[] copy = Arrays.copyOf(lat, latCount);
                Arrays.sort(copy);
                long p50 = copy.length == 0 ? 0 : copy[copy.length / 2];
                long p99 = copy.length == 0 ? 0 : copy[(int) (copy.length * 0.99)];
                long max = copy.length == 0 ? 0 : copy[copy.length - 1];
                long over1ms = Arrays.stream(copy).filter(v -> v > 1_000_000L).count();
                System.out.printf(Locale.ROOT, "%d,%d,%d,%d,%d,%d,%.1f%n",
                        second++, opsThisSecond, p50 / 1000, p99 / 1000, max / 1000, over1ms,
                        opsThisSecond * opBytes / 1048576.0);
                latCount = 0;
                opsThisSecond = 0;
                secondStart = now;
            }
        }
        System.out.println("liveKept=" + live.size());
    }
}

只改 ConcGCThreads,跑同样 22 秒。下面是 GC 日志原文(同一段周期,各摘三行):

# ConcGCThreads=1
[0.445s][info][gc          ] GC(3) Concurrent Mark Cycle
[0.454s][info][gc,task     ] GC(3) Using 1 workers of 1 for marking
[0.487s][info][gc          ] GC(3) Pause Remark 317M->315M(512M) 5.303ms
[0.487s][info][gc,marking  ] GC(3) Concurrent Mark 32.991ms
[0.526s][info][gc,marking  ] GC(3) Concurrent Rebuild Remembered Sets and Scrub Regions 39.360ms
[0.528s][info][gc          ] GC(3) Concurrent Mark Cycle 82.385ms
# ConcGCThreads=6
[0.111s][info][gc          ] GC(3) Concurrent Mark Cycle
[0.114s][info][gc,task     ] GC(3) Using 6 workers of 6 for marking
[0.119s][info][gc          ] GC(3) Pause Remark 312M->310M(512M) 0.407ms
[0.119s][info][gc,marking  ] GC(3) Concurrent Mark 5.120ms
[0.125s][info][gc,marking  ] GC(3) Concurrent Rebuild Remembered Sets and Scrub Regions 5.105ms
[0.125s][info][gc          ] GC(3) Concurrent Mark Cycle 14.067ms

把三个周期的数据列成表:

阶段1 条标记线程6 条标记线程解读
Concurrent Mark29–37 ms5–11 ms墙钟缩短约 5 倍
Rebuild Remset39–44 ms5–11 ms同样缩短约 6 倍
Pause Remark0.98–11.05 ms0.41–1.95 ms这是暂停,不受 ConcGCThreads 控制
Concurrent Mark Cycle75–82 ms12–24 ms整个并发周期的墙钟

关键不是「6 条更快」,而是总 CPU 基本不变:1 条线程跑 33 ms,约等于 33 ms 的标记 CPU;6 条线程跑 5.1 ms,约等于 31 ms 的标记 CPU。ConcGCThreads 做的是把同一份工作摊到更多核上,缩短的是并发周期的墙钟时间,代价是同时占用更多核。

这解释了两个常见现象:

  • 调大 ConcGCThreads 后 Young GC 没变快,业务 RT 反而更抖。因为标记线程和应用线程在抢 CPU,容器 CPU 配额越紧,抢得越狠。
  • 调小 ConcGCThreads 后并发周期变长,老年代增长更快时可能追不上分配速率,最终触发 Full GC。并发周期不是越慢越好。

判断该调哪边,看的是「并发周期墙钟 / 两次周期间隔」。如果周期墙钟接近间隔的一半,说明标记已经追得很吃力,再加线程或者降分配速率;如果墙钟远小于间隔,ConcGCThreads 可以往下调,把 CPU 还给业务。

JFR 里的并发阶段

GC 日志要人肉 grep,JFR 更适合做聚合。jdk.GCPhaseConcurrent 事件在 profile.jfc 里默认是关的,先打开:

jfr configure --input "$JAVA_HOME/lib/jfr/profile.jfc" --output mark.jfc \
  jdk.GCPhaseConcurrent#enabled=true \
  jdk.ObjectAllocationInNewTLAB#enabled=true

然后用 RecordingFile 把每个阶段的事件读出来,按 name 分组求和:

import java.nio.file.Path;
import java.util.Map;
import java.util.TreeMap;
import jdk.jfr.consumer.RecordedEvent;
import jdk.jfr.consumer.RecordingFile;

public final class GcPhaseReport {
    public static void main(String[] args) throws Exception {
        Map<String, long[]> concurrent = new TreeMap<>();
        Map<String, long[]> pauses = new TreeMap<>();
        long pauseTotalNanos = 0;
        long pauseMaxNanos = 0;

        try (RecordingFile file = new RecordingFile(Path.of(args[0]))) {
            while (file.hasMoreEvents()) {
                RecordedEvent e = file.readEvent();
                String type = e.getEventType().getName();
                long nanos = e.getDuration().toNanos();
                if (type.equals("jdk.GCPhaseConcurrent")) {
                    long[] agg = concurrent.computeIfAbsent(e.getString("name"), k -> new long[2]);
                    agg[0]++;
                    agg[1] += nanos;
                } else if (type.equals("jdk.GCPhasePause")) {
                    long[] agg = pauses.computeIfAbsent(e.getString("name"), k -> new long[2]);
                    agg[0]++;
                    agg[1] += nanos;
                    pauseTotalNanos += nanos;
                    pauseMaxNanos = Math.max(pauseMaxNanos, nanos);
                }
            }
        }
        System.out.println("== concurrent phases ==");
        concurrent.forEach((name, agg) -> System.out.printf(
                "%-46s events=%3d totalMs=%8.3f avgMs=%7.3f%n",
                name, agg[0], agg[1] / 1e6, agg[1] / 1e6 / agg[0]));
        System.out.println("== pause phases ==");
        pauses.forEach((name, agg) -> System.out.printf(
                "%-46s events=%3d totalMs=%8.3f avgMs=%7.3f%n",
                name, agg[0], agg[1] / 1e6, agg[1] / 1e6 / agg[0]));
        System.out.printf("pauseTotalMs=%.3f pauseMaxMs=%.3f%n",
                pauseTotalNanos / 1e6, pauseMaxNanos / 1e6);
    }
}
java -Xmx512m -XX:+UseG1GC -XX:ConcGCThreads=1 -XX:InitiatingHeapOccupancyPercent=15 \
  -XX:StartFlightRecording=filename=m3-c1.jfr,settings=mark.jfc,duration=25s \
  -cp classes MarkLoadProbe 22 100 300
java -cp classes GcPhaseReport m3-c1.jfr

本机输出:

== concurrent phases ==
Concurrent Cleanup for Next Mark               events=  6 totalMs=   3.920 avgMs=  0.653
Concurrent Clear Claimed Marks                 events=  6 totalMs=   0.020 avgMs=  0.003
Concurrent Mark From Roots                     events=  6 totalMs= 155.082 avgMs= 25.847
Concurrent Preclean                            events=  6 totalMs=   0.037 avgMs=  0.006
Concurrent Rebuild Remembered Sets and Scrub Regions events=  6 totalMs= 257.838 avgMs= 42.973
Concurrent Scan Root Regions                   events=  6 totalMs=   9.637 avgMs=  1.606
== pause phases ==
GC Pause                                       events= 20 totalMs=  92.720 avgMs=  4.636
Pause Cleanup                                  events=  6 totalMs=   0.616 avgMs=  0.103
Pause Remark                                   events=  6 totalMs=  23.993 avgMs=  3.999
pauseTotalMs=117.329 pauseMaxMs=25.003

三个结论直接从这份聚合里读出来:

  • 并发阶段的大头不一定是 Mark。 这里 Concurrent Mark From Roots 平均 25.8 ms,Rebuild Remembered Sets and Scrub Regions 平均 43.0 ms。后者是重建记忆集,扫描成本取决于跨 region 引用的密度,不改数据结构很难降下来。
  • 暂停里最大的不一定是 Remark。 GC Pause 平均 4.6 ms、最大 25 ms,反而高于 Remark 的平均 4 ms。这个 25 ms 的单次尖峰出现在高负载时刻,需要对照系统指标看,不能直接记到 GC 账上。
  • 一条标记线程时,一个周期里并发总耗时约 427 ms,其中 Mark 类约 155 ms。 同一个工作负载把 ConcGCThreads 提到 6,周期墙钟降到 12–24 ms,但并发线程的 CPU 总量并没有减少,只是被并行摊薄了。

对吞吐与延迟的影响

同一份负载的每秒延迟分布(ConcGCThreads=1,摘录):

sec,ops,p50us,p99us,maxUs,over1ms,allocMBps
0,50800,0,0,4586,3,100.0
3,51308,0,0,10528,1,101.0
4,50800,0,0,12033,1,100.0
12,50800,0,0,236,0,100.0
18,51308,0,0,3055,1,101.0
20,50800,0,0,288,0,100.0

读法与 13.1 一样:p50 和 p99 都在微秒级,因为单次分配操作本身只有几十纳秒;max 会跳到 3–12 毫秒,这些尖峰对应的是 Young GC 暂停、Remark,以及 load average 80+ 下的调度延迟。在本机这种负载下,无法把「标记线程抢 CPU」从系统噪声里干净地分离出来,这是必须说明的限制。

能确定的是方向:目标是 100 MB/s 的固定速率,所以每秒 ops 基本恒定在 5.08 万,说明标记期间的 CPU 抢占没有把吞吐压垮;但 max 的尖峰频率和 ConcGCThreads 正相关。含义是:并发标记影响的是尾延迟,不是平均吞吐。

这也给出一条实用的排查顺序:

  1. 先看并发周期的墙钟和间隔,判断标记是否吃力。
  2. 再看 ConcGCThreads 和容器 CPU limit 的关系。10 核机器上 6 条标记线程不算多;2 核容器里 2 条标记线程就吃掉一半 CPU。
  3. 最后才看停顿。如果 Young GC 和 Remark 都不大,尾延迟仍然高,那就不是 GC 的问题,回到第 1 章看调度和配额。

在 libraryd-conc 里落地

conc-ops 只采四个字段,不多采:

字段来源用途不要用来做什么
gc.concurrent.cycleWallMs日志 Concurrent Mark Cycle 或 JFR 阶段求和标记是否追得上分配当成暂停时间
gc.concurrent.cycleCount周期计数计算周期间隔当成 GC 次数
gc.pause.remarkMsjdk.GCPhasePause 里 Pause Remark尾延迟归因代表整个并发周期
gc.mark.threads-Xlog:gc+init 的 Concurrent Workers与 CPU limit 对照当成实际占用核数

参数上的取舍:

  • 容器 CPU limit ≤ 2 核时不要照搬 ConcGCThreads 默认值。 默认是 ParallelGCThreads/4 取整,本机 10 核是 2,2 核容器也是 1–2,但业务线程本身就没几个核可用,标记线程的每一次抢占都会被放大。
  • InitiatingHeapOccupancyPercent 不要为了压测手动压到 15% 以下。 压测里我们这么写是为了在 22 秒内制造 6 个周期;生产上这会让并发周期过密,标记线程长期在线。JDK 25 的 G1 默认是自适应 IHOP,除非有明确证据,不要覆盖。
  • 不要用 -XX:-UseG1GC 换 Parallel 来「减少并发标记」。 Parallel 没有并发标记,但它会在 Full GC 时整堆暂停,尾延迟更差。低延迟场景应该往 ZGC / Shenandoah 走,那是 13.3 的内容。

常见错误与边界

  • 把「并发」理解成「零成本」。 并发标记不暂停,但占 CPU,并且给每次引用写加屏障。
  • 把 ConcGCThreads 当成「越大越好」。 它只缩短并发周期墙钟,总 CPU 不变,核少的时候是纯损失。
  • 把 Concurrent Mark 当成整个周期。 一个周期还包括 Scan Root Regions、Rebuild Remset、Remark、Cleanup;本例里 Rebuild Remset 比 Mark 更耗时。
  • 把 Remark 的暂停算到 ConcGCThreads 头上。 Remark 是暂停阶段,用的是并行 worker,调标记线程数不改变它的成本。
  • 用 Young GC 次数判断并发标记是否正常。 两者看的是不同指标,并发周期要看 Concurrent Mark Cycle 的墙钟和间隔。
  • 在写密集的代码里假设「写字段没有成本」。 SATB 预写屏障和卡片标记都在写路径上;纯计算的微基准测不出这部分。
  • 拿 -Xlog:gc 的输出做精确归因。 日志只有阶段总时长,单次尖峰要和 JFR 事件、系统 load 对照看。
  • 什么时候不要用并发标记调优: 分配速率远高于回收速率时,先降分配;堆本身只有几百 MB、活对象很少时,Young GC 就够用,强行制造并发周期只会增加开销。

小结

并发标记的成本分两块:一块是写屏障,落在业务线程的每次引用写上,SATB 记旧值、卡片标记记脏卡,都不免费;另一块是并发线程,ConcGCThreads 从 1 提到 6,把同一个 300 MB 老年代的标记墙钟从 33 ms 压到 5 ms,但总 CPU 几乎不变,只是从 1 个核摊到 6 个核。

JFR 的 jdk.GCPhaseConcurrent 能把周期拆开:本例 6 个周期里,Concurrent Mark From Roots 平均 25.8 ms,Rebuild Remembered Sets and Scrub Regions 平均 43.0 ms,真正拖长周期的是记忆集重建而不是标记本身。业务侧能观测到的只有尾延迟尖峰,平均吞吐在固定速率下不受影响。

下一节换到低延迟 GC:ZGC 和 Shenandoah 在 JDK 25 都已经是分代实现,暂停压到亚毫秒之后,瓶颈就从「GC 停顿」转移到「分配速率、大对象和缓存行」这些应用侧的设计问题上。

阅读导航:上一节 13.1 分配速率、TLAB 与逃逸 | 下一节 13.3 低延迟 GC 下的并发设计

继续阅读

探索更多技术文章

浏览归档,发现更多关于系统设计、工具链和工程实践的内容。

全部文章 返回首页

「books」更多文章

  1. 《Java 消息中间件·事件驱动架构》附录 B 架构决策记录模板
  2. 《Java 消息中间件·事件驱动架构》附录 A 术语表
  3. 《Java 消息中间件·事件驱动架构》15.3 全书验收