MySQL 快速分析binlog定位问题

一. 基础使用场景

# 直接解析binlog文件内容

shell> mysqlbinlog mysql-bin.000001 |less

# 显示更详细的binlog信息

# binlog_rows_query_log_events为ON时，需要使用-vv才可看到具体SQL
#查看指定GTID事务记录

shell> mysqlbinlog -vv mysql-bin.000001 |less

## 只查看指定GTID事务记录

shell> mysqlbinlog --include-gtids='e165cded-5c97-11e8-9814-06d1a5b64aec:2'  mysql-bin.000001 |less

关于--exclude-gtids的用法

版本说明

本文写于 2022-03。
mysqlbinlog 工具用法与 binlog 分析思路未变，经 2026-07 复核仍适用。
文中的 CHANGE MASTER TO / START SLAVE / STOP SLAVE / SHOW SLAVE STATUS 为旧语法：SLAVE 系命令自 8.0.22 起弃用、CHANGE MASTER TO 自 8.0.23 起弃用，改名为 CHANGE REPLICATION SOURCE TO / START REPLICA / STOP REPLICA / SHOW REPLICA STATUS（旧名在 8.0 上仍作为别名可用，8.4 起部分已移除）。新语法示例见 MySQL8 快速 clone。

• 排除单条:'8528c8ee-1284-11e9-9e33-02000aba3c10:525'

• 排除连续:'8528c8ee-1284-11e9-9e33-02000aba3c10:525-526'

• 排除不连续多条:'8528c8ee-1284-11e9-9e33-02000aba3c10:525-526,8528c8ee-1284-11e9-9e33-02000aba3c10:528'

关于 --stop-datetime 指定时间点：

先记住它的语义——--stop-datetime 是"停在该时刻之前"，等于或晚于这个时间戳的事件都不会被输出（--start-datetime 反过来，是包含的）。很多人按「闭区间」理解，结果把误操作那条也恢复了进去，这是恢复时最容易出的错。

假如在 2019-01-01 21:00:00 误删了库，那么 --stop-datetime='2019-01-01 21:00:00' 恰好会把 DROP 这条排除在外——是对的。但不要依赖这个巧合：binlog 的时间戳精度是秒，同一秒内可能有多个事务，按时间截断有概率多带或少带。

更稳的做法是按位点（--stop-position）或 GTID（--exclude-gtids）截断，而不是按时间。 时间只用来粗定位：先用 --start-datetime/--stop-datetime 圈出一个几分钟的窗口，在这个窗口里用 mysqlbinlog -vv 人眼找到误操作那条事件的 # at NNNN，再用精确位点做恢复。

如以下 binlog 数据，先把窗口圈在 20:59 到 21:01：

• 2019-01-01 20:40:01 INSERT INTO XXX
• 2019-01-01 20:48:01 UPDATE INTO XXX
• 2019-01-01 20:50:01 DELETE INTO XXX
• 2019-01-01 20:59:01 DELETE INTO XXX
• 2019-01-01 21:00:00 DROP DATABASE XXX ← 要跳过的就是它

然后定位到它的起始位点，用位点截断：

# 1. 粗定位：先看这个时间窗里都有什么
mysqlbinlog --start-datetime='2019-01-01 20:59:00' --stop-datetime='2019-01-01 21:01:00' \
  -vv mysql-bin.000001 | grep -nE '^# at |^#19|DROP|DELETE'

# 2. 找到 DROP 那条事务的起始 "# at NNNN"，用它做 stop-position
mysqlbinlog --stop-position=NNNN mysql-bin.000001 > /tmp/recover.sql

恢复前务必先看一眼 /tmp/recover.sql 的末尾，确认最后一条不是那个 DROP：

tail -30 /tmp/recover.sql

二. 统计binlog中各表的[增删改]次数

mysqlbinlog  --no-defaults \
--base64-output=decode-rows  \
-vv mysql-bin.000032 | awk '/###/ {if($0~/UPDATE|INSERT|DELETE/)count[$2" "$NF]++}END{for(i in count) print i,"\t",count[i]}' | column -t | sort -k2nr

