带你解析MySQL binlog

前言：

我们都知道，binlog可以说是MySQL中比较重要的日志了，在日常学习及运维过程中，也经常会遇到。不清楚你对binlog了解多少呢？本篇文章将从binlog作用、binlog相关参数、解析binlog内容三个方面带你了解binlog。

1.binlog简介

binlog即binary log，二进制日志文件。它记录了数据库所有执行的DDL和DML语句（除了数据查询语句select、show等），以事件形式记录并保存在二进制文件中。

binlog主要有两个应用场景，一是用于复制，master把它的二进制日志传递给slaves来达到master-slave数据一致的目的。二是用于数据恢复，例如还原备份后，可以重新执行备份后新产生的binlog，使得数据库保持最新状态。除去这两个主要用途外，binlog可以用于异构系统之间数据的交互，binlog完整保存了一条记录的前项和后项记录，可以用DTS服务，将MySQL数据以准实时的方式抽取到底层数据平台，比如HBase、Hive、Spark等，打通OLTP和OLAP。

binlog日志可以选择三种模式，分别是 STATEMENT、 ROW、 MIXED，下面简单介绍下这三种模式：

• STATEMENT：基于SQL语句的复制，每一条会修改数据的sql语句会记录到binlog中。该模式下产生的binlog日志量会比较少，但可能导致主从数据不一致。
• ROW：基于行的复制，不记录每一条具体执行的SQL语句，仅需记录哪条数据被修改了，以及修改前后的样子。该模式下产生的binlog日志量会比较大，但优点是会非常清楚的记录下每一行数据修改的细节，主从复制不会出错。
• Mixed：混合模式复制，以上两种模式的混合使用，一般的复制使用STATEMENT模式保存binlog，对于STATEMENT模式无法复制的操作使用ROW模式保存binlog，MySQL会根据执行的SQL语句选择日志保存方式。

binlog模式在MySQL 5.7.7之前，默认为 STATEMENT，在之后的版本中，默认为ROW。这里建议采用ROW模式，因为ROW模式更安全，可以清楚记录每行数据修改的细节。

2.binlog相关参数

binlog默认情况下是不开启的，不过一般情况下，初始化的时候建议在配置文件中增加log-bin参数来开启binlog。

# 配置文件中增加log-bin配置
[mysqld]
log-bin = binlog

# 不指定路径默认在data目录下，也可以指定路径
[mysqld]
log-bin = /data/mysql/logs/binlog

# 查看数据库是否开启了binlog
show variables like 'log_bin%';

开启binlog后，还需注意一些与binlog相关的参数，下面简单介绍下相关参数：

binlog_format
设置binlog模式，建议设为ROW。

binlog_do_db
此参数表示只记录指定数据库的二进制日志，默认全部记录，一般情况下不建议更改。

binlog_ignore_db
此参数表示不记录指定的数据库的二进制日志，同上，一般不显式指定。

expire_logs_days
此参数控制二进制日志文件保留天数，默认值为0，表示不自动删除，可设置为0~99。可根据实际情况设置，比如保留15天或30天。MySQL8.0版本可用binlog_expire_logs_seconds参数代替。

max_binlog_size
控制单个二进制日志大小，当前日志文件大小超过此变量时，执行切换动作。此参数的最大和默认值是1GB，该设置并不能严格控制Binlog的大小，尤其是Binlog比较靠近最大值而又遇到一个比较大事务时，为了保证事务的完整性，不可能做切换日志的动作，只能将该事务的所有SQL都记录进当前日志，直到事务结束。一般情况下可采取默认值。

log_bin_trust_function_creators
当二进制日志启用后，此参数就会启用。它控制是否可以信任存储函数创建者，不会创建写入二进制日志引起不安全事件的存储函数。如果设置为0（默认值），用户不得创建或修改存储函数，除非它们具有除CREATE ROUTINE或ALTER ROUTINE特权之外的SUPER权限。建议设置为1。

sync_binlog
控制MySQL服务端将二进制日志同步到磁盘的频率，默认值为1。
设置为0，表示MySQL不控制binlog的刷新，由文件系统自己控制它的缓存的刷新；
设置为1，表示每次事务提交，MySQL都会把binlog刷下去，这是最安全的设置，但由于磁盘写入次数增加，可能会对性能产生负面影响；
设置为n，其中n为0或1以外的值，在进行n次事务提交以后，Mysql将执行一次fsync之类的磁盘同步指令，将Binlog文件缓存刷新到磁盘。
推荐设置为1，出于性能考虑也可酌情调整。

