Administrator
发布于 2021-05-11 / 4269 阅读
23

慢查询治理:建立一套 SQL 准入机制

半年内第四次,又是新 SQL 没索引

2021 年 5 月 10 号,一个上线不到两小时的功能把数据库打挂了。原因是一段新写的查询没走索引,全表扫 4000 万行。

难受的是,这不是第一次。我翻了下过去半年的故障记录:

日期原因影响时长
2020-12-08新接口 SQL 未加索引47 分钟
2021-02-15字段类型不匹配导致索引失效1 小时 22 分
2021-04-15导出功能缺联合索引23 分钟
2021-05-10新接口 SQL 未加索引38 分钟

四次,全是同一个模式:代码在测试环境跑得好好的(因为只有几千行数据),上线到生产就炸。

2 月那次之后我就在订单和商品两个核心服务上建了 SQL 卡口。这次出事的是营销服务,一个我们没接入卡口的服务——它当时刚拆出来两个月,还没排上。

那天下午我把卡口推广到全部服务,并且把规范整理成了文档。这篇就写这套机制。

三道防线

第一道  开发阶段:IDE 提示 + 本地扫描脚本
第二道  提交阶段:CI 里跑 SQL 审核,不通过不给合并
第三道  运行阶段:慢查询日志采集 + 每日报告 + 超标告警

重点是第二道。第三道是兜底,第一道聊胜于无。

先把规范写清楚

做自动化审核之前,必须先有明确的规则,不然工具不知道该判什么。我们定的是这份:

