Java 应用 CPU 占用过高排查手册

当线上 Java 应用出现 CPU 占用过高时，快速定位问题线程并分析其行为至关重要。以下就是一个详细的排查步骤，结合实际日志示例，可方便一步步诊断问题。

一、排查背景

在高并发或复杂业务场景下，Java 应用偶尔会出现 CPU 飙升的情况。这可能是由于代码中存在死循环、不合理的线程同步、频繁的 GC、或是某些耗时操作阻塞了核心线程等原因。及时有效的排查能够帮助我们快速恢复服务，并优化应用性能。

二、排查步骤

1. 识别高 CPU 占用的 Java 进程

首先，我们需要在服务器上找出哪个 Java 进程占用了较高的 CPU。

命令：top

操作：在 Linux 终端执行 top 命令，然后按 Shift + P 以 CPU 使用率排序，找到 CPU 占用较高的 Java 进程，并记录其 PID (Process ID)。

示例日志：

text
top - 23:19:57 up 8 days,  5:28,  3 users,  load average: 0.25, 0.17, 0.15
Tasks: 230 total,   1 running, 229 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.9 us,  0.6 sy,  0.0 ni, 97.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  7911152 total,   146560 free,  6164640 used,  1599952 buff/cache
KiB Swap:  1049596 total,        4 free,  1049592 used.  1185832 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 9782 git       20   0 2259716   1.0g   5012 S   5.0 13.6 494:50.66 bundle
31924 root      20   0  820456  16748   2576 S   2.0  0.2  42:02.84 barad_agent
16666 root      20   0 1066072  94192  11436 S   1.0  1.2 120:28.35 YDService
16135 ctm       20   0 3930436 407140   3132 S   0.7  5.1  33:20.42 java  <-- 假设这是我们的目标Java进程
 8511 git       20   0 1634656  20008   2436 S   0.3  0.3   8:56.97 gitlab-kas
14498 100       20   0 1023052  39656    752 S   0.3  0.5  35:27.95 python
    1 root      20   0  194004   5524   3156 S   0.0  0.1   2:30.51 systemd
    2 root      20   0       0      0      0 S   0.0  0.0   0:00.16 kthreadd

从上面的示例中，我们假设 PID 16135 (COMMAND java) 是我们要排查的 Java 进程，其 CPU 占用为 0.7%。 (注意：在实际高 CPU 场景中，这个百分比会显著更高。此处的日志仅为步骤演示。)

2. 定位高 CPU 占用的线程

确定了 Java 进程的 PID ，我们需要找出该进程内具体是哪个线程导致了 CPU 升高。

方法一：使用 top 命令

命令：top -H -p <PID>

-H：显示线程视图。
-p <PID>：指定进程 ID。

操作：执行 top -H -p 16135，然后同样按 Shift + P，找到 CPU 占用最高的线程，并记下其 TID (Thread ID，在 top 输出中通常也显示为 PID 列)。

方法二：使用 ps 命令

命令：ps -mp <PID> -o THREAD,tid,time

-m：显示所有线程。
-p <PID>：指定进程ID。
-o THREAD,tid,time：自定义输出格式，显示 CPU 使用率 (%CPU，这里是 THREAD 内部列)、线程 ID (tid) 和累计 CPU 时间 (time)。

操作：执行 ps -mp 16135 -o THREAD,tid,time，查看 %CPU 列，找到最高的线程并记录其 TID。

示例日志 (ps命令)：

text
[root@VM-12-14-centos ~]# ps -mp 16135 -o THREAD,tid,time
USER     %CPU PRI SCNT WCHAN  USER SYSTEM   TID     TIME
ctm       60.5   -    - -         -      -     - 00:33:20   <-- 这是进程的总CPU信息
ctm       0.0  19    - futex_    -      - 16135 00:00:00
ctm       0.0  19    - futex_    -      - 16138 00:00:08
ctm       0.0  19    - futex_    -      - 16140 00:00:01
... (省略部分输出) ...
ctm       0.0  19    - futex_    -      - 17178 00:00:00
ctm       50.1  19    - futex_    -      - 17179 00:07:18   <-- 假设这是CPU占用较高的线程 (TID: 17179)
ctm       0.1  19    - futex_    -      - 17180 00:07:21
ctm       0.1  19    - futex_    -      - 17181 00:07:20
ctm       0.0  19    - futex_    -      - 17182 00:00:00
... (省略部分输出) ...
ctm       0.0  19    - futex_    -      - 17186 00:00:14