关于binlog操作与管理相关的SQL也有很多，下面介绍下部分常用的语句：

SQL语句	语句含义
show master status	查看当前最新的一个binlog日志的编号名称，及最后一个事件结束的位置
show binary logs	查看目前保留的所有binlog日志列表及大小
flush logs	刷新binlog，此刻开始产生一个新编号的binlog日志文件
purge binary logs before '2020-07-01 12:00:00'	手动清理指定时间之前的binlog日志
purge binary logs to 'binlog.000012'	将指定日志文件之前的日志清除
reset master	清空所有的binlog日志，慎用
show binlog events in 'binlog.000030'	查看指定的binlog日志event
show binlog events in 'binlog.000030' from 931	从指定的位置开始，查看指定的binlog日志
show binlog events in 'binlog.000030' from 931 limit 2	从指定的位置开始，查看指定的binlog日志，限制查询的enent数

3.解析binlog内容

前面说过，所有对数据库的修改都会记录在binglog中。但binlog是二进制文件，无法直接查看，想要更直观的观测它就要借助mysqlbinlog命令工具了，下面的内容主要介绍如何使用mysqlbinlog来解析binlog日志内容。

为了故事的顺利发展，我们首先切换下binlog，然后创建测试库、测试表，执行插入数据，更新数据。这些前置操作暂不展示，下面我们来看下如何解析并查看生成的binlog内容：

# 本次解析基于MySQL8.0版本，实例已开启gtid，模式为ROW

