上周处理了一起线上告警凌晨三点监控平台报警某业务库的磁盘使用率冲破了90%。我登录服务器第一反应不是去看业务而是去看日志目录du -sh /var/lib/mysql/*一跑真相基本就摆在那儿了binlog日志攒了一百多个文件慢查询日志也膨胀到了好几个G。这种场景对专门做数据库运维的人来说早就见怪不怪但很多从业务开发转到后端的同学一提到MySQL日志就头疼——知道日志很重要可真出了故障却搞不清楚该翻哪个文件、看哪几行、怎么判断严重程度。这篇文章我打算把MySQL日志这个主题一次讲透。从日志家族的全景梳理到binlog和redo log的工作原理再到慢查询日志的实战优化最后用一次真实排查链路收尾。如果你正准备系统理解MySQL日志或者正在为日志把磁盘撑爆而发愁这篇应该能帮你省不少力气。1. 先看清全家谱MySQL日志到底分几类、归谁管MySQL日志从来不是一个东西它是一整套分层体系的组合。我第一次完整梳理这个体系的时候脑子里最大的收获就一句话先分清日志属于Server层还是InnoDB存储引擎层再看它记的是逻辑还是物理后面所有排查思路都会顺很多。1.1 一张表理清六类日志的定位这里直接上表格把最核心的信息先摆出来后面再逐类拆解。日志类型所属层核心作用默认状态错误日志error logServer层记录启动、运行、关闭阶段的错误与警告故障现场第一入口开启通用查询日志general logServer层记录所有连接和所有SQL语句适合审计与抓“幽灵查询”关闭慢查询日志slow query logServer层记录执行时间超过阈值的SQL性能优化核心依据关闭二进制日志binlogServer层记录数据变更逻辑主从复制和数据恢复依赖它由配置决定重做日志redo logInnoDB层记录数据页的物理修改崩溃恢复的关键底牌引擎默认开启回滚日志undo logInnoDB层记录事务回滚所需的逆向操作支撑MVCC多版本控制引擎默认开启除了这六类还有一类中继日志relay log它本质上是binlog在从库上的“转运副本”专门服务于主从复制链路排查复制问题的时候逃不开后面实战部分会带到。1.2 分层最大的价值决定排查思路我看到过不少同学排查问题时习惯性地把所有日志当成“一个东西”——一律先看有没有ERROR没看到就直接去查业务代码。这种思路在大多数情况下其实是碰运气。日志分层之后思路就清晰多了。Server层的错误日志和通用查询日志回答的是“发生了什么”偏逻辑视角比如哪个连接失败了、哪条SQL执行报错了InnoDB层的redo log和undo log回答的是“数据为什么会变成现在这样”偏物理和事务视角比如崩溃之后为什么没丢数据、某个事务为什么能回滚。真到排障的时候大多数场景是先在Server层定位到现象再下沉到InnoDB层分析根因这个顺序几乎贯穿所有MySQL疑难杂症。1.3 几个查看配置的入口命令日志相关的配置都可以通过SQL直接查不用翻配置文件猜SHOW VARIABLES LIKE log_error; SHOW VARIABLES LIKE general_log%; SHOW VARIABLES LIKE slow_query_log%; SHOW VARIABLES LIKE log_bin; SHOW VARIABLES LIKE binlog_format; SHOW VARIABLES LIKE innodb_log_file_size; SHOW VARIABLES LIKE innodb_redo_log%;实际执行的时候我建议把变量名后面那个%加上因为很多日志参数是一组前缀相同的变量比如slow_query_log、slow_query_log_file、slow_query_log_use_global_log_control。一次性都查出来比一个个猜名字要高效得多。2. 错误日志与通用查询日志两个经常被忽视的老实人这俩日志平时讨论热度远不如binlog和慢查询但真出了事它们往往是最早记录现场的那个。我对它们的定位很简单错误日志是看门大爷通用查询日志是临时架设的高清摄像头。2.1 错误日志启动失败和崩溃现场的第一入口错误日志默认在数据目录下文件名通常是hostname.err生产库里我们一般会通过log_error参数单独指定到一个固定路径方便采集。它记录的内容非常杂从mysqld启动时的初始化信息到InnoDB的崩溃恢复进度再到复制线程报错、连接数打满全都会写进来。几个典型的读取场景启动失败。[ERROR] Cant start server: Bind on TCP/IP port看到这种就别先去查应用了八成是3306端口被占[ERROR] Cant create/write to file /tmp/mysql.sock这是socket目录权限或磁盘只读问题。错误日志会把具体是哪一步挂的写得很清楚。InnoDB崩溃恢复。日志里会出现[Note] InnoDB: Starting crash recovery这时候千万别重启库让恢复流程跑完否则可能二次损伤数据文件。连接数打满。大量[Warning] Too many connections刷屏说明max_connections不够用或者应用连接池没释放。看错误日志有个习惯很关键不要只搜ERROR。Warning级别同样要定期翻很多故障是先从Warning开始的比如磁盘接近满、复制延迟严重、页清理线程跟不上这些都会以Warning的形式提前两三天冒头。养成每周扫一遍Warning的习惯能提前消灭掉不少线上的大雷。2.2 通用查询日志定位“幽灵SQL”的临时手段通用查询日志会把所有客户端发来的SQL原样记下来包括SELECT、SET、COMMIT这种平时“看不见”的操作。它的代价非常直观——I/O压力翻倍、日志量爆炸所以生产环境默认关闭是对的。但它有一类无法替代的使用场景**怀疑有人在执行你没见过的SQL或者开发来问你“这个库到底被谁在查”开着它抓几分钟就能真相大白。**比如某个核心表的数据经常被莫名修改但所有业务代码都查不到写入逻辑这时候开通用日志把SET GLOBAL general_log ON执行下去几分钟后去文件里翻一笔update语句的来源IP问题当场就定位了。我用通用日志从来都是“用完即关”SET GLOBAL general_log ON; -- 等待采集 SET GLOBAL general_log OFF;而且会临时把日志文件指到单独的路径比如/tmp/mysql_general.log避免它和日常业务日志搅在一起SET GLOBAL general_log_file /tmp/mysql_general.log;这里有一个小坑要提醒如果系统重启mysqld可能会尝试重建这个日志文件如果你只改了全局变量没改配置文件重启后它会回到默认路径继续写但前面的临时配置已经丢了。所以真正排查问题的时候最好同时把配置文件的对应项改掉或者干脆不要依赖临时路径直接在默认位置清理干净了再开。3. 慢查询日志性价比最高的性能优化入口如果说只能给MySQL日志体系加一项配置我第一个选慢查询日志。它在所有日志类型里是“投入产出比”最高的一类——开启成本极低但能持续不断地把数据库里最需要优化的SQL送到你面前。3.1 上线前就应该配置好的参数慢查询日志的核心参数就四个我建议在MySQL实例初始化的时候就写入配置文件而不是等出问题了再现场改slow_query_log ON slow_query_log_file /var/log/mysql/slow.log long_query_time 1 log_queries_not_using_indexes ON min_examined_row_limit 1000long_query_time单位是秒。生产主库我一般设1秒也就是执行超过1秒的SQL全部记录分析型从库或者专门的只读库可以设到0.2甚至0.1因为副本上的查询通常对延迟更敏感很多慢在“毫秒级”的查询在主库上无感但在从库上会影响业务侧读路径。log_queries_not_using_indexes是记录不走索引的SQL这个参数必须和min_examined_row_limit一起配否则会记录大量“没走索引但只扫了几行”的小查询日志里全是噪音。后面这个参数的意思是扫描行数超过1000行且没走索引的SQL才记录低于这个阈值的放过有效过滤掉sys库和临时表的干扰。如果你是在线调整也可以直接用SQLSET GLOBAL slow_query_log ON; SET GLOBAL long_query_time 1; SET GLOBAL log_queries_not_using_indexes ON; SET GLOBAL min_examined_row_limit 1000;注意long_query_time修改后只对新连接生效老连接可能还沿用旧值排查问题如果发现设置没生效先看看是不是连接池里的长连接没重建。3.2 分析慢日志两把趁手的工具日志文件本身就是文本可以直接tail看但生产环境的慢日志往往一天就能攒几百MB裸眼盯文件效率太低。这里推荐两把工具第一把mysqldumpslowMySQL自带不装额外依赖mysqldumpslow -t 20 /var/log/mysql/slow.log这个工具会把结构相似的SQL自动归类比如WHERE user_id N这种不同参数值的语句会合并成一条模板这样你看到的不是几百条重复SQL挤在一起而是“同一类SQL总共执行了多少次、平均耗时多少”。它的问题在于展示信息不够细没有执行计划的关联适合快速看一眼Top N。第二把pt-query-digestPercona Toolkit主力工具分析慢日志的头号选手pt-query-digest /var/log/mysql/slow.log它的输出会把每条SQL模板按总耗时排序然后给出每个模板的调用次数、平均耗时、响应时间占比还能按库名、用户名、时间维度拆分。最关键的是它会直接展示“这一类SQL具体是什么”比mysqldumpslow更直观。用过几次之后你再也不想回去手动翻慢日志了。3.3 完整优化链路从慢日志到执行计划再到验证分享一个我最近优化过的案例帮助理解慢日志到底怎么用。某订单系统的接口最近偶发超时业务方反馈体感很明显。我第一时间翻了慢查询日志很快锁定了一条模板SELECT * FROM orders WHERE user_id 12345 AND create_time BETWEEN 2024-01-01 AND 2024-06-01 ORDER BY create_time DESC LIMIT 20;慢日志显示这类查询平均执行1.9秒最大4.7秒。接下来用EXPLAIN看一下执行计划EXPLAIN SELECT * FROM orders WHERE user_id 12345 AND create_time BETWEEN 2024-01-01 AND 2024-06-01 ORDER BY create_time DESC LIMIT 20;结果里type是ALL也就是全表扫描rows估算到了80万行。orders表有接近千万行这个SQL每次都要扫全表再排序慢是必然的。优化动作很简单加一个联合索引ALTER TABLE orders ADD INDEX idx_user_time (user_id, create_time DESC);加完再跑执行时间掉到20毫秒。整个过程从看慢日志到定位问题再到验证效果加起来不超过半小时。慢日志的价值就在于它把“排查目标”直接指到了这条SQL上你不需要去全量代码里猜哪条语句性能差。3.4 慢日志的超时上下文与业务钩子慢日志里除了SQL文本还会记录执行时间戳、用户、数据库、连接ID。建议业务在写关键SQL时顺手在SQL里带一个注释标记比如/* ordercenter-query-detail */ SELECT ...这样后续从慢日志分析时直接就能看出是哪条业务链路产生的不用再靠SQL文本去代码库里搜索。这个习惯花不了几秒但能在日志统计分析时节省大量时间。4. binlog与redo logMySQL事务安全的“双引擎”到了整个体系最核心的部分。binlog和redo log在日志讨论里出现的频率最高被误解的次数也最多。很多人把它们统称“日志”实际上它们的定位、格式、使用场景完全不同。4.1 redo log物理层面上的“后悔药”redo log是InnoDB存储引擎的日志记录的是“数据页第几页第几个偏移量被改成了什么”属于物理粒度的变更。它的核心机制是WALWrite-Ahead Logging——数据页落盘之前先把变更记录写入redo log并且这个日志文件是顺序写的速度远快于随机写。为什么要这么做InnoDB的数据页默认16KB每次修改如果直接写回磁盘需要随机I/O成本太高。所以InnoDB采用“先写日志、再异步刷盘”的策略你执行一条UPDATE内存中的Buffer Pool数据页被修改了同时redo log把这次修改记录下来事务就能提交真正的数据页等后台线程攒够一批再刷回磁盘。如果这一刻数据库崩溃缓冲池里的脏页还没来得及落盘没关系重启后InnoDB会回放redo log把那些没来得及写回的数据页重新恢复出来。这就是为什么redo log在崩溃恢复里是不可或缺的。它管的是“数据一定能恢复”而不是“SQL能重放”。4.2 binlog逻辑层面上的“回放录音带”binlog属于Server层记录的是逻辑变更。说白了它有三种格式STATEMENT记录原始SQL文本ROW记录每一行变更前后的完整值MIXED是两者的混合。8.0之后默认就是ROW我强烈建议线上无条件用ROW。为什么STATEMENT格式记录的是“当时执行的那条SQL”但SQL里如果带了NOW()、UUID()这种非确定性函数同一SQL在主库和从库执行出来的结果可能完全不一样。更麻烦的是如果应用逻辑依赖数据库的隐式状态回放起来很容易出幺蛾子。ROW格式则不一样它记录的是一行数据“从什么值变成什么值”不依赖SQL上下文回放一定精确主从复制和数据恢复都看得清清楚楚。binlog的主要用途有两个一是主从复制从库拉主库的binlog事件在本地回放就能保持数据一致二是基于时间点或位点的数据恢复比如全量备份之后用binlog把备份点之后的所有变更重放到某个误操作之前的时刻就能找回被误删的数据。4.3 两阶段提交为什么两个日志必须配合这里有个关键机制如果事务只写binlog不写redo log崩溃恢复时redo log可能回放到一半binlog里少了一条事件复制链路就断了如果只写redo log不写binlog那崩溃恢复倒是没问题但主从复制的从库会缺失这个事务。所以MySQL必须让两个日志对齐用两阶段提交来解决事务执行期间InnoDB把变更写入redo log并标记为prepare状态。事务提交时先写binlogbinlog落盘成功后再把redo log的状态改记为commit。崩溃恢复时检查redo log里的事务状态已经prepare但没有commit的事务再看binlog里有没有对应事件有就继续提交没有就回滚。这个过程可以类比成办合同你先登记签字prepare然后拿去备案写binlog最后盖上公章commit。中间任何一步断了整个事务都不会生效。理解这个机制你就明白为什么说binlog和redo log是事务安全的双保险缺一不可。4.4 binlog的常用配置与查询命令实际运维中binlog相关配置通常长这样server_id 100 log_bin /var/lib/mysql/binlog binlog_format ROW max_binlog_size 512M binlog_expire_logs_seconds 604800max_binlog_size单文件上限超过后自动滚动到下一个文件binlog_expire_logs_seconds是自动清理周期按秒计604800就是7天。文件的滚动方式跟应用日志很像binlog.000001、binlog.000002这样编号递增定期自动切换和清理。查看当前binlog状态SHOW BINARY LOGS; SHOW MASTER STATUS;解析binlog内容常用mysqlbinlog工具mysqlbinlog --no-defaults --base64-outputDECODE-ROWS -v /var/lib/mysql/binlog.000023ROW格式的binlog默认以base64编码展示加上-v和--base64-outputDECODE-ROWS就能看到可读的行级变更内容在排查“某条数据到底什么时候被改过”这类问题时这个命令是标准答案。4.5 关于binlog的一个高频问题能不能直接删文件这个问题的答案是**可以删但绝对不推荐直接rm文件。**正确的姿势是通过PURGE BINARY LOGS命令清理PURGE BINARY LOGS TO binlog.000012; PURGE BINARY LOGS BEFORE 2024-06-01 00:00:00;原因是MySQL内部维护着一个binlog索引文件直接rm会让索引和实际文件对应不上更严重的是如果从库正在拉取你删掉的那个文件复制会立刻中断。即使一个binlog确实已经过期了也要先确认所有从库都已经消费完它的位置再执行PURGE。用命令清理MySQL会自己处理索引和文件句柄安全得多。还有一个很容易踩的坑**不同版本binlog过期参数不一样。**MySQL 5.7经典版本用的是expire_logs_days按天设置MySQL 8.0虽然还兼容这个参数但更推荐用binlog_expire_logs_seconds按秒设置更灵活到了8.4以上expire_logs_days直接被移除了只保留按秒的版本。如果你拿着老的配置直接迁移到8.4启动阶段会报参数不存在这类问题我已经见了好几次顺手写在这里提醒一下。5. 磁盘说爆就爆日志清理的正确姿势与踩坑记录日志把磁盘写满这是MySQL运维里最经典的故障之一。处理这种问题我一般按照“先定位、再处置、后预防”三个步骤走每一步都有值得说的讲究。5.1 第一步定位到底是什么日志在膨胀登录服务器后先不要急着删用一条命令看各个文件的大小du -sh /var/lib/mysql/* | sort -rh | head -20这个命令会按大小倒序显示整个数据目录下的文件哪个日志占了大头一目了然。再用ls -lhtr /var/lib/mysql/看最近修改时间确认哪些日志还在持续增长。定位清楚是binlog、慢查询、还是错误日志在膨胀才能选择对应的处理手段。5.2 第二步分类型清理如果大头是binlog执行上面的PURGE BINARY LOGS命令如果大头是慢查询日志或错误日志这类文本日志可以用truncate -s 0或者 /var/log/mysql/slow.log直接清空文件内容不需要中断mysqld进程比rm安全得多。这里有几个常见错误要避免很多人处理日志膨胀时习惯直接rm /var/lib/mysql/binlog.000011这是很危险的。从库复制位置可能正好在这个文件里删了立刻中断而且binlog索引文件还记着它主库自己也会一脸懵。有人用cat /dev/null slow.log这个操作方向没问题但它和你用清空是同一个效果关键在于文件被mysqld进程打开着清空文件内容不等于删除文件磁盘空间会释放。千万记住rm一个被进程打开的文件磁盘空间不会马上释放因为进程还持有文件句柄必须杀掉进程或重启才能释放。这就是为什么我强烈推荐truncate而不是rm。5.3 第三步用logrotate做日志轮转日志不可能永远靠人工清生产环境一定要配logrotate。下面是一个在线MySQL实例上的经典配置/var/log/mysql/slow.log { daily rotate 14 compress delaycompress missingok notifempty postrotate /usr/bin/mysqladmin flush-logs endscript }这段配置表示慢查询日志每天切割一次保留14份切割后压缩上一份并且切割后执行mysqladmin flush-logs让mysqld切换并打开新的日志文件。如果不执行flush-logsmysqld会一直往同一个inode里写切割就失去了意义。错误日志和通用查询日志也可以套用同一套模板只要把路径换掉就好。配置好logrotate之后别忘了用logrotate -d /etc/logrotate.d/mysql验证一次配置确认没有语法错误。5.4 关于“删了文件空间不释放”的一次处理记录有段时间我遇到一个典型问题慢日志已经清空了但磁盘空间依然满的。df -h显示使用率没变可du看文件明明只剩几十KB。原因就是之前用rm删掉了慢日志文件而mysqld进程始终持有该文件句柄导致数据块删不掉空间被“僵尸文件”占着。处理办法很简单找到进程打开的已删除文件句柄lsof | grep deleted确认是哪个进程持有了旧日志然后要么重启mysqld进程要么优雅一点——直接清空现有文件内容让mysqld写的新日志落到新的inode上。从这里开始我再也不在生产环境用rm处理正在写的日志文件一律truncate或者通过logrotate解决。6. 一次真实的日志排查链路从复制延迟到揪出大事务前面讲了不少方法论最后用一个我近期处理的真实案例把日志排查的完整链路串起来。这个案例虽然不算惊心动魄但特别有代表性几乎把错误日志、慢查询日志、binlog三类日志全部用上了。6.1 故障现象主从延迟突破600秒某天凌晨监控平台报主从复制延迟超过600秒而且还在持续上涨。我们数据库用的是经典的一主一从架构从库承担一部分分析型查询。延迟这么高意味着从库的数据差不多滞后了十分钟如果此时主库宕机做切换业务会丢相当一部分最新数据性质很严重。6.2 第一跳错误日志没有致命信息但有一条奇怪Warning我先看从库的错误日志复制线程没有报错Last_SQL_Error也是空的说明不是复制中断而是执行能力跟不上。当然日志里有一条很显眼的Warning[Warning] InnoDB: page_cleaner: 1000ms intended loop took 4560ms。这行日志的意思是InnoDB后台刷脏线程超过了预期循环时间通常是磁盘I/O吃紧的信号。顺着这条往下查I/O繁忙不是来源只是结果——那什么操作把I/O打满了6.3 第二跳慢查询日志里锚定了大家的原始SQL接着翻慢查询日志从库上慢日志记录了大量DELETE操作单条执行时间超过3秒其中一条的Rows_examined显示扫描了180万行。SQL长这样DELETE FROM t_operation_log WHERE status 0;熟悉业务的一看就知道坏了t_operation_log是一张千万级流水表这个DELETE没有加时间范围、没有LIMIT、没有按主键批量循环直接全表范围删除。它在主库执行时因为主库磁盘性能好、并发低勉强在几十秒内完成了但到了从库单线程回放这个超大事务时日志里这一条从库会话就得执行非常久后续的所有变更全部排队延迟就像滚雪球一样越滚越大。6.4 第三跳用binlog确认事务体量和影响行数确定SQL之后我用mysqlbinlog把主库对应时段的binlog拉出来找到这条DELETE事务。因为binlog_format是ROW事件展开后能直接看到这个事务被拆成了多少条行级删除总行数约189万单个事务在binlog里占用了近500MB空间。看到这个数据一切就都解释得通了一个大事务在从库回放时被无限放大直接把从库的复制线程拖垮。6.5 根因与处置根因很快定位夜间定时任务本意是按批次清理7天前的过期日志但脚本在传参时出了问题导致清理条件失效变成了全表delete。处置分三步走先在从库上确认没有复制报错然后等这个超大事务回放完成接着在主库KILL掉残留的连接防止再次触发最后修复定时任务脚本加上明确的时间范围和分批提交逻辑并对该表建立合适的时间索引。事后复盘这个案例最大的启示是**如果当初没开慢查询日志我们可能还要花数小时从业务代码里逐条排查如果没有用ROW格式的binlog我甚至无法快速确定这个DELETE到底影响了多少行。**日志配置在故障前就位才是排障效率的根本保障。最后再说几句掏心窝的话日志这种东西平时存在感很低既不会给系统加性能也不会给业务加功能但等到出了故障它就是你唯一的救星。我见过太多项目MySQL都上线两三年了慢查询日志还是关着的binlog过期时间也没配过等到磁盘被日志撑爆才手忙脚乱。说实话等你需要看日志的时候才想起配置这属于给自己挖坑。我自己现在每接手一个新环境第一件事就是把错误日志的路径、慢查询的阈值、binlog的保留策略全部过一遍顶多花十分钟换来的却是日后排查问题时的无数个从容时刻。这篇文章如果能帮你少踩一次日志的坑就算没白写。