这份附录怎么用
正文按事故讲，附录按问题查。每节结构固定：「我要知道什么」→ 命令 → 「看到什么说明什么」。命令里的 <pid> 换成目标进程号。本机口径：Apple M1 Pro，10 核，32 GB，macOS 26.3，Temurin 25.0.5+8；写作期间 load average 常在 70–170，所以耗时只作量级参考。标注「本机输出」的 text 块是原样粘贴，没跑过的会写明「未执行」。
| 我要知道什么 | 第一条命令 | 常见误判 |
|---|---|---|
| 平台线程卡在哪 | jcmd <pid> Thread.print -l | 在里面找虚拟线程 |
| 虚拟线程有多少 | jcmd <pid> Thread.dump_to_file -format=plain | 用 Thread.print 判断 |
| 谁在抢锁 | jcmd <pid> JFR.start + jfr view | 只看转储里的 BLOCKED |
| 有没有 pin | jfr view pinned-threads，阈值归零 | 用默认 20 ms 配置下结论 |
| 谁占着堆 | jcmd <pid> GC.class_histogram | 忘了它先做一次 Full GC |
| 机器是否过载 | top -l 1 -pid <pid>、uptime | 把 load average 当 CPU 使用率 |
线程：谁在跑、谁在等、谁卡住
Thread.print 看平台线程
jcmd <pid> Thread.print -l
jstack -l <pid>
两条输出基本一致，jcmd 不用装额外工具、容器里也能用，优先选它。本机对一个持有 100 000 个虚拟线程的进程执行，得到 299 行、_java_thread_list 长度 32，grep -c virtual 为 0。另一次复现（2 个平台线程争同一监视器，sleep 期间持锁）的节选如下，用来示范怎么读：
37879:
2026-10-29 03:40:29
Full thread dump OpenJDK 64-Bit Server VM (25.0.5+8-LTS mixed mode, sharing)
"looper-0" #25 [28931] prio=5 os_prio=31 cpu=0.74ms elapsed=2.71s
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleepNanos0(java.base@25.0.5/Native Method)
- locked <0x0000000320418250> (a java.lang.Object)
"looper-1" #26 [33027] prio=5 os_prio=31 cpu=0.20ms elapsed=2.71s
java.lang.Thread.State: BLOCKED (on object monitor)
- waiting to lock <0x0000000320418250> (a java.lang.Object)
判读要点：
waiting to lock <地址>是被谁挡住；同一个转储里搜这个地址，能找到locked <同一地址>的线程，那就是持有者。parking to wait for ... ReentrantLock$NonfairSync说明在等显式锁，不是在等监视器；两类等待的处置完全不同。-l多出的Locked ownable synchronizers段落列出ReentrantLock等持有的同步器，死锁排查必看。cpu=是累计 CPU 时间，不是瞬时占用；判断谁在烧 CPU 要看两次采样的差值。
虚拟线程不在这份输出里。 前面那个 100 000 虚拟线程的进程确实有 100 000 个存活线程，Thread.print 里一个都没有。拿它判断「虚拟线程是不是泄漏」，一定得出错误结论。
Thread.dump_to_file 看全部线程
jcmd <pid> Thread.dump_to_file -format=plain /tmp/vt.txt
jcmd <pid> Thread.dump_to_file -format=json /tmp/vt.json
本机对 100 000 个虚拟线程实测：plain 45 MB / 1.06 秒，json 67 MB / 1.16 秒。plain 的头部与一条虚拟线程记录：
18928
2026-10-28T19:22:00.520009Z
25.0.5+8-LTS
#33 "vt-sleeper-0" virtual TIMED_WAITING 2026-10-28T19:22:00.531209Z
at java.base/java.lang.Thread.sleepNanos0(Native Method)
at java.base/java.lang.Thread.sleepNanos(Thread.java:509)
判读要点：#<threadId> 是前缀，virtual 只在这种转储里出现；按名字前缀分组计数即可确认创建数和存活数。100 万条约 781 MB / 8 秒（同一台机器、同一版本的实测记录），先看磁盘再执行，容器磁盘配额小的机器上一次全量转储就能把节点写满。
ThreadMXBean：在进程内自查
import java.lang.management.*;
import java.util.*;
public class MxProbe {
public static void main(String[] args) throws Exception {
int n = 100_000;
List<Thread> vts = new ArrayList<>();
for (int i = 0; i < n; i++) {
vts.add(Thread.ofVirtual().name("vt-" + i).start(() -> {
try { Thread.sleep(600_000); } catch (InterruptedException e) { }
}));
}
Thread.sleep(1000);
ThreadMXBean mx = ManagementFactory.getThreadMXBean();
System.out.println("getThreadCount = " + mx.getThreadCount());
System.out.println("dumpAllThreads = " + mx.dumpAllThreads(false, false).length);
System.out.println("getAllStackTraces= " + Thread.getAllStackTraces().size());
System.out.println("liveVirtual = " + vts.stream().filter(Thread::isAlive).count());
}
}
getThreadCount = 18
dumpAllThreads = 18
getAllStackTraces= 18
liveVirtual = 100000
判读要点：三个「18」对十万个「100000」。getThreadCount()、getTotalStartedThreadCount()、dumpAllThreads()、Thread.getAllStackTraces() 全部只算平台线程。拿 MXBean 做虚拟线程水位告警，这条告警永远不会响；规模只能从 Thread.dump_to_file 或 JFR 的 jdk.VirtualThreadStart 事件里看。
死锁：JVM 会替你找
两个线程反序拿同一对监视器，jcmd <pid> Thread.print 末尾会多出一段：
Found one Java-level deadlock:
=============================
"loan-lock-A-then-B":
waiting to lock monitor 0x0000000aa74ba680 (object 0x0000000320418438, a java.lang.Object),
which is held by "loan-lock-B-then-A"
"loan-lock-B-then-A":
waiting to lock monitor 0x0000000aa74ba760 (object 0x0000000320418428, a java.lang.Object),
which is held by "loan-lock-A-then-B"
Found 1 deadlock.
判读要点：这是 JVM 自己做环检测，Found 1 deadlock. 是结论行。synchronized 监视器与 AbstractOwnableSynchronizer 的锁都参与检测，StampedLock 不在其列（所有权不由 AOS 记录）。没有这一段不等于没有死锁：全员 park 等任务、没人持锁的「逻辑死锁」，JVM 看不出来。
JFR：把「等」变成可统计的事件
启动只能用 jcmd
jcmd <pid> JFR.start name=appx settings=profile duration=8s filename=/tmp/appx.jfr
JDK 25 的 jfr 命令行没有 start 子命令：
jfr: unknown command 'start'
List of available commands:
jfr 只有 print、view、configure、metadata、scrub、summary 六个子命令，负责读和配置；往运行中的进程里启动录制，必须走 jcmd <pid> JFR.start，或启动参数 -XX:StartFlightRecording。录制结束后的概览（节选，只留三行事件计数）：
Version: 2.1
Chunks: 1
Start: 2026-10-28 19:22:07 (UTC)
Duration: 8 s
jdk.ExecutionSample 587
jdk.ThreadPark 120
jdk.JavaMonitorEnter 0
判读要点：Duration 是录制窗口，不是 JVM 运行时长。ThreadPark 有 120 条而 JavaMonitorEnter 为 0，说明等待集中在 LockSupport.park（ReentrantLock、队列、sleep 的底层），不是 synchronized。先看这两个计数，就能区分两类等待。
视图：先 view 再 print
jfr view 把事件聚合成表，视图名固定，不带参数会列出全部。常用的：
| 视图 | 回答什么 | 依赖事件 |
|---|---|---|
contention-by-site / -class / -thread | 哪里、哪类锁、哪个线程在抢 | jdk.JavaMonitorEnter |
pinned-threads | 哪些虚拟线程被钉住 | jdk.VirtualThreadPinned |
allocation-by-class / -thread | 谁在造对象、谁造得最多 | jdk.ObjectAllocationSample |
hot-methods | CPU 花在哪些方法 | jdk.ExecutionSample |
thread-count / thread-cpu-load | 线程数、每线程 CPU | jdk.JavaThreadStatistics / jdk.ThreadCPULoad |
gc-pauses / safepoints | GC 与安全点停顿 | jdk.GCPhasePause / jdk.SafepointBegin |
4 个平台线程在很短的 synchronized 块里反复自增、threshold=0ms 录制 3 秒：
Contention by Site
StackTrace Count Avg. Max.
----------------------------------------------------------------------------------- ----- --------- ---------
MonTight.lambda$main$0() 4,857 1.25 ms 21.1 ms
jdk.jfr.internal.PlatformRecorder.periodicTask() 1 5.90 ms 5.90 ms
jdk.jfr.internal.PlatformRecording.getId() 1 0.0249 ms 0.0249 ms
判读要点：业务行 4,857 条、平均 1.25 ms，说明竞争真实存在但不严重；后两行来自 JFR 自己，任何录制都有。业务行是 0、只剩 JFR 自己时，先确认临界区是不是太短被阈值滤掉，再确认用的是 synchronized 而不是 ReentrantLock——后者产生 jdk.ThreadPark，contention-by-* 一条都不会有。
一条必须记住的反例：把 Thread.sleep(300) 放进 synchronized，2 个线程反复进出同一监视器，线程转储稳定显示 BLOCKED (on object monitor)，但 5 秒录制（threshold=0ms）只记到 0–1 条 jdk.JavaMonitorEnter。该事件不是「每次阻塞都记一条」，0 条不能反证没有竞争，必须和线程转储互证。
单条事件用 jfr print --events jdk.JavaMonitorEnter --stack-depth 4 <file>，关键是三个字段：eventThread 是等待者，previousOwner 是它开始等待时的持有者，duration 是等待时长而不是持有时间。两个线程 ID 不同，才说明是一次真实交接。
threshold=0ms：pin 的必要配置
profile.jfc 里 jdk.VirtualThreadPinned 默认 threshold = 20 ms，jdk.JavaMonitorEnter 默认 10 ms。短于阈值的样本直接丢弃，「0 条」经常是配置问题：
jfr configure --input "$JAVA_HOME/lib/jfr/profile.jfc" \
--output /tmp/zero.jfc jdk.VirtualThreadPinned#threshold=0ms
Configuration written successfully to:
/tmp/zero.jfc
用这份配置录 5 个虚拟线程触发类初始化（static 块里 Thread.sleep(10)），jfr view pinned-threads 的输出：
Pinned Virtual Threads
Method Pinned Count Longest Pinning Total Time Pinned
--------------------------------------------- ------------ --------------- -----------------
P4.<clinit>() 1 15.0 ms 15.0 ms
P1.<clinit>() 1 13.7 ms 13.7 ms
P3.<clinit>() 1 11.5 ms 11.5 ms
P5.<clinit>() 1 11.1 ms 11.1 ms
P2.<clinit>() 1 11.0 ms 11.0 ms
其中一条的完整事件（jfr print --events jdk.VirtualThreadPinned，这里省略 startTime 与 stackTrace）：
jdk.VirtualThreadPinned {
duration = 13.7 ms
blockingOperation = "LockSupport.park"
pinnedReason = "VM call to P1.<clinit> on stack"
carrierThread = "ForkJoinPool-1-worker-1" (javaThreadId = 31)
eventThread = "pin-vt-0" (javaThreadId = 30, virtual)
}
判读要点：pinnedReason 是根因，carrierThread 是被占住的载体，eventThread 是虚拟线程。同一份录制里还有两条 0.008 ms / 0.070 ms 的事件，pinnedReason = "Freeze or preempt failed (2)"——阈值归零后连微秒级抖动都会入库，所以不要按条数下结论，看总时长和栈。默认配置下上面 5 条类初始化 pin 一条都不会出现。
内存与 GC：谁占着堆
jcmd <pid> GC.heap_info
jcmd <pid> GC.class_histogram
本机对 100 000 个虚拟线程的进程（输出节选，直方图只留前三行）：
garbage-first heap total reserved 8388608K, committed 528384K, used 404588K
region size 4096K, 71 young (290816K), 1 survivors (4096K)
num #instances #bytes class name (module)
-------------------------------------------------------
1: 100000 61994560 jdk.internal.vm.StackChunk (java.base@25.0.5)
2: 100000 16800000 java.lang.VirtualThread (java.base@25.0.5)
3: 100000 7200000 java.util.concurrent.DelayScheduler$ScheduledForkJoinTask
判读要点：StackChunk 是虚拟线程挂起时保存的栈。100 000 个「只是 sleep」的虚拟线程约占 91 MB 对象（61.9 + 16.8 + 7.2 + 4.8 MB），已用堆 404588K（约 395 MiB）里其余是 G1 尚未回收的垃圾。GC.class_histogram 默认先做一次 Full GC 再统计存活对象，慢且会停顿；看趋势就对两个时间点各采一次，比较字节增量。
GC 日志：
java -Xmx64m '-Xlog:gc*:file=/tmp/gc.log' -cp out AllocChurn
[0.011s][info][gc ] Using G1
[0.012s][info][gc,init] Heap Region Size: 1M
[0.047s][info][gc ] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 35M->1M(64M) 0.609ms
判读要点：35M->1M(64M) 是「回收前 -> 回收后（堆容量）」，0.609ms 是停顿。并发事故里更该看两次 GC 的间隔和回收后仍上涨的基线：基线持续抬高说明对象被长期持有，去查直方图；间隔变短而基线不涨说明分配速率高，去查 allocation-by-class。
堆转储按「进程还活着吗」选入口：
# 启动时准备，OOM 当场落盘
java -Xmx48m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/oom.hprof -cp out OomTarget
# 进程还活着
jcmd <pid> GC.heap_dump /tmp/cmd.hprof
jmap -dump:live,format=b,file=/tmp/jmap.hprof <pid>
# OOM 触发（-Xmx48m），进程退出前落盘
java.lang.OutOfMemoryError: Java heap space
Dumping heap to /tmp/jc-appx/gc/oom.hprof ...
# jmap -dump:live
Dumping heap to /private/tmp/jc-appx/gc/jmap.hprof ...
Heap dump file created [3772684 bytes in 0.037 secs]
# jcmd GC.heap_dump
Dumping heap to /tmp/jc-appx/gc/cmd-dump.hprof ...
Heap dump file created [8188517 bytes in 0.035 secs]
判读要点：dump 通常比 -Xmx 小，但可能是存活对象的数倍，落盘前先算磁盘。jmap -dump:live 与 jcmd GC.heap_dump 默认都会先请求一次 Full GC、只留存活对象（后者加 -all 才包含不可达对象）；jmap -dump 不带 live 时不做 GC。dump 完立刻清理，别让排查动作制造磁盘告警。
CPU 与调度：这台机器忙不忙
macOS 没有 vmstat / pidstat，替代组合：
uptime
top -l 1 -pid <pid> -stats pid,command,cpu,mem,threads,state
ps -M <pid>
vm_stat
# uptime
3:28 up 9 days, 20:51, 6 users, load averages: 86.14 75.99 64.83
# top -l 1 -pid 18928
PID COMMAND %CPU MEM #TH STATE
18928 java 0.0 347M 42/1 running
# vm_stat
Mach Virtual Memory Statistics: (page size of 16384 bytes)
Pages free: 13479.
Pages active: 592557.
判读要点：load averages 是 1/5/15 分钟可运行队列长度，不是 CPU 百分比；10 核机器上 86 说明严重排队，此时任何墙钟时间和 JMH 数字都只能作量级参考。#TH 42/1 是「42 个线程、1 个在运行」，虚拟线程不计入。ps -M 列每个平台线程的累计 UTIME/STIME，两次采样相减才是占用率。Pages free 在 macOS 上天然很低（空闲页被文件缓存占满），判断内存压力看 active 与 swap。
容器内看 cgroup
宿主 macOS 没有 /sys/fs/cgroup（本机 ls 报 No such file or directory），看配额必须进容器。本机 Docker 由 colima 提供（Virtualization.Framework、aarch64、cgroup v2），docker info 报告 4 vCPU、8307167232 字节内存。对运行中的容器：
docker exec <container> sh -c 'cat /sys/fs/cgroup/cpu.max; cat /sys/fs/cgroup/memory.max; \
cat /sys/fs/cgroup/pids.max; head -3 /sys/fs/cgroup/cpu.stat'
本机没有现成业务容器，用一次性容器验证同一路径（docker run --rm --cpus=2 --memory=512m eclipse-temurin:25-jre-alpine 加同一段 sh -c）。容器内真实输出：
200000 100000
536870912
max
usage_usec 18128
user_usec 5724
system_usec 12403
判读要点：cpu.max 是两个数「配额 周期」，200000 100000 表示每 100 ms 可用 200 ms CPU，即 2 个 CPU；memory.max = 536870912 是 512 MiB；pids.max = max 表示未限制；cpu.stat 的 usage_usec 是累计消耗，两次采样相减才是占用率。镜像里的 JDK 是 25.0.4.1+1（容器内 java -version 实测），与宿主 25.0.5+8 不是同一构建，容器内的版本结论要单独标注。
-XX:ActiveProcessorCount=N 只能改 JVM 看到的核数，模拟不了 CFS 节流：第 14 章实测，宿主上 ActiveProcessorCount=1 的调度 maxGap 是 2 ms，而 --cpus=0.5 的容器里是 97 ms、30 次超过 10 ms。要复现节流，必须在容器配额上做文章。
本机不可用清单
| 工具/路径 | 本机状态 | 替代方案 |
|---|---|---|
async-profiler（asprof） | command not found，未安装 | JFR 的 hot-methods、allocation-by-class；装好后 asprof -e lock -d 30 <pid> |
vmstat | command not found（macOS 无） | vm_stat + top -l 1 + uptime |
pidstat | command not found（sysstat 未装） | ps -M <pid> 两次采样相减 |
| Eclipse MAT / VisualVM | 未安装 | 先用 jcmd GC.class_histogram 与 jfr view memory-leaks-by-class 缩小范围 |
kubectl / K8s 集群 | 无，本机只有单机 Docker | 容器配额用上一节的 cgroup v2 文件读；集群侧未在本机验证 |
jfr start | 子命令不存在 | jcmd <pid> JFR.start ... |
-Djdk.tracePinnedThreads | JDK 25 已失效，输出为空 | JFR jdk.VirtualThreadPinned + threshold=0ms |
Thread.print 看虚拟线程 | 永远为空 | Thread.dump_to_file -format=plain|json |
小结
诊断顺序是「先确定线程模型，再选命令」：平台线程用 Thread.print -l，虚拟线程用 Thread.dump_to_file，两者不能拿同一份输出下结论。JFR 负责把等待变成可聚合事件，但阈值、事件类型和 ReentrantLock/synchronized 的差异都会让「0 条」变成假阴性，必须和线程转储互证。内存先看 GC.heap_info 与 class_histogram 的两次采样，再决定要不要 dump。不可用的工具单列成表，替代方案写清楚，比假装跑过有用。
继续阅读
探索更多技术文章
浏览归档，发现更多关于系统设计、工具链和工程实践的内容。