三. 解析定位binlog中大事务

结果将输出大事务的大小及起始点位置

mysqlbinlog mysql-bin.000001 | grep "last_committed=" -B 1| awk '/^# at/&&NR==1 {tmp=$NF} /^# at/&&NR>1 {print($NF-tmp,"--start-position="tmp,"--stop-position="$NF);tmp=$NF}' | sort -n -r | head -n 20

## 直接指定大事务的起始点位置查看事务具体内容
mysqlbinlog -vv --start-position=46746293 --stop-position=938267951 mysql-bin.000001|less

四. 多维度解析binlog

这一节的 awk 脚本来自网络，我在本地 8.0 上验证过能跑通，但它是纯文本匹配、没有解析 binlog 协议——遇到 SQL 内容里本身含有 ### INSERT 这类字符串、或跨事件换行的大字段时会误统计。它给的是量级参考，不是精确计数。要精确统计用 mysqlbinlog --base64-output=decode-rows 配合专门的解析工具（如 binlog2sql），或直接查 performance_schema。

基本逻辑: 先用脚本将binlog的结果解析汇总,再基于汇总的数据做过滤排序汇总

vim analyze_binlog.sh

具体解析命令

mysqlbinlog --base64-output=decode-rows -vv ${BINLOG_DIR}/${BINLOG_FILE} | awk \
'BEGIN {s_type=""; s_count=0;count=0;insert_count=0;update_count=0;delete_count=0;flag=0;} \
{if(match($0, /#.*Table_map:.*mapped to number/)) {printf "Timestamp : " $1 " " $2 " Table : " $(NF-4); flag=1} \
else if (match($0, /(### INSERT INTO .*..*)/)) {count=count+1;insert_count=insert_count+1;s_type="INSERT"; s_count=s_count+1;}  \
else if (match($0, /(### UPDATE .*..*)/)) {count=count+1;update_count=update_count+1;s_type="UPDATE"; s_count=s_count+1;} \
else if (match($0, /(### DELETE FROM .*..*)/)) {count=count+1;delete_count=delete_count+1;s_type="DELETE"; s_count=s_count+1;}  \
else if (match($0, /^(# at) /) && flag==1 && s_count>0) {print " Query Type : "s_type " " s_count " row(s) affected" ;s_type=""; s_count=0; }  \
else if (match($0, /^(COMMIT)/)) {print "[Transaction total : " count " Insert(s) : " insert_count " Update(s) : " update_count " Delete(s) : " \
delete_count "] \n+----------------------+----------------------+----------------------+----------------------+"; \
count=0;insert_count=0;update_count=0; delete_count=0;s_type=""; s_count=0; flag=0} } '

执行方式

sh analyze_binlog.sh >> analyze_binlog.log

输出样式

1.查看该binlog中 操作最多的表
cat analyze_binlog.log | grep Table |cut -d':' -f5| cut -d' ' -f2 | sort | uniq -c | sort -nr
2.查看该binlog中 删除操作最多的表
cat analyze_binlog.log |grep -E 'DELETE' |cut -d':' -f5| cut -d' ' -f2 | sort | uniq -c | sort -nr
3.查看该binlog中 指定库表的操作统计
cat analyze_binlog.log |grep -i '`demo`.`t1`' | awk '{print $7 " " $11}' | sort -k1,2 | uniq -c
4.查看该binlog中 单个操作影响行数的top 3
cat analyze_binlog.log | grep Table | sort -nr -k 12 | head -n 3
5.查看该binlog中 删除超过1000行的操作
cat analyze_binlog.log |grep -E 'DELETE' | awk '{if($12>1000) print $0}'
6.查看该binlog中 所有类型操作超过1000行的操作
cat analyze_binlog.log |grep -E 'Table' | awk '{if($12>1000) print $0}'

五. MySQL Binlog Server

1. 获取远程数据库binlog日志

• --read-from-remote-server 从远端服务器获取binlog到本地

• --raw 指定以binlog日志原始格式转储

• --to-last-log 从指定binlog日志开始直到获取到最新的binlog结束

# 获取单个文件

