祥哥的技术博客

主题

📅 2025年11月12日 🏷️ JVM & GC ⏱️ 9 分钟阅读 jvmgcjfrjmc诊断

JFR + JMC 生产诊断 ​

先看一个真实案例 ​

2023 年双 11 大促，某支付中台的核心交易服务在高峰时段出现周期性 RT 抖动：TP99 从 15ms 跳到 120ms，每 5 分钟一次，持续 20 秒后恢复。运维先上了 Arthas，发现 Old Gen 使用率在 60%~80% 之间波动，看不出明显异常。又加了 -XX:+HeapDumpOnOutOfMemoryError，但 OOM 没发生，Heap Dump 也没触发。最后用 JFR + JMC 定位到根因：G1 的 Mixed GC 周期中，Remembered Set 扫描时间异常（一次 Mixed GC 的 STW 达到 380ms），原因是某个表的数据量溢出导致 RSet 密度过高，GC 线程花了大量时间扫描跨 Region 引用。用 JFR 的 GC 事件时间线一看，STW 峰值和 RT 抖动完全对齐。最终方案是调大 -XX:G1MixedGCLiveThresholdPercent=85 让 Mixed GC 跳过存活率高的 Region，配合 -XX:G1HeapWastePercent=10 延迟触发，抖动消失。

JFR 的定位能力在这里是其他工具替代不了的：Arthas 看当前线程堆栈，Heap Dump 只有 OOM 才能触发，而 JFR 在常态运行中就能精确记录每一次 GC 事件的时间和耗时时长，事后拉出时间线做关联分析。

JFR 的低开销原理——为什么能跑在生产环境 ​

事件驱动架构（不是采样轮询） ​

JFR 不走「定时采样」路线，它在 JVM 内部注册了 300+ 个预定义事件点（Event Point），比如 GC 阶段开始/结束、Java Monitor 进入/退出、方法抛异常、TLAB 分配等。这些事件点本身是 JVM 代码里的固定桩，JFR 运行时只做两件事：

  1. 阈值过滤：对每个事件类型设置 Duration 阈值，比如 synchronized 锁等待超过 10ms 才记录，小于 10ms 的直接丢弃。这避免了记录大量无害的短锁竞争。
  2. 无锁写入 Ring Buffer：事件数据写入线程本地的 TLAB 风格缓冲区，满了再刷到全局 Ring Buffer，全程无锁。Ring Buffer 的默认大小是 4MB（-XX:FlightRecorderBufferSize=4m），写满后会覆盖最旧的数据，所以 JFR 不会因为内存不够而 OOM。

对比采样工具（如 async-profiler 的 CPU 采样模式，每 10ms 打断一次线程），JFR 在 CPU 总量上更可控，尤其在 1000+ 线程的场景下，JFR 的 CPU 开销稳定在 0.5-1% 左右，而 async-profiler 的采样中断在超高线程数下会达到 3-5%。

二进制格式——不经过堆内存 ​

JFR 的输出格式 .jfr 是自描述二进制流，写入路径直接从 Ring Buffer 写入文件系统，完全不经过 Java 堆。这意味着：

  • 不会触发 GC 停顿
  • 不会因为 Full GC 丢了录制数据
  • 文件体积极小：1 小时 default 模板约 30-50MB，profile 模板约 100-200MB

对比 Heap Dump 在 OOM 时写十几 GB 文件把容器撑爆，JFR 的存储开销几乎可以忽略。

命令行操作流程 ​

bash
# 1. 启动时开启 JFR（JDK 8u40+，JDK 11+ 内置）
java -XX:StartFlightRecording=name=production,filename=recording.jfr,duration=60s,settings=profile \
     -jar myapp.jar

# 2. 运行时动态开启（推荐，生产环境用这个）
jcmd <pid> JFR.start name=myrecording settings=profile duration=60s filename=/tmp/recording.jfr

# 3. 另存为（不停止录制）
jcmd <pid> JFR.dump name=myrecording filename=/tmp/dump-$(date +%s).jfr

# 4. 停止并写出
jcmd <pid> JFR.stop name=myrecording

# 5. 查看当前录制状态
jcmd <pid> JFR.check

# 输出示例：
# Recording: name=myrecording, duration=60s, recording=15s (running)
# Settings: profile, maxsize=250MB, maxage=30m

jcmd <pid> JFR.check 在没有 JMC 的容器里也能快速确认录制是否正常，是排查 JFR 本身问题的第一手工具。

用 JFR 分析 GC 和锁竞争的实战流程 ​

GC 分析——定位 STW 抖动 ​

在 JMC 中打开 .jfr 文件，切到 Flight Recorder → GC 标签页，你会看到以下信息：

指标含义正常值告警阈值
GC Pause Time每次 STW 时长G1 下 < 50ms> 200ms
GC Interval两次 GC 间隔30-120s< 5s
GC Cause触发原因G1 Evacuation PauseSystem.gc()
Promotion Failed晋升失败次数0> 0
Concurrent Mode Failure并发标记失败0> 0

典型案例：某营销系统在整点发券时，G1 的 Young GC 耗时从 30ms 飙升到 250ms。JFR 显示触发原因是 G1 Evacuation Pause (to-space exhausted)，说明 Survivor 区太小，对象晋升失败被迫 Full GC。调参 -XX:SurvivorRatio=6 和 -XX:G1NewSizePercent=10 后，GC 耗时回到 35ms。

锁竞争分析——找到热点锁 ​

