线上问题排查手册

// 典型 bug: BigDecimal 比较错误
public void calculateDiscount(BigDecimal price) {
    BigDecimal result = price;
    while (result.compareTo(BigDecimal.ZERO) > 0) {
        result.subtract(BigDecimal.TEN);  // BUG!
        // subtract() 返回新对象,不改原值!
        // result 永远不变,循环永远不退出
    }
}

// 正确写法:
result = result.subtract(BigDecimal.TEN);  // 必须接收返回值!

// jstack 特征: 业务方法反复出现
"pool-3-thread-1" #45 nid=0x2324 runnable
  java.lang.Thread.State: RUNNABLE
  at com.app.service.OrderService.calculateDiscount(OrderService.java:87)
  // 多次 jstack,每次都卡在这行 ← 死循环确认!

// 危险正则: 嵌套量词 (a+)+
Pattern badRegex = Pattern.compile("^([a-zA-Z0-9]+[a-zA-Z0-9._-]*)+$");
// 输入 "aaaaaaaaaaaaaaaaaaaaaaaaaaaa!" → CPU瞬间100%
Matcher m = badRegex.matcher(input);
m.matches();  // 这一行卡死,CPU疯狂计算

// jstack 特征: Pattern 相关方法占满调用栈
" http-nio-8080-exec-5" nid=0x2348 runnable
  java.lang.Thread.State: RUNNABLE
  at java.util.regex.Pattern$Curly.match(Pattern.java:4148)
  at java.util.regex.Pattern$GroupHead.match(Pattern.java:4660)
  at java.util.regex.Pattern$Curly.match0(Pattern.java:4259)
  at java.util.regex.Pattern$Curly.match(Pattern.java:4148)
  // 满屏都是 Pattern$xxx.match ← 正则回溯确认!

# 用 jstat 查看 GC 情况, 每1秒打印一次, 共10次
$ jstat -gcutil 8921 1000 10
  S0     S1     E      O      M     CCS    YGC   YGCT    FGC   FGCT
  0.00  45.32  89.12  98.76  94.50  91.23   234   3.456   28   12.890
  0.00  45.32  92.56  98.76  94.50  91.23   235   3.512   29   13.234
  0.00  45.32  95.89  98.76  94.50  91.23   236   3.567   30   13.578
#  O列(Old Gen) = 98.76% ← 老年代快满了!
#  FGC(Full GC次数) = 28→29→30, 每秒+1 ← 每秒一次Full GC!
#  FGCT(Full GC总耗时) = 12.890→13.234 → 每次 Full GC 耗时 0.3秒

# jstack 特征: "GC task thread" CPU 高
"GC task thread#0 (ParallelGC)" nid=0x1a2b runnable

关键指标: FGC 每秒+1 说明 Full GC 频率极高(正常应该几分钟甚至几小时才一次)。O=98.76% 说明老年代几乎满了,GC回收不了东西,就疯狂重试。

// 堆栈显示加密/压缩相关类
"batch-task-thread-3" nid=0x3b2c runnable
  java.lang.Thread.State: RUNNABLE
  at javax.crypto.CipherCore.encryptFinal(CipherCore.java:1024)
  at com.sun.crypto.provider.AESCipher.engineDoFinal(...)
  at com.app.service.DataExportService.encryptBatch(DataExportService.java:120)

// 典型 bug: 忘记写终止条件,或终止条件错误
public TreeNode findRoot(TreeNode node) {
    // BUG: 忘记判断 node == null 或 node.parent == null
    return findRoot(node.getParent());  // 无限递归!
}

// 正确写法:
public TreeNode findRoot(TreeNode node) {
    if (node == null || node.getParent() == null) {
        return node;  // 终止条件!
    }
    return findRoot(node.getParent());
}

// jstack 特征: 同一个方法名反复出现,像复印一样
" http-nio-8080-exec-3" nid=0x4c5d runnable
  java.lang.Thread.State: RUNNABLE
  at com.app.model.TreeNode.findRoot(TreeNode.java:28)
  at com.app.model.TreeNode.findRoot(TreeNode.java:28)
  at com.app.model.TreeNode.findRoot(TreeNode.java:28)
  at com.app.model.TreeNode.findRoot(TreeNode.java:28)
  at com.app.model.TreeNode.findRoot(TreeNode.java:28)
  // ... 重复几百行,都是同一个方法 ← 无限递归确认!

