一次线上 P99 从 2100ms 降到 78ms：一条慢查询引发的雪崩排查实录

## 一、现象：一个"时好时坏"的接口

某天下午开始，告警群里陆续有人反馈"订单列表加载慢"。

打开监控，看到的曲线很耐人寻味——

| 指标 | 正常时 | 故障时 |
|---|---|---|
| P50 | 45ms | 52ms |
| P99 | 120ms | **2100ms** |
| 错误率 | 0.01% | 3.7% |
| CPU | 35% | 41% |
| Full GC | 0 次/分 | 0 次/分 |

几个关键特征先记下来，因为它们直接决定了排查方向：

1. **P50 几乎没变，只有 P99 炸了** → 不是全局性能退化，是**一部分请求**被拖慢了。
2. **不是持续飙高，是每隔几分钟来一次毛刺** → 像排队/争抢，不像算力不足。
3. **CPU 和 GC 都很平静** → 线程没有在疯狂算东西，大概率在**等**。
4. 下游调用方开始报熔断 → 影响已经在扩散。

> **经验一：看曲线的形状，比看数值重要。**
> - 阶跃式抬升 → 通常是发布/配置变更/数据量跨过阈值
> - 周期性毛刺 → 争抢资源（锁、池、定时任务）
> - 缓慢爬升 → 泄漏（内存、连接、文件句柄）
> - P99 炸而 P50 稳 → 长尾请求，先找"谁在排队"

---

## 二、第一步：先划边界，别急着 dump

很多同学线上出问题第一反应是 `jstack` 抓一把。我更习惯先**分层定性**，确认耗时落在哪一层，再下钻。

我们的链路是：`Nginx → API 网关 → 订单服务 → MySQL / Redis`。

先看 APM 的耗时分布：

```
Nginx:      2ms
网关:       5ms
订单服务:   2087ms   ← 几乎全部在这里
  ├─ Redis 查询:   3ms
  ├─ DB 查询:   2051ms   ← 98% 在这一行
  └─ 结果组装:    33ms
```

DB 慢，看起来是条慢 SQL。但奇怪的是——**去 MySQL 慢查询日志里翻，同一条 SQL 的耗时是双峰的**：

```sql
-- 慢查询日志摘录（同一条 SQL）
# Query_time: 0.000521   Rows_examined: 43
# Query_time: 0.000488   Rows_examined: 43
# Query_time: 2.140237   Rows_examined: 7923410   ← ???
# Query_time: 0.000612   Rows_examined: 43
```

同一个语句，扫描行数在 **43** 和 **792 万** 之间反复横跳。

**扫描行数不一样，说明执行计划不一样。** 这条线索是整篇文章的转折点。

---

## 三、第二步：抓现场，问"连接被谁占着"

回到应用层。P99 毛刺 + CPU 平静 + 请求变慢，先怀疑池子。

```bash
# HikariCP 指标（Micrometer）
hikaricp_connections_active     = 20   # 打满，maximumPoolSize = 20
hikaricp_connections_pending    = 137  # 137 个线程在门口排队等连接
hikaricp_connections_timeout    = 41   # 已经开始超时了
```

再看线程在干嘛：

```bash
$ arthas> thread -n 3
"http-nio-8080-exec-187" Id=312 WAITING
    at sun.misc.Unsafe.park(Native Method)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(...)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:198)
    at com.zaxxer.hikari.HikariDataSource.getConnection(...)
    at com.xxx.order.dao.OrderMapper.selectByUser(...)
```

**137 个线程堵在 `getConnection()` 上。** 应用层根本没有在"算"，全在"等"。

顺着这条线往上游看，Tomcat 线程池也跟着打满，然后调用方因为超时开始重试——

```
请求量（网关入口）:  300 QPS
请求量（订单服务）:  910 QPS   ← 3 倍！
```

**上游每个失败请求重试 3 次。** 这下闭环了：

```
一条 SQL 偶发变慢（全表扫描）
  → 占住连接不放
  → 连接池 20 个瞬间耗尽，其余请求排队
  → Tomcat 线程池堆积，接口超时
  → 上游重试 ×3，流量翻三倍
  → 更多连接被占住
  → 雪崩
```

