承接的问题
2.3 把微基准和系统压测的边界划清了:JMH 能回答「一次操作在本机要多少纳秒」,回答不了「线上这 300 ms 到底花在哪个锁上」。进入第 3 章,工具从受控实验换成运行态观测,第一个要解决的就是锁竞争。
典型症状是这样:接口 RT 从 40 ms 涨到 300 ms,CPU 利用率只有 35%,线程池没有满,日志里也没有异常。抓一份线程转储,能看到一片 BLOCKED (on object monitor),但不知道谁持有锁、持有了多久。打开 JFR,jfr view contention-by-class 可能只剩很少几条,甚至只有 JFR 自己的 PlatformRecorder,看起来「没有锁竞争」。
这三个现象指向同一组问题:
jdk.JavaMonitorEnter到底在什么时候提交,duration量的是等待还是持有;settings=profile的默认阈值是多少,为什么它会把大量短竞争直接丢掉;jfr summary、jfr view、jfr print各看什么,怎么从事件回到代码行。
本节的实验都跑在同一台机器上:
Apple M1 Pro,10 核,32 GB,macOS 26.3 (25D125)
Temurin 25.0.5+8
写作时 uptime 的 load average 是 108.37 119.89 117.88。所有计时数字都是单次运行、随调度波动、不作基准;本节只比较方向,不比较绝对快慢。
三个事件各记什么
JFR 的锁相关事件不止一个。名字写错,--events 过滤器会静默返回空,所以先把分工钉死。
| 事件 | JFR 标签 | 提交时机 | 关键字段 | 本卷出现 |
|---|---|---|---|---|
jdk.JavaMonitorEnter | Java Monitor Blocked | 线程等待进入 synchronized 监视器,最终进入后提交 | monitorClass、previousOwner、address、duration | 3.1、4.1、11.1 |
jdk.JavaMonitorWait | Java Monitor Wait | Object.wait 返回、超时或被中断后提交 | monitorClass、notifier、timeout、timedOut、address | 3.1、4.2 |
jdk.ThreadPark | Java Thread Park | LockSupport.park 返回后提交 | parkedClass、timeout、until、address | 3.1、5.3、10.3 |
三个事件都是持续时间事件:startTime 回填为等待开始的时刻,duration 是等待时长,不是持有锁的时长。想看「这把锁被持有多久」,JFR 的这三个事件回答不了,要结合 3.2 的采样和 3.3 的转储。
previousOwner 是竞争开始时的持有者,不等于整段等待里唯一的持有者。监视器可能在等待期间被交接给别的线程;这个字段只适合回答「我一开始在等谁」。
monitorClass 是被锁对象的运行时类,不是变量声明类型。锁 new Object() 时它是 java.lang.Object;锁一个 Book 实例时它是 Book。address 是监视器地址,同一次录制里相同地址代表同一个对象;跨录制、跨进程不能拿地址做比较,GC 之后地址也可能被复用。
最容易踩的坑是锁的实现方式。ReentrantLock 的竞争不会产生 jdk.JavaMonitorEnter,它走 LockSupport.park,对应 jdk.ThreadPark。本机另写一个把临界区改成 ReentrantLock 的靶子(同一进程里还保留 wait/notify 线程)后,同一份录制里 jdk.JavaMonitorEnter 只剩 2 条,其中 1 条是 JFR 自己的 PlatformRecorder,另 1 条来自通知线程进入监视器;jdk.ThreadPark 涨到 8366 条。看到 Monitor 事件为空,先确认代码里等的是监视器还是 AQS。
阈值:10 ms 的默认值会过滤掉短竞争
先把一个容易写错的命令说清楚:JDK 25 的 jfr 命令行没有 start 子命令。它只有 print、view、summary、configure、metadata、scrub、assemble、disassemble。启动录制只有两条路:JVM 启动参数,或 jcmd 的 JFR.start。
# 方式一:启动时挂参数
java -XX:StartFlightRecording=filename=/tmp/lock.jfr,settings=profile,dumponexit=true \
-cp classes MicroLockProbe
# 方式二:对运行中的进程
jcmd <pid> JFR.start name=lock settings=profile duration=5s filename=/tmp/lock.jfr
jcmd <pid> JFR.dump name=lock filename=/tmp/lock.jfr
jcmd <pid> JFR.stop name=lock
settings=profile 不是「全量录制」。本机 $JAVA_HOME/lib/jfr/profile.jfc 里,jdk.JavaMonitorEnter 的阈值是 10 ms;default.jfc 里是 20 ms。有些资料笼统写 20 ms,那是 default.jfc 的值,profile 配置在本机是 10 ms。以你机器上的 jfc 为准:
rg -A3 '<event name="jdk.JavaMonitorEnter"' "$JAVA_HOME/lib/jfr/profile.jfc"
<event name="jdk.JavaMonitorEnter">
<setting name="enabled">true</setting>
<setting name="stackTrace">true</setting>
<setting name="threshold" control="locking-threshold">10 ms</setting>
阈值是按事件时长过滤,不是按固定速率采样:每次等待只要不短于阈值就记录,短于阈值就丢掉。它和 async-profiler 的采样是两种口径,3.2 会对照。profile.jfc 里这些锁事件的 threshold 都挂在 locking-threshold 控制项下;但命令行覆盖是按事件写的,只改 JavaMonitorEnter 不会顺带放开 ThreadPark,要逐个事件设置。
覆盖阈值最直接的方式是启动参数里追加事件设置:
java -XX:StartFlightRecording=filename=/tmp/lock-zero.jfr,settings=profile,\
jdk.JavaMonitorEnter#threshold=0ms,jdk.ThreadPark#threshold=0ms,dumponexit=true \
-cp classes MicroLockProbe
在线进程不能改启动参数,做法是先复制一份配置再启动录制:
jfr configure --input "$JAVA_HOME/lib/jfr/profile.jfc" \
--output /tmp/zero-lock.jfc \
jdk.JavaMonitorEnter#threshold=0ms jdk.ThreadPark#threshold=0ms
jcmd <pid> JFR.start name=lock settings=/tmp/zero-lock.jfc duration=30s \
filename=/tmp/lock-live.jfr
这两条命令在本机对 DumpTarget 进程跑通过,jfr configure 会输出 Configuration written successfully to: /private/tmp/.../zero-lock.jfc,JFR.start 会返回 Started recording 1。阈值取 0 的代价是事件量随竞争次数线性上涨,生产上一般从 1 ms 到 10 ms 起步,只在短窗口内用 0。
实跑:4 个线程抢同一把监视器锁
靶子只做一件事:4 个平台线程反复进入同一个 synchronized 块,块里做一次自增。临界区越短,默认阈值越容易把它过滤掉。
public final class MicroLockProbe {
private static final Object LOCK = new Object();
private static long counter;
private static volatile boolean running = true;
public static void main(String[] args) throws Exception {
Thread[] threads = new Thread[4];
for (int i = 0; i < threads.length; i++) {
int id = i;
threads[i] = Thread.ofPlatform().name("micro-" + id).start(() -> {
while (running) {
synchronized (LOCK) {
counter++;
}
}
});
}
Thread.sleep(2_000);
running = false;
for (Thread t : threads) {
t.join();
}
System.out.println("counter=" + counter);
}
}
编译并按两种阈值各录一次:
javac --release 25 -d classes MicroLockProbe.java
java -XX:StartFlightRecording=filename=out/micro-default.jfr,settings=profile,dumponexit=true \
-cp classes MicroLockProbe
java -XX:StartFlightRecording=filename=out/micro-zero-3s.jfr,settings=profile,\
jdk.JavaMonitorEnter#threshold=0ms,dumponexit=true \
-cp classes MicroLockProbe
两次运行的自增结果分别是 counter=9180874 和 counter=11227070。两份录制文件的 Duration 都是 2 s,但机器负载不同,所以只比较阈值的过滤方向,不把事件数换算成速率。jfr view 的对照:
| 录制 | java.lang.Object 事件数 | Avg | P90 | Max |
|---|---|---|---|---|
settings=profile(10 ms) | 10 | 11.1 ms | 14.8 ms | 15.0 ms |
jdk.JavaMonitorEnter#threshold=0ms | 7,895 | 0.504 ms | 1.62 ms | 14.0 ms |
默认配置下只剩 10 条,因为只有等待不短于 10 ms 的竞争才会被记录;把阈值降到 0,同样的代码在同样的 2 秒窗口里记下 7,895 条,平均等待只有 0.504 ms。默认那条 Avg 11.1 ms 不是「竞争更严重」,而是低于 10 ms 的样本被删掉了,剩下的自然都偏大。
jfr summary 的原始行如下(threshold=0ms 那次):
jdk.JavaMonitorEnter 7897 161689
jfr view 先看按类聚合,命令和输出如下:
jfr view --width 100 contention-by-class out/micro-zero-3s.jfr
jfr view --width 100 contention-by-site out/micro-zero-3s.jfr
java.lang.Object 7,895 0.504 ms 1.62 ms 14.0 ms
jdk.jfr.internal.PlatformRecorder 2 1.55 ms 3.07 ms 3.07 ms
按站点聚合时,7,895 条中有 7,895 条落在 MicroLockProbe.lambda$main$0() 这一行,另外 2 条来自 JFR 自身(PlatformRecorder.periodicTask() 和 PlatformRecording.isToDisk())。jfr print 给出单条事件的完整字段,默认阈值下的一条 duration 正好落在 10.0 ms:
jdk.JavaMonitorEnter {
startTime = 02:06:17.216 (2026-10-29)
duration = 10.0 ms
monitorClass = java.lang.Object (classLoader = bootstrap)
previousOwner = "micro-1" (javaThreadId = 30)
address = 0xA208040E0
eventThread = "micro-0" (javaThreadId = 29)
stackTrace = [
MicroLockProbe.lambda$main$0() line: 12
java.lang.Thread.run() line: 1474
]
}
阈值 0 下的短事件则是 duration = 0.0465 ms、previousOwner = "micro-3"、eventThread = "micro-1",两个线程 ID 不同,说明这是一次真实的交接,不是自旋。从一条事件能读出四件事:等待时间、竞争开始时的持有者、被锁对象、等待者自己的栈。eventThread 是等待者,previousOwner 是它开始等的时候的持有者。
jfr print 默认只打印 5 层栈,业务栈深时加 --stack-depth:
jfr print --events jdk.JavaMonitorEnter --stack-depth 12 out/micro-zero-3s.jfr
Object.wait 与 ThreadPark 的记录方式
MicroLockProbe 只覆盖了监视器进入。再看一个同时包含 Object.wait 和 ReentrantLock 的靶子:
import java.util.concurrent.locks.LockSupport;
import java.util.concurrent.locks.ReentrantLock;
public final class WaitParkProbe {
private static final Object WAIT_MONITOR = new Object();
private static final ReentrantLock LOCK = new ReentrantLock();
private static volatile boolean running = true;
public static void main(String[] args) throws Exception {
Thread waiter = Thread.ofPlatform().name("loan-wait").start(() -> {
while (running) {
synchronized (WAIT_MONITOR) {
try {
WAIT_MONITOR.wait(20);
} catch (InterruptedException e) {
return;
}
}
LockSupport.parkNanos(2_000_000L);
}
});
Thread notifier = Thread.ofPlatform().name("loan-notify").start(() -> {
while (running) {
synchronized (WAIT_MONITOR) {
WAIT_MONITOR.notifyAll();
}
try {
Thread.sleep(20);
} catch (InterruptedException e) {
return;
}
}
});
Thread holder = lockLoop("loan-lock-holder");
Thread contender = lockLoop("loan-lock-waiter");
Thread.sleep(3_000);
running = false;
waiter.interrupt();
notifier.interrupt();
waiter.join();
notifier.join();
holder.join();
contender.join();
}
private static Thread lockLoop(String name) {
return Thread.ofPlatform().name(name).start(() -> {
while (running) {
LOCK.lock();
try {
Thread.sleep(0, 500_000);
} catch (InterruptedException e) {
return;
} finally {
LOCK.unlock();
}
}
});
}
}
录制时把三个事件的阈值一起放开:
javac --release 25 -d classes WaitParkProbe.java
java -XX:StartFlightRecording=filename=out/waitpark.jfr,settings=profile,\
jdk.JavaMonitorEnter#threshold=0ms,jdk.JavaMonitorWait#threshold=0ms,\
jdk.ThreadPark#threshold=0ms,dumponexit=true \
-cp classes WaitParkProbe
jfr summary 的三行:
jdk.ThreadPark 3899 142948
jdk.JavaMonitorWait 133 3176
jdk.JavaMonitorEnter 3 61
jdk.JavaMonitorWait 的一条:
jdk.JavaMonitorWait {
startTime = 02:09:37.428 (2026-10-29)
duration = 0.102 ms
monitorClass = java.lang.Object (classLoader = bootstrap)
notifier = "loan-notify" (javaThreadId = 30)
timeout = 20.0 ms
timedOut = false
address = 0xC55155180
eventThread = "loan-wait" (javaThreadId = 29)
stackTrace = [
java.lang.Object.wait0(long)
java.lang.Object.wait(long) line: 389
WaitParkProbe.lambda$main$0() line: 14
java.lang.Thread.run() line: 1474
]
}
notifier 是调用 notifyAll 的线程,timeout 是 wait(20) 传入的上限,timedOut=false 说明这次是被通知唤醒、不是超时。并不是每条都有 notifier:超时或被中断时它可能是 N/A,所以不能拿 notifier 是否存在判断有没有竞争。
jdk.ThreadPark 的一条(摘录,省略 until 与中间 AQS 栈帧):
jdk.ThreadPark {
startTime = 02:09:37.429 (2026-10-29)
duration = 0.639 ms
parkedClass = java.util.concurrent.locks.ReentrantLock$NonfairSync (classLoader = bootstrap)
timeout = N/A
address = 0x61EECB9A0
eventThread = "loan-lock-waiter" (javaThreadId = 32)
stackTrace = [
jdk.internal.misc.Unsafe.park(boolean, long)
java.util.concurrent.locks.LockSupport.park(Object) line: 223
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer$Node, int, boolean, boolean, boolean, long) line: 790
java.util.concurrent.locks.ReentrantLock$Sync.lock() line: 154
]
}
parkedClass 是 ReentrantLock$NonfairSync,timeout=N/A 表示无超时 park。栈里的 acquire(Node, int, boolean, boolean, boolean, long) 是 JDK 25 的新 AQS 主路径,卷二已经讲过;看到这串签名,就能确认等的是 AQS 而不是监视器。ThreadPark 的 eventThread 同样是等待者,持有者不在这条栈里,要找持有者得回到 3.3 的转储或看 Locked ownable synchronizers。
在 libraryd-conc 里落地
conc-ops 不把 JFR 当一次性手工工具,而是固定成一段可复用的采集脚本。下面的脚本对运行中的进程开 30 秒自定义阈值录制,结束后直接出两张聚合表:
#!/bin/sh
set -eu
PID=$1
OUT=${2:-/tmp/conc-lock}
DURATION=${3:-30}
mkdir -p "$OUT"
jfr configure --input "$JAVA_HOME/lib/jfr/profile.jfc" --output "$OUT/lock.jfc" \
jdk.JavaMonitorEnter#threshold=0ms jdk.JavaMonitorWait#threshold=0ms jdk.ThreadPark#threshold=0ms
jcmd "$PID" JFR.start name=conc-lock settings="$OUT/lock.jfc" \
duration="${DURATION}s" filename="$OUT/lock.jfr"
sleep $((DURATION + 2))
jfr summary "$OUT/lock.jfr" | grep -E 'JavaMonitor|ThreadPark'
jfr view --width 140 contention-by-class "$OUT/lock.jfr"
jfr view --width 140 contention-by-site "$OUT/lock.jfr"
脚本的关键不是命令本身,而是三件事:阈值写进独立的 jfc,不污染 JDK 自带配置;录制窗口固定,避免事件量失控;录完立刻按类和站点聚合,先看热点再看单条事件。生产上把 0ms 改成 1ms 或 5ms,并把 duration 控制在 30 秒以内。要在应用内埋录制,用 jdk.jfr.Recording 加 enable("jdk.JavaMonitorEnter").withThreshold(Duration.ZERO) 即可,API 与命令行是同一套事件设置,不再单独展开。
常见错误与边界
- 把
jfr start当命令。 JDK 25 没有这个子命令,正确入口是启动参数或jcmd JFR.start。 - 只改
JavaMonitorEnter的阈值。ReentrantLock竞争走ThreadPark,不放开它,看到的仍然是「没有锁」。 - 把
duration当成持锁时间。 它是等待时间;持锁时间要靠采样或业务埋点。 - 把
previousOwner当成唯一持有者。 监视器可能在等待期间交接,这个字段只表示竞争开始时的持有者。 - 拿地址跨录制比较。 同一次录制里相同地址是同一个对象;跨进程、跨 GC 之后没有可比性。
- 在生产上长期开
threshold=0ms。 事件量随竞争次数上涨,录制文件、磁盘 I/O 和 JFR 自身开销都会跟着涨;短窗口抓现场可以,长期常开要用 1–10 ms。 - 把
JavaMonitorWait都当竞争。 工作线程等任务队列也会wait;要看notifier、timeout、栈和业务语义,不能只看条数。 - 以为 JFR 覆盖所有锁。
StampedLock、Semaphore、Condition.await等走的是 park 或其他路径;先确认事件类型,再解释数据。
小结
JFR 的锁诊断有三层:事件层看 JavaMonitorEnter、JavaMonitorWait、ThreadPark 各自记什么;配置层看 profile.jfc 的 10 ms 阈值和 #threshold=0ms 的覆盖方式;聚合层用 jfr view contention-by-class/site 把事件压回代码行,再用 jfr print 看单条的 previousOwner、address、notifier。
本节最重要的两个实测结论:默认 profile 下 2 秒只留下 10 条不短于 10 ms 的竞争,阈值降到 0 后同一份代码记下 7,895 条、平均 0.504 ms;ReentrantLock 的竞争不会出现在 JavaMonitorEnter 里,而是 ThreadPark。把临界区里的 synchronized 自增换成 LongAdder 后,同样的 0 ms 录制里 java.lang.Object 的竞争事件归零,只剩 JFR 自己的 2 条 PlatformRecorder。修复是否有效,用同一套录制参数复跑一次就能验证。
阅读导航:上一节 2.3 从微基准到系统压测 | 下一节 3.2 async-profiler 的锁与分配火焰图
继续阅读
探索更多技术文章
浏览归档,发现更多关于系统设计、工具链和工程实践的内容。