mysql -h192.0.2.11 -uapp -papp -P3306 -e "show binary logs"
mysqlbinlog --raw --read-from-remote-server -h192.0.2.11 -uapp -papp -P3306 mysql-bin-zhenxing.000001>mysql-bin-zhenxing.000001

## 从指定文件获取到最后一个文件
mysqlbinlog --read-from-remote-server -h192.0.2.11 -uapp -papp -P3306 --to-last-log mysql-bin-zhenxing.000001 --raw

2. 模拟复制线程实现Binlog Server --raw 指定以binlog日志原始格式转储 --result-file 增加转储的binlog文件名前缀，也可指定具体目录 --stop-never 指定持续转储binlog日志 --stop-never-slave-server-id 默认65535，显式指定可避免与其他dump线程冲突 mysqlbinlog --raw --read-from-remote-server -h192.0.2.11 -urepl -prepl -P3306 --result-file=remote- mysql-bin-zhenxing.000001 --stop-never --stop-never-slave-server-id=100 & 局限性 数据库重启后，需重新开启mysqlbinlog 转储线程并指定新的binlog日志转储起始点 mysqlbinlog 转储线程异常断开后，服务端dump线程不会消失而一直处于僵死状态 如果mysqlbinlog转储线程重新以相同配置启动，则僵死进程会被激活再次使用 指定-raw选项以binlog日志原始格式转储时，最后一个事务始终会被标记为rollback状态，导致最后一个事务丢失(MySQL5.7.22未复现该问题,可能已被修复)

六. binlog备份恢复-基于复制特性

1. 使用mysqlbinlog恢复的劣势

通常我们在数据库误操作,如drop database后需要基于物理备份及binlog实现数据的恢复,常规的做法如下

• 恢复全量备份数据

• 恢复增量备份数据(如有)

• 基于备份记录的日志位点或GTID恢复binlog数据到误操作删除之前

• 但使用mysqlbinlog解析还原binlog过程存在以下问题

• 存在大量binlog时,效率过低

• 一旦解析异常,不便于做断点同步

• 跨binlog解析存在一些限制(如创建临时表操作)

• 对于单库或单表的还原,无法做到精细化控制

2. 使用SQL线程回放binlog的优势

基于以上直接用mysqlbinlog解析日志会带来的问题,结合MySQL复制同步特性,我们知道relay log本质上就是binlog,那我们可以尝试将binlog伪装成relay log,用复制的SQL线程来回放binlog,从而达到高效恢复的目的,且由于用到SQL线程回放,也就能使用到回放的特性,如并行回放,库表过滤等等

• 优势点基本就是MySQL复制的基本特点,有如下优势

• 只需配置好同步的位点,数据库自动使用SQL线程恢复数据

• 可以使用MySQL并行复制的特性,提升恢复效率

• 可以精细化控制恢复的库表

• 可以指定恢复到具体的GTID及跳过误操作的GTID

• 数据恢复可以暂停,也可重新基于当前位置继续同步

3. 恢复的场景示例

以下是使用SQL线程回放binlog的故障场景模拟信息