> **经验二：看到"池子打满"，第一反应不要是"扩容"。**
> 要先问两个问题：
> 1. **谁**占着连接？→ 慢 SQL
> 2. 占着多久？→ 2s，而不是正常的 0.5ms
>
> 连接池不够只是**症状**，持有时间过长才是**病灶**。盲目把池子加到 200，只会让 MySQL 承受 200 个并发全表扫描，死得更快。

---

## 四、第三步：为什么同一条 SQL 会有两套执行计划

现在回到那个双峰现象。SQL 长这样：

```sql
SELECT *
FROM `order`
WHERE user_id = ?
  AND status = ?
ORDER BY create_time DESC
LIMIT 20;
```

表上是有索引的：

```sql
KEY `idx_user_status` (`user_id`, `status`)
```

按理说应该走索引。我把参数换成常量试了一下：

```sql
-- A：数字，不加引号
EXPLAIN SELECT * FROM `order` WHERE user_id = 10086 AND status = 1 ORDER BY create_time DESC LIMIT 20;
+------+---------------+------+---------+------+---------+------------------------------------------+
| type | possible_keys | key  | rows    | ref  | Extra                                    |
+------+---------------+------+---------+------+---------+------------------------------------------+
| ALL  | idx_user_status| NULL| 7923410 | NULL | Using where; Using filesort; Using MRR   |
+------+---------------+------+---------+------+---------+------------------------------------------+

-- B：字符串，加引号
EXPLAIN SELECT * FROM `order` WHERE user_id = '10086' AND status = 1 ORDER BY create_time DESC LIMIT 20;
+------+---------------+-----------------+---------+-------+---------+----------------+
| type | possible_keys | key             | rows    | ref   | Extra                        |
+------+---------------+-----------------+---------+-------+---------+----------------+
| ref  | idx_user_status| idx_user_status| 43      | const | Using where; Using filesort   |
+------+---------------+-----------------+---------+-------+---------+----------------+
```

**索引到底走不走，取决于传入的是数字还是字符串。**

### 根因：MySQL 的隐式类型转换规则

MySQL 的比较规则是：**当字符串列和数字比较时，会把字符串列转成数字再做比较。**

```
user_id = 10086
    ↓ 等价于
CAST(user_id AS SIGNED) = 10086
```

注意这个 `CAST` 是**加在列上**的。索引里存的是 `'10086'` 这个字符串的有序结构，`CAST(user_id)` 的结果在索引里没有任何顺序保证 —— 优化器只能放弃索引，老老实实全表扫一遍、逐行转换、逐行比较。

反过来（数字列 vs 字符串常量）不会失效，因为被转换的是**常量**而不是列：

```sql
-- 数字列 vs 字符串：字符串常量被转成数字，索引仍可用 ✅
WHERE id = '12345'   -- id 是 BIGINT，索引正常
```

一句话记牢：**被 CAST 的如果是列，索引死；被 CAST 的如果是常量，索引活。**

### 那"偶发"是怎么回事？

如果索引一直失效，应该一直慢才对。这里有两个因素叠加：

1. **数据分布不均**。全表扫描时，命中在前 1000 行的用户很快就返回了（buffer pool 里热着），命中在表尾的用户就要读几百万行。所以 P50 只从 45ms 涨到 52ms，P99 却直接爆炸。
2. **buffer pool 的冷热**。表被挤出缓存时需要走磁盘 IO，耗时跳一个数量级。

这解释了为什么测试环境、灰度环境都没复现：测试数据里每个用户就几十条订单，全表扫描也就几毫秒。

### 代码里是怎么写错的

```java
// ❌ 错误：数据库 user_id 是 varchar(32)，实体类却用了 Long
public class OrderQuery {
    private Long userId;      // 拿着 Long 去查 varchar
    private Integer status;
}
```

```xml
<!-- MyBatis 里没指定 jdbcType，PreparedStatement 按 Long 绑定 -->
<select id="selectByUser" resultType="Order">
    SELECT * FROM `order`
    WHERE user_id = #{userId}
      AND status = #{status}
    ORDER BY create_time DESC
    LIMIT 20
</select>
```

