MySQL教程（14）二进制日志binlog的原理与运维管理

一、Binlog 原理介绍

在 MySQL 中有一种非常特殊的二进制日志（binlog），该日志记录了数据库中每行数据的变动情况，数据库的主从复制、数据闪回等核心功能都需要依赖该日志来实现。binlog在记录每个事务时，会先写入到 binlog cache，等事务提交时再从 cache 写入 binlog 文件。在写入日志时，一个事务所产生的 binlog 不能被拆开，无论该事务有多大都需要一次性完整写入（这也是binlog大小有时候会超出单个文件限制的原因）。

另外需要搞清楚binlog和redo log的区别，两者虽然都可以用于数据恢复，但是侧重点完全不同。redo log 属于 InnoDB 引擎层，用于数据库实例崩溃恢复，而 binlog 属于 MySQL Server 层，用于主从复制和时间点恢复。由于一个事务在提交时这两份日志都需要写入，但是不可能同时写完，为了避免出现中途宕机而导致数据不一致的情况，这两个独立日志需要通过参数 sync_binlog=1 与 innodb_flush_log_at_trx_commit=1 实现两阶段提交，也就是双1参数。

二、Binlog 格式介绍

1、statement

标准模式，简称SBR，该格式下保存了每一条修改数据的SQL语句本身，日志记录量较少，对于一些执行结果不明确的语句会造成主从数据不一致，比如SYSDATE（）函数、sql_mode、字符集、用户变量等。只要有一点点差异，同一条语句执行出的结果就不同，而且这类语句不一致在执行的时候不会报错，不容易发现

2、row

行模式，简称RBR，是 5.7.7 之后的默认格式，也是最推荐、最安全的模式。该日志会将数据的具体改变记录下来，不会因为某些执行结果不明确的语句导致主从数据不一致。该日志记录量较大，如果有对BLOB等大字段进行操作，记录会更耗时，因为row会记录BLOB字段的具体值，而不单单是生成数据的语句。该格式的文件内容无法直接查看，需要通过mysqlbinlog --base64-output=decode-rows 转码

delete from test; #假设这条SQL删除100万条数据，STATEMENT语句模式仅记录这一条SQL语句，ROW会记录执行删除时的每一个语句，会记录100万次

3、mixed

混合模式，简称MBR，是statement和row的结合模式，当基于statement的语句无法精确复制时，就自动采用行模式进行复制

三、binlog 查看与解析

1、查看当前所有binlog

#两条等价
sql > SHOW BINARY LOGS;
sql > SHOW MASTER LOGS;
Log_name                File_size
master-bin.047572	13059910614
master-bin.047573       1442223014
master-bin.047574       1744328041

2、查看当前正在写的binlog

File 是当前正在写的文件，Position 是当前位点，Executed_Gtid_Set 是已执行的 GTID 集合（开了 GTID 才有内容）。8.4 起这条命令改成了 SHOW BINARY LOG STATUS，原有语法会报错

mysql> SHOW MASTER STATUS;
+-------------------+-----------+----------------+------------------+-------------------+
| File              | Position  | Binlog_Do_DB   | Binlog_Ignore_DB | Executed_Gtid_Set |
+-------------------+-----------+----------------+------------------+-------------------+
| master-bin.047708 | 485658162 | restapi,market |                  |                   |
+-------------------+-----------+----------------+------------------+-------------------+
1 row in set (0.00 sec)

3、查看 binlog 存放路径

log_bin_basename 是路径和文件名前缀，log_bin_index 是索引文件的路径。这里的 .index 文件是文本文件，可以直接查看，该文件记录 MySQL 认为有效的所有 binlog 文件，SHOW BINARY LOGS 输出内容也来自这个文件。如果有binlog被手工删除过就会导致.index和目录里的实际文件不一致。如果 SHOW BINARY LOGS 报 “You are not using binary logging”，说明实例没有开启 binlog，用 SHOW VARIABLES LIKE 'log_bin'; 确认，值为 OFF 的话需要在 my.cnf 里配置 log_bin 和 server_id 后重启。

mysql> SHOW VARIABLES LIKE 'log_bin%';
+---------------------------------+--------------------------------------------+
| Variable_name                   | Value                                      |
+---------------------------------+--------------------------------------------+
| log_bin                         | ON                                         |
| log_bin_basename                | /data/mysql/var/lib/mysql/master-bin       |
| log_bin_index                   | /data/mysql/var/lib/mysql/master-bin.index |
| log_bin_trust_function_creators | OFF                                        |
| log_bin_use_v1_row_events       | OFF                                        |
+---------------------------------+--------------------------------------------+
5 rows in set (0.01 sec)

4、binlog 解析查看

由于binlog是二进制文件，不能使用vi等文本工具直接查看和修改，需要使用专门的命令或者工具

