4.4 JFR 与 jcmd：能常开的剖析与无依赖应急

上一节：4.3 async-profiler　|　下一节：4.5 系统级观测 配套代码：04-toolchain/04-jfr-and-jcmd

一句话结论

JFR（JDK Flight Recorder）是唯一适合在生产环境长期开着的剖析工具（开销约 1%），它记录的是「系统发生了什么」的完整事件流。jcmd 则是零依赖的应急手段——什么都不用装，出问题时随手可用。

一、用「24 小时动态心电图」理解 JFR

普通心电图只在医院做几分钟。但有些心脏问题只在特定时刻发作——所以医生给病人戴一个24 小时动态心电图记录仪：

关键价值：性能问题往往偶发且不可复现。JFR 让你能在问题发生后回到现场。

二、JFR 的三种用法

用法一：出问题时临时录一段

PID=$(jcmd | grep app.jar | awk '{print $1}')

# 录制 120 秒，输出到文件
jcmd "$PID" JFR.start name=perf settings=profile duration=120s filename=/tmp/perf.jfr

# 结束后自动停止；也可以手动
jcmd "$PID" JFR.stop name=perf

用法二：滚动录制（推荐用于生产）⭐

# 保持最多 256MB / 1 小时的事件，超出后自动丢弃最旧的
jcmd "$PID" JFR.start name=rolling settings=profile maxsize=256m maxage=1h

# 出问题时立刻 dump（不用等录制结束）
jcmd "$PID" JFR.dump name=rolling filename=/tmp/incident-$(date +%s).jfr

# 不再需要时停止
jcmd "$PID" JFR.stop name=rolling

这是最实用的模式：平时默默记录，出事时 dump 出「过去 1 小时」的事件。

用法三：启动时就开着

java -XX:StartFlightRecording=name=app,settings=profile,maxsize=256m,maxage=1h,dumponexit=true,filename=/var/log/app/recording.jfr \
     -jar app.jar

dumponexit=true 很重要：进程退出（包括崩溃）时会把录制内容落盘——这是排查 OOM/崩溃的关键证据。

三、JFR 最值得看的 8 类事件

⭐ 最容易被忽略、最有用的两类：

• jdk.SocketRead / jdk.FileRead：它们直接告诉你「阻塞在哪个 IO 上、花了多久」。这是「CPU 不高但慢」的确定性证据。
• jdk.JavaMonitorEnter：直接给出锁等待时长排行榜——比火焰图更精确（火焰图只能看采样比例）。

用 JDK Mission Control 分析

JMC 是官方分析工具，几个最有用的视图：

最实用的一个动作：在 Event Browser 里，把 jdk.GCPhasePause 的时间点和你监控里的 P99 尖刺时间点对齐。对齐 → GC 是根因；不对齐 → 排除 GC（第 2 章 2.5 节）。

四、jcmd：零依赖的应急工具

jcmd 的价值：JDK 自带，什么都不用装，进程还活着就能用。

线程快照的正确用法

一次快照没有价值，连续多次对比才有。

PID=$(jcmd | grep app.jar | awk '{print $1}')

# 连续取 5 份，间隔 3 秒
for i in $(seq 1 5); do
  jcmd "$PID" Thread.print > "threads-$i.txt"
  sleep 3
done

# 观察：哪些栈在多次快照中【持续存在】
for i in $(seq 1 5); do
  echo "--- 第 $i 次 ---"
  grep -A2 "java.lang.Thread.State" "threads-$i.txt" | grep -E "^\s+at " | sort | uniq -c | sort -rn | head -5
done

判读规则：

一个实用技巧：搜 HikariPool、socketRead、BLOCKED 这三个关键词，能覆盖大部分常见问题。

五、JFR vs async-profiler：怎么选

推荐组合：

生产环境：JFR 滚动录制（常开）+ Prometheus 指标 + 结构化日志
出问题时：dump JFR → JMC 定位到大致范围 → async-profiler 深挖 → 结论
应急时刻：jcmd Thread.print（连续多份）

六、本节小结

1. JFR 是唯一适合生产常开的剖析工具（约 1% 开销），用滚动录制模式最实用。
2. dumponexit=true 能在进程崩溃时保留证据——排查 OOM 的关键。
3. JFR 有几十类事件，最有价值的是 SocketRead/FileRead（阻塞 IO 耗时）和 JavaMonitorEnter（锁等待时长）——它们比火焰图更精确。
4. 把 GC 停顿的时间戳与 P99 尖刺对齐，是排除/确认 GC 的标准动作。
5. jcmd 是零依赖应急工具：Thread.print 必须连续取多份对比才有价值。
6. 用 jcmd <pid> VM.flags 确认线上真正的 JVM 参数——不要相信文档。

七、自测

1. 一个服务的性能问题「偶发、不可复现」。你会怎么配置 JFR 来保证下次发生时有证据？
2. 你取了 5 份线程快照，发现每份里都有 40+ 个线程停在 HikariPool.getConnection。这说明什么？接下来该看什么指标？（这道题的答案会连接到第 7 节）
3. JFR 的 jdk.SocketRead 事件显示某个下游调用的 P99 是 800 ms，而 CPU 火焰图里完全看不到这个调用。请解释为什么不矛盾，以及这个信息对定位的价值。

1. 用 JFR 滚动录制并在启动参数里配置：-XX:StartFlightRecording=name=rolling,settings=profile,maxsize=256m,maxage=1h,dumponexit=true,filename=/var/log/app/recording.jfr。这样：① 平时持续记录最近 1 小时的事件（开销约 1%，可以常开）；② 用户报障或告警触发时，立刻用 jcmd <pid> JFR.dump name=rolling filename=/tmp/incident.jfr 保存现场；③ 如果进程崩溃/重启，dumponexit=true 会自动落盘。关键点：不要等出问题才开始录——偶发问题的证据只存在于"过去"。
2. 说明大量请求在等连接池分配连接——这是「连接池排队」的直接证据（不是"数据库慢"，而是"连不上数据库"这个环节在排队）。接下来要看的指标：① db_pool_pending（是否 > 0，以及数值大小）；② db_pool_active / db_pool_total（是不是已经打满）；③ 数据库侧的 pg_stat_activity（连接数是否触顶、有没有长时间运行的查询）；④ 应用侧依赖计时 dep.postgres 的 P99（它包含了等连接的时间）；⑤ 如果有，看单条 SQL 的执行时间（用来区分「池太小」还是「查询太慢」）。注意：这两种情况的修法完全相反——池太小要按 Little’s Law 调整，查询太慢要优化 SQL，盲目加池会把压力转移到数据库。
3. 不矛盾，因为 SocketRead 是「阻塞时间」而不是「CPU 时间」。CPU 火焰图只统计「CPU 正在执行什么」，而等待网络响应时线程是阻塞的、不消耗 CPU，所以在 CPU 火焰图里看不到（甚至看不到这个调用栈）。价值：jdk.SocketRead 事件直接给出「阻塞在哪个 socket、远端是谁、花了多久」——这就把「CPU 不高但慢」的原因确定性地指向了某个下游依赖，比火焰图的采样比例更精确。下一步：用 tracing（第 6 节）或依赖级指标确认是哪个下游，再去查那个服务或网络。