RDS慢查询把CPU打满后的排查记录

周二凌晨 01:17，支付回调服务 5xx 比例从 0.2% 直接跳到 11.6%，CES 连续推了两条同类告警，都是 api-gateway p95 > 2000ms 持续 5 分钟。业务链路马上跟着抖，下游重试倍率从 1.1 涨到 2.7，Kafka 的 callback_result 主题积压到 3.4 万条，客服在 01:24 开始收“订单状态没更新”的工单。Grafana 上我又补看了两块，支付回调接口 QPS 从 320 掉到 190，超时请求数在 01:21 这个点到 1468/min，已经不是偶发抖动。

那天值班手机在 01:17 到 01:20 连着响了四次。

故障现场和我前二十分钟的误判

链路在华为云广州，应用跑在两台 ECS c6.large.2，2 vCPU/4 GiB，EulerOS 2.0 SP11，JDK 17.0.10，Spring Boot 3.2.4，mysql-connector-j 8.3.0。数据库是 RDS for MySQL 8.0.28 主备，4 vCPU/16 GiB，500 GiB 高IO，包月账单 1986 元，按小时算约 2.72 元。平时 CPU 在 25% 到 40%，出事后连续 8 分钟高于 96%，连接数从 180 冲到 512，实例上限 600，Threads_running 一度卡在 87 到 96。

[CES] rds_cpu_util: 98.21% (阈值 85%，3/3 周期)
[CES] rds_slow_queries: 463/min (阈值 50/min)
[CES] rds_active_connections: 512 (阈值 450)

我当时盯着应用日志，先入为主地以为是连接池打满。用这条命令抓最近 200 行：

grep -E 'HikariPool|CommunicationsException|SQLTransientConnectionException' /var/log/pay-callback/app.log | tail -n 200

2026-05-14 01:19:43.772 WARN 1 --- [nio-8080-exec-9] com.zaxxer.hikari.pool.HikariPool :
HikariPool-1 - Connection is not available, request timed out after 30000ms.
2026-05-14 01:19:43.775 ERROR 1 --- [nio-8080-exec-9] c.x.pay.callback.CallbackController :
com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
2026-05-14 01:20:01.102 ERROR 1 --- [nio-8080-exec-3] o.s.jdbc.CannotGetJdbcConnectionException :
Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException

我改了 application-prod.yml 里三处参数，改动是有记录的，不是口头“调大一点”：maximum-pool-size 40 改到 80，minimum-idle 10 改到 20，validation-timeout 5000 改到 2000，connection-timeout 维持 30000 不动。理由是我想先压缩拿连接时的排队时间，确认是否只是池子太小。发布方式是滚动重启，两台 ECS 分别重启 48 秒和 51 秒，整轮 3 分 12 秒。结果几乎没变，5xx 从 11.6% 只到 10.9%，网关 p95 还在 2.3s 以上，01:31 到 01:34 反而多出一次 12% 的毛刺。

这个方向我当时就是走偏了。

01:38 我把注意力拉回数据库，登到 RDS 执行 SHOW FULL PROCESSLIST;，一眼看到大量线程状态是 Sending data，Time 在 12 到 19 秒，SQL 文本都指向 orders 表同一条查询。再看 information_schema.innodb_trx，活跃事务并不多，说明不是锁等待主导。

Id: 392811  User: app_user  Host: 10.23.17.41:51236  db: paydb
Command: Query  Time: 17  State: Sending data
Info: SELECT id, tenant_id, status, amount, created_at FROM orders ... LIMIT 20

Id: 392845  User: app_user  Host: 10.23.17.42:48820  db: paydb
Command: Query  Time: 19  State: Sending data
Info: SELECT id, tenant_id, status, amount, created_at FROM orders ... LIMIT 20

慢日志定位、DDL执行和返工

