mysql的binlog
文章转载自：博客园Arnold的技术博客--https://www.cnblogs.com/zh94/
背景
开发了一段时间的canal，中间也陆陆续续出现了一些问题，今天趁着新开发的canal引擎已经上线，简单汇总下之前所遇到的一些问题，本篇则主要是说明一下与MySQL相关的一些问题；
关于canal的介绍可以点击这里。
关于MySql binlog的概念，可以看下MySql官网（中文）的这篇介绍：MySQL服务器日志；
想要先简单理解下binlog日志的，可以参考如下内容：
在MySql中常用的数据库表结构变更DDL和DML都会产生对应的操作日志，通过这个操作日志一般可以用来进行MySql故障后的数据恢复，以及MySql的主从同步使用；那么这个日志就是我们常说的MySql的binlog日志，binlog日志是一个二进制日志文件，并非是纯粹的文本文件。
开启MySql binlog
配置 binlog-format 为 ROW 模式，my.cnf 中配置如下
[mysqld]
log-bin=mysql-bin # 开启 binlog
binlog-format=ROW # 选择 ROW 模式
binlog-format
这里重点说一下binlog-format 配置的含义：
MySql中binlog-format 用来设置所产生的binLog日志格式，分别支持如下三种格式类型：
- STATEMENT：基于SQL语句的复制（statement-based replication, SBR）
- ROW：基于行的复制（row-based replication, RBR）
- MIXED：混合模式复制（mixed-based replication, MBR）
在 MySQL 5.7.7 之前，默认的格式是 STATEMENT，在 MySQL 5.7.7 及更高版本中，默认值是 ROW。
Statement
每一条会修改数据的sql都会记录在binlog中
优点：不需要记录每一行的变化，减少了binlog日志量，节约了IO, 提高了性能。
缺点：由于记录的只是执行语句，为了这些语句能在slave上正确运行，因此还必须记录每条语句在执行的时候的一些相关信息，以保证所有语句能在slave得到和在master端执行的时候相同的结果。另外mysql的复制，像一些特定函数的功能，slave与master要保持一致会有很多相关问题。
Row
5.1.5版本的MySQL才开始支持 row level 的复制,它不记录sql语句上下文相关信息，仅保存哪条记录被修改。
优点： binlog中可以不记录执行的sql语句的上下文相关的信息，仅需要记录那一条记录被修改成什么了。所以row的日志内容会非常清楚的记录下每一行数据修改的细节。而且不会出现某些特定情况下的存储过程，或function，以及trigger的调用和触发无法被正确复制的问题.
缺点:所有的执行的语句当记录到日志中的时候，都将以每行记录的修改来记录，这样可能会产生大量的日志内容。
将二进制日志格式设置为ROW时，有些更改仍然使用基于语句的格式，包括所有DDL语句，例如CREATE TABLE， ALTER TABLE，或 DROP TABLE。
Mixed
从5.1.8版本开始，MySQL提供了Mixed格式，实际上就是Statement与Row的结合。
在Mixed模式下，一般的语句修改使用statment格式保存binlog，如一些函数，statement无法完成主从复制的操作，则采用row格式保存binlog，MySQL会根据执行的每一条具体的sql语句来区分对待记录的日志形式，也就是在Statement和Row之间选择一种。
关于二进制日志格式的官网介绍可以参考这里
5.7版本以后默认情况下binlog的格式设置为ROW，ROW模式记录的是每行实际数据的变更，所以将会导致对应的日志文件较大的情况，但是现在有SSD和万兆光纤网络，所以这些磁盘IO和网络IO也是问题不大的；
binlog_row_image
在MySql5.7 版本以后除了binlog-format参数用来调整binlog日志的格式外，还多了另外一个参数：binlog_row_image，这个参数一般情况下不太会被注意的到，但实际的作用也是异常强烈的；
上面提到了，设置binlog-format为ROW后，MySql会记录每一行数据修改的细节日志，在此之上，binlog_row_image则是对ROW的配置进行了更下一步的细分；
binlog_row_image可设置的值如下：
- FULL：记录数据变更的所有前镜像和后镜像
- MINIMAL：binlog日志的前镜像只记录唯一识别列(唯一索引列、主键列)，后镜像只记录修改列。
- NOBLOB：binlog记录所有的列，就像full格式一样。但对于BLOB或TEXT格式的列，如果他不是唯一识别列(唯一索引列、主键列)，或者没有修改，那就不记录。
此处的前镜像是指：数据库表中修改前的内容；后镜像则指：数据库表中修改后的内容；
详细解释：
binlog_row_image=FULL,binlog记录所有数据的前后镜像，是最安全的设置，但性能也是最低的，如果数据出现误操作，可以能通过flashback或binlog2sql等快速闪回工具恢复数据，如果对短时间前后数据安全性要求比较高，推荐此设置。
binlog_row_image=MINIMAL,binlog日志的前镜像只记录唯一识别列(唯一索引列、主键列)，后镜像只记录修改列，性能是最高的，占用的资源等也是最少的，如果数据出现误操作，不能通过flashback或binlog2sql等快速闪回工具恢复数据。
binlog_row_image=NOBLOB,binlog记录所有的列，就像full格式一样。但对于BLOB或TEXT格式的列，如果他不是唯一识别列(唯一索引列、主键列)，或者没有修改，那就不记录。此设置可以简单理解为在没有text和blob等大字段时，效果同FULL一样；在有text和blob等大字段时，如果大字段不是唯一识别列(唯一索引列、主键列)，或者没有修改，那就不记录。
也就是说，虽然binlog每次记录的数据格式还是按照行来进行日志记录，但是通过设置binlog_row_image参数可以调整当前所记录的行日志是只记录行的变更前的日志镜像的主键列，还是记录行变更前的所有列的信息记录等。可能到此处，对于不知道binlog所记录的内容具体是何物的同学还是觉得有一丝迷茫，毕竟上述的都是概念，所以如下开始查看一下MySql库中的binlog日志。使其更加清晰上述的概念
测试参数变更对日志记录内容的影响
MySql测试服务器my.cnf的binlog配置如下：
# 指定binlog的产生日志目录
log_bin = /opt/mysqlDB/logs/binLog/mysql-bin
binlog_format = ROW
expire_logs_days = 7 #超过7天的binlog删除
# 当前开启的为FULL模式
binlog_row_image = FULL
log_error = /opt/mysqlDB/logs/errorLog/mysql-error.log #错误日志路径
slow_query_log = 1
long_query_time = 10 #慢查询时间 超过1秒则为慢查询
slow_query_log_file = /opt/mysqlDB/logs/slowLog/mysql-slow.log
performance_schema = 0
explicit_defaults_for_timestamp
lower_case_table_names = 1 #不区分大小写
skip-external-locking #MySQL选项以避免外部锁定。该选项默认开启
default-storage-engine = InnoDB #默认存储引擎
binlog_row_image 配置为FULL进行测试
在开启对应的binlog日志，以及设置完对应的binlog_row_image的日志后，新建一条测试数据;
insert into whitelist(id,phone,create_time) values(2,'新增测试数据','2020-11-17')
切换至linux服务器查看当前MySql已生成的binlog日志信息，可以看到如下内容：
使用show master status 查看当前主库正在使用的binlog的文件信息
使用 mysqlbinlog命令查看对应的binlog日志内容
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000011 | tail -n 25
#201117 15:56:44 server id 1 end_log_pos 3620 CRC32 0x0d682928 Anonymous_GTID last_committed=3 sequence_number=4 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 3620
#201117 15:56:44 server id 1 end_log_pos 3701 CRC32 0xd969bac8 Query thread_id=53 exec_time=0 error_code=0
SET TIMESTAMP=1605599804/*!*/;
BEGIN
/*!*/;
# at 3701
#201117 15:56:44 server id 1 end_log_pos 3767 CRC32 0xb8d6a89d Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 3767
#201117 15:56:44 server id 1 end_log_pos 3831 CRC32 0x10b7810a Write_rows: table id 112 flags: STMT_END_F
### INSERT INTO `gangtise_test`.`whitelist`
### SET
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
### @2='新增测试数据' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
# at 3831
#201117 15:56:44 server id 1 end_log_pos 3862 CRC32 0xc47a86ca Xid = 446
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日志
update whitelist set phone='修改测试数据' where id=2
重新查看binlog日志内容
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000011 | tail -n 25
#201117 16:11:24 server id 1 end_log_pos 4008 CRC32 0xa5dd2930 Query thread_id=53 exec_time=0 error_code=0
SET TIMESTAMP=1605600684/*!*/;
BEGIN
/*!*/;
# at 4008
#201117 16:11:24 server id 1 end_log_pos 4074 CRC32 0xafd4f105 Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 4074
#201117 16:11:24 server id 1 end_log_pos 4168 CRC32 0x82219047 Update_rows: table id 112 flags: STMT_END_F
### UPDATE `gangtise_test`.`whitelist`
### WHERE
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
### @2='新增测试数据' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
### SET
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
### @2='修改测试数据' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
# at 4168
#201117 16:11:24 server id 1 end_log_pos 4199 CRC32 0x6c4d894f Xid = 474
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_row_image配置为MINIMAL
重新新增一条数据
insert into whitelist(id,phone,create_time) values(3,'新增测试数据2','2020-11-17')
查看binlog日志如下
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000012 | tail -n 25
#201117 16:40:13 server id 1 end_log_pos 524 CRC32 0x74417b92 Anonymous_GTID last_committed=1 sequence_number=2 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 524
#201117 16:40:13 server id 1 end_log_pos 605 CRC32 0x8c934110 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1605602413/*!*/;
BEGIN
/*!*/;
# at 605
#201117 16:40:13 server id 1 end_log_pos 671 CRC32 0x343d3210 Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 671
#201117 16:40:13 server id 1 end_log_pos 736 CRC32 0x710c0aac Write_rows: table id 112 flags: STMT_END_F
### INSERT INTO `gangtise_test`.`whitelist`
### SET
### @1=3 /* INT meta=0 nullable=0 is_null=0 */
### @2='新增测试数据2' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
### @3='2020-11-17 00:00:00' /* DATETIME(0) meta=0 nullable=1 is_null=0 */
# at 736
#201117 16:40:13 server id 1 end_log_pos 767 CRC32 0x05dd65be Xid = 22
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*/;
修改数据
update whitelist set phone='修改测试数据2' where id=3
查看binlog日志
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000012 | tail -n 25
#201117 16:45:45 server id 1 end_log_pos 832 CRC32 0x226707b1 Anonymous_GTID last_committed=2 sequence_number=3 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 832
#201117 16:45:45 server id 1 end_log_pos 913 CRC32 0x0d67fee3 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1605602745/*!*/;
BEGIN
/*!*/;
# at 913
#201117 16:45:45 server id 1 end_log_pos 979 CRC32 0xd2ed2ad9 Table_map: `gangtise_test`.`whitelist` mapped to number 112
# at 979
#201117 16:45:45 server id 1 end_log_pos 1041 CRC32 0xb633518f Update_rows: table id 112 flags: STMT_END_F
### UPDATE `gangtise_test`.`whitelist`
### WHERE
### @1=3 /* INT meta=0 nullable=0 is_null=0 */
### SET
### @2='修改测试数据2' /* VARSTRING(192) meta=192 nullable=1 is_null=0 */
# at 1041
#201117 16:45:45 server id 1 end_log_pos 1072 CRC32 0x88b19729 Xid = 29
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*/;
如上，就可以很清晰的知道MySql中binlog_row_image配置后所产生的结果和不同，在配置为MINIMAL的情况下进行update时，就只会记录前镜像的唯一识别列，而后镜像则只会记录修改列；而并不是像FULL的配置时会记录完整的修改前和修改后的镜像；
由于canal中间件是直接接入的MySql的主从协议，模拟自身为MySql从节点以此获取对应的MySql实时binlog日志信息，然后再进行实时的日志解析和数据同步等操作。由于canal自身只是从MySql master处获取对应的binlog信息后进行解析再同步的操作，所以，当MySql所产生的日志内容不符合canal的解析规则，那么此时canal将会无解。。导致一系列的数据同步问题产生；
关于canal会产生上述问题的现象，可以查看github上canal的该issue：点击这里查看issue；
本篇的内容，也算是对该issue问题的一个详细说明而存在；
常用的MySql binlog命令
-- 查看主库当前正在使用的binlog文件是那个文件
show master status
-- 查看从库正在使用的binlog文件
show slave status
-- 查看当前master机器所有的binlog文件
show master logs
show master logs where log_name like '%004288%';
-- 查看当前Mysql配置
show variables
-- 查看当前MySql binLog的format值
show variables like 'binlog_format';
-- 查看当前MySql是否开启bin log
show variables like 'log_bin';
-- 查看log相关的配置
show variables like '%log_%';
show variables like 'log_slave_updates';
# 事件查询命令
# IN 'log_name' ：指定要查询的binlog文件名(不指定就是第一个binlog文件)
# FROM pos ：指定从哪个pos起始点开始查起(不指定就是从整个文件首个pos点开始算)
# LIMIT [offset,] ：偏移量(不指定就是0)
# row_count ：查询总条数(不指定就是所有行)
show binlog events [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count];
# 查看 binlog 内容
show binlog events;
# 查看具体一个binlog文件的内容 （in 后面为binlog的文件名）
show binlog events in 'master.000003';
# 设置binlog文件保存事件，过期删除，单位天
set global expire_log_days=3;
# 删除当前的binlog文件
reset master;
# 删除slave的中继日志
reset slave;
# 删除指定日期前的日志索引中binlog日志文件
purge master logs before '2019-03-09 14:00:00';
# 删除指定日志文件
purge master logs to 'master.000003';
# mysqlbinlog 的执行格式
mysqlbinlog [options] log_file ...
# 查看bin-log二进制文件（shell方式）
mysqlbinlog -v --base64-output=decode-rows /var/lib/mysql/master.000003
# 查看bin-log二进制文件（带查询条件）
mysqlbinlog -v --base64-output=decode-rows /var/lib/mysql/master.000003 \
--start-datetime="2019-03-01 00:00:00" \
--stop-datetime="2019-03-10 00:00:00" \
--start-position="5000" \
--stop-position="20000"
查看binglog开头的MySql配置
show variables like '%binlog_%';
查看指定MySql的binglog日志
[root@dev bin]# ./mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS /opt/mysqlDB/logs/binLog/mysql-bin.000009 | tail -n 100
设置指定参数的配置
set binlog_row_image ='FULL';
设置指定的参数永久有效的方式是直接修改my.cnf配置，然后重启即可；上述直接通过运行sql的方式修改配置，只能在当前的connection会话中有效，会话重新断开后则配置无效，所以进行测试验证的时候，直接修改my.cnf的方式是最有效的方式，
对于自建 MySQL , 需要先开启 Binlog 写入功能，配置 binlog-format 为 ROW 模式，my.cnf 中配置如下
[mysqld]
log-bin=mysql-bin # 开启 binlog
binlog-format=ROW # 选择 ROW 模式
server_id=1 # 配置 MySQL replaction 需要定义，不要和 canal 的 slaveId 重复
-- 创建canal账号，并赋予mysql slave权限
CREATE USER canal IDENTIFIED BY 'canal';
GRANT SELECT, REPLICATION SLAVE, REPLICATION CLIENT ON *.* TO 'canal'@'%';
-- GRANT ALL PRIVILEGES ON *.* TO 'canal'@'%' ;
FLUSH PRIVILEGES;
-- 查询账户权限
show grants for 'canal'
参考链接：
官方：MySql二进制文件说明；
官方：接入MySql Slave需遵从的协议规范
MySql CPU彪高到百分之1000的排查思路；
Canal 数据更新异常的issues地址
Mysql的Binlog原理；MySql Binlog介绍
binlog_row_image参数；MySQL 5.7贴心参数之binlog_row_image