从上述 ps 输出中，我们关注到线程 TID 17179 的 %CPU 为 0.1。在实际高 CPU 场景下，某个线程的 %CPU 会非常突出。我们记录下这个 TID： 17179。

3. 将线程 TID 转换为十六进制

Java 的线程堆栈工具 jstack 输出中的线程 ID (nid) 是十六进制的，因此我们需要将上一步获取的十进制 TID 转换为十六进制。

命令：printf "%x\n" <TID>

操作：将十进制 TID 17179 转换为十六进制。

示例日志：

bash
[root@VM-12-14-centos ~]# printf "%x\n" 17179
431b

我们得到十六进制的线程 ID 431b。

4. 导出线程堆栈信息

使用 jstack 工具来 dump Java 进程的线程堆栈，并筛选出我们关心的线程信息。

命令：jstack <PID> | grep <hex_tid> -A<n>

<PID>：Java 进程的 PID。
<hex_tid>：上一步转换得到的十六进制线程 ID。
-A<n>：显示匹配行及其后的 n 行，以便查看完整的线程堆栈。通常 n 可以取 30-100 之间的值。

重要提示：

重要提示

执行 jstack 的用户需要与目标 Java 进程的启动用户一致，或者使用 root 用户（如果 Java 进程不是 root 启动，可能需要切换到对应用户 su - <java_process_user> 再执行 jstack）。
jstack 工具位于 JDK 的 bin 目录下。如果系统环境变量没有配置，需要使用绝对路径。
为避免 jstack 对线上服务产生影响（尽管通常影响较小），可以在问题复现时快速执行，或者考虑非高峰期操作。如果 CPU 100%，jstack 可能会有卡顿。
建议多次 dump 线程堆栈（例如，间隔5-10秒执行3-5次），因为单次快照可能无法完全反映问题，尤其是对于间歇性 CPU 飙高的情况。

操作：使用进程 PID 16135 和十六进制线程ID 431b。

示例日志：

bash
# bash-4.2$ jstack 16135 | grep 431b -A60
"SimplePauseDetectorThread_0" #469 daemon prio=5 os_prio=0 tid=0x00007f67a005c000 nid=0x431b waiting on condition [0x00007f67e8be1000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
        at org.LatencyUtils.TimeServices.sleepNanos(TimeServices.java:62)
        at org.LatencyUtils.SimplePauseDetector$SimplePauseDetectorThread.run(SimplePauseDetector.java:116)

"Thread-442" #468 daemon prio=5 os_prio=0 tid=0x00007f67a0059000 nid=0x431a waiting on condition [0x00007f67e8ce2000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000f92a74f0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at org.LatencyUtils.PauseDetector$PauseDetectorThread.run(PauseDetector.java:85)

"lettuce-eventExecutorLoop-1-2" #467 daemon prio=5 os_prio=0 tid=0x00007f67a004f800 nid=0x4319 waiting on condition [0x00007f67e8de3000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000f90a7898> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at io.netty.util.concurrent.SingleThreadEventExecutor.takeTask(SingleThreadEventExecutor.java:243)
        at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:64)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:748)

"lettuce-epollEventLoop-4-1" #466 daemon prio=5 os_prio=0 tid=0x00007f6808dd0800 nid=0x4318 runnable [0x00007f67f1dc0000]
   java.lang.Thread.State: RUNNABLE
        at io.netty.channel.epoll.Native.epollWait(Native Method)
        at io.netty.channel.epoll.Native.epollWait(Native.java:148)
        at io.netty.channel.epoll.Native.epollWait(Native.java:141)
        at io.netty.channel.epoll.EpollEventLoop.epollWaitNoTimerChange(EpollEventLoop.java:290)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:347)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:748)