慢日志阈值原本是 1 秒，我直接查 mysql.slow_log，5 分钟里同指纹 SQL 出现了 1321 次，最慢 18.732s，Rows_examined 1287344，返回只有 20 行。执行计划也很直白，命中 idx_tenant_id 后扫 1248731 行，再 filesort。orders 当时 1.9 亿行，tenant 90217 又是热点租户，晚高峰每分钟新增 1.2 万单，这条 SQL 在并发高的时候把 CPU 顶满。

SELECT start_time, query_time, lock_time, rows_sent, rows_examined, sql_text
FROM mysql.slow_log
WHERE start_time > NOW() - INTERVAL 10 MINUTE
ORDER BY query_time DESC
LIMIT 3;

# Query_time: 18.732418  Lock_time: 0.000231 Rows_sent: 20 Rows_examined: 1287344
SELECT id, tenant_id, status, amount, created_at
FROM orders
WHERE tenant_id = 90217
  AND status IN ('PAID','REFUNDING')
ORDER BY created_at DESC
LIMIT 20;

EXPLAIN FORMAT=TRADITIONAL ...
type: range
key: idx_tenant_id
rows: 1248731
Extra: Using where; Using filesort

01:52 我先在测试实例重放流量，规格 4 vCPU/8 GiB，MySQL 8.0.28，按量跑 6 小时花 8.52 元。流量重放不是全量抓包，我从生产提了 01:10 到 01:20 的 SQL digest，拼成 JMeter JDBC 脚本，200 线程压了 8 分钟，目标是复现 p95>2s。测试里我有一次失败尝试，想一步到位建覆盖索引，DDL 写成 idx_tenant_status_created_note (tenant_id, status, created_at DESC, note)，执行直接报错：

ALTER TABLE orders
ADD INDEX idx_tenant_status_created_note (tenant_id, status, created_at DESC, note);
ERROR 1071 (42000): Specified key was too long; max key length is 3072 bytes

note 是 utf8mb4 varchar(1024)。我花了十几分钟算前缀，又试了 note(128)，索引能建，但 explain 还是走 Using filesort，因为这个列既不参与过滤也不参与排序，等于白加，写入开销还会上去。我把这个方案撤了。

02:17 在生产执行真正的 DDL，只保留筛选列和排序列：

ALTER TABLE orders
ADD INDEX idx_tenant_status_created (tenant_id, status, created_at DESC),
ALGORITHM=INPLACE, LOCK=NONE;

在线 DDL 持续 11 分 43 秒。那段时间写入延迟从 7ms 抬到 35ms，binlog flush 从 4ms 到 12ms，没有触发复制延迟告警。索引生效后同 SQL 的 rows 估算降到 1836，Extra 里的 Using filesort 消失，单条 query_time 回到 40ms 到 90ms，p95 在压测里是 128ms。

参数侧我也补了一轮，这里我也踩了权限坑。

SET GLOBAL tmp_table_size=268435456;
ERROR 1227 (42000): Access denied; you need (at least one of) the SYSTEM_VARIABLES_ADMIN privilege(s) for this operation

后面改走 RDS 参数模板，tmp_table_size 和 max_heap_table_size 从 67108864 调到 268435456，long_query_time 从 1 调到 0.5，这三个是动态参数，控制台显示 2 分钟内下发完成。03:12 以后 CPU 回到 35% 到 45%，支付回调 p95 从 2.8s 降到 320ms，p99 还在 1.1s。慢查询从 463/min 降到 37/min，Kafka 积压 47 分钟清空，临时升配到 8 vCPU/32 GiB 的工单我直接取消了，按当时价格每月省 1270 元。

现在还卡着两件事，orders 这 1.9 亿行的冷热分布太偏，单一复合索引对长尾租户提升一般，我准备在影子库试按月分区并演练回滚；应用侧还有 3 条 SQL 会走临时表，query_time 600ms 到 900ms，我已经把 SQL digest、接口名、tenant_id 一起打进日志，打算先观察两周再决定要不要拆查询。

分区方案我现在还不敢直接上生产。