• 做全量xtrabackup备份模拟日常备份
• 执行sysbench压测4张表，20个线程，压测10分钟，模拟大量binlog
• 删除实例模拟数据库被误删除或硬件故障(binlog需要保留)
• 使用xtrabackup恢复全量备份
• 使用MySQL Replication SQL线程回放binlog(注意:恢复前需要将relay_log_recovery参数设置为0

4. 环境准备及故障模拟

4.1 binlog Server备份模拟

使用mysqlbinlog将binlog文件实时转储到备份目录,模拟binlog备份(当前环境备份目录配置在/data/mysql/backup),该步骤可以改为其他binlog备份方式如定期cp或rsync或不备份也可

[root@db-server-01 ~]# mkdir -p /data/mysql/backup/binlog
[root@db-server-01 ~]# mysqlbinlog --raw --read-from-remote-server -h192.0.2.12 -urepl -p<password> -P3306 --result-file=/data/mysql/backup/binlog/ mysql-bin.000001 --stop-never --stop-never-slave-server-id=100 &

注：下面的 sysbench 命令已改成 1.0+ 的语法（直接写测试名，不再是 --test=/path/to/xxx.lua）。如果你手上的教程还在用 --num-threads、--max-time、--test=，那是 0.5 时代的写法，在 1.0 上会报 unknown option——对照见 MySQL 性能压测：Sysbench 1.0 实战。

4.2 生成模拟数据并模拟压力

生成sysbench测试数据,创建4张表，每张各100W数据库并压测一分钟模拟数据变化

插入基础数据

[root@db-server-01 ~]# sysbench oltp_read_write --db-ps-mode=disable --mysql-host=127.0.0.1 --mysql-port=3306 --mysql-user=sysbench --mysql-password=sysbench --mysql-db=sbtest --tables=4 --table-size=1000000 --report-interval=1 --time=600 --threads=20  prepare

执行sysbench压测模拟数据变化，压测1分钟

[root@db-server-01 ~]# sysbench oltp_read_write --db-ps-mode=disable --mysql-host=127.0.0.1 --mysql-port=3306 --mysql-user=sysbench --mysql-password=sysbench --mysql-db=sbtest --tables=4 --table-size=1000000 --report-interval=1 --time=60 --threads=20 run

4.3 模拟每天物理备份

执行物理备份模拟每天的全量备份

[root@db-server-01 ~]# innobackupex --host=192.0.2.13 --port=3306 --user=backup --password=<MYSQL_PASSWORD> /data/mysql/backup/

4.4 模拟备份后的数据变更

[root@db-server-01 ~]# sysbench oltp_read_write --db-ps-mode=disable --mysql-host=127.0.0.1 --mysql-port=3306 --mysql-user=sysbench --mysql-password=sysbench --mysql-db=sbtest --tables=4 --table-size=1000000 --report-interval=1 --time=600 --threads=20  run

4.5 触发误操作模拟故障

## 生成一个新的binlog包含误操作测试环境为了方便查找binlog位点
flush logs

## 执行误操作删库
drop database sbtest;

5. 数据还原操作步骤

5.1 还原全量备份

[root@db-server-01 ~]# cd /data/mysql/backup
[root@db-server-01 backup]# innobackupex --apply-log 2020-03-02_17-39-07/
[root@db-server-01 backup]# innobackupex --defaults-file=/etc/my.cnf --copy-back 2020-03-02_17-39-07/

5.2 binlog转relay log

将binlog转换为relay log并拷贝到数据目录以便SQL线程回放数据

[root@db-server-01 backup]# cd /data/mysql/backup/binlog/
  
## 将binlog重命名为relay log
[root@db-server-01 binlog]# rename mysql-bin mysql-relay mysql-bin*
  
## 创建relay log index文件
[root@db-server-01 binlog]# ls ./mysql-relay.0000* >mysql-relay.index
  
## 拷贝relay log到数据目录
[root@db-server-01 binlog]# cp mysql-relay.* /data/mysql/data/
  
## 修改数据目录权限
[root@db-server-01 binlog]# chown -R mysql:mysql /data/mysql/data/

5.3 relay_log_recovery参数配置

修改relay_log_recovery参数，设置为0并启动数据库,relay_log_recovery为1时，relay log会在复制线程启动时被清除重新拉

# 获取备份文件中的binlog位点信息及GTID点对应的relay log文件

[root@db-server-01 ~]# cd /data/mysql/backup/2020-03-02_17-39-07/
[root@db-server-01 2020-03-02_17-39-07]# cat xtrabackup_binlog_info
mysql-bin.000007    80456866    f41abe78-5c62-11ea-abf1-02000aba3da2:1-52013
  
## 启动数据库
[root@db-server-01 2020-03-02_17-39-07]# systemctl start mysql_3306
  
## change master指定一个空的主库，创建SQL线程
root@localhost[(none)]> reset master;
  
## 指定备份文件中对应的binlog位点
## 其中MASTER_HOST任意指定一个不存在的地址即可,RELAY_LOG_FILE和RELAY_LOG_POS填入全量备份中的值
root@localhost[(none)]> CHANGE MASTER TO MASTER_HOST='1.1.1.1',RELAY_LOG_FILE='mysql-relay.000007',RELAY_LOG_POS=80456866;
  
## 查看指定的位点是否生效
root@localhost[(none)]> select * from mysql.slave_relay_log_info;
+-----------------+----------------------+---------------+-----------------+----------------+-----------+-------------------+----+--------------+
| Number_of_lines | Relay_log_name       | Relay_log_pos | Master_log_name | Master_log_pos | Sql_delay | Number_of_workers | Id | Channel_name |
+-----------------+----------------------+---------------+-----------------+----------------+-----------+-------------------+----+--------------+
|               7 | ./mysql-relay.000007 |      80456866 |                 |              0 |         0 |                 0 |  1 |              |
+-----------------+----------------------+---------------+-----------------+----------------+-----------+-------------------+----+--------------+
  
## 只需要开启SQL线程对指定的relay log开始回放即可
root@localhost[(none)]> START SLAVE SQL_THREAD;

## 持续执行可看到binlog数据开始回放
root@localhost[(none)]> show slave status\G
  
## 待binlog恢复完成且数据校验无问题后可将复制关系重置
root@localhost[(none)]> stop slave;
root@localhost[(none)]> reset slave;
root@localhost[(none)]> reset slave all;

6. 数据还原精细化控制

6.1 只恢复单个库的数据

由于备份是全量备份，无法单库还原(如果已知表结构可使用可传输表空间方式单库还原),可先将全量恢复后对只对单库做binlog还原 只需在数据恢复步骤的基础上,开启SQL线程回放操作前增加一条以下命令即可实现对sbtest单库的binlog还原 CHANGE REPLICATION FILTER REPLICATE_WILD_DO_TABLE = ('sbtest.%');

6.2 只恢复单个表的数据

该步骤与单库还原类似,只需将复制过滤属性指定为具体的表,如

• CHANGE REPLICATION FILTER REPLICATE_WILD_DO_TABLE = ('sbtest.sbtest1','sbtest.sbtest2'); 可在开启binlog还原前后对sbtest1-4表做checksum，验证是否只有sbtest1和sbtest2做了binlog还原 checksum table sbtest1,sbtest2,sbtest3,sbtest4;

6.3 恢复到指定的GTID或position点

该步骤只需在数据恢复步骤的基础上,将START SLAVE SQL_THREAD改为START SLAVE SQL_THREAD UNTIL SQL_BEFORE_GTIDS，如只恢复到GTID=499999

START SLAVE SQL_THREAD UNTIL SQL_BEFORE_GTIDS = 'f41abe78-5c62-11ea-abf1-02000aba3da2:500000; 6.4 提升恢复效率的参数优化

set global sync_binlog=0;                     ## 不是"关闭 binlog"，是把 binlog 的 fsync 交给操作系统决定时机
set global innodb_flush_log_at_trx_commit=0;  ## 不是"关闭 redo log"，是每秒刷一次而不是每次提交刷
set global slave_parallel_type=LOGICAL_CLOCK;
set global slave_parallel_workers=8;

这两个参数的含义别记错

sync_binlog=0 和 innodb_flush_log_at_trx_commit=0 都不是"关闭日志"，binlog 和 redo log 照样在写，变的只是刷盘时机：主机断电最多丢一秒左右的事务。真正关闭 redo log 是 8.0.21 起的 ALTER INSTANCE DISABLE INNODB REDO_LOG，那是导数据专用的实例级开关，开着它期间实例崩溃不可恢复，且不能用于备份源。两个参数的完整语义见 MySQL8 双 1 设置保障安全。

这里的降级只在恢复窗口内用，恢复完成必须改回双 1，否则相当于长期裸奔。

6.5 mysqlbinlog与SQL线程回放效率对比

恢复方式 binlog数量 恢复耗时 备注

• mysqlbinlog 1.2G 722s sync_binlog=0和innodb_flush_log_at_trx_commit=0
• SQL_THREAD 1.2G 151s sync_binlog=0和innodb_flush_log_at_trx_commit=0,且并行复制设置为8,实际仅使用2个线程回放