[root@centos logs]# mysqlbinlog  --no-defaults --base64-output=decode-rows -vv binlog.000013
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
...
...
#200708 16:52:09 server id 1003306  end_log_pos 1049 CRC32 0xbcf3de39   Query   thread_id=85    exec_time=0     error_code=0    Xid = 1514
use `bindb`/*!*/;
SET TIMESTAMP=1594198329/*!*/;
SET @@session.explicit_defaults_for_timestamp=1/*!*/;
/*!80013 SET @@session.sql_require_primary_key=0*//*!*/;
CREATE TABLE  `bin_tb` (
  `increment_id` int(11) NOT NULL AUTO_INCREMENT COMMENT '自增主键',
  `stu_id` int(11) NOT NULL COMMENT '学号',
  `stu_name` varchar(20) DEFAULT NULL COMMENT '学生姓名',
  `create_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT '创建时间',
  `update_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT '修改时间',
  PRIMARY KEY (`increment_id`)
) ENGINE=InnoDB  DEFAULT CHARSET=utf8 COMMENT='测试binlog'
/*!*/;
# at 1049
#200708 16:52:45 server id 1003306  end_log_pos 1128 CRC32 0xf19ea0a9   GTID    last_committed=2        sequence_number=3       rbr_only=yes    original_committed_timestamp=1594198365741300   immediate_commit_timestamp=1594198365741300        transaction_length=468
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1594198365741300 (2020-07-08 16:52:45.741300 CST)
# immediate_commit_timestamp=1594198365741300 (2020-07-08 16:52:45.741300 CST)
/*!80001 SET @@session.original_commit_timestamp=1594198365741300*//*!*/;
/*!80014 SET @@session.original_server_version=80019*//*!*/;
/*!80014 SET @@session.immediate_server_version=80019*//*!*/;
SET @@SESSION.GTID_NEXT= '0032d819-2d32-11ea-91b5-5254002ae61f:24883'/*!*/;
# at 1128
#200708 16:52:45 server id 1003306  end_log_pos 1204 CRC32 0x5b4b03db   Query   thread_id=85    exec_time=0     error_code=0
SET TIMESTAMP=1594198365/*!*/;
BEGIN
/*!*/;
# at 1204
#200708 16:52:45 server id 1003306  end_log_pos 1268 CRC32 0xd4755d50   Table_map: `bindb`.`bin_tb` mapped to number 139
# at 1268
#200708 16:52:45 server id 1003306  end_log_pos 1486 CRC32 0x274cf734   Write_rows: table id 139 flags: STMT_END_F
### INSERT INTO `bindb`.`bin_tb`
### SET
###   @1=1 /* INT meta=0 nullable=0 is_null=0 */
###   @2=1001 /* INT meta=0 nullable=0 is_null=0 */
###   @3='from1' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
###   @4=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###   @5=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
### INSERT INTO `bindb`.`bin_tb`
### SET
###   @1=2 /* INT meta=0 nullable=0 is_null=0 */
###   @2=1002 /* INT meta=0 nullable=0 is_null=0 */
###   @3='dfsfd' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
###   @4=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###   @5=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
...
# at 1486
#200708 16:52:45 server id 1003306  end_log_pos 1517 CRC32 0x0437e777   Xid = 1515
COMMIT/*!*/;
...
# at 1596
#200708 16:54:35 server id 1003306  end_log_pos 1681 CRC32 0x111539b6   Query   thread_id=85    exec_time=0     error_code=0
SET TIMESTAMP=1594198475/*!*/;
BEGIN
/*!*/;
# at 1681
#200708 16:54:35 server id 1003306  end_log_pos 1745 CRC32 0x6f0664ee   Table_map: `bindb`.`bin_tb` mapped to number 139
# at 1745
#200708 16:54:35 server id 1003306  end_log_pos 1939 CRC32 0xfafe7ae8   Update_rows: table id 139 flags: STMT_END_F
### UPDATE `bindb`.`bin_tb`
### WHERE
###   @1=5 /* INT meta=0 nullable=0 is_null=0 */
###   @2=1005 /* INT meta=0 nullable=0 is_null=0 */
###   @3='dsfsdg' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
###   @4=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###   @5=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
### SET
###   @1=5 /* INT meta=0 nullable=0 is_null=0 */
###   @2=1005 /* INT meta=0 nullable=0 is_null=0 */
###   @3=NULL /* VARSTRING(60) meta=60 nullable=1 is_null=1 */
###   @4=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###   @5=1594198475 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
### UPDATE `bindb`.`bin_tb`
### WHERE
###   @1=6 /* INT meta=0 nullable=0 is_null=0 */
###   @2=1006 /* INT meta=0 nullable=0 is_null=0 */
###   @3='fgd' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
###   @4=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###   @5=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
### SET
###   @1=6 /* INT meta=0 nullable=0 is_null=0 */
###   @2=1006 /* INT meta=0 nullable=0 is_null=0 */
###   @3=NULL /* VARSTRING(60) meta=60 nullable=1 is_null=1 */
###   @4=1594198365 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
###   @5=1594198475 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
...
# at 1939
#200708 16:54:35 server id 1003306  end_log_pos 1970 CRC32 0x632a82b7   Xid = 1516
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

# 可以看出，binlog中详细记录了每条sql执行产生的变化，
并且包括执行时间、pos位点、server_id等系统值。

关于mysqlbinlog工具的使用技巧还有很多，例如只解析对某个库的操作或者某个时间段内的操作等。简单分享几个常用的语句，更多操作可以参考官方文档。

mysqlbinlog --no-defaults --base64-output=decode-rows -vv binlog.000013 > /tmp/bin13.sql
将解析到的SQL导入文件中

mysqlbinlog --no-defaults --base64-output=decode-rows -vv --database=testdb binlog.000013
只解析某个库的操作

mysqlbinlog --no-defaults --base64-output=decode-rows -vv --start-datetime="2020-01-11 01:00:00" --stop-datetime="2020-01-11 23:59:00" binlog.000008
解析指定时间段内的操作

mysqlbinlog --no-defaults --base64-output=decode-rows -vv --start-position=204136360 --stop-position=204136499 binlog.000008
解析指定pos位点内的操作

mysqlbinlog --no-defaults --start-position=204136360 --stop-position=204136499 binlog.000008 | mysql -uroot -pxxxx testdb
在指定库中恢复指定位点间的操作

总结：

不知不觉写的挺长了，本文讲述了各类binlog相关知识点，希望你读完会对binlog有更深的认识。其实最重要的还是实践，只有多学多用才能更好的掌握。这么硬核的知识，希望大家用到的时候可以拿来读读，欢迎各位转发分享，让更多人看到。