【面试笔录】实战演练:一次CPU飙高问题的线程栈排查记录

40 阅读3分钟

本文将通过一个真实的线上案例,带你一步步使用命令行工具,分析Java线程栈,并定位问题根源。

问题背景

监控系统报警:一台服务器CPU使用率持续超过90%。应用并未完全宕机,但响应极其缓慢。

第一步:定位目标进程和线程

1. 找到Java进程PID

首先,我们需要确定是哪个Java进程消耗了大量CPU。

# 查看当前Java进程
$ jps -l
1234 com.example.MyApplication  # <-- 这就是我们的目标应用
5678 sun.tools.jps.Jps

确认目标进程PID:1234

2. 查看进程内线程的CPU占用

接下来,查看这个进程内哪些线程最消耗CPU。

# 查看进程1234内所有线程的资源占用
$ top -H -p 1234

PID   USER    PR  NI  VIRT    RES    SHR S  %CPU %MEM   TIME+   COMMAND
1280  appuser 20  0   10.8g   1.2g   1.1g R   99.5 0.4   10:20.15 java  # <-- 异常线程!
1281  appuser 20  0   10.8g   1.2g   1.1g S   0.0  0.4    0:00.00 java
...(其他线程)

发现异常:线程PID 1280的CPU占用率高达99.5%,这显然不正常。

3. 转换线程PID为十六进制

线程栈中的线程ID是十六进制的,我们需要进行转换。

# 将十进制1280转换为十六进制
$ printf "%x\n" 1280
500

得到十六进制线程ID:0x500(在线程栈中显示为nid=0x500

第二步:捕获线程栈快照

现在捕获当前的线程栈,用于分析线程1280在做什么。

# 抓取进程1234的完整线程栈
$ jstack -l 1234 > thread_dump.log

# 如果jstack无响应,使用强制模式
$ jstack -F -l 1234 > thread_dump.log

第三步:分析线程栈信息

1. 首先检查最严重的死锁问题

# 检查死锁
$ grep -A 20 -i "deadlock" thread_dump.log

# 本例输出为空,说明没有死锁

2. 分析高CPU线程(1280 → 0x500)

现在分析我们之前发现的那个高CPU线程:

# 查找线程0x500的详细信息
$ grep -A 30 -B 2 "nid=0x500" thread_dump.log

关键输出如下:

"data-processor-1" daemon prio=10 tid=0x00007f8a1c123000 nid=0x500 runnable [0x00007f8a0a7f6000]
   java.lang.Thread.State: RUNNABLE
        at java.util.HashMap.get(HashMap.java:557)
        at java.util.HashMap.containsKey(HashMap.java:595)
        at com.example.DataProcessor.processRecord(DataProcessor.java:45)
        at com.example.DataProcessor.run(DataProcessor.java:28)
        at java.lang.Thread.run(Thread.java:750)

3. 查看整体线程状态分布

# 统计各种状态的线程数量
$ grep "java.lang.Thread.State" thread_dump.log | sort | uniq -c | sort -nr

   45    java.lang.Thread.State: TIMED_WAITING (on object monitor)
   20    java.lang.Thread.State: WAITING (on object monitor)
   8     java.lang.Thread.State: RUNNABLE        # 注意:有8个运行中线程
   3     java.lang.Thread.State: BLOCKED (on object monitor)

第四步:问题定位与分析

基于以上信息,我们可以得出关键结论:

问题线程的关键信息:

  • 线程名data-processor-1(数据处理线程)
  • 线程状态RUNNABLE(正在运行,符合高CPU特征)
  • 执行位置:卡在 HashMap.get()方法中(DataProcessor.java:45

问题推测:

高CPU线程正在频繁执行HashMap的查询操作。结合RUNNABLE状态和99.5%的CPU占用,极有可能是在执行一个密集的循环查询,或者HashMap出现了哈希冲突导致查询性能退化。

验证推测:

查看源码 DataProcessor.java第45行附近:

public class DataProcessor implements Runnable {
    private Map<String, Object> cache = new HashMap<>();
    
    public void processRecord(String record) {
        // 第45行附近:
        while (cache.containsKey(record)) {  // 疑似死循环!
            // 一些处理逻辑
        }
    }
}

根本原因:代码中存在一个基于HashMap查询的循环条件,在某些数据状态下可能形成无限循环,导致CPU飙高。

第五步:解决方案

  1. 紧急措施:重启该问题实例,恢复服务
  2. 根本解决:修复代码中的循环逻辑,增加循环退出条件或超时机制
  3. 优化建议:使用线程安全的ConcurrentHashMap,并优化查询逻辑

排查命令总结

整个排查过程的核心命令总结:

# 1. 定位进程
jps -l

# 2. 定位高CPU线程
top -H -p <PID>

# 3. 转换线程ID
printf "%x\n" <Thread_PID>

# 4. 抓取线程栈
jstack -l <PID> > dump.log

# 5. 分析关键信息
grep -i "deadlock" dump.log                    # 死锁检查
grep -A 30 "nid=0x<HEX_ID>" dump.log          # 特定线程分析  
grep "java.lang.Thread.State" dump.log | sort | uniq -c  # 状态统计

经验总结

通过这个案例,我们可以总结出线程排查的金字塔原则

  1. 先整体后局部:先看线程状态分布,再分析具体问题线程
  2. 先紧急后次要:先检查死锁等致命问题,再分析性能问题
  3. 关联系统指标:将线程栈与系统监控(CPU、内存)关联分析

掌握这套方法论,你就能在短时间内快速定位大多数线上线程问题。