# Step 1: 确认是哪个进程
$ top
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM
  8921 java      20   0  3896544 512320  24320 S  98.3  6.4
  ...

# Step 2: 用 top -Hp 找到高CPU线程
$ top -Hp 8921
  PID    USER     %CPU   TID
  9032   java     95.6   ...

# Step 3: 线程TID转十六进制,用jstack定位
$ printf '%x\n' 9032
  2348
$ jstack 8921 | grep -A 20 'nid=0x2348'
  "http-nio-8080-exec-5" #45 daemon prio=5 os_prio=0
    java.lang.Thread.State: RUNNABLE
    at java.util.regex.Pattern$Curly.match(Pattern.java:4148)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4660)
    ...

# 也可以用 Arthas 一键定位
$ arthas-boot.jar → 选择 8921
  [arthas@8921]$ thread -n 3
  # Count CPU%   Name
  45  95.6%     http-nio-8080-exec-5

# Step 1: 确认内存状况
$ free -h
              total        used        free
Mem:           7.8Gi       6.2Gi       400Mi
Swap:          2.0Gi       1.8Gi       200Mi

# Step 2: 找到内存大户
$ ps aux --sort=-%mem | head -5
java  8921  6.4  35.2  3896544  2744320  ...  -jar app.jar

# Step 3: jmap 查看对象直方图
$ jmap -histo:live 8921 | head -20
  num     #instances         #bytes  class name
  1:        8426310      606694320  java.util.HashMap$Node
  2:        8426300      269641600  java.lang.String
  3:        8426300      201943120  com.app.dto.UserSession
  4:         126543       40490400  java.util.HashMap
  ...

# Step 4: 导出 heap dump,用 MAT (Memory Analyzer Tool) 分析
$ jcmd 8921 GC.heap_dump /tmp/heap.hprof
# 用 Eclipse MAT 打开,执行 Leak Suspects Report
# 发现: com.app.service.SessionCache 的 ConcurrentHashMap 占了 1.8GB
# 且 ThreadLocal 中残留大量 UserSession 对象

在 Eclipse MAT 的 Dominator Tree 中发现:

• SessionCache.sessions (ConcurrentHashMap) 占了 1.8GB,840万+ 个 UserSession
• 每个 UserSession 内部还持有 ThreadLocal 引用,GC 无法回收

# Step 1: MySQL 状态
$ systemctl status mysql
  Active: failed (Result: exit-code)

# Step 2: 查看 MySQL 错误日志
$ tail -50 /var/log/mysql/error.log
  [ERROR] InnoDB: Write to file ./ib_logfile0 failed at offset ...
  [ERROR] InnoDB: Operating system error number 28 ...
  [ERROR] InnoDB: Error number 28 means 'No space left on device'

# Step 3: 磁盘使用情况
$ df -h
  Filesystem      Size  Used Avail Use% Mounted on
  /dev/vda1        50G   49G  512M  99% /

