CPU 100% 排查实战(top + jstack)
问题
线上服务 CPU 突然飙到 100%,服务响应变慢甚至超时,怎么快速定位是哪个线程、哪段代码导致的?
先区分两个场景:单核 100%(某个线程把一核吃完)和多核打满(CPU 总利用率 80%+)。前者多半是死循环或 GC 线程,后者可能是流量陡增或锁竞争导致线程大量上下文切换。排查套路一样,但根因判断不同。
排查步骤(五步法)
第一步:找到 CPU 最高的进程和线程
# 找到目标 Java 进程(注意看 CPU 列)
top -c -o %CPU-c 显示完整命令行,区分同一台机器上的多个 Java 进程。-o %CPU 按 CPU 降序排。
确认进程后,看它内部哪个线程最吃 CPU:
top -Hp <pid>输出中 %CPU 列最高的线程就是罪魁祸首。记下它的 PID(十进制的 LWP ID)。
关键细节:top -Hp 的 S 列是线程状态——R(running/runnable)表示正在跑,S(sleeping)表示在等锁或 IO,D(uninterruptible sleep)表示在等内核 IO。如果高 CPU 线程是 R 状态,说明它在持续执行运算;如果是 S 状态但 CPU 高,说明它频繁被唤醒又睡回去——上下文切换开销本身就耗 CPU。
第二步:将十进制 PID 转成十六进制
printf "%x\n" <pid>比如线程 PID 是 12345,printf "%x\n" 12345 输出 3039,等会儿在 jstack 里搜 nid=0x3039。
第三步:导出线程栈,搜索对应线程
jstack <pid> > thread.dump在 thread.dump 中搜 nid=0x<十六进制>,就能看到该线程的完整调用栈。
jstack 输出解读:
- 栈顶(最前面几行)是正在执行的代码,越往下越是调用链上层
- 线程状态行:
java.lang.Thread.State: RUNNABLE/BLOCKED/WAITING/TIMED_WAITINGRUNNABLE+ 高 CPU:正在执行运算,看栈顶方法名BLOCKED+ 高 CPU:大量线程在争同一把锁,锁竞争本身导致 CPU 空转(线程调度开销)WAITING+ 高 CPU:不正常,通常意味着线程反复被 interrupt/notify 唤醒
第四步:看栈顶,识别常见模式
| 模式 | 线程状态 | 栈顶特征 | 根因 |
|---|---|---|---|
| GC 密集 | RUNNABLE | gc task thread / G1 Young RemSet / ParNew / ConcurrentMarkSweep | 堆太小、对象分配速率过高、或内存泄漏 |
| 死循环 | RUNNABLE | 业务代码无限循环(while(true) 无 break) | 逻辑 bug,比如 HashMap.put() 在 JDK 7 死循环 |
| 锁竞争 | BLOCKED(大量线程) | 多个线程等待 org.apache.logging.log4j.core.appender 或 java.util.HashMap | 锁粒度太大,或同步容器被并发访问 |
| 频繁 syscall | RUNNABLE | java.lang.System.currentTimeMillis() 或 sun.misc.Unsafe.park() | Linux 下 clock_gettime 每次调用都陷入内核态,高 QPS 下不可忽视 |
| 上下文切换爆炸 | 混合态 | 大量线程在 LockSupport.park() / Unsafe.park() 之间切换 | 线程数远大于 CPU 核数,时间片竞争导致切换开销 |
为什么 System.currentTimeMillis() 会成为 CPU 杀手?
在 HotSpot 的实现里,System.currentTimeMillis() 走的是 clock_gettime(CLOCK_REALTIME, ...) 这个系统调用。每次调用都要从用户态切到内核态,再切回来。单次开销不大(约 50-100ns),但在高并发场景下如果每个请求都调、每次调用都切上下文,累计起来就是可观的 CPU 开销。我见过一个案例:一个 API 网关每请求调用 5 次 currentTimeMillis() 打日志,QPS 2000 时仅这一个方法就吃掉 1 个核。解决方案是用 System.nanoTime() 取相对时间差,或者用定时器缓存当前时间戳(秒级刷新)。
第五步:根因修复
GC 密集:
- 调堆参数:
-Xms和-Xmx对等,避免扩容抖动;-XX:NewRatio调整新生代比例 - 排查泄漏:用
jmap -histo:live <pid>看看哪些类实例数量异常,再用jmap -dump:live,format=b,file=heap.hprof <pid>导出堆进一步分析
死循环:
- 加日志看分支条件,确认循环退出条件是否永远不满足
- 看循环体内是否有
break/return分支遗漏
锁竞争:
- 减少锁粒度:
synchronized方法 →synchronized代码块 - 读写锁:读多写少用
ReentrantReadWriteLock或StampedLock - 无锁化:用
ConcurrentHashMap代替HashMap,AtomicLong代替synchronized计数
频繁 syscall:
- 缓存
System.currentTimeMillis()结果,每秒刷新一次 - 用
System.nanoTime()替代相对时间计算
用 Arthas 和 async-profiler 更高效
手动 top -Hp + jstack 转十六进制比较繁琐,用工具更快:
# Arthas:直接显示最耗 CPU 的前 3 个线程
thread -n 3
# async-profiler:生成火焰图
profiler.sh -d 30 -e cpu -f flamegraph.html <pid>火焰图怎么看:
- 横轴是采样分布,越宽的框占用 CPU 越多
- 纵轴是调用栈,从下往上按调用链展开
- 从上往下找最宽的矩形,就是热点方法
- 颜色没有特殊含义,纯属区分模块
火焰图能直接告诉你"哪条调用路径最耗 CPU",不用手动查线程 ID,比 jstack 挨个搜效率高一个数量级。但 jstack 的优势是不依赖任何工具,只要有 JDK 就能用——线上容器里不一定装了 perf 或 profiler。
典型 Case 分析(含真实数据)
Case 1:HashMap 并发扩容死循环(JDK 7)
现象:线上两台 4C8G 机器,CPU 从 20% 瞬间飙到 380%(4 核打满 4×100%),服务 RT 从 5ms 涨到 30s。jstack 看到大量 HashMap.put() 栈帧,线程状态全是 RUNNABLE,不触发 OOM。
原理:JDK 7 的 HashMap.resize() 使用头插法。假设两个线程同时执行 transfer():
- 线程 A 遍历 Entry 链表 e1→e2→null,准备迁移到新数组
- 线程 B 先完成迁移,新数组里链表变成 e2→e1→null(头插反转)
- 线程 A 继续自己的迁移,在新数组上操作,e1.next=e2、e2.next=e1——环形链表形成
- 任何 get/put 操作遍历到这个环形链表,
while(e.next != null)永远不退出
解决:改用 ConcurrentHashMap。JDK 7 的 ConcurrentHashMap 用 Segment 分段锁,JDK 8 改为 CAS + synchronized(Node),性能更好。不升级 JDK 的话用 Collections.synchronizedMap() 也能解决,但并发性能差 5-10 倍。
Case 2:Finalizer 线程 CPU 居高不下
现象:Finalizer 线程 CPU 持续 30% 以上,ReferenceHandler 线程繁忙,堆里 java.lang.ref.Finalizer 实例数稳步增长。
根因:大量对象覆盖了 finalize() 方法但未在方法内清除引用,Finalizer 线程串行处理堆积。Finalizer 是单线程,如果对象生产速度大于处理速度,堆积会越来越多,最终 CPU 持续走高。
真实数据:一个 4C8G 的订单服务,单日订单量 50 万,每个订单对象都 finalize() 了数据库连接释放。上线后 3 小时 CPU 从 15% 爬到 60%,Finalizer 线程占满一个核。切到 try-with-resources 后 CPU 回落到 18%。
解决:移除 finalize(),改用 Cleaner(JDK 9+)或 try-with-resources。Cleaner 用 PhantomReference 实现,注册回调在线程池里跑,不阻塞单线程。
Case 3:日志框架同步锁竞争
现象:20 个业务线程全部 BLOCKED 等待 RollingFileAppender 的锁,CPU 40% 但吞吐量极低。
根因:logback 和 log4j2 的 FileAppender 默认同步写入,每次 logger.info() 都获取锁写文件。高并发下,所有业务线程被同一个 appender 锁串行化。
对比:AsyncAppender 把日志写入从同步路径移到后台线程,瓶颈从 IO 锁变为内存队列。代价是日志丢失风险(应用 crash 时队列里未写入的日志会丢)。
| 策略 | 吞吐量(TPS) | P99 RT | 日志丢失风险 | 适用场景 |
|---|---|---|---|---|
| 同步写入 | 2000 | 50ms | 无 | 低并发、日志完整性要求高 |
| AsyncAppender(无丢弃策略) | 8000 | 5ms | 10-100ms 内的日志可能丢失 | 常规业务 |
| AsyncAppender(Disruptor 实现) | 50000+ | 1ms | 同左 | 高并发、可接受少量丢失 |
解决:logback 配置 AsyncAppender,log4j2 配置 AsyncLogger。生产环境日志级别设为 INFO,流量大的模块只 WARN 以上写日志,DEBUG 日志只在压测或故障时开启。
总结
CPU 100% 排查的核心是定位到具体的线程和方法。五步法(top -Hp → 转十六进制 → jstack → 看栈顶 → 修复)是不依赖任何工具的通用手段,任何时候都能用。Arthas 和 async-profiler 能大幅提速,但原理不变。
最重要的原则:碰到 CPU 问题第一反应不是"重启大法",而是先留现场——jstack 保存线程栈(连续保存 3 份,间隔 5 秒,看线程状态是否变化)、保留 GC 日志、保留 top 快照——再分析根因。重启只能缓解症状,不能根治。下次复现时,你连现场都没留下,就真的只能靠猜了。
面试高频追问:
- 为什么
System.currentTimeMillis()在 Linux 上比 Windows 慢?——因为 Linux 的clock_gettime是 syscall,Windows 的GetSystemTimeAsFileTime在用户态完成 - 怎么区分 GC 导致的 CPU 高和业务代码导致的?——GC 线程的栈帧全是
G1YoungRemSetSamplingClosure或ParNew等 GC 类名,业务代码栈帧全是你的包名 - 为什么
top -Hp看到的线程 CPU 总和可能超过 100%?——-Hp显示的%CPU是相对于单核的,4 核上 100% 表示占满一个核