MySQL binlog：格式、增量恢复、闪回、Java 解析

MySQL 的 binlog 日志文件，记录了数据库表的全部修改操作。本文简单整理 MySQL binlog 相关知识，以及如何使用 binlog 恢复或闪回数据库数据。

STATEMENT 格式的 binlog

要想开启 binlog，需要在启动 MySQL 时传入 --log-bin 参数。或者也可以在 MySQL 配置文件 /etc/my.cnf，设置 log_bin 开启 binlog。MySQL 5.7 开始，开启 binlog 后，--server-id 参数也必须指定，否则 MySQL 服务器会启动失败。

binlog_format 支持 STATEMENT, ROW, MIXED 三种格式，MySQL 5.5 和 5.6 默认为 STATEMENT，MySQL 5.7.7 开始默认为 ROW。若 SQL 使用 UUID(), RAND(), VERSION() 等函数，或者使用存储过程、自定义函数，基于 STATEMENT 的主从复时，是不安全的（很多人可能会认为 NOW(), CURRENT_TIMESTAMP 这些函数也是不安全的，事实上是安全的）[ doc1, doc2 ]。基于 ROW 的主从复制，是最安全的复制方式。

现在先来看下 STATEMENT 格式的 binlog，/etc/my.cnf 文件修改的内容如下：

server_id = 1
log_bin = mysql-bin
binlog_format = STATEMENT
binlog_row_image=FULL

重启 MySQL 后，在数据目录 datadir 下，比如 /var/lib/mysql/，将会生成相应的 binlog 文件，mysql-bin.index 和 mysql-bin.000001。.index 后缀的文件保存全部 binlog 文件名。mysql-bin.000001 文件记录 binlog 内容。每次 MySQL 启动或者 flush 日志，都将按序号创建一个新的日志文件。另外，当日志文件大小超过 max_binlog_size 时，也会创建一个新的日志文件。

现在来试一试 binlog 功能。假设在 testdb 库在有 hello 表，并对其中某行做修改操作：

mysql> select * from hello;
+----+-------+
| id | name  |
+----+-------+
|  1 | Andy  |
|  2 | Bill  |
|  3 | Candy |
+----+-------+
4 rows in set (0.00 sec)

mysql> update hello set name = 'Will' where id = 3;
Query OK, 1 row affected (0.02 sec)
Rows matched: 1  Changed: 1  Warnings: 0

binlog 为二进制文件，需要使用 mysqlbinlog（doc, man）命令查看：

$ sudo mysqlbinlog /var/lib/mysql/mysql-bin.000001  # 直接在 mysql 服务器上读取 binlog 文件
$ mysqlbinlog -R -h192.168.2.107 -uroot -p123456 mysql-bin.000001  # 或者，远程读取 binlog 文件

执行 update 后相应新增的 binlog 文件内容：

# at 154
#180617 22:47:49 server id 1  end_log_pos 219 CRC32 0x4bd9d69b     Anonymous_GTID    last_committed=0    sequence_number=1    rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 219
#180617 22:47:49 server id 1  end_log_pos 302 CRC32 0x476fafc9     Query    thread_id=2    exec_time=0    error_code=0
SET TIMESTAMP=1529246869/*!*/;
SET @@session.pseudo_thread_id=2/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 302
#180617 22:47:49 server id 1  end_log_pos 423 CRC32 0x7f2c2c7a     Query    thread_id=2    exec_time=0    error_code=0
use `testdb`/*!*/;
SET TIMESTAMP=1529246869/*!*/;
update hello set name = 'Will' where id = 3
/*!*/;
# at 423
#180617 22:47:49 server id 1  end_log_pos 454 CRC32 0x68da744a     Xid = 12
COMMIT/*!*/;

ROW 格式的 binlog

修改 /etc/my.cnf 的 binlog_format 为 ROW，再重启 MySQL。格式修改后，会生成一个新的 binlog 文件 mysql-bin.000002。

