Debug排查
线上事故
排查思路
日志分析
Arthas
事故复盘
后端排查问题的通用方法论
在进入具体案例之前，先看后端排查问题的通用思路。不管是接口超时、OOM、数据不一致，排查的框架是一样的：
① 报警触发
→
② 确认范围
→
③ 收集信息
④ 定位原因
→
⑤ 紧急修复
→
⑥ 验证恢复
⑦ 根因分析
→
⑧ 防止复发
→
⑨ 复盘文档
很多新手拿到报警第一反应是"立刻打开IDE找代码bug"。但老手的反应是：先止血，再找原因。止血 = 回滚/降级/限流，让线上先恢复正常。然后再慢慢查根因。因为线上每多挂一分钟，都是真金白银的损失。
| 步骤 | 做什么 | 时间窗口 | 新手 vs 老手 |
|---|
| ① 报警触发 | 收到钉钉/短信告警 | 0-1分钟 | 新手：慌张。老手：看告警级别，判断紧急程度 |
| ② 确认范围 | 影响多少用户？哪些接口挂了？ | 1-3分钟 | 新手：直接看代码。老手：先看监控大盘+日志 |
| ③ 紧急止血 | 回滚/限流/降级 | 3-5分钟 | 新手：试图改代码修复。老手：先回滚恢复服务 |
| ④ 收集证据 | 保留现场：线程dump/堆dump/慢SQL | 5-10分钟 | 新手：重启丢失现场。老手：先dump再处理 |
| ⑤ 定位根因 | 读日志、查代码、复现问题 | 10分钟-数小时 | 新手：猜测。老手：证据驱动的假设验证 |
| ⑥ 修复+验证 | 写修复代码，测试环境验证 | 数小时 | 新手：修完直接上线。老手：测试通过再上线 |
| ⑦ 复盘 | 写事故报告，加防护措施 | 1-2天 | 新人：忘掉。老手：建立checklist防止复发 |
⚡ Debug习惯 #1：收到报警后，先止血再找原因。如果线上已经出问题了，你的第一要务是恢复服务，不是找bug。先回滚到上一个稳定版本，然后慢慢查。线上恢复速度 > 找到根因速度。
10:23事故1：订单列表接口大面积超时
10:23
🤖
Grafana Alert Bot
🔴 P0告警：订单列表接口 /api/v1/orders 平均响应时间 3.2s（阈值500ms）
错误率：23%（正常<0.1%）
影响范围：全部用户
持续时间：已持续2分钟
Step 1：看监控大盘（1分钟内）
老王的第一步不是打开IDE，而是打开Grafana监控面板。他要回答3个问题：1.是什么时候开始的？2.影响范围多大？3.有没有伴随其他异常？
Grafana — 订单服务监控大盘
📊 接口响应时间（最近15分钟）
10:08 │████ │ 45ms ✅
10:10 │████ │ 52ms ✅
10:12 │████ │ 48ms ✅
10:14 │██████ │ 120ms ⚠️
10:16 │██████████████████ │ 380ms ⚠️
10:18 │██████████████████████████████│ 890ms 🔴
10:20 │████████████████████████████████████████│ 2.1s 🔴
10:22 │████████████████████████████████████████████████████│ 3.2s 🔴🔴
📊 数据库连接池
活跃连接数：50/50 （⚠️ 连接池已满！）
等待线程数：127
连接获取平均耗时：4.5s （正常<10ms）
📊 JVM线程状态
RUNNABLE: 15
WAITING: 203 （⚠️ 大量线程在等待数据库连接）
TIMED_WAITING: 12
BLOCKED: 8
监控画面很清晰：
1. 10:14开始变慢，逐渐恶化——不是突然崩溃，说明是"慢查询逐渐拖垮"
2. 数据库连接池满了——所有连接都在等
3. 大量线程WAITING——都在等数据库连接
结论：不是应用bug，是数据库出了问题。下一步：查慢SQL。
Step 2：查慢SQL日志（2分钟内）
wang@prod-server ~ $ tail -100 /var/log/mysql/slow-query.log | grep "Query_time"
# Query_time: 4.82s Lock_time: 0.00s Rows_sent: 1 Rows_examined: 2,847,193
SELECT * FROM orders WHERE user_id = 88123 AND status != 'DELETED' ORDER BY created_at DESC LIMIT 20;
# Query_time: 5.13s Lock_time: 0.00s Rows_sent: 20 Rows_examined: 3,102,445
SELECT * FROM orders WHERE user_id = 76341 AND status != 'DELETED' ORDER BY created_at DESC LIMIT 20;
找到了！订单列表查询扫描了280万行，只返回20条。Rows_examined: 2,847,193 是铁证——这条SQL在做全表扫描，没有走索引。现在的问题是：为什么之前不慢，现在突然慢了？
Step 3：EXPLAIN分析（3分钟内）
EXPLAIN结果一目了然：
type=ALL = 全表扫描
key=NULL = 没有用到索引
rows=2,847,193 = 扫描了280万行
Using filesort = 在内存里排序
这个查询没有走索引！但之前为什么不慢呢？因为之前orders表只有10万行，全表扫描也就200ms。现在订单量增长到了280万行，全表扫描需要5秒。
Step 4：紧急止血（5分钟内）
找到原因了，但线上还在超时。止血方案有两个：
方案A：加索引（需要30秒-几分钟，期间可能锁表）
方案B：先回滚最近上线的代码（看看是不是最近的改动引起的）
老王选了A——因为这是个老接口，最近没改过，不是代码问题。而且加索引是最直接的修复。
wang@prod-mysql> ALTER TABLE orders ADD INDEX idx_user_status_created
-> (user_id, status, created_at),
-> ALGORITHM=INSTANT, LOCK=NONE;
Query OK, 0 rows affected (0.03 sec)
Records: 0 Duplicates: 0 Warnings: 0
wang@prod-mysql> EXPLAIN SELECT * FROM orders
-> WHERE user_id = 88123 AND status != 'DELETED'
-> ORDER BY created_at DESC LIMIT 20;
+----+----------+--------+-------+--------------------------+---------+---------+------+----------+-------+
| id | type | key | rows | Extra |
+----+----------+--------+-------+--------------------------+---------+
| 1 | ref | idx_user_status_created | 45 | Using where |
+----+----------+--------+-------+--------------------------+
Step 5：验证恢复（6分钟）
10:29
王
老王
已加联合索引 idx_user_status_created，接口RT恢复到45ms。告警可解除。
🤖
Grafana Alert Bot
✅ 告警已解除。订单列表接口平均RT：48ms。错误率：0%。
⚡ Debug习惯 #2：慢SQL排查的黄金三件套：慢查询日志 + EXPLAIN + SHOW PROCESSLIST。慢查询日志告诉你是哪条SQL慢，EXPLAIN告诉你为什么慢（有没有走索引），SHOW PROCESSLIST告诉你当前数据库在干什么。这三个工具是后端排查数据库问题的基本功。
事后复盘
根因：订单表增长到280万行后，缺少(user_id, status, created_at)联合索引，导致全表扫描。
防护措施：①上慢SQL告警（>1s的SQL自动告警）；②Code Review增加EXPLAIN检查环节；③定期跑索引审计脚本。
14:15事故2：导出功能导致OOM内存溢出
14:15
🤖
K8s Alert
🔴 P0告警：order-service Pod重启（OOMKilled）
重启次数：3次（最近5分钟）
内存使用：2.0Gi / 2.0Gi（100%）
上次部署：2026-04-16 11:00（今天上午上线了导出功能）
K8s报OOMKilled = Pod被K8s杀掉了，因为内存用满了。
关键线索：今天上午刚上线了导出功能。高度怀疑是导出功能导致的。
止血策略：立刻关掉导出接口（降级/功能开关）。
Step 1：紧急降级（1分钟）
wang@config-center ~ $ curl -X PUT http://config-center/api/configs/order-service -d '{"feature.export.enabled": false}'
{"status": "ok", "message": "配置已更新，30秒内生效"}
Step 2：保留现场 — 拿到Heap Dump
OOM后Pod会重启，重启后内存现场就丢失了。但K8s的OOMKilled行为是：先dump再kill（如果配了-XX:+HeapDumpOnOutOfMemoryError）。所以heap dump文件应该在容器里。另外，老王在另一台还没被kill的Pod上用Arthas抓取了实时内存信息。
wang@prod-pod-2 ~ $ java -jar arthas-boot.jar 1
[arthas@1]$ dashboard
Memory used total max
heap 1.8Gi 2.0Gi 2.0Gi ← 90%已满！
non_heap 150Mi 200Mi 300Mi
Thread States
RUNNABLE: 8
BLOCKED: 3
WAITING: 45 ← 大量线程在等待
GC Statistics
gc.ps_marksweep.count 15 ← Full GC已经15次了！
gc.ps_marksweep.time 82340ms ← GC总耗时82秒！
[arthas@1]$ heapdump --live /tmp/heap.bin
Dumping heap to /tmp/heap.bin ...
Heap dump file created [1854632248 bytes in 3.21 secs]
（1.8GB的heap dump！）
wang@local ~/Downloads $ /opt/mat/ParseHeapDump.sh /tmp/heap.bin
Problem Suspect 1:
One instance of "java.util.ArrayList" occupies 1,523,847,816 (82.1%) bytes.
The memory is accumulated in one instance of "java.util.ArrayList"
loaded by "java.net.URLClassLoader @ 0x78001234".
Contents:
- ArrayList contains 2,847,193 elements of type
"com.example.entity.Order"
- Each Order object is approximately 535 bytes
Step 3：定位代码（5分钟）
MAT的分析结果指向一个ArrayList装了284万个Order对象。这只有一种可能：导出功能把所有订单一次性全部查出来放到内存里了。让老王看看导出功能的代码。
OrderExportService.java — 出问题的代码
1public byte[] exportOrders(ExportQuery query) {
2 // ❌ 把所有订单一次性查出来！284万行！
3 List<Order> allOrders = orderMapper.selectAll(query);
4
5 // ❌ 284万个对象全部在内存里构建Excel
6 ExcelWriter writer = new ExcelWriter();
7 for (Order order : allOrders) {
8 writer.addRow(order);
9 }
10
11 return writer.getBytes(); // ❌ 整个Excel字节数组也在内存里
12}
问题清晰了。这段代码有三个致命问题：
1. 一次查全量：284万行数据一次性加载到内存
2. 全量构建Excel：284万个对象+Excel Writer同时存在于内存
3. 字节数组：最终Excel的字节数组也在内存
修复方案：用分页查询 + 流式写入，每次只查1000条，写完释放。
Step 4：修复代码 — 流式导出
@Service
public class OrderExportServiceFix {
@Autowired
private OrderMapper orderMapper;
public void exportOrders(ExportQuery query, OutputStream out) {
// 使用 EasyExcel 的流式写入（不需要全量加载到内存）
ExcelWriter writer = new ExcelWriterBuilder()
.output(out)
.head(OrderExportVO.class)
.build();
WriteSheet sheet = new WriteSheet();
sheet.setSheetNo(0);
sheet.setSheetName("订单列表");
int pageNum = 1;
int pageSize = 1000; // 每次只查1000条
while (true) {
// 分页查询：每次只拿1000条到内存
Page<Order> page = orderMapper.selectPage(
new Page<>(pageNum, pageSize), query);
if (page.getRecords().isEmpty()) {
break; // 没有数据了，结束
}
// 转 VO 并写入（EasyExcel会自动刷盘）
List<OrderExportVO> voList = page.getRecords().stream()
.map(this::toVO)
.collect(Collectors.toList());
writer.write(voList, sheet);
// 写完这批就可以被GC回收，不会一直占内存
pageNum++;
}
writer.finish();
}
}
修复后的代码：
1. 分页查询：每次只查1000条，内存里最多1000个Order对象（~500KB）
2. 流式写入：EasyExcel的ExcelWriter会把已写入的数据刷到磁盘，不会一直在内存里
3. OutputStream输出：不返回byte数组，直接写到输出流（可以是文件、HTTP响应）
内存占用从1.5GB降到~50MB。
⚡ Debug习惯 #3：OOM排查的黄金工具链：JVM参数(-XX:+HeapDumpOnOutOfMemoryError) + Arthas(dashboard/heapdump) + MAT(分析heap dump)。Arthas是在线诊断神器——不需要重启应用就能看内存、线程、方法执行时间。每一个Java后端都应该会用Arthas。
类比——水管爆裂：OOM就像家里的水管爆了。水表报警（监控告警），你第一反应不是找水管哪里破了，而是先关总阀（功能开关/降级）。然后拍照留证（heap dump = 拍照），再请水管工来修（MAT分析 = 水管工）。最后在总阀上装压力报警器（内存告警），防止下次再爆。
16:30事故3：Redis缓存和数据库数据不一致
16:30
客
客服小李
用户反馈：修改了收货地址，但下单时显示的还是旧地址。刷新了好几次都是旧的。过了大概5分钟才变成新地址。
数据不一致 = 修改了数据库，但读到的还是旧数据。99%是缓存问题。排查思路：
1. 确认数据库里数据是否已更新
2. 确认Redis缓存里的数据是否已更新
3. 查代码里的缓存更新逻辑
Step 1：验证假设
mysql> SELECT address FROM user_address WHERE user_id = 12345;
+---------------------------+
| address |
+---------------------------+
| 北京市朝阳区新地址100号 | ← 数据库已经是新地址
+---------------------------+
redis> GET user:addr:12345
"北京市海淀区旧地址200号" ← 缓存里还是旧地址！
Step 2：查代码中的缓存更新逻辑
UserAddressService.java — 缓存更新代码
1@Transactional
2public void updateAddress(Long userId, AddressDTO dto) {
3 // 1. 先删缓存
4 redis.del("user:addr:" + userId);
5
6 // 2. 再更新数据库
7 addressMapper.update(userId, dto);
8}
⚠️ 这里有并发问题！
这段代码看着没问题——"先删缓存再更新数据库"是最常见的缓存更新策略。但它在并发场景下有问题：
时间线：
T1：线程A执行 del cache（缓存被删除）
T2：线程B读取数据，发现缓存不存在
T3：线程B从数据库读到旧数据（因为线程A还没来得及更新DB）
T4：线程B把旧数据写入缓存
T5：线程A更新数据库
结果：缓存里是旧数据，数据库是新数据。不一致！
并发不一致的时间线：
线程A（写）: del cache → ......... → update DB
线程B（读）: ......... → cache miss → read DB(旧) → set cache(旧)
结果：缓存=旧数据，DB=新数据 → 不一致！
Step 3：修复方案
缓存不一致是经典问题。有几种修复方案，各有优缺点：
| 方案 | 做法 | 优点 | 缺点 |
|---|
| 延迟双删 | 删缓存 → 更新DB → sleep(500ms) → 再删一次缓存 | 简单 | 500ms不好把控，且用户仍可能看到短暂旧数据 |
| 消息队列 | 更新DB后发MQ消息 → 消费者异步删缓存 | 可靠 | 引入MQ增加复杂度，有延迟 |
| 监听Binlog | Canal监听MySQL binlog → 解析到数据变更 → 删除缓存 | 最可靠 | 架构复杂度高，需要Canal组件 |
| 缓存过期 | 缓存设置较短TTL（如30秒），让它自然过期 | 最简单 | 过期前数据不一致，不适合高实时性场景 |
老王选了"延迟双删 + 短TTL"的组合方案——既不太复杂，又能基本解决一致性问题：
@Transactional
public void updateAddress(Long userId, AddressDTO dto) {
// 1. 先删缓存
String key = "user:addr:" + userId;
redis.delete(key);
// 2. 更新数据库
addressMapper.update(userId, dto);
// 3. 延迟双删：500ms后再删一次（清理并发读产生的脏缓存）
CompletableFuture.runAsync(() -> {
try {
Thread.sleep(500);
redis.delete(key);
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
}
});
}
// 读取时设置30秒TTL作为兜底
public Address getAddress(Long userId) {
String key = "user:addr:" + userId;
Address addr = (Address) redis.opsForValue().get(key);
if (addr != null) {
return addr;
}
// 缓存miss，从DB读
addr = addressMapper.selectByUserId(userId);
if (addr != null) {
// 设置30秒TTL，即使出问题30秒后也会自愈
redis.opsForValue().set(key, addr, 30, TimeUnit.SECONDS);
}
return addr;
}
⚡ Debug习惯 #4：缓存不一致问题排查的关键：先确认是DB新还是缓存新。如果DB是新的、缓存是旧的 = 缓存更新逻辑有问题。如果DB和缓存都是旧的 = 写入流程有问题。先在Redis CLI里直接GET看缓存值，再去数据库SELECT看DB值，一对比就知道了。不要一上来就猜。
事故复盘模板：每次事故都是改进的机会
📋 标准事故复盘报告模板
# 事故复盘报告
## 1. 事故概述
- 发生时间：2026-04-16 10:23 ~ 10:29
- 持续时长：6分钟
- 影响范围：全部用户，订单列表接口不可用
- 影响程度：P0（核心功能不可用）
## 2. 时间线
- 10:23 Grafana告警，接口RT 3.2s
- 10:24 老王确认告警，开始排查
- 10:25 查看监控大盘，发现DB连接池满
- 10:26 查慢SQL日志，定位到全表扫描
- 10:27 EXPLAIN确认无索引
- 10:28 加联合索引 idx_user_status_created
- 10:29 接口恢复，告警解除
## 3. 根因分析
订单表增长到280万行后，缺少(user_id, status, created_at)联合索引，
导致查询走全表扫描。每次查询扫描280万行，耗时4-5秒，
大量请求占满数据库连接池，导致服务不可用。
## 4. 损失评估
- 约3,500笔订单下单受影响
- 客服收到约120个投诉
- 预估GMV损失约8万元
## 5. 改进措施
| # | 措施 | 负责人 | 截止时间 |
|---|------|--------|----------|
| 1 | 全量SQL索引审计 | DBA组 | 4月20日 |
| 2 | 上线慢SQL告警（>1s） | 运维组 | 4月18日 |
| 3 | Code Review增加EXPLAIN检查 | 开发组 | 4月17日 |
| 4 | 定期跑索引审计脚本 | DBA组 | 每周日 |
## 6. 经验教训
- 高频查询接口必须有覆盖索引
- 数据量增长到一定量级后需要重新评估索引
- 应建立"慢SQL自动告警"机制，不能等用户反馈
复盘报告不是为了追责，而是为了改进。每一份复盘报告的最终产出应该是"改进措施"——具体的、可执行的、有负责人的action item。如果复盘完没有action item，等于白复盘了。下次同样的问题还会再犯。
⚡ Debug习惯 #6：复盘的5Why分析法：对每一个"为什么"，连续追问5次。
"为什么接口慢？" → 全表扫描
"为什么全表扫描？" → 没有索引
"为什么没有索引？" → 上线时没做EXPLAIN检查
"为什么没做检查？" → Code Review流程里没有这个环节
"为什么没有这个环节？" → 缺少SQL审核规范
根因找到了：缺少SQL审核规范。改进措施：建立SQL审核流程。
Debug排查核心思路总结
🎯 后端Debug的6条核心习惯
| # | 习惯 | 核心要点 |
|---|
| 1 | 先止血再找因 | 线上恢复速度 > 找到根因速度。先回滚/降级 |
| 2 | 证据驱动 | 监控→日志→代码→dump，每一步用数据说话 |
| 3 | 保留现场 | 重启前先dump（heap dump / thread dump） |
| 4 | 二分法排查 | 不确定哪段代码有问题？注释一半看是否复现 |
| 5 | 能复现就能修 | 无法稳定复现的bug最难修。先找复现条件 |
| 6 | 复盘必有action | 没有改进措施的复盘等于白做 |
类比——侦探破案：后端排查线上问题就像侦探破案。
犯罪现场 = 线上环境（先封锁现场，保留证据）
监控录像 = Grafana大盘（看看发生了什么）
目击证词 = 应用日志（谁在什么时候做了什么）
法医鉴定 = heap dump / thread dump（DNA检测/尸检报告）
嫌疑审讯 = 代码审查（哪段代码有作案动机和机会）
破案总结 = 复盘报告（怎么防止下次再发生）
新手debug像莽撞的警察——冲进去乱翻；老手debug像福尔摩斯——先观察、再推理、最后验证。