· show binlog events 命令

该命令可以快速看到每个position的大概操作，输出结果中 Event_type = Query 的行就是修改数据的具体 SQL ，Pos 和 End_log_pos 字段记录了开始和结束位置。由于每个DDL本身就是一个事件，所以能直接在Info中看到，而DML语句都是由BEGIN开头，COMMIT结束。

#显示指定二进制日志内容
mysql > show binlog  events in 'master-bin.000002';          

#显示指定N条二进制日志内容
mysql > show binlog  events in 'master-bin.000002' limit5;      

#从指定位置开始显示日志
mysql > show binlog  events in 'master-bin.000002' from 3390 limit5;    

#也支持使用 show relaylog events 命令查看relaylog
show relaylog events in 'relay-bin.000002';

如下图1596处Position执行了truncate语句，要使用该binlog进行数据恢复的话就需要恢复到1512处

· mysqlbinlog工具

该工具是实际运维中binlog的解析利器，除了可以同时解析多个binlog，还可以用作数据恢复。主要参数有以下：

· 过滤范围

· 输出内容

--base64-output=decode-rows 与 -v | -vv 输出区别展示

# 不加--base64-output=decode-rows
mysqlbinlog mysql-bin.000003  

# 输出结果中BINLOG后面是一串看不懂的二进制格式
# at 420
#261027 10:15:02 server id 1  end_log_pos 477  Table_map: `test1`.`students` mapped to number 108
# at 477
#261027 10:15:02 server id 1  end_log_pos 540  Update_rows: table id 108 flags: STMT_END_F

BINLOG '
Vk07ZhMBAAAAOQAAAN0BAAAAAGwAAAAAAAEABXRlc3QxAAhzdHVkZW50cwACAw8CKAAC
...
'/*!*/;


#加上 decode-rows
mysqlbinlog --base64-output=decode-rows mysql-bin.000003

# 可以看到有一个UPDATE的操作，但是依然看不到内容
# at 420
#261027 10:15:02 server id 1  end_log_pos 477  Table_map: `test1`.`students` mapped to number 108
# at 477
#261027 10:15:02 server id 1  end_log_pos 540  Update_rows: table id 108 flags: STMT_END_F
# at 540
#261027 10:15:02 server id 1  end_log_pos 571  Xid = 1025
COMMIT/*!*/;


# 加上-v可以看到出现了以 ### 开头的伪 SQL，列名会以 @1、@2 这样的序号进行显示，这也是闪回工具生成反向 SQL 的依据,把 WHERE 和 SET 对调即可
mysqlbinlog -v --base64-output=decode-rows mysql-bin.000003
# at 477
#261027 10:15:02 server id 1  end_log_pos 540  Update_rows: table id 108 flags: STMT_END_F
### UPDATE `test1`.`students`
### WHERE
###   @1=1
###   @2='zhangsan'
### SET
###   @1=1
###   @2='lisi'


# 加上-vv可以看到增加了列名的数据类型以及开启 binlog_rows_query_log_events 后所记录的原始 SQL
mysqlbinlog -vv --base64-output=decode-rows mysql-bin.000003
# at 420
# update students set name='lisi' where id=1
# at 477
### UPDATE `test1`.`students`
### WHERE
###   @1=1 /* INT meta=0 nullable=1 is_null=0 */
###   @2='zhangsan' /* VARSTRING(40) meta=40 nullable=1 is_null=0 */
### SET
###   @1=1 /* INT meta=0 nullable=1 is_null=0 */
###   @2='lisi' /* VARSTRING(40) meta=40 nullable=1 is_null=0 */

· 回放和恢复相关参数

· 远程连接相关参数

mysqlbinlog命令示例

· 解析指定binlog或relaylog所有内容

#将rows的日志内容解码，可用于数据恢复时查找正确的操作
mysqlbinlog -vv --base64-output=decode-rows  master.bin.000003  > /tmp/master.bin.000003.txt

· 解析指定日期范围内的binlog或relaylog

mysqlbinlog -vv --base64-output=decode-rows --start-datetime='2018-02-13 11:37:00'  --stop-datetime='2018-02-15 12:00:00' master-bin.000001 > /tmp/master.bin.000001.txt

· 解析指定position范围内的binlog或relaylog

mysqlbinlog -vv --base64-output=decode-rows --start-position=3052 master-bin.000002    
mysqlbinlog -vv --base64-output=decode-rows --start-position=3052 --stop-position=3849 master-bin.000002

· 显示指定某个库的binlog或relaylog，并且对rows格式的日志解码

mysqlbinlog  -vvv --base64-output=decode-rows  --start-datetime='2018-10-12 14:42:00'  --stop-datetime='2018-10-12 14:45:00' --database=test_database mysql-bin.000008 > /tmp/bin.sql

· gtid模式下导出多个binlog或relaylog文件中的数据