索引规范

  • 单表索引数量不超过 5 个,联合索引字段不超过 3 个
  • 建表必须有主键,推荐自增 BIGINT
  • 区分度低于 5% 的字段不建单列索引(比如 statusis_deleted
  • 联合索引遵循最左前缀,区分度高的字段放前面
  • 不超过 3 张表 JOIN,被 JOIN 的字段必须有索引且类型完全一致

SQL 写法

  • 禁止 SELECT *,必须写清字段
  • 禁止在索引列上做函数运算WHERE DATE(create_time) = '2021-05-01' 不行
  • 禁止 隐式类型转换:字段是 varchar,参数传了数字
  • 禁止 前置通配符LIKE '%abc'
  • IN 里的元素不超过 500 个
  • 深分页限制:OFFSET 不超过 10000
  • 禁止不带 WHEREUPDATE / DELETE
  • 禁止 SELECT ... FOR UPDATE 后跟长事务

工具选型

工具形态说明
SOAR(小米开源)命令行SQL 评分和优化建议,Go 写的,单文件部署
YearningWeb 平台偏 SQL 工单审批流程,我们要的是自动卡口
ArcheryWeb 平台功能全,但太重,要配数据库和一堆依赖

我们选了 SOAR + 自己写的几十行脚本。理由:SOAR 是纯命令行,容易集成到 CI 里,而 Yearning 和 Archery 都是"人去平台上提工单"的模式,跟我们的研发流程对不上。

$ wget https://github.com/XiaoMi/soar/releases/download/0.11.0/soar.linux-amd64
$ chmod +x soar.linux-amd64
$ echo "SELECT * FROM t_order WHERE status = 1" | ./soar.linux-amd64 -report-type markdown

输出:

## 4.1. 建议

* **Item:  COL.001**
  * Severity: L2
  * Content: 请为 GROUP BY 或 ORDER BY 的字段建立合适的索引
* **Item:  RES.001**
  * Severity: L3
  * Content: 单次查询建议使用 LIMIT 语句限制返回条数
* **Item:  CLA.009**
  * Severity: L1
  * Content: 最外层 SELECT 未指定 WHERE 条件

SOAR 的严重级别从 L0(最高)到 L8。我们卡在 L1 及以上,L2、L3 只是提示。

CI 集成

流程是:开发提交 Merge Request → Jenkins 拉代码 → 提取 SQL → 送 SOAR 审核 → 结果评论回 GitLab。

提取 SQL

我们的 SQL 都在 MyBatis 的 mapper XML 里,也有少量注解方式。用 Python 解析 XML:

#!/usr/bin/env python3
# check_sql.py
import xml.etree.ElementTree as ET
import glob, subprocess, sys, os

MYBATIS_NS = "{http://mybatis.org/dtd/mybatis-3-mapper.dtd}"

def extract_sql(path):
    tree = ET.parse(path)
    root = tree.getroot()
    result = []
    for tag in ('select', 'insert', 'update', 'delete'):
        for node in root.iter(MYBATIS_NS + tag):
            sql_id = node.get('id', 'unknown')
            text = ''.join(node.itertext()).strip()
            if text:
                # 把 MyBatis 的 #{} 占位符换成常量,SOAR 才能解析
                text = re.sub(r'#\{[^}]*\}', '1', text)
                result.append((os.path.basename(path), sql_id, text))
    return result

这里有个必须处理的问题:#{userId} 这种占位符 SOAR 解析不了,要先替换成常量。同理 <if><foreach> 这些动态标签也要处理,我们的做法是把 <foreach> 展开成一个固定的 IN (1,2,3)

for f in glob.glob('src/main/resources/mapper/**/*.xml', recursive=True):
    for file, sid, sql in extract_sql(f):
        out = subprocess.run(['./soar', '-report-type', 'markdown', '-query', sql],
                             capture_output=True, text=True)
        if 'Severity: L1' in out.stdout or 'Severity: L0' in out.stdout:
            violations.append((file, sid, sql, out.stdout))
            print(f"[FAIL] {file}#{sid}")
        elif 'Severity: L2' in out.stdout:
            warnings.append((file, sid, out.stdout))

Jenkinsfile 里加一步:

stage('SQL Audit') {
    steps {
        sh 'python3 scripts/check_sql.py'
        sh 'test -f sql_violations.txt && exit 1 || exit 0'
    }
    post {
        always {
            sh 'python3 scripts/comment_mr.py'   // 把结果评论回 MR
        }
    }
}

关键是 exit 1 让流水线失败,MR 上显示一个红叉,合不进去。

explain 卡口:光看语法不够

SOAR 只能做静态分析,它不知道你的表里有多少数据、索引的实际选择性如何。比如这条 SQL 语法上完全没问题:

SELECT * FROM t_order WHERE create_time > '2021-01-01' AND merchant_id = 882341;

两个字段都有单列索引,SOAR 不会报错。但实际执行计划是全表扫(这是我前面那次事故的真实 SQL)。

所以第二道卡口是 explain 实测。我们在测试环境灌了生产 10% 抽样的数据(800 万行),CI 里对每个新增/修改的 SQL 跑一遍 EXPLAIN

import pymysql

def check_explain(sql):
    conn = pymysql.connect(host='test-db', user='audit', password=os.environ['DB_PWD'])
    with conn.cursor() as cur:
        cur.execute('EXPLAIN ' + sql)
        row = dict(zip([d[0] for d in cur.description], cur.fetchone()))
    return {
        'type': row['type'],
        'key': row['key'],
        'rows': row['rows'],
        'extra': row.get('Extra', '')
    }

卡口规则:

rules = [
    ('ALL',      lambda r: r['type'] == 'ALL',              '全表扫描'),
    ('NO_INDEX', lambda r: r['key'] is None and r['rows'] > 10000, '未使用索引且扫描行数超过 1 万'),
    ('SCAN',     lambda r: r['rows'] > 100000,              '扫描行数超过 10 万'),
    ('FILESORT', lambda r: 'Using filesort' in r['extra'] and r['rows'] > 10000, '大结果集排序'),
    ('TEMP',     lambda r: 'Using temporary' in r['extra'], '使用了临时表'),
]

第一次跑这个卡口,一次性扫出 47 条问题 SQL,其中 12 条全表扫描、31 条扫描行数超过 10 万。这些代码全在生产上跑着,只是因为访问量低或者数据量还没到临界点,一直没暴露。

这个数字挺吓人的。我们花了两周把 P0 的 12 条全表扫描全修了。

第三道防线:慢查询日报

线上的兜底。MySQL 8.0 的慢查询日志配置:

SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 0.5;        -- 我们的阈值是 500 ms
SET GLOBAL log_queries_not_using_indexes = OFF;   -- 不开,太吵
SET GLOBAL slow_query_log_file = '/data/mysql/slow.log';

log_queries_not_using_indexes 我特意关掉了。开启后小表(几百行)的全表扫描也会记录,一天能产生几十万条,完全没法看。

用 Percona Toolkit 的 pt-query-digest 分析:

$ pt-query-digest --limit=20 /data/mysql/slow.log > /tmp/slow_report.txt
# 3.2s user time, 180ms system time, 41.21M rss, 210.11M vsz
# Current date: Mon May 10 09:00:12 2021
# Hostname: db-order-01
# Files: /data/mysql/slow.log
# Overall: 1.82M total, 342 unique, 341.21 QPS, 1.21x concurrency _____
# Time range: 2021-05-10 08:00:02 to 09:00:02
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          4122s   501us     42s     2ms     4ms    42ms   401us
# Rows examine     841.22M       0  42.11M  461.82   1.21k  88.21k       0

# Profile
# Rank Query ID           Response time   Calls  R/Call  V/M   Item
# ==== ================== =============== ====== ======= ===== ==========
#    1 0x8F2A1B3C4D5E6F7  1822.4122s 44.2%  18221  0.1000  0.12 SELECT t_order_item
#    2 0x1A2B3C4D5E6F7081   812.8821s 19.7%   8821  0.0921  0.44 SELECT t_order

把 Top 20 抽出来,每天早上 9 点发到钉钉群。这个动作的价值不在报告本身,在于它让慢查询变成了一件"每天被所有人看见"的事。

同时配了实时告警:

单条 SQL 执行时间 > 5 秒        → 立即告警(说明有异常 SQL)
慢查询条数 5 分钟内 > 1000      → 警告(说明影响面在扩大)

订单和商品服务的三个月数据

这两个服务是 2021 年 2 月中旬接入卡口的,到 5 月中旬正好三个月:

指标接入前(2021-02)三个月后(2021-05)
日均慢查询条数182 万2.1 万
慢查询占比1.82%0.02%
单次最慢42 秒8.4 秒
因 SQL 引发的故障3 起0 起
CI 拦截的问题 SQL累计 213 条

213 条是三个月里 CI 拦下来的。这些 SQL 如果流到生产,按之前的概率算大概会引发 1 到 2 次故障。这个数字是我说服老板支持推广这件事的最有力论据。

而 5 月 10 号出事的营销服务,恰恰就是没接入的那一个。这个对比比任何汇报都管用。

几个执行中的教训

  • 一开始别卡太严。我们第一版把 L2、L3 也设成失败,结果第一天就有 11 个 MR 被卡,怨声载道。改成 L1 卡口、L2 以下只提示后,接受度高了很多。
  • 要有白名单机制。有些 SQL 确实必须全表扫(比如数据核对任务),硬卡会让开发绕过整个流程。我们加了一个 sql-audit-ignore.txt 文件,写进去的需要 DBA 审批。
  • 测试环境的数据量很重要。一开始我们的测试库只有 5 万行,EXPLAIN 结果全是 type=ALL 也看不出问题——因为优化器在小表上本来就会选全表扫。灌到 800 万行之后 EXPLAIN 才有参考价值。
  • 规则要定期修订。我们每两个月 review 一次误报和漏报,调整规则。第一版规则有 23% 的误报率,现在降到 4%。

小结

  • 同类故障半年 4 次,"下次注意"不管用,必须建机制。
  • 三道防线:开发阶段提示、CI 卡口、线上慢查询监控。第二道是核心
  • SOAR 做静态语法审核(卡 L1 及以上),测试环境 EXPLAIN 做实测卡口(全表扫、扫描超 10 万行)。静态分析发现不了"有索引但优化器不用"这类问题,必须靠 explain。
  • 测试环境要灌生产量级的数据,不然 EXPLAIN 没意义。
  • pt-query-digest 出日报发群,让慢查询被所有人看见。
  • 卡口别一次设太严,配白名单,规则定期修订。

最后说个观察:机制建起来之后,团队写 SQL 的习惯真的变了。以前是"能跑就行",现在提交前会自己先 EXPLAIN 一下。工具的作用不只是拦截错误,更是把规范变成一种肌肉记忆。

参考