这个字段类型是从上游 RPC 的 DTO 一路"继承"下来的，写的时候没人去核对表结构。

> **经验三：ORM 帮你屏蔽了类型差异，也屏蔽了索引失效。**
> 这种问题在代码 review 里几乎不可能被发现——SQL 一模一样，语法完全正确，测试环境跑得飞快。
> 唯一能提前拦住它的手段是：**上线前用真实绑定变量跑 EXPLAIN**，而不是拿常量在命令行里试。

顺带一提，`EXPLAIN` 直接写常量和走 PreparedStatement 的执行计划可能不同，MySQL 8.0 更稳的做法是看真实执行计划：

```sql
-- 看真实执行计划（含绑定变量的实际选择）
EXPLAIN FORMAT=JSON SELECT ... ;
EXPLAIN ANALYZE SELECT ... ;   -- MySQL 8.0.18+
```

---

## 五、修复：五刀下去，每一刀都有理由

### 1. 类型对齐（治本）

```java
public class OrderQuery {
    private String userId;    // ✅ 与 varchar(32) 对齐
    private Integer status;
}
```

```xml
WHERE user_id = #{userId, jdbcType=VARCHAR}
```

改完立刻 `EXPLAIN`：

```
type: ref   key: idx_user_status   rows: 43   ← 从 792 万回到 43
```

### 2. 联合索引补上排序列，消灭 filesort

注意上面 B 计划的 Extra 里还有 `Using filesort` —— `create_time` 不在索引里，还要额外排序。把排序列并进索引：

```sql
ALTER TABLE `order`
  ADD INDEX idx_user_status_ct (user_id, status, create_time),
  ALGORITHM = INPLACE, LOCK = NONE;   -- 大表务必用 Online DDL
```

```sql
EXPLAIN SELECT ... WHERE user_id = '10086' AND status = 1 ORDER BY create_time DESC LIMIT 20;
-- type: ref   key: idx_user_status_ct   rows: 20   Extra: Using index condition
-- filesort 消失，LIMIT 20 真的只扫 20 行
```

### 3. 别 `SELECT *`

```sql
-- ❌ 回表取全部 30 多个字段，其中还有个 text 类型的 remark
SELECT * FROM `order` WHERE ...

-- ✅ 只取列表页需要的列
SELECT order_id, order_no, status, amount, create_time
FROM `order` WHERE ...
```

宽表 + `SELECT *` 意味着每次查询都要回表拖一堆用不上的列，IO 和网络传输都是白烧的。

### 4. 连接池：快速失败，而不是无限排队

```yaml
spring:
  datasource:
    hikari:
      maximum-pool-size: 50
      minimum-idle: 10
      connection-timeout: 250       # 250ms 拿不到连接就报错，别堆着
      validation-timeout: 1000
      leak-detection-threshold: 10000  # 超过 10s 未归还连接就打日志
```

这里的核心思路是：**让失败发生在毫秒级，而不是让请求在池子门口排 2 秒的队**。快速失败能让上游立刻感知、立刻熔断，反而是保护整个链路。

### 5. 掐掉无脑重试

```java
// ❌ 反例：失败就重试 3 次，把 300 QPS 放大成 900 QPS
for (int i = 0; i < 3; i++) {
    try { return client.queryOrder(req); }
    catch (Exception e) { /* 什么都没做，立刻再试 */ }
}
```

```java
// ✅ 正例：限制次数 + 指数退避 + 熔断
RetryConfig retry = RetryConfig.custom()
        .maxAttempts(2)
        .intervalFunction(IntervalFunction.ofExponentialBackoff(200, 2.0, 1000))
        .retryExceptions(TimeoutException.class)   // 只重试超时，不重试业务异常
        .build();

CircuitBreakerConfig cb = CircuitBreakerConfig.custom()
        .failureRateThreshold(50)
        .waitDurationInOpenState(Duration.ofSeconds(10))
        .slidingWindowSize(100)
        .build();
```

