凌晨1点47分监控群弹出一条磁盘告警DB-02主机 /data 分区使用率91%5分钟后直接冲到95%再过几分钟就要触顶。我第一反应是binlog堆积因为这台实例最近在做主从切换演练第二反应才是undolog或临时文件。登录服务器先跑df看了两眼排在前面的居然不是binlog而是/data/mysql/mysql-slow.log大小397G。这个文件一周之前我还看过不到2G。当时只是在巡检记录里写了一句“慢查询日志增长偏快”没有当回事。结果一周后它以这种形式把生产磁盘顶到报警线逼着我在凌晨起来做一次清理和参数优化。整个过程谈不上复杂但里面有几个操作顺序和参数组合的坑稍不注意就会把“清个日志”变成“丢现场”或者“清一个变两个”。这篇就把当时从排查到清理、到参数整定的完整过程写下来给遇到同样问题的朋友一个可参考的处置路径。1. 故障现场先从“最常见的磁盘吞噬者”排除起1.1 第一轮定位binlog、undo、临时文件全被排除告警来自Zabbix对挂载点的磁盘使用率监控不是MySQL自身的告警。所以我的排查顺序不是打开慢查询开关而是先找出哪些文件在吃空间。登录服务器后依次执行了下面几组命令df -hT du -h --max-depth1 /data 2/dev/null | sort -rh | head -20 find /data -xdev -type f -size 10G -exec ls -lh {} \; 2/dev/nulldu的结果很直接/data/mysql占了绝大部分空间其他目录加起来不到30G。于是继续往/data/mysql里面看用ls -lhS按文件大小倒序排列ls -lhS /data/mysql | head -30排在最前面的是mysql-slow.log大小显示为397G。同一目录下的binlog单个只有1G加上保留的近100个也才100G左右undo文件被自动截断过ibdata1 是12G远程临时目录里也没有大文件。第一个念头当然是“是不是binlog备份没有清理”但看到慢查询日志这个体积心里基本有底了。这里有个容易走弯路的地方很多人看到/data分区满会先去看binlog、redo、undo、临时表这些“惯性嫌疑对象”但慢查询日志这种文件经常被忽略。因为正常生产环境里它可能只有几百MB日志告警也不会单独盯着它看。可一旦写入量上来它就是个没有“水位”概念的黑洞比binlog难防多了。1.2 确凿证据MySQL进程还握着它找到大文件之后我没有马上清空而是先确认这个文件是不是正在被mysqld写。用lsof看一眼文件句柄lsof /data/mysql/mysql-slow.log输出里明确能看到mysqld进程持有它的写句柄这就是一个“活文件”不是废弃的备份或者归档残留。确认是慢查询日志本尊在写之后我心里反而踏实了问题范围不大就是日志层的事。但这里有个原则必须坚持在清理之前先保留现场。日志文件大到397G不能整份搬走但我至少应该截取头部和尾部各一部分记录文件起始时间戳方便后面定位根因。这一步在后来的溯源中起了大作用后面会细讲。2. 397G从哪来慢查询日志的“写放大”机制2.1 一条慢查询日志到底占多少空间MySQL 8.x在log_outputFILE时慢查询日志是纯文本写入。每一条日志由头信息、SQL语句文本、可能的参数信息组成典型长这样# Time: 2026-04-06T00:31:22.123456Z # UserHost: report_user[report_user] [10.20.30.40] Id: 882211 # Query_time: 8.234567 Lock_time: 0.000213 Rows_sent: 1 Rows_examined: 89001234 SET timestamp1749076282; SELECT c.customer_no, SUM(o.order_amount) FROM customer_info c LEFT JOIN order_info o ON CONVERT(c.customer_no USING utf8mb4) o.customer_no WHERE c.source_channel API GROUP BY c.customer_no ORDER BY c.customer_no LIMIT 20;这个例子里的SQL有254个字符加上头信息三行大约500字节左右。如果查询再复杂一点比如带多个子查询、上百行的UNION ALL日志条目上到1KB、2KB非常正常。也就是说慢查询日志大小取决于“慢查询条数 × 单条SQL文本长度”而不只取决于慢查询条数。很多人以为把慢查询时间调长一点日志大小就会线性下降其实如果某条SQL文本特别长且被高频重复记录文件照样会迅速膨胀。2.2 粗算一下397G意味着什么回到这次故障。我先看了日志头部和尾部的时间戳发现这个文件大约写了18个小时。按平均每条日志1KB粗算397G大概对应4亿条记录分摊到18小时差不多每秒6000条写入。这个数字对于一台高峰期QPS过万的生产实例来说并不夸张尤其是当long_query_time被设置得很小的时候。后来拉配置确认真正的触发条件是两件事叠加long_query_time被改成了0等于所有查询都要进慢日志log_queries_not_using_indexes也被打开且没有设置log_throttle_queries_not_using_indexes做限流。long_query_time0是个极其危险的配置。它意味着“慢查询日志”退化成了“全量查询日志”只要实例业务流量正常几个小时内就能写出几十GB甚至上百GB文件。这不是慢查询本身造成的而是日志采集口径出了问题。它就像一个水表本来只统计漏水结果有人把口径改成统计所有流过的水水箱再小也会被冲垮。2.3 数据库没慢是因为“慢”的判定根本不看响应时间还有一个值得解释的点为什么磁盘告警都95%了应用侧却迟迟没有人反馈数据库慢因为long_query_time0之后所有查询都会成为“待记录对象”包括大量本身就很快的查询。日志写入量高但对数据库性能的直接影响未必立刻体现在业务查询响应上。真正先出问题的是磁盘空间和IO负载。当文件系统使用率接近100%MySQL可能因为无法扩展临时文件、无法写入binlog而突然hang住那时候业务才会大面积超时。所以这次故障最讽刺的地方就在这里表面上是“慢查询日志爆炸”实际上在爆炸阶段应用还没觉得慢如果晚发现半小时磁盘彻底写满binlog写不进去整个实例才会真正变成生产事故。磁盘告警其实是给我们的最后刹车机会。3. 溯源在397G日志里捞出真正的“罪魁SQL”3.1 先切一段日志样本来分析397G的文件不能直接用编辑器打开也别在满盘状态下复制整个文件空间不允许。我采用的办法是“切片”mkdir -p /tmp/slowsample head -c 200M /data/mysql/mysql-slow.log /tmp/slowsample/head_200m.log tail -c 200M /data/mysql/mysql-slow.log /tmp/slowsample/tail_200m.log tail -n 200000 /data/mysql/mysql-slow.log /tmp/slowsample/last_200k.log三个文件各有用处head_200m看日志开头是什么时候开始暴涨的tail_200m看最近增长模式last_200k看最近20万条日志的分布。先把样本保存好再去清文件防止后续把现场清没了导致根因查不出来。这一步强烈建议做尤其当故障源还未知时日志本身就是唯一物证。3.2 mysqldumpslow 直接给出Top SQL切好样本后我直接用MySQL自带的mysqldumpslow分析last_200kmysqldumpslow -s c -t 10 /tmp/slowsample/last_200k.log mysqldumpslow -s at -t 10 /tmp/slowsample/last_200k.log-s c按次数排序-s at按平均查询时间排序。结果非常明确排名第一的SQL占整个样本总次数的83%而且执行时间集中在7到9秒之间检查行数在8000万到9000万行之间。输出大致是这样的Count: 34215 Time8.21s (280903s) Lock0.00s (0s) Rows1.0 (34215) report_user[report_user][10.20.30.40] SELECT c.customer_no, SUM(o.order_amount) FROM customer_info c LEFT JOIN order_info o ON CONVERT(c.customer_no USING utf8mb4) o.customer_no ...这种“Count几十万、平均时间8秒、Rows_sent只有1行”的查询是最典型的危险分子不是真的慢到没人用而是某处调用端在反复触发它。它每次执行8秒但日志里记录的时间跨度和Rows_examined都异常庞大导致写入量被无限放大。3.3 Explain验证字符集转换把索引废了为了确认根因我拿这条SQL单独做了EXPLAINEXPLAIN SELECT c.customer_no, SUM(o.order_amount) FROM customer_info c LEFT JOIN order_info o ON CONVERT(c.customer_no USING utf8mb4) o.customer_no WHERE c.source_channel API GROUP BY c.customer_no ORDER BY c.customer_no LIMIT 20;执行计划里两张大表都走全表扫描其中一个表的rows估算超过4000万Extra里出现Using join buffer (hash join)。问题很直观连接条件里对c.customer_no做了CONVERT(... USING utf8mb4)函数包裹索引在这个表达式上完全失效优化器只能放弃索引选择全表扫描加join buffer。所以这次故障的完整链条是应用端某个报表任务在跑一条跨多表的汇总SQL由于字符集转换导致索引失效SQL每次要扫近9000万行耗时8秒以上调用端因为外部接口超时设定得太短2秒就判定失败失败后立即重试慢查询日志因为被改成long_query_time0和log_queries_not_using_indexesON把每一次执行都原样写进去每次日志条目又因为SQL文本本身很长达到1KB以上最终18小时形成397G日志。单纯修SQL是一条路但只修SQL不够因为调用端重试、日志开关、索引失效这三个环节任何一个不处理下次换一条SQL还能炸。所以现场处置顺序必须先是“止血”然后才是“治病”。4. 磁盘空间救援如何安全地缩小一个正在被MySQL写入的文件4.1 为什么不能直接rm也不能只truncate很多人的第一反应是rm -f /data/mysql/mysql-slow.log删了就完事。这个操作在MySQL运行时会留下一个“幽灵文件”进程还握着旧inode的写句柄目录项虽然删了但磁盘空间一点都不会释放。你执行完rm后看df会发现空间没变然后就会陷入“文件明明没了但磁盘还是满的”的困惑。正确思路是关闭慢查询日志这个写入源头截断文件再重新打开。但要注意一个细节如果只执行truncate -s 0而MySQL还在同一个文件句柄上继续写那么文件偏移量并不会归零后续写入会从原来的偏移位置继续日志文件中间就会出现一个巨大的“空洞”实际占用的空间很快又会涨回去。所以标准的操作顺序必须是“关闭日志 → 截断文件 → 重新打开日志”不能只做一半。4.2 标准操作序列关闭 → 截断 → 开启我当时执行的完整序列如下# 1. 先关闭慢查询日志切断写入源头 mysql -uroot -p -e SET GLOBAL slow_query_log OFF; # 2. 确认已经关闭 mysql -uroot -p -e SHOW VARIABLES LIKE slow_query_log; # 3. 将文件截断为0 truncate -s 0 /data/mysql/mysql-slow.log # 4. 确认磁盘空间 df -hT /data # 5. 重新打开慢查询日志 mysql -uroot -p -e SET GLOBAL slow_query_log ON;执行完第4步时df显示/data的使用率直接从95%回落到61%397G的空间全部释放。第5步重新开启前必须确认根因SQL还在跑否则刚开启又会立刻报警。我当时是先保持关闭状态把SQL和参数都改完最后才重新开启。还有一个替代方案是mysqladmin flush-logs它会让MySQL关闭当前慢日志文件并重新打开一个同名文件。但如果文件已经被truncate成0单纯flush也足够从头开始写。把“关闭→截断→开启”这个顺序记牢比纠结用哪个命令更安全。4.3 顺手把日志挪出数据目录这次清理的同时我还做了一个变更把慢查询日志文件从/data/mysql挪到独立挂载的日志盘/var/log/mysql下。原因很简单日志不应该和数据文件放在同一个文件系统。/data满会影响binlog写入进而影响整个实例可用性而/var/log满顶多影响日志记录不会直接拖垮数据库。迁移步骤如下# 创建日志目录属主改成mysql install -d -o mysql -g mysql /var/log/mysql # 修改my.cnf中的slow_query_log_file路径 # [mysqld] # slow_query_log_file /var/log/mysql/mysql-slow.log # 动态修改并重开日志 mysql -uroot -p -e SET GLOBAL slow_query_log_file /var/log/mysql/mysql-slow.log; FLUSH LOGS; # 确认新路径 mysql -uroot -p -e SHOW VARIABLES LIKE slow_query_log_file;执行FLUSH LOGS时如果旧文件已经截断为0MySQL会正常创建新文件。目录权限如果不对MySQL可能写不进去所以install -d -o mysql -g mysql这一步不能省。这里还有个容易踩的坑如果你直接把日志路径改到一个MySQL进程没有权限的目录slow_query_log虽然显示ON但实际写日志会失败而且错误可能只出现在错误日志里不显眼。5. 参数优化让慢查询日志有据可查又不失控5.1 最终落地的my.cnf参数清单故障处理完我把这套参数定成了该实例的基线配置[mysqld] slow_query_log 1 slow_query_log_file /var/log/mysql/mysql-slow.log long_query_time 2 log_queries_not_using_indexes 1 log_throttle_queries_not_using_indexes 10 min_examined_row_limit 1000 log_output FILE log_slow_admin_statements 0 log_slow_replica_statements 0下面对每个参数说明为什么这么设。5.2 每个参数背后的防呆逻辑long_query_time 2只记录执行超过2秒的查询。之前被改成0是全量记录必须纠正。如果后续业务SLA要求更严可以降到1秒但尽量不要用0。log_queries_not_using_indexes 1记录没走索引的查询这个开关很有价值它能把“隐形的全表扫描”暴露出来。但单独打开它风险很大必须配合下面的限流参数。log_throttle_queries_not_using_indexes 10这是这次故障里最关键的“保险丝”。它的作用是限制“未使用索引类慢查询”每分钟最多写10条超过部分只计数不写SQL。没有它log_queries_not_using_indexes会把几十万条同类SQL全部写进去。min_examined_row_limit 1000只记录“检查行数≥1000”的查询。这个参数能把那些执行时间虽然超阈值、但检查行数很少的查询过滤掉减少大量低价值日志。它与long_query_time是“同时满足”的关系不是二选一。log_output FILE继续用文件方式输出。MySQL 8也可以把慢日志写到mysql.slow_log表里方便查询但表同样会膨胀而且清理要走SQL比文件轮转麻烦。对生产环境我偏好FILE加外部轮转。log_slow_admin_statements 0不记录ALTER TABLE、OPTIMIZE TABLE等管理语句。这类语句在执行期间本身就长如果被记录等于把大DDL全量写日志容易造成二次膨胀。log_slow_replica_statements 0副本上来自复制线程的慢语句也不记录。如果开了这个从库在复制大事务时会把SQL大量写进日志危害类似。5.3 动态调整的坑全局变量不等于所有会话立即生效参数配置写好后我先把配置落了my.cnf然后用SET GLOBAL动态调整避免重启实例SET GLOBAL slow_query_log OFF; SET GLOBAL long_query_time 2; SET GLOBAL log_queries_not_using_indexes ON; SET GLOBAL log_throttle_queries_not_using_indexes 10; SET GLOBAL min_examined_row_limit 1000; SET GLOBAL slow_query_log_file /var/log/mysql/mysql-slow.log; FLUSH LOGS; SET GLOBAL slow_query_log ON;这里有个非常容易踩的坑SET GLOBAL只影响新建立的会话已经存在的连接池老会话仍然保留原来的会话级变量。也就是说如果你只改了全局配置但应用连接池里的连接还是旧参数慢日志可能继续按旧标准写一段时间。我当时处理的办法是先把slow_query_log保持关闭等主要连接池回收一轮大概几分钟再重新开启。如果业务不允许等也可以在新版本中手动对特定连接执行SET SESSION long_query_time 2但生产环境不建议操作应用侧连接。用“关闭 → 等回收 → 开启”的顺序最稳。动态调整完还要验证参数是否真的生效SHOW GLOBAL VARIABLES LIKE slow_query_log; SHOW GLOBAL VARIABLES LIKE long_query_time; SHOW GLOBAL VARIABLES LIKE log_throttle_queries_not_using_indexes;同时用下面这条SQL验证新日志文件在正常增长ls -lh /var/log/mysql/mysql-slow.log tail -n 5 /var/log/mysql/mysql-slow.log看到新路径下有新条目产生才说明这次参数优化真正闭环。6. 复盘与长效机制给慢查询日志装上“水位线”6.1 轮转脚本不能省即使参数调好了慢查询日志仍然会持续增长只是增长速度从“爆炸式”变成“可接受式”。所以必须配套轮转机制。我在crontab里放了一个小时级脚本#!/bin/bash LOG/var/log/mysql/mysql-slow.log MAX_SIZE$((4*1024*1024*1024)) NOW$(date %Y%m%d%H%M) if [ $(stat -c%s $LOG 2/dev/null || echo 0) -gt $MAX_SIZE ]; then mv $LOG $LOG.$NOW mysqladmin flush-logs gzip $LOG.$NOW fi逻辑很简单日志超过4G就轮转一次先改文件名再让MySQL重新打开新文件最后把旧文件压缩归档。注意顺序不能乱如果先gzip再flush压缩期间MySQL还在往旧文件写会导致文件内容不完整。运维脚本里这种顺序错误非常隐蔽实际执行时要反复验证。6.2 监控指标要细分到“单文件增长速率”这次故障还暴露了一个监控盲区我们只监控了分区使用率没有监控慢日志文件本身。分区使用率达到95%的时候距离写满只剩几个小时留给处理的时间窗口太小。我后来在监控系统里增加了两个触发器慢查询日志文件大小超过2G时告警慢查询日志文件在1小时内增长超过500MB时告警。实现方式可以很朴素用cron跑一个检查脚本把stat -c%s的结果和上一次记录值做差超过阈值就调监控API发告警。如果是Prometheus体系可以用textfile collector或node_exporter的自定义指标原理一样。关键是让“日志增速”成为一个独立监控项而不是被动等磁盘满了再响应。6.3 这次故障真正教会我们的事把整个事件复盘下来技术动作其实不复杂但有几个原则值得写进团队规范日志开关就是容量开关。任何日志从“关闭”到“开启”都要先估算写入量。慢查询日志尤其如此因为它可能会被全表扫描、无索引查询、应用重试三类因素同时放大。先止血再找根因。遇到磁盘告警第一步永远是切断写入源也就是SET GLOBAL slow_query_logOFF然后再分析SQL、设计参数。不要在磁盘要满的时候还想着“先看看日志里是什么”那是把现场保全和故障恢复的顺序搞反了。调用端重试机制必须设置上限。这次的SQL本身确实有问题但真正把日志写成397G的是API在超时后不停重试。如果重试次数有上限即使SQL慢日志量也只是线性增长而不是爆发式增长。慢日志文件不允许放在datadir。日志盘和数据盘要分离这是这起事故留给我最深的教训。处理完这个故障之后我习惯性看了一眼新慢日志文件两条记录之后又安静下来了。磁盘水位持续稳定在60%以下。复盘文档最后一行写着“397G不是慢查询造成的是一次日志误配置、一条低效SQL和一个没有重试上限的调用端共同造成的。”这句话后来成了团队排查日志类故障的标准开场。