# Step 4: 找大文件
$ du -sh /var/log/*
  120G    /var/log/app/app.log   <-- 就是它!
    4.0K    /var/log/app/app.log.1

# 查看连接状态统计
$ ss -s
TCP:   28431 (estab 231, closed 28000, orphaned 0, timewait 27800)

# 27800个TIME_WAIT! 几乎占满了所有可用端口

# 详细看连接状态
$ netstat -antp | awk '{print $6}' | sort | uniq -c | sort -rn
  27800 TIME_WAIT
    231 ESTABLISHED
     12 LISTEN

# 查看本地可用端口范围
$ cat /proc/sys/net/ipv4/ip_local_port_range
32768   61000
# 最多约28000个端口,已被TIME_WAIT全部占满

# 查看慢查询
mysql> SELECT * FROM orders
         WHERE user_id = 12345
         AND status = 'PAID'
         AND created_at > '2025-01-01'
         ORDER BY created_at DESC
         LIMIT 20;

# EXPLAIN 分析
mysql> EXPLAIN SELECT * FROM orders WHERE user_id=12345 AND status='PAID' AND created_at>'2025-01-01' ORDER BY created_at DESC LIMIT 20\G
  type: ALL          <-- 全表扫描!
  rows: 5800000      <-- 扫描了580万行
  Extra: Using where; Using filesort  <-- 文件排序

# 查看最近的死锁信息
mysql> SHOW ENGINE INNODB STATUS\G
------------------------
LATEST DETECTED DEADLOCK
------------------------
*** (1) TRANSACTION:
TRANSACTION 1234567, ACTIVE 2 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)
MySQL thread id 101, OS thread handle 140234567890
UPDATE account SET balance = balance - 100 WHERE id = 2
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 58 page no 4 n bits 72 index PRIMARY

*** (2) TRANSACTION:
TRANSACTION 1234568, ACTIVE 1 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s)
UPDATE account SET balance = balance - 50 WHERE id = 1

# 查看当前连接数
mysql> SHOW PROCESSLIST;
| Id    | User    | Host           | db   | Command | Time | State         |
| 1     | app     | 10.0.1.5:42311 | prod | Sleep   | 3600 |               |
| 2     | app     | 10.0.1.5:42312 | prod | Sleep   | 2800 |               |
| ...   | ...     | ...            | ...  | Sleep   | ...  |               |
| 151   | app     | 10.0.1.5:42461 | prod | Sleep   | 1200 |               |
| 152   | app     | 10.0.1.5:42462 | prod | Query   | 0    | Showing proc  |
# 大量 Sleep 连接,长时间不释放!

mysql> SHOW VARIABLES LIKE 'max_connections';
  151

# 1. 让用户打开 DevTools → Network
#    发现: app.js 返回的是旧版本(没有新接口的调用)
#    但 index.html 是新版本(引用了新组件)

# 2. 检查 index.html 中 app.js 的引用方式
<script src="https://cdn.example.com/static/js/app.js"></script>
#        问题: 没有 hash! 文件名永远是 app.js

# 3. 检查CDN缓存配置
#    Cache-Control: max-age=86400 (缓存24小时)
#    CDN节点缓存了旧版 app.js

# Step 1: 查看 Pod 状态
$ kubectl get pods
NAME                     READY   STATUS             RESTARTS   AGE
my-app-7d9f8b6c4-x2k9l   0/1     CrashLoopBackOff   17         42m

# Step 2: 查看 Pod 事件
$ kubectl describe pod my-app-7d9f8b6c4-x2k9l
  Warning  BackOff    3m  kubelet  Back-off restarting failed container
  Last State:    Terminated
    Reason:    Error
    Exit Code: 1

# Step 3: 查看容器日志(上一次的,因为当前可能还没启动完)
$ kubectl logs my-app-7d9f8b6c4-x2k9l --previous
  ERROR o.s.boot.SpringApplication - Application run failed
  com.zaxxer.hikari.pool.HikariPool$PoolInitializationException:
    Failed to initialize pool: HikariPool-1
    Caused by: com.mysql.cj.jdbc.exceptions.CommunicationsException:
      Communications link failure
    at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(...)
  ...
  ***************************
  APPLICATION FAILED TO START
  ***************************

top -Hp <pid> 发现线程TID 0x3a。jstack发现一个 while(true) 中的条件判断永远为 true。

jstat -gcutil 显示 Full GC 频率异常。jmap 导出堆发现大量 byte[] 对象。

Heap snapshot 对比发现大量 RequestContext 对象未释放。

redis-cli info clients 显示连接数达到 maxclients 上限。

Nginx error.log: write() failed (28: No space left on device)

在超时时间点用 dig 发现DNS解析耗时5秒+。

SHOW SLAVE STATUS Seconds_Behind_Master = 600+。慢查询日志发现一个 UPDATE 扫描了300万行。

查看 resources.limits.memory = 256Mi,应用启动后需要400MB+。

检查CDN缓存命中率,HTML文件缓存了2小时。

SHOW PROCESSLIST 大量 Sleep 连接来自应用服务器。

jstack 显示所有线程都处于 WAITING 状态,等待一个慢接口返回。

SHOW ENGINE INNODB STATUS 显示一个事务持有了大量行锁,运行了30分钟。

ES日志: OutOfMemoryError: Java heap space。

Nginx error.log: upstream timed out (110: Connection timed out)。

Heap dump发现大量 WebSocket connection 对象没有关闭。

kubectl describe pod: Failed to pull image: authentication required。

RabbitMQ 管理界面显示队列积压 50000+ 消息,消费者只有2个。

后端CORS配置只允许 http://localhost:3000,生产域名没加。

检查证书有效期发现已过期3小时。

搜索日志文件,发现登录接口的DEBUG日志打印了完整request body。