所有应用线程在 GC 等操作时都要先「停到安全点」。停下来要多久,取决于最慢的那个线程什么时候遇到安全点检查。这篇用真实的日志和一个故意去掉安全点检查的计数循环,看到达安全点的时间怎么变成一个线程拖住所有线程。
分配 400 MB 小对象 + System.gc() + 3 次 Thread.getAllStackTraces() 完成
本次运行共 25 次安全点;按原因统计(次数 / 到达安全点耗时中位 μs / 在安全点内耗时中位 μs):
G1CollectForAllocation 11 次 到达 12.9 μs 在安全点内 267.1 μs
G1TryInitiateConcMark 4 次 到达 0.7 μs 在安全点内 293.6 μs
G1PauseRemark 3 次 到达 1.3 μs 在安全点内 167.9 μs
G1PauseCleanup 3 次 到达 38.1 μs 在安全点内 34.2 μs
ThreadDump 3 次 到达 0.2 μs 在安全点内 8.2 μs
G1CollectFull 1 次 到达 9.2 μs 在安全点内 1148.8 μs [默认(JDK 21,G1)]
工作线程在 JIT 编译后的 int 计数循环里(内层 20 亿次迭代、外层死循环),主线程调用 Thread.getAllStackTraces()(需要全局安全点)8 次的耗时(ms):[0, 0, 0, 0, 0, 0, 0, 0]
再调用 System.gc() 耗时 1 ms
日志里「到达安全点」最慢的 3 次: [('ThreadDump', '0.1 ms'), ('ThreadDump', '0.1 ms'), ('ThreadDump', '0.0 ms')]
[-XX:LoopStripMiningIter=0 -XX:-UseCountedLoopSafepoints]
工作线程在 JIT 编译后的 int 计数循环里(内层 20 亿次迭代、外层死循环),主线程调用 Thread.getAllStackTraces()(需要全局安全点)8 次的耗时(ms):[1100, 1067, 1066, 1065, 1062, 1070, 1065, 1064]
再调用 System.gc() 耗时 1066 ms
日志里「到达安全点」最慢的 3 次: [('ThreadDump', '1099.8 ms'), ('ThreadDump', '1070.4 ms'), ('ThreadDump', '1066.9 ms')] 空闲 1 秒(基线) 耗时 1002 ms:ticker 线程(每 1 ms 醒一次)最大延迟 0.6 ms,延迟 ≥1 ms 的次数 0,≥5 ms 0,≥20 ms 0
1000 次 getThreadInfo(单个线程,栈深 1) 耗时 23 ms:ticker 线程(每 1 ms 醒一次)最大延迟 0.5 ms,延迟 ≥1 ms 的次数 0,≥5 ms 0,≥20 ms 0
200 次 Thread.getAllStackTraces() 耗时 10 ms:ticker 线程(每 1 ms 醒一次)最大延迟 0.5 ms,延迟 ≥1 ms 的次数 0,≥5 ms 0,≥20 ms 0
5 次 System.gc() 耗时 15 ms:ticker 线程(每 1 ms 醒一次)最大延迟 2.9 ms,延迟 ≥1 ms 的次数 5,≥5 ms 0,≥20 ms 0
这次运行的日志里全局安全点按原因统计(getThreadInfo 与 getAllStackTraces 都记为 ThreadDump): {'Cleanup': 1, 'ThreadDump': 1200, 'G1CollectFull': 5}空闲 6 秒结束 空闲 6 秒里日志里的安全点共 0 次: [] 加 -XX:GuaranteedSafepointInterval=0(关闭周期性安全点)后空闲 6 秒:0 次 加 -XX:GuaranteedSafepointInterval=200 后空闲 6 秒:0 次;原因 []