"lettuce-eventExecutorLoop-1-1" #465 daemon prio=5 os_prio=0 tid=0x00007f6809d11000 nid=0x4317 waiting on condition [0x00007f67f1ec1000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000f90a7f20> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
        at io.netty.util.concurrent.SingleThreadEventExecutor.takeTask(SingleThreadEventExecutor.java:256)
        at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:64)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:748)

"Service Thread" #8 daemon prio=9 os_prio=0 tid=0x00007f6808187800 nid=0x3f32 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f6808184800 nid=0x3f31 waiting on condition [0x0000000000000000]

5. 分析线程堆栈

现在我们有了目标线程 (nid=0x431b) 的堆栈信息：

java
"SimplePauseDetectorThread_0" #469 daemon prio=5 os_prio=0 tid=0x00007f67a005c000 nid=0x431b waiting on condition [0x00007f67e8be1000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
        at org.LatencyUtils.TimeServices.sleepNanos(TimeServices.java:62)
        at org.LatencyUtils.SimplePauseDetector$SimplePauseDetectorThread.run(SimplePauseDetector.java:116)

关键点分析：

Thread Name: "SimplePauseDetectorThread_0"
nid: 0x431b (与我们追踪的线程ID匹配)
java.lang.Thread.State: TIMED_WAITING (sleeping)

解读：在这个特定的示例中，线程 SimplePauseDetectorThread_0 (隶属于 org.LatencyUtils，一个用于延迟检测的库) 处于 TIMED_WAITING 状态，并且正在执行 Thread.sleep()。这意味着在 jstack 抓取快照的那个瞬间，这个线程本身并不是 CPU 的使用者，因为它在休眠。

那么 CPU 占用是从哪里来的呢？

瞬时性问题：可能 CPU 占用高是短暂的，或者是由其他线程造成的，而我们在 ps 命令中看到的 50.1% CPU 可能是一个平均值或者一个峰值的残留。
观察误差：top / ps 看到的 CPU 占用和 jstack dump 的瞬间可能存在几秒的延迟，CPU 占用高的线程可能已经执行完它的繁忙任务，进入了等待或休眠状态。
错误的线程定位：如果 CPU 使用率非常高且持续（例如 90%+），那么 RUNNABLE 状态的线程更有可能是元凶。如果所有高 CPU 线程 dump 出来都是 WAITING 或 TIMED_WAITING，需要考虑：
- 大量线程频繁唤醒和休眠：这种模式切换本身也消耗 CPU。
- GC 问题：频繁的 Full GC 会导致所有应用线程暂停（Stop-The-World），此时 CPU 也会飙高。jstack 可能只显示 WAITING，但 GC 日志或 jstat -gcutil <PID> <interval> 会揭示真相。
- JIT 编译：热点代码的即时编译也可能短暂消耗 CPU。
- 其他线程：或许我们关注的线程（如本例的 17179）并非真正的罪魁祸首，或者说它只是众多有少量 CPU 活动的线程之一。真正持续消耗 CPU 的线程，其堆栈会明确指向执行中的代码，状态为 RUNNABLE。

正确的分析姿势：

寻找 RUNNABLE 状态的线程：在高 CPU 场景下，重点关注那些处于 RUNNABLE 状态的线程的堆栈。看它们正在执行哪个类的哪个方法。例如，在上述 jstack 输出中，有一个 Netty 的 IO 线程：
```
java
"lettuce-epollEventLoop-4-1" #466 daemon prio=5 os_prio=0 tid=0x00007f6808dd0800 nid=0x4318 runnable [0x00007f67f1dc0000]
   java.lang.Thread.State: RUNNABLE
        at io.netty.channel.epoll.Native.epollWait(Native Method)
        at io.netty.channel.epoll.Native.epollWait(Native.java:148)
        ...
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:347)
        ...
```
这个线程处于 RUNNABLE 状态，正在执行 epollWait，这是正常的 NIO 事件循环行为。如果它持续占用高 CPU，就需要看是否有大量请求或处理逻辑问题。
分析代码逻辑：根据堆栈顶部的类名和方法名，追踪到自己的业务代码或使用的框架/库代码，分析是否存在：
- 死循环 (while(true) 没有出口)
- 复杂的算法或正则表达式处理大量数据
- 大量对象的创建导致频繁 GC
- 线程不安全的集合操作导致并发问题
- 锁竞争激烈，但某些线程仍可能在自旋等待
结合多次 jstack dump：如果一个线程在多次 dump 中都出现在堆栈顶部并且是 RUNNABLE，那么它很可能就是问题所在。