三条原则：
- **只重试幂等的、可能是瞬时故障的请求**（超时、连接被重置），业务校验失败别重试
- **退避而不是立即重试**，给下游喘息空间
- **重试预算**：整条链路上的重试总次数要有上限，否则末端抖动会被层层放大

> **经验四：链路越深，重试越危险。**
> 三层调用各重试 3 次 = 27 倍放大。一个组件的轻微抖动，经过重试网络会被放大成一场 DDoS —— 而发起方是我们自己。

---

## 六、验证结果

灰度 10% → 观察 30 分钟 → 全量：

| 指标 | 修复前 | 修复后 |
|---|---|---|
| P50 | 52ms | 18ms |
| P99 | 2100ms | **78ms** |
| 错误率 | 3.7% | 0.01% |
| DB CPU | 78% | 31% |
| 应用 CPU | 41% | 24% |
| 慢查询数 | 200+/分 | 0 |

DB 的 CPU 从 78% 掉到 31% —— 之前那一半算力，全都烧在反复全表扫描 800 万行上了。

---

## 七、可复用的排查清单

这次排查走的路径，我整理成了一份清单，之后遇到"接口变慢"都能照着走一遍。

### 排查顺序

```
1. 看曲线形状（毛刺/阶跃/爬升） → 定性
2. 分层看耗时（网关/应用/DB/缓存） → 定位到层
3. 看池子指标（线程池、连接池、等待数） → 判断是不是在排队
4. 抓线程栈（thread -n / -b） → 确认"在等什么"
5. 拿慢 SQL 去 EXPLAIN，重点看 rows 和 key
6. 对比"预期执行计划"和"实际执行计划"
7. 改完必须回看监控，别只看本地跑通
```

### 索引失效的六种经典死法

| 场景 | 例子 | 失效原因 |
|---|---|---|
| 隐式类型转换 | `varchar_col = 123` | 列被 CAST |
| 列上套函数 | `DATE(create_time) = '2026-01-01'` | 列被函数包裹 |
| 前导模糊查询 | `LIKE '%abc'` | 无法用索引前缀匹配 |
| 违反最左前缀 | 索引 `(a,b,c)`，条件只给 `b` | 跳过了最左列 |
| `OR` 连接非索引列 | `a = 1 OR d = 2`（d 无索引） | 优化器放弃索引 |
| 统计信息过期 | 大批量导入后 | 优化器估算错误选错计划 |

### 上线前必做的三件事

1. **SQL 走 CI 卡点**：在 CI 里对新增/变更的 SQL 自动跑 `EXPLAIN`，出现 `type=ALL` 或 `rows > 10000` 直接 fail。
2. **慢查询阈值收紧**：`long_query_time` 从 1s 调到 200ms，并接入告警。1s 的阈值对 C 端接口来说已经太晚了。
3. **池子指标入监控**：`active / pending / timeout / acquire time` 四个指标，缺一不可。连接池的等待数是最灵敏的早期信号。

---

## 八、写在最后

复盘会上有人问：**"如果当时直接把连接池加到 200，是不是也能扛过去？"**

大概率扛不过去。20 个并发全表扫描 800 万行已经让 DB CPU 冲到 78%，200 个只会让它瞬间到 100%，然后整库不可用。

这次真正让我后背发凉的，不是那个 `Long` —— 类型写错是小事。可怕的是这个错误在**代码 review、单测、集成测试、灰度**四个环节全部安然通过，一直到真实流量 + 真实数据分布的组合下才暴露。

**线上问题从来不是单点错误，而是"错误 × 数据量 × 并发 × 放大机制"的乘积。** 单个因子都不致命，乘在一起就是一场事故。

所以与其追求"写出没有 bug 的代码"，不如把精力放在另外两件事上：

- **让错误的暴露时间从"线上"提前到"CI"**（SQL 卡点、EXPLAIN 自动化）
- **让错误的影响半径可控**（快速失败、熔断、重试预算）

前者降低出错概率，后者降低出错代价。两件事做扎实了，写错一个字段类型，也就只是个字段类型而已。