mysqlbinlog --include-gtids='yourgtid:1-100' mysql-bin.00001 mysql-bin.00002 > /tmp/gtid.sql  #假设101的GTID为drop table，就截取到100即可

四、如何正确删除binlog日志

由于二进制日志会随着数据库操作的增多而不断增长，所以需要配置合适的清理策略以及必要时进行手动清理。但是binlog不能直接通过rm去删除，因为这样会导致和binlog索引文件不一致，需要用以下方式进行清除

· reset master命令

清空所有binlog文件，但是会导致从库异常，主从架构下无法使用

· expire_logs_days变量

通过该变量可以指定自动删除日期，如果日志过多，在删除时会有IO过高问题，可能导致性能抖动

set global expire_logs_days=3  #设置只保留3天的binlog
FLUSH BINARY LOGS;    #触发一次binlog的清理

· purge命令：推荐方法，可以快速删除指定binlog

mysql > PURGE MASTER LOGS TO 'mysql-bin.000003'  #删除binlog到指定的文件为止
mysql > PURGE MASTER LOGS BEFORE '2020-12-21 00:00:00'  #删除指定日期之前的文件

五、通过binlog还原数据

binlog 最重要的用途之一是可以实现时间点恢复，通过全备+binlog可以把数据回放到误操作之前。恢复的前提是数据库开启了binlog，并且从备份时间点到误操作时间点的binlog没有缺失，最后是全备文件里记录了对应的 binlog 位点

以今天10:30误操作执行了 drop table students 为例进行操作演示。如果是 delete 或 update 忘了加 where 这类操作，在开启 ROW 格式日志并且 binlog_row_image=FULL 时，可以直接用 binlog2sql、my2sql 解析出反向 SQL闪回。DROP、TRUNCATE 这类 DDL 操作只能通过下面的全备 + binlog 进行恢复。

1、止损操作

一是停止数据库写入，避免恢复期间数据继续变化；二是切换新的日志文件，让误操作在已关闭的文件里

set global super_read_only=1
FLUSH BINARY LOGS;

拷贝相关 binlog 到别的目录，后面的解析和回放都用拷贝

mkdir -p /backup/recover
cp /data/mysql/mysql-bin.0000{12,13,14} /backup/recover/

2、确定全备对应的 binlog 位点

· mysqldump 备份的 binlog 位点查看方法 

备份时如果带了 --single-transaction --master-data=2（8.0.26 起为 --source-data=2），位点记录在备份文件开头

grep -m1 'CHANGE MASTER' /backup/full.sql
# -- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000012', MASTER_LOG_POS=154;

· xtrabackup 备份的 binlog 位点查看方法 

cat /backup/full/xtrabackup_binlog_info
# mysql-bin.000012   154

3、找到误操作的位置

解析binlog，找到误操作前后的语句

mysqlbinlog -vv --base64-output=decode-rows --start-datetime='2026-10-27 10:00:00' --stop-datetime='2026-10-27 11:00:00' \
/backup/recover/mysql-bin.000013 > /tmp/view.txt


grep -n -i -B8 -A3 'drop table' /tmp/view.txt
# 找到的内容如下，误操作事务起点是 5756（这个位点也是上一个事务的结束位置），终点是5940（end_log_pos）
# at 5756
#261027 10:30:11 server id 1  end_log_pos 5821 CRC32 0x5b1c0c4e GTID last_committed=20 sequence_number=21 rbr_only=no
SET @@SESSION.GTID_NEXT= '9e70471a-4175-11ed-b3b9-000c29d026c5:2301'/*!*/;
# at 5821
#261027 10:30:11 server id 1  end_log_pos 5940 CRC32 0x86db0796 Query thread_id=8 exec_time=0 error_code=0
use `test1`/*!*/;
drop table students

4、新起实例恢复数据

准备一个临时的全新实例，先恢复全备，然后再回放binlog，验证无误后再迁回生产，不要直接在生产库上操作。恢复全备的步骤这里跳过了，直接从回放binlog开始

# 先导出文件，检查首尾位点后再执行，不要直接管道给 mysql 执行，这里的154就是全量备份里的位点，而5756就是误操作前的位点
mysqlbinlog --start-position=154 --stop-position=5756 --skip-gtids -D \
  /backup/recover/mysql-bin.000012 \
  /backup/recover/mysql-bin.000013 > /tmp/recover.sql

# 确认最后一个事务是 drop 之前的那个
head -30 /tmp/recover.sql
tail -30 /tmp/recover.sql       

# 执行导入
mysql -uroot -p < /tmp/recover.sql

5、验证数据

对照业务上能确认的数据检查，如果没有问题再把数据从临时实例迁回生产。如果是误操作之后生产库又产生了数据，可以在临时实例上继续回放误操作之后的 binlog，跳过误操作本身