三、常见高 CPU 场景及分析思路扩展

业务逻辑死循环/高复杂度计算：
- 现象：某个线程持续处于 RUNNABLE 状态，堆栈顶端是业务代码中的某个循环或计算密集型方法。
- 解决：审查对应代码逻辑，优化算法，修复死循环。
正则表达式不当：
- 现象：线程 RUNNABLE，堆栈在 java.util.regex.Pattern 相关方法。
- 解决：优化正则表达式，避免回溯过多，或对输入进行预处理。
频繁 Full GC：
- 现象：top 看到 Java 进程 CPU 高，但 jstack 中大部分线程可能处于 WAITING 或 BLOCKED 状态（因为 STW）。
- 工具：jstat -gcutil <PID> <interval_ms> <count> (如 jstat -gcutil 16135 1000 10) 查看 GC 活动，尤其是 FGC (Full GC) 的次数和耗时。
- 解决：通过 -Xms, -Xmx, -XX:NewRatio, 年轻代/老年代大小调整等参数优化 JVM 内存配置。分析内存 dump (jmap -dump:live,format=b,file=heap.hprof <PID>) 找到内存泄漏或大对象。
线程池配置不当/任务堆积：
- 现象：大量线程池工作线程 RUNNABLE，都在执行相似的任务。
- 解决：调整线程池核心数、最大数、队列策略，或优化任务本身执行效率。
锁竞争/死锁：
- 现象：jstack 中大量线程 BLOCKED 在同一个锁对象上。如果是死锁，jstack 会直接提示 "Found one Java-level deadlock"。
- 解决：优化锁的粒度，减少锁的持有时间，使用并发集合，避免嵌套锁等。
Netty/IO 密集型应用：
- 现象：Netty 的 NioEventLoop 线程 CPU 占用高。
- 分析：可能是连接数过多、消息处理耗时过长阻塞了 IO 线程。应将耗时业务逻辑异步化，避免阻塞 IO 线程。

四、辅助工具与进阶排查

perf (Linux): 更底层的性能分析工具，可以采样 CPU 正在执行的函数（包括 JVM 内部函数和 JIT编译后的代码）。perf top / perf record / perf report。
async-profiler: 一款非常强大的 Java 低开销性能分析器，可以生成火焰图，直观展示 CPU 热点。
Java Mission Control (JMC) & Java Flight Recorder (JFR): JDK 自带的强大工具，可以记录 JVM 运行时的详细事件，用于事后分析。
APM 工具: 如 SkyWalking, Pinpoint, New Relic 等，可以提供更全面的应用性能监控和链路追踪。

五、总结与预防

排查 Java 应用 CPU 占用过高问题，是一个结合系统命令、JVM 工具和代码分析的综合过程。

使用 top 定位进程。
使用 top -H -p <PID> 或 ps -mp <PID> ... 定位线程。
使用 printf "%x\n" <TID> 转换线程ID。
使用 jstack <PID> 获取线程堆栈，并结合 grep 筛选。
分析 RUNNABLE 状态的线程堆栈，结合多次 dump 和业务代码进行诊断。
考虑 GC、锁、IO 等其他因素。

预防措施：

代码Review：重点关注循环、并发处理、资源使用等。
压力测试：在上线前进行充分的压力测试，模拟高并发场景。
监控告警：建立完善的 CPU、内存、GC、线程池等指标的监控和告警体系。
定期巡检：定期对 JVM 参数、线程池配置进行审视和优化。

目录

Java 应用 CPU 占用过高排查手册

一、排查背景

二、排查步骤

1. 识别高 CPU 占用的 Java 进程

2. 定位高 CPU 占用的线程

3. 将线程 TID 转换为十六进制

4. 导出线程堆栈信息

5. 分析线程堆栈

三、常见高 CPU 场景及分析思路扩展

四、辅助工具与进阶排查

五、总结与预防