JMC 的 Lock Instances 标签页展示每个锁的竞争情况。关键指标：

  • Total Contentions：锁上的总竞争次数
  • Total Wait Time：所有线程等待这个锁的总耗时
  • Average Wait Time：平均每次等待时间
  • Contended Lock Class：锁的对象类型

实战案例：某订单服务 TP99 从 30ms 涨到 200ms。JFR 显示 java.util.concurrent.ConcurrentHashMap 的 resize 方法上出现大量锁竞争，总等待时间占到了 RT 的 42%。排查发现某个热点缓存 Key 的 Hash 碰撞导致 ConcurrentHashMap 频繁扩容。改成 HashMap + 读写锁 后，TP99 降到 28ms。

java
// 用 jdk.jfr API 自定义事件（JDK 14+）
import jdk.jfr.*;

@Label("DB Query")
@Description("Track slow database queries")
@Category({"Application", "Database"})
public class DBQueryEvent extends Event {
    @Label("SQL")
    public String sql;

    @Label("Duration (ms)")
    @Timespan(Timespan.MILLISECONDS)
    public long durationMs;

    @Label("Result Size")
    public int resultSize;

    @Label("Pool Name")
    public String poolName;
}

// 使用
DBQueryEvent event = new DBQueryEvent();
event.sql = query;
event.poolName = "readPool";
event.begin();
try {
    List<Order> result = jdbcTemplate.query(query, mapper);
    event.resultSize = result.size();
    return result;
} finally {
    event.commit();
}

注意：自定义 Event 的 begin() 和 commit() 必须成对调用，漏写 commit() 会导致事件丢失，且 JFR 不会报错，只能通过 jcmd <pid> JFR.check 看 Event 总数来确认是否正常记录。

生产环境常态开启的实践 ​

轮转录制方案 ​

bash
# 持续录制，每 2 小时写一个文件，保留最近 3 个文件
jcmd <pid> JFR.start name=continuous \
    settings=default \
    maxage=2h \
    maxsize=500m

# 告警触发时 dump 当前录制到持久存储
jcmd <pid> JFR.dump name=continuous \
    filename=/data/jfr/alert-$(date +%s).jfr

# 定时任务：压缩并归档旧文件
# 0 * * * * find /data/jfr -name "*.jfr" -mtime +7 -delete

模板选择 ​

模板开销记录粒度适用场景
default0.3-0.5%只记录关键事件常态开启，7×24
profile1-2%更细粒度，包括方法采样定位阶段，1-2 小时
自定义可控只开需要的事件针对特定问题

自定义模板文件（JFC 格式）放在 $JAVA_HOME/lib/jfr/ 下，也可以用 jcmd <pid> JFR.configure 在线修改部分参数。

远程触发（JDK 16+ 的 JMX 支持） ​

java
// 通过 JMX 远程触发 JFR dump
MBeanServerConnection conn = ...;
ObjectName jfrBean = new ObjectName("jdk.management.jfr:type=FlightRecorder");
String[] signature = new String[] { String.class.getName() };
Object[] params = new Object[] { "continuous" };
conn.invoke(jfrBean, "dumpRecording", params, signature);

配合 Prometheus AlertManager 的 Webhook，可以在 CPU 飙高或 GC 停顿超过阈值时自动 dump JFR 并上传到 OSS。

常见踩坑 ​

  1. JFR 本身被禁用了：部分 JDK 8 发行版（如某些 OpenJDK 构建）不包含 JFR。JDK 11+ 全部内置，JDK 8 需要确认是 Oracle JDK 或 Zulu JDK 等商业构建。
  2. maxage 和 maxsize 同时设置：JFR 会取二者中先到达的限制。如果 maxage=2h 但 maxsize=100m，写入速度快的应用可能在 10 分钟内就触发了 maxsize 覆盖，导致 2 小时内的事件被提前丢弃。
  3. 容器内存限制：JFR 的 Ring Buffer 默认 4MB 虽然小，但如果容器配置了 -XX:MaxRAMPercentage=70 且堆外内存不足，JFR 的写入线程可能被 OOM Killer 杀死。建议容器环境给 JFR 预留 64MB 堆外内存（-XX:MaxDirectMemorySize=64m）。
  4. JMC 版本不匹配：JDK 17 的 JFR 文件格式和 JDK 11 不完全兼容，用旧版 JMC 打开新版 JFR 会报 Unsupported magic number。JMC 9.x 兼容 JDK 11-21，JMC 8.x 兼容 JDK 8-17。

总结 ​

  • JFR 生产开销 < 1%，基于事件驱动 + 环形缓冲区，不经过堆，不触发 GC
  • jcmd <pid> JFR.start 可动态开启/停止/转储，无需重启，命令行和 JMX 双通道可用
  • JMC 是 JFR 的可视化分析工具，GC 标签页看 STW 时间线，Lock Instances 标签页看锁竞争
  • 自定义 Event 可以埋点业务代码，用 jdk.jfr.Event API 自动管理时间，但注意 begin/commit 配对
  • 生产实践：常态开启 default 轮转录制 + 告警触发 dump + 归档，避免事后追查空手而归
  • 重要：JFR 是"常态武器"不是"事后急救"，先开起来，等出问题才有数据

参考 ​

  • JDK 官方文档 — Java Flight Recorder (JFR) — oracle.com
  • JDK 源码 — jdk.jfr.Event
  • JMC 用户指南 — openjdk.org
  • JFR 自定义事件模板 — Baeldung Guide to JFR
  • 《Java Performance: The Definitive Guide》— Scott Oaks

手撕 → 框架 → 生产化，一步步把 AI Agent 工程化搞透。

Copyright © 2026 祥哥