mysql> show create table hello;
+-------+-------------------------------------------------------------------------+
| Table | Create Table
+-------+-------------------------------------------------------------------------+
| hello | CREATE TABLE `hello` (
  `id` bigint(20) NOT NULL AUTO_INCREMENT,
  `name` varchar(20) DEFAULT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=4 DEFAULT CHARSET=utf8mb4 |
+-------+-------------------------------------------------------------------------+
1 row in set (0.00 sec)

mysql> select * from hello where id;
+----+------+
| id | name |
+----+------+
|  1 | Andy |
|  2 | Lily |
|  3 | Will |
+----+------+
1 row in set (0.00 sec)

mysql> update hello set name = 'David' where id = 3;
Query OK, 1 row affected (0.02 sec)
Rows matched: 1  Changed: 1  Warnings: 0

查看 ROW 格式的 binlog，需要使用 sudo mysqlbinlog -v --base64-output=DECODE-ROWS /var/lib/mysql/mysql-bin.000002 命令。执行 update 后相应新增的 binlog 内容：

# at 154
#180617 22:54:13 server id 1  end_log_pos 219 CRC32 0x2ce70d4d     Anonymous_GTID    last_committed=0    sequence_number=1    rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 219
#180617 22:54:13 server id 1  end_log_pos 293 CRC32 0x8183fddf     Query    thread_id=2    exec_time=0    error_code=0
SET TIMESTAMP=1529247253/*!*/;
SET @@session.pseudo_thread_id=2/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 293
#180617 22:54:13 server id 1  end_log_pos 346 CRC32 0x0fc7e1a4     Table_map: `testdb`.`hello` mapped to number 110
# at 346
#180617 22:54:13 server id 1  end_log_pos 411 CRC32 0xb58e729d     Update_rows: table id 110 flags: STMT_END_F
### UPDATE `testdb`.`hello`
### WHERE
###   @1=3
###   @2='Will'
### SET
###   @1=3
###   @2='David'
# at 411
#180617 22:54:13 server id 1  end_log_pos 442 CRC32 0xef964db8     Xid = 13
COMMIT/*!*/;

若执行如下 SQL：

mysql> insert hello (name) values ('Frank');
Query OK, 1 row affected (0.02 sec)

相应生成的 binlog 内容：

# at 442
#180617 22:55:47 server id 1  end_log_pos 507 CRC32 0x79de08a7     Anonymous_GTID    last_committed=1    sequence_number=2    rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 507
#180617 22:55:47 server id 1  end_log_pos 581 CRC32 0x56f9eb6a     Query    thread_id=2    exec_time=0    error_code=0
SET TIMESTAMP=1529247347/*!*/;
BEGIN
/*!*/;
# at 581
#180617 22:55:47 server id 1  end_log_pos 634 CRC32 0xedb73620     Table_map: `testdb`.`hello` mapped to number 110
# at 634
#180617 22:55:47 server id 1  end_log_pos 684 CRC32 0x525a6a70     Write_rows: table id 110 flags: STMT_END_F
### INSERT INTO `testdb`.`hello`
### SET
###   @1=4
###   @2='Frank'
# at 684
#180617 22:55:47 server id 1  end_log_pos 715 CRC32 0x09a0d4de     Xid = 14
COMMIT/*!*/;

若执行如下 SQL：

mysql> delete from hello where id = 2;
Query OK, 1 row affected (0.02 sec)

相应生成的 binlog 内容：

# at 715
#180617 22:56:44 server id 1  end_log_pos 780 CRC32 0x9f52450e     Anonymous_GTID    last_committed=2    sequence_number=3    rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 780
#180617 22:56:44 server id 1  end_log_pos 854 CRC32 0x0959bc8d     Query    thread_id=2    exec_time=0    error_code=0
SET TIMESTAMP=1529247404/*!*/;
BEGIN
/*!*/;
# at 854
#180617 22:56:44 server id 1  end_log_pos 907 CRC32 0x2945260f     Table_map: `testdb`.`hello` mapped to number 110
# at 907
#180617 22:56:44 server id 1  end_log_pos 956 CRC32 0xc70df255     Delete_rows: table id 110 flags: STMT_END_F
### DELETE FROM `testdb`.`hello`
### WHERE
###   @1=2
###   @2='Bill'
# at 956
#180617 22:56:44 server id 1  end_log_pos 987 CRC32 0x0c98f18e     Xid = 15
COMMIT/*!*/;

使用 binlog 增量恢复

MySQL 逻辑备份通常会结合全量备份和增量备份，使用 mysqldump 定期全量备份数据库，然后利用 binlog 保存增量数据。恢复数据时，就是用 mysqldump 备份的数据恢复到备份的时间点。数据库在备份时间点到当前时间的增量修改，则通过 mysqlbinlog 将 binlog 中的增量数据恢复到数据库。现在假设已经使用 mysqldump 将数据库还原到：

mysql> select * from hello;
+----+------+
| id | name |
+----+------+
|  1 | Andy |
|  2 | Lily |
|  3 | Will |
+----+------+
3 rows in set (0.00 sec)

之后执行的 SQL：

update hello set name = 'David' where id = 3;
insert hello (name) values ('Frank');
delete from hello where id = 2;

不管是使用 STATEMENT 还是 ROW，mysqlbinlog 命令都可以将 binlog 增量恢复到数据库 [doc ]。

观察 binlog 可以看到，从最开始的 update hello set name = 'David' where id = 3; 到最终的 delete from hello where id = 2;，时间上从 "2018-06-17 22:54:13" 到 "2018-06-17 22:56:44"，所以基于时间点恢复，命令如下：

$ sudo mysqlbinlog --start-datetime="2018-06-17 22:54:13" --stop-datetime="2018-06-17 22:56:44" mysql-bin.000002 | mysql -uroot -p123456

binlog 的事件位置号是从 "154" 到 "956"，但需要注意的是用 --start-position 和 --stop-position 指定位置点范围，逻辑上对应的是 start <= position < stop，所以基于时间点恢复，命令如下：

$ sudo mysqlbinlog --start-position=154 --stop-position=957 mysql-bin.000002 | mysql -uroot -p123456

两种方式任意执行，都能将数据恢复到：

mysql> select * from hello;
+----+-------+
| id | name  |
+----+-------+
|  1 | Andy  |
|  3 | David |
|  4 | Frank |
+----+-------+
3 rows in set (0.00 sec)

使用 binlog2sql 闪回

binlog2sql，作者为曹单锋，大众点评 DBA。binlog2sql，从 MySQL binlog 解析出你要的 SQL。根据不同选项，你可以得到原始 SQL、回滚 SQL、去除主键的 INSERT SQL 等。binlog2sql，底层实现依赖 python-mysql-replication，由该库完成 MySQL 复制协议和 binlog 格式的解析。

$ python binlog2sql/binlog2sql.py -h192.168.2.107 -uroot -p123456 --start-position=154 --stop-position=957 --start-file='mysql-bin.000002'
UPDATE `testdb`.`hello` SET `id`=3, `name`='David' WHERE `id`=3 AND `name`='Will' LIMIT 1; #start 4 end 411 time 2018-06-17 22:54:13
INSERT INTO `testdb`.`hello`(`id`, `name`) VALUES (4, 'Frank'); #start 442 end 684 time 2018-06-17 22:55:47
DELETE FROM `testdb`.`hello` WHERE `id`=2 AND `name`='Bill' LIMIT 1; #start 715 end 956 time 2018-06-17 22:56:44

生成回滚 sql：

$ python binlog2sql/binlog2sql.py --flashback -h192.168.2.107 -uroot -p123456 --start-position=154 --stop-position=956 --start-file='mysql-bin.000002'
INSERT INTO `testdb`.`hello`(`id`, `name`) VALUES (2, 'Bill'); #start 715 end 956 time 2018-06-17 22:56:44
DELETE FROM `testdb`.`hello` WHERE `id`=4 AND `name`='Frank' LIMIT 1; #start 442 end 684 time 2018-06-17 22:55:47
UPDATE `testdb`.`hello` SET `id`=3, `name`='Will' WHERE `id`=3 AND `name`='David' LIMIT 1; #start 154 end 411 time 2018-06-17 22:54:13

闪回的现实原理很简单，先通过 MySQL 复制协议的 com-binlog-dump 命令 dump 出 binlog，然后按照 binlog 的格式规范解析 binlog，将 binlog 转换成 SQL，再将这些 SQL 转换反向逻辑的 SQL，最后再倒序执行。具体可以看，binlog2sql 作者的文章 [ref ]。

Java 解析 binlog

上文中的 binlog2sql 其实底层依赖 python-mysql-replication 库，这是 Python 库。如果想使用 Java 解析 binlog 可以使用 mysql-binlog-connector-java（github）库。目前开源的 CDC 工具，如 Zendesk maxwell、Redhat debezium、LinkedIn Databus 等都底层依赖 mysql-binlog-connector-java 或者其前身 open-replicator。使用 mysql-binlog-connector-java 的示例代码如下：

BinaryLogClient client = new BinaryLogClient("192.168.2.107", 3306, "root", "123456");
client.setBinlogFilename("mysql-bin.000001");
client.setBinlogPosition(4);
client.setBlocking(false);
client.registerEventListener(event -> {
    System.out.println(event);
});
client.connect();

输出（省略部分内容）：

...
Event{header=EventHeaderV4{timestamp=1529247253000, eventType=TABLE_MAP, serverId=1, headerLength=19, dataLength=34, nextPosition=346, flags=0}, data=TableMapEventData{tableId=110, database='testdb', table='hello', columnTypes=8, 15, columnMetadata=0, 40, columnNullability={1}}}
Event{header=EventHeaderV4{timestamp=1529247253000, eventType=EXT_UPDATE_ROWS, serverId=1, headerLength=19, dataLength=46, nextPosition=411, flags=0}, data=UpdateRowsEventData{tableId=110, includedColumnsBeforeUpdate={0, 1}, includedColumns={0, 1}, rows=[
    {before=[3, Will], after=[3, David]}
]}}
...
Event{header=EventHeaderV4{timestamp=1529247347000, eventType=TABLE_MAP, serverId=1, headerLength=19, dataLength=34, nextPosition=634, flags=0}, data=TableMapEventData{tableId=110, database='testdb', table='hello', columnTypes=8, 15, columnMetadata=0, 40, columnNullability={1}}}
Event{header=EventHeaderV4{timestamp=1529247347000, eventType=EXT_WRITE_ROWS, serverId=1, headerLength=19, dataLength=31, nextPosition=684, flags=0}, data=WriteRowsEventData{tableId=110, includedColumns={0, 1}, rows=[
    [4, Frank]
]}}
...
Event{header=EventHeaderV4{timestamp=1529247404000, eventType=TABLE_MAP, serverId=1, headerLength=19, dataLength=34, nextPosition=907, flags=0}, data=TableMapEventData{tableId=110, database='testdb', table='hello', columnTypes=8, 15, columnMetadata=0, 40, columnNullability={1}}}
Event{header=EventHeaderV4{timestamp=1529247404000, eventType=EXT_DELETE_ROWS, serverId=1, headerLength=19, dataLength=30, nextPosition=956, flags=0}, data=DeleteRowsEventData{tableId=110, includedColumns={0, 1}, rows=[
    [2, Bill]
]}}

转自
https://nullwy.me/2018/06/mysql-binlog/

人面猴
序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
沈念sama阅读 205,033评论 6赞 478
死咒
序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
沈念sama阅读 87,725评论 2赞 381
救了他两次的神仙让他今天三更去死
文/潘晓璐我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
开封第一讲书人阅读 151,473评论 0赞 338
道士缉凶录：失踪的卖姜人
文/不坏的土叔我叫张陵，是天一观的道长。经常有香客问我，道长，这世上最难降的妖魔是什么？我笑而不...
开封第一讲书人阅读 54,846评论 1赞 277
港岛之恋（遗憾婚礼）
正文为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
茶点故事阅读 63,848评论 5赞 368
恶毒庶女顶嫁案：这布局不是一般人想出来的
文/花漫我一把揭开白布。她就那样静静地躺着，像睡着了一般。火红的嫁衣衬着肌肤如雪。梳的纹丝不乱的头发上，一...
开封第一讲书人阅读 48,691评论 1赞 282
城市分裂传说
那天，我揣着相机与录音，去河边找鬼。笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。我是一名探鬼主播，决...
沈念sama阅读 38,053评论 3赞 399
双鸳鸯连环套：你想象不到人心有多黑
文/苍兰香墨我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
开封第一讲书人阅读 36,700评论 0赞 258
万荣杀人案实录
序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
沈念sama阅读 42,856评论 1赞 300
护林员之死
正文独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋以下内容为张勋视角年9月15日...
茶点故事阅读 35,676评论 2赞 323
白月光启示录
正文我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
茶点故事阅读 37,787评论 1赞 333
活死人
序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
沈念sama阅读 33,430评论 4赞 321
日本核电站爆炸内幕
正文年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
茶点故事阅读 39,034评论 3赞 307
男人毒药：我在死后第九天来索命
文/蒙蒙一、第九天我趴在偏房一处隐蔽的房顶上张望。院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
开封第一讲书人阅读 29,990评论 0赞 19
一桩弑父案，背后竟有这般阴谋
文/苍兰香墨我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。一阵脚步声响...
开封第一讲书人阅读 31,218评论 1赞 260
情欲美人皮
我被黑心中介骗来泰国打工，没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。一个月前我还...
沈念sama阅读 45,174评论 2赞 352
代替公主和亲
正文我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
茶点故事阅读 42,526评论 2赞 343