4. 慢查询发现过程:APM告警、慢查询日志、DBA介入、根因定位
在支付核心链路的性能保障体系中,慢查询的发现与定位是数据库性能优化(DBP-Tuning)的第一道防线。本章复盘一次真实生产案例:某支付订单查询接口在晚高峰出现持续毛刺,TP99从50ms飙升至2.3s。我们按照“APM告警 → 慢查询日志 → DBA介入 → 根因定位”四步法,还原完整的排查链路。
核心原则:慢查询发现不是单一工具的事,而是“应用层监控 → 数据库层日志 → 人工分析 → 代码/索引验证”的闭环。任何一步缺失都可能导致根因遗漏。
4.1 第一步:APM告警——从业务指标到数据库指标的穿透
APM(Application Performance Monitoring)系统首先捕获到异常:pay_order_detail 接口的响应时间在20:00-20:05期间从50ms陡升至2.3s,错误率从0.1%升至3.2%。APM的数据库拓扑图自动关联出该接口对应的SQL模板,并标记为“疑似慢查询”。
| APM指标 | 正常基线 | 告警阈值 | 告警值 |
|---|---|---|---|
| 接口TP99 (ms) | 50 | 200 | 2300 |
| 数据库查询耗时 (ms) | 15 | 100 | 1850 |
| 数据库连接池活跃数 | 12 | 50 | 78 |
| 慢查询数量 (次/分钟) | 0 | 5 | 342 |
APM的调用链追踪(Distributed Tracing)进一步定位到:该接口在一次请求中执行了两次相同的SQL查询,且第二次查询的数据库等待时间(DB Wait Time)占比高达82%。这提示我们:问题不在应用逻辑,而在数据库执行层。
4.2 第二步:慢查询日志——捕获“罪魁祸首”SQL
DBA登录数据库实例,开启 slow_query_log 并设置 long_query_time = 0.5(单位:秒),捕获到以下慢查询记录:
# Time: 2025-03-15T20:02:17.123456Z
# User@Host: pay_app[pay_app] @ [10.0.1.100] Id: 45231
# Query_time: 1.852315 Lock_time: 0.000123 Rows_sent: 1 Rows_examined: 1587234
SET timestamp=1742061737;
SELECT
o.id, o.order_no, o.amount, o.status, o.create_time,
p.payment_id, p.pay_channel, p.pay_time,
r.refund_id, r.refund_amount, r.refund_status
FROM pay_order o
LEFT JOIN pay_payment p ON o.id = p.order_id
LEFT JOIN pay_refund r ON o.id = r.order_id
WHERE o.user_id = 12345678
AND o.status IN (2, 3, 5)
ORDER BY o.create_time DESC
LIMIT 20;
关键指标解读:
•
•
•
•
Query_time: 1.85s —— 远超正常预期的50ms,属于严重慢查询。•
Rows_examined: 1,587,234 —— 扫描了158万行,但只返回1行,说明索引失效或全表扫描。•
Lock_time: 0.000123s —— 锁等待时间极短,排除锁竞争,问题聚焦在数据扫描量过大。
4.3 第三步:DBA介入——执行计划分析与索引诊断
DBA使用 EXPLAIN 分析该SQL的执行计划:
EXPLAIN SELECT
o.id, o.order_no, o.amount, o.status, o.create_time,
p.payment_id, p.pay_channel, p.pay_time,
r.refund_id, r.refund_amount, r.refund_status
FROM pay_order o
LEFT JOIN pay_payment p ON o.id = p.order_id
LEFT JOIN pay_refund r ON o.id = r.order_id
WHERE o.user_id = 12345678
AND o.status IN (2, 3, 5)
ORDER BY o.create_time DESC
LIMIT 20;
| 表名 | type | possible_keys | key | rows | Extra |
|---|---|---|---|---|---|
| pay_order (o) | ALL | idx_user_id, idx_status | NULL | 1,580,000 | Using where; Using filesort |
| pay_payment (p) | ref | idx_order_id | idx_order_id | 1 | Using where |
| pay_refund (r) | ref | idx_order_id | idx_order_id | 1 | Using where |
诊断结论:
•
• 虽然存在
•
•
pay_order 表出现 ALL(全表扫描),预估扫描158万行。• 虽然存在
idx_user_id 和 idx_status 两个单列索引,但优化器未使用,因为 WHERE 条件同时包含 user_id 和 status IN (...),单列索引无法有效过滤。•
Using filesort 表示排序无法使用索引,需要额外排序操作,进一步增加开销。
4.4 第四步:根因定位——索引缺失与SQL改写
结合执行计划与业务逻辑,DBA定位到两个根因:
- 联合索引缺失:
pay_order表缺少(user_id, status, create_time)联合索引,导致无法同时利用user_id过滤、status过滤和create_time排序。 - SQL写法低效:
LEFT JOIN关联了pay_payment和pay_refund两张表,但业务场景只需要最近一笔支付和退款记录。全量关联导致驱动表扫描行数被放大。
优化方案:
-- 方案一:创建联合索引(推荐)
ALTER TABLE pay_order ADD INDEX idx_user_status_time (user_id, status, create_time DESC);
-- 方案二:SQL改写为子查询+JOIN,减少驱动表扫描
SELECT
o.id, o.order_no, o.amount, o.status, o.create_time,
p.payment_id, p.pay_channel, p.pay_time,
r.refund_id, r.refund_amount, r.refund_status
FROM (
SELECT id, order_no, amount, status, create_time
FROM pay_order
WHERE user_id = 12345678
AND status IN (2, 3, 5)
ORDER BY create_time DESC
LIMIT 20
) o
LEFT JOIN pay_payment p ON o.id = p.order_id
LEFT JOIN pay_refund r ON o.id = r.order_id;
4.5 复盘要点总结
| 步骤 | 工具/方法 | 关键输出 | 耗时 |
|---|---|---|---|
| APM告警 | SkyWalking / Datadog | 接口TP99飙升至2.3s,数据库耗时占比82% | 1分钟(自动) |
| 慢查询日志 | MySQL slow_query_log | 捕获具体SQL,Query_time=1.85s,Rows_examined=158万 | 2分钟 |
| DBA介入 | EXPLAIN + 索引分析 | 发现全表扫描、Using filesort、索引未命中 | 5分钟 |
| 根因定位 | 索引设计评审 + SQL Review | 缺失联合索引、SQL未做子查询裁剪 | 3分钟 |
本次复盘启示:
• 慢查询发现不能只依赖单一工具,APM负责“报警”,慢查询日志负责“取证”,DBA负责“诊断”,三者缺一不可。
• 支付场景中,
• SQL改写(子查询先LIMIT再JOIN)在驱动表数据量大时,能显著减少扫描行数,是“不建索引也能优化”的备选方案。
• 慢查询发现不能只依赖单一工具,APM负责“报警”,慢查询日志负责“取证”,DBA负责“诊断”,三者缺一不可。
• 支付场景中,
user_id + status + create_time 是高频查询模式,必须建立联合索引,且排序字段要放在索引最后。• SQL改写(子查询先LIMIT再JOIN)在驱动表数据量大时,能显著减少扫描行数,是“不建索引也能优化”的备选方案。