凌晨两点被电话叫醒,对面传来一句"数据库好像挂了"。我揉着眼睛打开电脑,第一反应不是看监控面板,而是直接翻日志。但翻了半天才发现——有些日志没开,有些开了不知道怎么看,有些看了也不知道说明什么。那种感觉,做过数据库的人应该都懂。
MySQL的日志体系,说白了就是四样东西:错误日志、二进制日志(binlog)、慢查询日志、通用查询日志。它们各管一摊,相互独立又彼此补充。搞清楚这四种日志分别记什么、怎么开、怎么看、能帮你解决什么问题,是排查任何MySQL故障的基本功,也是从"会用MySQL"走向"能救火"的分水岭。这篇就按我日常实战的经验,把四种日志彻底捋一遍,顺带分享一些只有踩过坑才明白的细节。
1. 先说清楚一件事:四种日志各自管什么,别混着看
很多人提到"MySQL日志"第一反应就是binlog和慢查询日志,错误日志和通用查询日志常年被忽略。这很正常,因为前两种在复制和性能调优里出镜率太高。但真要出事的时候,四种日志的分工完全不同,混着看很容易误判方向。
我一般这样给刚接触的人讲:错误日志是MySQL自己写的病历本,启动失败、磁盘满、InnoDB损坏、复制报错,都记在里面;二进制日志是所有数据变更的录像带,谁在什么时间改了哪一行,都能翻出来;慢查询日志是体检报告里的异常指标,专门把执行时间超过阈值的SQL捞出来;通用查询日志则是一个过于诚实的录音笔,每个连接、每条SQL都原原本本地录下来,所以日常默认是关着的。
从配置角度看,四种日志也完全是独立的开关,互不影响。
| 日志类型 | 默认状态 | 默认位置/文件 | 核心配置项 | 记录内容 |
|---|---|---|---|---|
| 错误日志 | 开启 | datadir下主机名.err | log_error | 启动关闭过程、错误信息、警告 |
| 二进制日志 | MySQL 8.0起默认开启,5.7默认关闭 | datadir下mysql-bin.000001 | log_bin、binlog_format、sync_binlog | 所有导致数据变更的操作 |
| 慢查询日志 | 关闭 | datadir下主机名-slow.log | slow_query_log、long_query_time | 执行时间超过阈值的SQL |
| 通用查询日志 | 关闭 | datadir下主机名.log | general_log、log_output | 所有客户端连接和所有SQL语句 |
这张表看清楚之后,你已经能建立基本的排查直觉了:系统启动不了看错误日志,数据莫名其妙变了看binlog,业务变慢看慢查询日志,完全不知道谁在干什么时才开通用查询日志。接下来四种日志分别展开,每种我都会给出实际场景里的用法和坑。
2. 错误日志:平时最不起眼,出事时第一个要翻的证据
错误日志是MySQL最先有、也最"朴素"的日志。它不记录具体的SQL,只记录MySQL服务自身生命周期里发生的事:启动时的参数加载、InnoDB的初始化、连接数打满、主从复制报错、安全事件(比如认证失败),都会写到这里。
默认情况下错误日志写在数据目录下,文件名通常是主机名.err。用下面这条命令可以确认当前实例的错误日志位置:
mysql> SHOW VARIABLES LIKE 'log_error'; +---------------+---------------------+ | Variable_name | Value | +---------------+---------------------+ | log_error | /var/log/mysql/error.log | +---------------+---------------------+需要说明的是,log_error的值可能是文件路径,也可能是stderr(这种情况下日志由systemd之类的进程管理器接管),所以先确认一下不亏。
2.1 启动失败的排查入口
我见过不少案例:MySQL服务起不来,第一反应是去查配置文件是不是写错了,其实最快的路径是先看错误日志。比如InnoDB崩溃恢复时有日志文件损坏、缓冲池初始化内存不足、权限问题导致无法创建socket文件,这些错误都会直白地写在错误日志里。
一次典型的启动失败排查流程是这样的:
sudo tail -100 /var/log/mysql/error.log我最常遇到的几类启动报错:
[ERROR] InnoDB: Unable to lock ./ibdata1:通常是上一次进程没退干净,或者文件被其他进程占用。[ERROR] Can't open the mysql.plugin table:表损坏或者目录权限不对。[ERROR] Aborting:往往是初始化或恢复阶段直接放弃,需要继续往上翻日志找真正原因。
这里有个实操经验:错误日志别只看最后几行,要往前翻一大段。因为MySQL启动失败时,真正的根因往往在"Aborting"之前十几行甚至几十行,最后几行只是"我放弃了"的结论。就像看电影只看结局不知道原因,翻日志同理。
2.2 运行期的"隐形信号"
启动之外,错误日志在运行期也是排查利器。举几个我实际遇到的场景:
连接数打满时,错误日志会大量出现Too many connections;某台备库的复制线程中断,错误日志会记录Got fatal error 1236以及具体位点信息;磁盘分区满了,日志会直接告诉你Disk is full writing。这些信息在监控告警里通常看不出来龙去脉,但错误日志会告诉你接近精确的时间点和上下文。
我自己的习惯是给错误日志配好logrotate,并做两件事:一是保留至少90天的历史,二是单独写一条监控规则,对错误日志里出现ERROR关键字做告警。因为很多隐患——比如复制中断、认证失败——在影响业务之前,已经先在错误日志里露出马脚了。
2.3 一个容易被忽略的坑:日志权限
踩过这个坑之后我特别想提醒一句:错误日志的轮转权限问题。我用logrotate轮转错误日志时,如果配置里写的create权限和MySQL运行用户的权限不匹配,日志就会被MySQL用原来的文件描述符继续写入,轮转出来的新文件一直是空的,旧文件越撑越大。加上copytruncate选项可以规避这个问题,代价是会丢失轮转瞬间极少量的日志内容,对错误日志来说完全可接受。
/var/log/mysql/error.log { daily rotate 90 copytruncate compress missingok notifempty }这段配置的意图是:每天轮转一次,保留90份,轮转时先复制再清空原文件。MySQL一直持有旧文件句柄也没关系,因为文件本身还在。
3. 二进制日志:能做时间点恢复,也能当"案发现场"的监控录像
二进制日志,通常叫binlog,是MySQL日志体系里最核心的一环。它记录的是所有可能导致数据变更的操作:INSERT、UPDATE、DELETE、CREATE TABLE、DROP TABLE等等。SELECT不会进binlog(除非你开了log_queries_not_using_indexes这种变相记录)。
binlog的两大用途,一个是主从复制——从库靠读取主库的binlog来重放数据变更;另一个是数据恢复——误删数据之后,靠全量备份加binlog回放到误删前的位点。很多人提到binlog第一反应是复制,但我觉得把它当作"数据变更的监控录像"来理解更容易记住它的价值。
3.1 三种格式的取舍:STATEMENT、ROW、MIXED
binlog有三种格式,这个选择直接决定了几件事:日志膨胀速度、复制是否安全、能不能精确恢复。
- STATEMENT格式:记录的是原始SQL语句。优点是日志量小;缺点是在某些非确定性函数场景下,主从执行结果可能不一致。比如
NOW()、UUID()、RAND(),在从库重放时会生成不同的值,主从数据就对不上了。 - ROW格式:记录的是每一行的实际变更(前镜像和后镜像)。优点是复制安全性极高,任何函数结果都是主库算好的;缺点是日志量会膨胀得厉害,特别是大表的批量UPDATE。
- MIXED格式:MySQL自己判断,SQL是安全的就用STATEMENT,不安全的就自动切成ROW。
我在生产环境只用ROW格式,几台实例都是。原因很实际:用STATEMENT省下的磁盘,远不够弥补一次主从数据不一致带来的麻烦。一张大表批量UPDATE,ROW格式可能产生几百MB的binlog,但这是为了保证两个库完全一样。
server-id = 100 log_bin = mysql-bin binlog_format = ROW sync_binlog = 1 binlog_expire_logs_seconds = 604800参数含义逐个解释:
server-id:必配,主从复制环境里每个实例的唯一标识。log_bin:开启binlog并指定文件前缀。服务器会在此基础上生成mysql-bin.000001、mysql-bin.000002这样的序列文件。binlog_format = ROW:如前所述,选最安全的行级记录。sync_binlog = 1:每次事务提交都强制把binlog刷到磁盘,保证不会因为宕机丢binlog。binlog_expire_logs_seconds = 604800:binlog保留7天,防止磁盘被历史日志占满。
关于sync_binlog = 1,值得多说一句。这个配置对数据安全极重要,但代价是每个提交事务都要多一次磁盘fsync,性能会有明显开销。如果业务对强一致要求没那么高,有些DBA会设成0或N来换取吞吐,但我的建议是默认保持1,除非你能接受最多丢最近N个事务的binlog——这个决定得是业务方拍板,DBA不能替业务做这个担保。
3.2 用mysqlbinlog看录像回放
binlog是二进制文件,直接cat会看到一堆乱码。查看它的标准工具是mysqlbinlog。
假设有个场景:同事误执行了一条DELETE,把订单表某天的数据删了,要找回到底删了什么。先把binlog拉出来看:
mysqlbinlog --base64-output=decode-rows -vv mysql-bin.000032 > binlog_032.sql参数解释:
--base64-output=decode-rows:把ROW格式的二进制事件解码成可读的伪SQL。-vv:输出更详细的信息,包括每行的字段值。
打开输出的文件,你会看到类似这样的内容:
### DELETE FROM `shop`.`orders` ### WHERE ### @1='100001' ### @2='2024-05-20 10:30:00' ### @3='Alice' ### @4='299.00'@1、@2对应表中第1列、第2列,后面的值就是被删除的行的原始内容。看到这个,你可以精确定位误删的数据范围,然后决定是直接拼INSERT恢复,还是用stop-position/start-position做位点回放完整恢复。
这里有个实操技巧:binlog文件是按序号递增的,恢复之前先确认一下跨了几个文件。如果事务跨binlog文件边界,恢复时要用--start-position和--stop-position把两个文件串起来,否则容易漏掉事务。
3.3 我踩过的坑:binlog恢复的"半个事务"
说一个印象很深的坑。某次恢复数据,我用mysqlbinlog恢复了指定位点,结果恢复完发现有几行数据还是不对。反复排查才发现,我用的位点卡在了一个事务的中间——这个事务跨越了两个binlog文件,我恢复的起始位点在这个事务的"前半段",恢复结束位点也在事务中间,导致这个事务只执行了一半。
从那以后我的习惯是:恢复时先定位事务边界。mysqlbinlog输出里每个事务都有明确的BEGIN和COMMIT标记,恢复起始位点必须选在某条BEGIN之前,结束位点必须选在某条COMMIT之后。宁可多恢复几行后再手动补DELETE,也不要卡在事务中间搞出一个"半事务"。
3.4 binlog还能用来做审计线索
除了复制和恢复,binlog还有一个常被忽略的用途:审计线索。只要业务只通过MySQL主库写数据,binlog就是一份完整的"谁在什么时候改了哪张表哪些行"的记录。虽然ROW格式看不到执行SQL的人是谁(那要看general_log或者应用自己打的日志),但结合应用层日志里的会话ID,可以很方便地追溯数据变更链路。
4. 慢查询日志:抓的不是"慢语句",而是系统瓶颈的入口
慢查询日志是四种日志里最常用、但坑也最多的一种。它记录的是执行时间超过阈值的SQL语句,核心参数是long_query_time,单位是秒,默认10秒,支持小数。
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 = 100上面配置的含义:
slow_query_log = ON:开启慢查询日志。long_query_time = 1:超过1秒的语句才算慢。log_queries_not_using_indexes = ON:没走索引的查询也记录,哪怕执行很快。这个开关很多团队会开,它能帮你抓到"表明明有索引但查询没用上"的问题。min_examined_row_limit = 100:只有扫描行数超过100的才记录,避免把全表只有几行的小查询全打进日志。
我见过不少团队直接抄配置把long_query_time设为0.1甚至0.01,结果慢查询日志每分钟生成几百MB,最后不得不关掉。阈值设太低,日志就失去了"挑重点"的意义。我一般的建议是先用1秒跑一段时间,看看量和内容,再根据实际需求调整。
4.1 慢查询日志真正帮你发现的问题
慢查询日志记录的SQL,不仅仅是"执行了很长时间"的SQL。深入看它,还能发现几类深层次问题:
一是**"单条不慢,加起来要命"的查询**。某条SQL只要200ms,不算慢,但被应用以每分钟几千次的频率调用时,累加起来直接把数据库CPU吃满。慢查询日志按执行次数排序时,这类语句会非常活跃地出现。
二是**"语句本身不慢,但把他人拖慢"的查询**。有些UPDATE会锁住一行甚至锁住一张表,其他事务虽然SQL执行时间很短,但大量时间花在了等锁上。InnoDB有个指标叫锁等待时间,慢查询日志记录的execution_time包括了锁等待时间——如果某条语句的执行时间异常高,但单查又很快,那就要考虑是不是锁竞争问题。
三是隐式类型转换导致索引失效。WHERE mobile = 13800138000,手机号字段是字符串,参数传的是数字,MySQL可能会放弃索引全表扫描。这类SQL执行时间未必慢,但扫描行数极高,log_queries_not_using_indexes和min_examined_row_limit这两个参数组合就是为了抓这类问题的。
4.2 慢日志分析的两种工具
命令行直接tail慢日志可以应急,但要做系统性分析,我一般用两个工具。
第一个是MySQL自带的mysqldumpslow,简单、不需要安装、也没啥学习成本:
mysqldumpslow -s c -t 10 /var/log/mysql/slow.log参数含义:
-s c:按执行次数排序(count)。-t 10:只看前10条。
它会自动把SQL里的具体数值替换成N,把相似的SQL归类汇总。比如WHERE user_id = N AND status = N这样的语句会被聚合成一类,让你快速看到哪些"模板"的SQL占用了最多的执行次数或累计时间。
第二个是pt-query-digest,Percona Toolkit里的分析工具,功能更强,能输出执行时间分布、百分位、Top SQL排行榜等。输出比较长,我通常在分析线上慢日志时用它:
pt-query-digest /var/log/mysql/slow.log > digest_report.txt打开报告后,重点看最前面的"Profile"部分,它按累计执行时间排序,直接告诉你哪几类SQL消耗了绝大部分的数据库时间。这个信息比单条慢SQL要重要得多。
4.3 慢查询日志的一个理解误区
我刚用MySQL那会儿有个误解:以为慢查询日志是"正在执行超过1秒"才记,或者以为记录的是"执行中"的状态。实际上MySQL慢查询日志是在语句执行完成之后才判定并写入的。这意味着:如果一条SQL跑了几分钟还没结束,慢查询日志里暂时是看不到它的——它得等自己跑完才能被记录。
这带来的实际问题是:一条SQL卡了10分钟,你想通过慢查询日志实时观察它的进度,是看不到的。想实时看正在执行的SQL,要用SHOW PROCESSLIST或者performance_schema里的events_statements_current。我曾经在一次故障里盯着慢查询日志干等了十几分钟,然后才意识到这个问题。
5. 通用查询日志:平时别开,排查"谁动了数据"时再打开
通用查询日志(general query log)是四种日志里最"非主流"的一个。它记录的内容太全面了:每一个客户端连接和断开、每一条发送给MySQL的SQL语句(包括SELECT)、甚至管理命令USE db都会记进去。
注意关键词:每一条SQL。包括成功的、失败的、只查一行数据的、凌晨定时跑的SELECT 1——全都会记录。这就是为什么它默认关闭:开着它,性能和磁盘都扛不住。
5.1 怎么开、怎么关:动态开关的妙处
通用查询日志最实用的一个特点,是它可以在运行时动态开关,不需要重启MySQL:
-- 开启 SET GLOBAL general_log = 'ON'; -- 关闭 SET GLOBAL general_log = 'OFF';这给了你一个很安全的使用姿势:平时保持关闭,需要排查时再打开,查完立刻关闭。排查窗口期内产生的日志量是可控的,不会把磁盘写爆。
需要确认日志写到文件还是表:
mysql> SHOW VARIABLES LIKE 'log_output'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | log_output | TABLE | +---------------+-------+log_output有两个选项:
FILE:写入文本文件,默认文件名是主机名.log,查看方便。TABLE:写入系统库里的mysql.general_log表,可以用SQL查询,但每写一条日志就多一次表写入,对性能开销反而更大。
我的用法是排查时临时改成FILE,抓完就把general_log关掉,再把log_output改回TABLE(如果你平时依赖表的话)。文件形式便于开发同事直接grep,表形式便于按条件筛选,看场景选。
5.2 通用查询日志的实战价值:抓"谁动了数据"
我一直保留这个日志类型的排查方式,是因为在某些场景下它的定位作用无法替代:
第一个场景是定位"幽灵SQL"。业务反馈数据库在某段时间CPU异常高,慢查询日志也开了,但里面没什么大查询。这时打开通用查询日志,你可能会发现某个应用连接在疯狂执行同一条低消耗SQL,单条不慢,但频率极高——这种"数量型攻击"是慢查询日志抓不到的。
第二个场景是追踪变更来源。某天发现一张表的数据被动过了,binlog能看到改了哪一行,但看不到是谁。结合通用查询日志里的连接信息和SQL内容,再对照应用日志里的会话上下文,就能大致确认是哪个客户端IP、哪个应用模块发的指令。
我用过一次很典型的案例:某应用配置页面自动保存功能写了个死循环,每秒钟向配置表发起好几十次UPDATE。慢查询日志一条都没记录(因为每条都不到10ms),binlog也只显示高频变更,完全看不出异常。打开通用查询日志3秒钟,问题SQL立刻浮出水面,记录了连接IP和完整语句。
5.3 代价与风险:磁盘暴涨
通用查询日志最大的风险就一个词:暴涨。
在5.1节我说排查时要"查完立刻关闭",这不是矫情,是真的踩过坑。某次为了排查一个偶发问题,我打开general_log后去开了个会,回来一看,磁盘已经满了,生产库直接进入只读状态。通用查询日志的写入速度比你想象得快得多——它记录的是所有语句,包括应用的心跳探测(SELECT 1),高流量下每秒能产生几十MB。
所以谈到通用查询日志,我的经验是两句话:
- 把磁盘空间监控和
general_log开关联动,日志文件超过预设大小自动触发告警。 - 开它的时候设个闹钟,10分钟后强制自己看一眼。
6. 四份日志配合排查:一个CPU飙升问题的完整走查链路
前面把四种日志逐个讲完了,但真正的实战里,它们很少单独出现。一次故障排查往往是四份日志轮流看、交叉验证的过程。用一个我经历过的典型问题来串一下整个链路——某天下午业务方反馈系统响应变慢,监控显示数据库CPU接近100%。
6.1 明确问题时间窗口
排查任何数据库问题,第一步都是确认"从什么时候开始变慢的"。这个窗口越精确,后面翻日志的效率越高。监控面板上确认是14:30左右开始的异常,这个时间点会成为后面所有日志分析的锚点。
6.2 慢查询日志先看大方向
CPU飙高,第一怀疑对象是慢查询日志,但要看得巧妙。直接看14:30~14:40这10分钟的慢日志内容,尤其是mysqldumpslow -s c按次数排序的输出。结果发现一条UPDATE语句出现频率极高,单次执行时间只有约100ms,但累计执行次数是平时的几十倍。
这里有个关键判断:如果单条语句不慢、但是次数暴涨,通常意味着应用侧出了循环或重试风暴,而不是数据库本身变慢。所以下一步是确认这条高频UPDATE是不是正常业务流量。
6.3 通用查询日志确认执行频率
为了确认频率,我临时打开了通用查询日志,抓了3分钟就立刻关闭。统计结果显示:这个UPDATE在3分钟内被执行了约2400次,平均每分钟800次,正常时每分钟只有30次左右。执行来源IP指向了某台应用服务器的一个特定端口。
与此同时,错误日志里没有任何异常——连接数正常,没有认证失败,说明不是数据库自身的问题,而是应用发了大量请求进来。
6.4 binlog交叉验证数据影响
CPU飙高的同时,数据流也要确认。用mysqlbinlog查看14:30~14:40这个时间窗口的binlog,确认这笔高频UPDATE确实产生了大量行变更,变更的行数集中在某一个用户的数据上。至此基本可以还原全貌:应用侧某个用户触发了一个异常逻辑,导致对该用户的配置数据反复执行UPDATE,把数据库CPU打满。
6.5 复盘整个链路
这次排查里四份日志的分工是这样的:
- 慢查询日志锁定了"嫌疑SQL";
- 通用查询日志确认了"执行频率异常";
- 错误日志排除了"服务自身故障";
- binlog验证了"数据变更的真实规模"。
每份日志解决的是一个特定层面的问题,单靠任何一份都没法给出完整答案。这也是我在开头强调"先搞清各自管什么再下手"的原因。
最终的处理方案是让应用方修复了对应的循环逻辑,恢复流量后CPU立刻回落。之后我把通用查询日志永久关闭,只保留错误日志、binlog和慢查询日志,回到最小必要日志集。
7. 日志配置的最终建议:最小必要集
四份日志不是开得越多越好,而是够用就好。根据几年的运维经验,我最后给出一套"最小必要集"配置建议,适合绝大多数中小规模MySQL实例。
- 错误日志:必须开启,不需要额外配置,但一定要做轮转和监控。
- binlog:生产环境必须开启,建议
binlog_format = ROW、sync_binlog = 1,保留周期根据备份策略定,一般7天足够配合全量备份做任意时间点恢复。 - 慢查询日志:建议常开,
long_query_time = 1起步,配合log_queries_not_using_indexes和min_examined_row_limit过滤噪音。周期性用pt-query-digest分析,是数据库性能优化的长期抓手。 - 通用查询日志:保持关闭,只在需要追踪"谁在干什么"时临时打开,查完立即关闭,并随时关注磁盘水位。
我还想再多提一句日志的轮转与保留:无论哪类日志,都不建议让MySQL自己无限制写下去。binlog有expire_logs_days(老版本)或binlog_expire_logs_seconds(8.0推荐),文本类日志用logrotate轮转,并确保MySQL运行用户对轮转后的文件有写权限。
数据库日志这东西,平时安安静静躺在那儿,你可能一个月都不翻一次。但每一次能快速解决故障,都得益于日志从配置、轮转到查看方式早已形成了一套顺手的工作流。把这四种日志的脾性摸清楚,出问题时你就已经走在大部分人前面了。