mysqlbinlog --start-position=5940 /backup/recover/mysql-bin.000013 /backup/recover/mysql-bin.000014 > /tmp/after.sql

六、实时同步binlog

通过mysqlbinlog可以部署 binlog server，实现实时拉取指定数据库实例上的binlog日志到本地进行统一存储，可应用于数据增量备份、MHA binlog server等场景。

· 自动同步脚本

该脚本可以自动判断需要拉取的正确binlog，无需手动指定同步文件

#!/bin/sh
MYSQL_BIN=/usr/local/mysql/bin/mysql
BACKUP_BIN=/usr/local/mysql/bin/mysqlbinlog
LOCAL_BACKUP_DIR=/data/mysql_binlog_backup/public/binlog
BACKUP_LOG=/data/mysql_binlog_backup/public/backuplog

REMOTE_HOST=10.3.0.221
REMOTE_PORT=3306
REMOTE_USER='binlog_backup'
REMOTE_PASS='binlog_backup'
SERVER_ID='3023401'
FIRST_BINLOG=`${MYSQL_BIN}  -uroot -p123456 -h${REMOTE_HOST} -P${REMOTE_PORT} -e "show master status;" 2> /dev/null | grep "mysql-bin" | awk '{print $1}'`

#create local_backup_dir if necessary
mkdir -p ${LOCAL_BACKUP_DIR}
cd ${LOCAL_BACKUP_DIR}

if [ `ls -A "${LOCAL_BACKUP_DIR}" | wc -l` -eq 0 ];then
  LASTFILE=${FIRST_BINLOG}
else
  LASTFILE=`ls -al ${LOCAL_BACKUP_DIR} | tail -n 1 | awk '{print $9}'`
fi
echo 'Starting binlog backup'
${BACKUP_BIN} -h${REMOTE_HOST} -P${REMOTE_PORT} -u${REMOTE_USER} -p${REMOTE_PASS} --raw --stop-never --read-from-remote-server --stop-never-slave-server-id=${SERVER_ID} ${LASTFILE}  ${LOCAL_BACKUP_DIR}
echo "实例binlog实时同步出错 $(date +%F\ %T)" | mail -s "实例binlog实时同步出错 $(date +%F\ %T)" your_email@domain

· 同步任务巡检脚本

#!/bin/bash
echo > /usr/local/shell/check_binlog_backup.log

#统计应同步实例数量
INSTANCE_COUNT=`ls /data/mysql_backup/ | grep -v archived |grep -v bi1 | wc -l`
#统计应同步实例名
ls /data/mysql_backup/ | grep -v archived |grep -v bi1 > /usr/local/shell/instance_list.txt

#统计当前同步实例数量
BINLOG_COUNT=`ps aux | grep "_binlog_backup" | egrep -v "/usr/local/mysql/bin/mysqlbinlog|--color|grep|check_binlog_backup"  |awk '{print $9,$12}'|wc -l`
#统计应同步实例名
ps aux | grep "_binlog_backup" | egrep -v "/usr/local/mysql/bin/mysqlbinlog|--color|grep|check_binlog_backup" |awk '{print $12}'|awk -F'/' '{print $5}' | awk -F'_' '{print $1}' > /usr/local/shell/binlog_instance_list.txt
#

#判断未同步实例并通知
if [ $BINLOG_COUNT -eq $INSTANCE_COUNT ];then
  echo "`date +%F\ %T` : Binlog Server运行数量与实例数量一致,Binlog备份正常" | mail -s "Binlog备份运行正常" ops@huize.com
else
  echo -e "`date +%F\ %T` : Binlog Server运行数：$BINLOG_COUNT , 应同步实例数：$INSTANCE_COUNT" >> /usr/local/shell/check_binlog_backup.log
  echo "" >> /usr/local/shell/check_binlog_backup.log
  echo -e "当前正常同步实例信息:" >> /usr/local/shell/check_binlog_backup.log
  ps aux | grep "_binlog_backup" | egrep -v "/usr/local/mysql/bin/mysqlbinlog|--color|grep|check_binlog_backup" |awk '{print $1,$9,$12}'>> /usr/local/shell/check_binlog_backup.log
  echo "" >> /usr/local/shell/check_binlog_backup.log
  echo -e "备份异常实例信息:" >> /usr/local/shell/check_binlog_backup.log
  for i in `grep -vwf /usr/local/shell/binlog_instance_list.txt /usr/local/shell/instance_list.txt`
  do
    echo "${i}实例Binlog备份异常，请运行/usr/local/shell/${i}_binlog_backup.sh &" >> /usr/local/shell/check_binlog_backup.log
  done
  cat /usr/local/shell/check_binlog_backup.log | mail -s "Binlog Server运行数量少于实例数，请检查" your_email@domain
fi

mysql数据库