binlog 想必大家都不陌生,在主从复制或者某些情况下的数据恢复会用到。由于 binlog 是二进制数据,要查看一般都借助 mysqlbinlog 工具。这篇笔记分析了 binlog 格式,希望能够了解下 mysqlbinlog 工具背后所做的事情。

1. 什么时候写 binlog

在说明什么时候写 binlog 前,先简单介绍下 binlog 的用途。binlog 是二进制日志文件,用于记录 mysql 的数据更新或者潜在更新 (比如 DELETE 语句执行删除而实际并没有符合条件的数据),在 mysql 主从复制中就是依靠的 binlog。在 mysql 中开启 binlog 需要设置 my.cnf 中的 log_bin 参数,另外也可以通过 binlog_do_db
指定要记录 binlog 的数据库和 binlog_ignore_db 指定不记录 binlog 的数据库。对运行中的 mysql 要启用 binlog 可以通过命令SET SQL_LOG_BIN=1来设置。设置完成,我们就可以来测试 binlog 了。

需要注意下 innodb 引擎中的 redo/undo log 与 mysql binlog 是完全不同的日志,它们主要有以下几个区别:

  • a)层次不同。redo/undo log 是 innodb 层维护的,而 binlog 是 mysql server 层维护的,跟采用何种引擎没有关系,记录的是所有引擎的更新操作的日志记录。innodb 的 redo/undo log 更详细的说明可以参见姜承尧的《mysql 技术内幕 - innodb 存储引擎》一书中相关章节。
  • b)记录内容不同。redo/undo 日志记录的是每个页的修改情况,属于物理日志 + 逻辑日志结合的方式(redo log 物理到页,页内采用逻辑日志,undo log 采用的是逻辑日志),目的是保证数据的一致性。binlog 记录的都是事务操作内容,比如一条语句DELETE FROM TABLE WHERE i > 1之类的,不管采用的是什么引擎,当然格式是二进制的,要解析日志内容可以用这个命令mysqlbinlog -vv BINLOG。
  • c)记录时机不同。redo/undo 日志在事务执行过程中会不断的写入;而 binlog 仅仅在事务提交后才写入到日志,之前描述有误,binlog 是在事务最终 commit 前写入的,多谢anti-semicolon 指出。当然,binlog 什么时候刷新到磁盘跟参数sync_binlog相关。

显然,我们执行 SELECT 等不涉及数据更新的语句是不会记 binlog 的,而涉及到数据更新则会记录。要注意的是,对支持事务的引擎如 innodb 而言,必须要提交了事务才会记录 binlog。

binlog 刷新到磁盘的时机跟 sync_binlog 参数相关,如果设置为 0,则表示 MySQL 不控制 binlog 的刷新,由文件系统去控制它缓存的刷新,而如果设置为不为 0 的值则表示每 sync_binlog 次事务,MySQL 调用文件系统的刷新操作刷新 binlog 到磁盘中。设为 1 是最安全的,在系统故障时最多丢失一个事务的更新,但是会对性能有所影响,一般情况下会设置为 100 或者 0,牺牲一定的一致性来获取更好的性能。

通过命令SHOW MASTER LOGS可以看到当前的 binlog 数目。如下面就是我机器上的 mysql 的 binlog 情况,第一列是 binlog 文件名,第二列是 binlog 文件大小。可以通过设置expire_logs_days来指定 binlog 保留时间,要手动清理 binlog 可以通过指定 binlog 名字或者指定保留的日期,命令分别是:purge master logs to BINLOGNAME;和purge master logs before DATE;。

  1. ......
  2. | mysql-bin.000018 | 515 |
  3. | mysql-bin.000019 | 504 |
  4. | mysql-bin.000020 | 107 |
  5. +------------------+-----------+

2 binlog 格式解析

2.1 binlog 文件格式简介

binlog 格式分为 statement,row 以及 mixed 三种,mysql5.5 默认的还是 statement 模式,当然我们在主从同步中一般是不建议用 statement 模式的,因为会有些语句不支持,比如语句中包含 UUID 函数,以及 LOAD DATA IN FILE 语句等,一般推荐的是 mixed 格式。暂且不管这三种格式的区别,看看 binlog 的存储格式是什么样的。binlog 是一个二进制文件集合,当然除了我们看到的 mysql-bin.xxxxxx 这些 binlog 文件外,还有个 binlog 索引文件 mysql-bin.index。如官方文档中所写,binlog 格式如下:

  • binlog 文件以一个值为 0Xfe62696e 的魔数开头,这个魔数对应 0xfe ‘b’’i’’n’。
  • binlog 由一系列的 binlog event 构成。每个 binlog event 包含 header 和 data 两部分。
    • header 部分提供的是 event 的公共的类型信息,包括 event 的创建时间,服务器等等。
    • data 部分提供的是针对该 event 的具体信息,如具体数据的修改。
  • 从 mysql5.0 版本开始,binlog 采用的是 v4 版本,第一个 event 都是format_desc event 用于描述 binlog 文件的格式版本,这个格式就是 event 写入 binlog 文件的格式。关于之前版本的 binlog 格式,可以参见http://dev.mysql.com/doc/internals/en/binary-log-versions.html
  • 接下来的 event 就是按照上面的格式版本写入的 event。
  • 最后一个rotate event用于说明下一个 binlog 文件。
  • binlog 索引文件是一个文本文件,其中内容为当前的 binlog 文件列表。比如下面就是一个 mysql-bin.index 文件的内容。
/var/log/mysql/mysql-bin.000019
/var/log/mysql/mysql-bin.000020
/var/log/mysql/mysql-bin.000021

接下来分析下几种常见的 event,其他的 event 类型可以参见官方文档。event 数据结构如下:

+=====================================+
| event  | timestamp         0 : 4    |
| header +----------------------------+
|        | type_code         4 : 1    |
|        +----------------------------+
|        | server_id         5 : 4    |
|        +----------------------------+
|        | event_length      9 : 4    |
|        +----------------------------+
|        | next_position    13 : 4    |
|        +----------------------------+
|        | flags            17 : 2    |
|        +----------------------------+
|        | extra_headers    19 : x-19 |
+=====================================+
| event  | fixed part        x : y    |
| data   +----------------------------+
|        | variable part              |
+=====================================+

2.2 format_desc event

下面是我在FLUSH LOGS之后新建的一个全新的 binlog 文件 mysql-bin.000053,从 binlog 第一个 event 也就是 format_desc event 开始分析(mysql 日志是小端字节序):

root@ubuntu:/var/log/mysql# hexdump -C mysql-bin.000053

00000000  fe 62 69 6e b8 b2 7f 56  0f 04 00 00 00 67 00 00  |.bin...V.....g..|
00000010  00 6b 00 00 00 01 00 04  00 35 2e 35 2e 34 36 2d  |.k.......5.5.46-|
00000020  30 75 62 75 6e 74 75 30  2e 31 34 2e 30 34 2e 32  |0ubuntu0.14.04.2|
00000030  2d 6c 6f 67 00 00 00 00  00 00 00 00 00 00 00 00  |-log............|
00000040  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 13  |................|
00000050  38 0d 00 08 00 12 00 04  04 04 04 12 00 00 54 00  |8.............T.|
00000060  04 1a 08 00 00 00 08 08  08 02 00                 |...........|

对照官方文档中的说明来看下format_desc event格式:

+=====================================+
| event  | timestamp         0 : 4    |
| header +----------------------------+
|        | type_code         4 : 1    | = FORMAT_DESCRIPTION_EVENT = 15
|        +----------------------------+
|        | server_id         5 : 4    |
|        +----------------------------+
|        | event_length      9 : 4    | >= 91
|        +----------------------------+
|        | next_position    13 : 4    |
|        +----------------------------+
|        | flags            17 : 2    |
+=====================================+
| event  | binlog_version   19 : 2    | = 4
| data   +----------------------------+
|        | server_version   21 : 50   |
|        +----------------------------+
|        | create_timestamp 71 : 4    |
|        +----------------------------+
|        | header_length    75 : 1    |
|        +----------------------------+
|        | post-header      76 : n    | = array of n bytes, one byte per event
|        | lengths for all            |   type that the server knows about
|        | event types                |
+=====================================+

前面 4 个字节是固定的 magic number, 值为 0x6e6962fe。接着是一个format_desc event,先看下 19 个字节的 header。这 19 个字节中前 4 个字节 0x567fb2b8 是时间戳,第 5 个字节 0x0f 是 event type,接着 4 个字节 0x00000004 是 server_id,再接着 4 个字节 0x00000067 是长度 103,然后的 4 个字节 0x0000006b 是下一个 event 的起始位置 107,接着的 2 个字节的 0x0001 是 flag(1 为 LOG_EVENT_BINLOG_IN_USE_F,标识 binlog 还没有关闭,binlog 关闭后,flag 会被设置为 0),这样 4+1+4+4+4+2=19 个字节的公共头就完了 (extra_headers 暂时没有用到)。然后是这个 event 的 data 部分,event 的 data 分为Fixed data和Variable data两部分,其中Fixed data是 event 的固定长度和格式的数据,Variable data则是长度变化的数据,比如 format_desc event 的 Fixed data 长度是 0x54=84 个字节。下面看下这 84=2+50+4+1+27 个字节的分配:开始的 2 个字节 0x0004 为 binlog 的版本号 4,接着的 50 个字节为 mysql-server 版本,如我的版本是 5.5.46-0ubuntu0.14.04.2-log,与SELECT version();查看的结果一致。接下来 4 个字节是 binlog 创建时间,这里是 0;然后的 1 个字节 0x13 是指之后所有 event 的公共头长度,这里都是 19;接着的 27 个字节中每个字节为 mysql 已知的 event(共 27 个)的 Fixed data 的长度;可以发现 format_desc event 自身的 Variable data 部分为空。

2.3 rotate event

接着我们不做额外操作,直接FLUSH LOGS,可以看到一个rotate event,此时的 binlog 内容如下:

......
00000060  ................................. c2 b3 7f 56 04  |..............V.|
00000070  04 00 00 00 2b 00 00 00  96 00 00 00 00 00 04 00  |....+...........|
00000080  00 00 00 00 00 00 6d 79  73 71 6c 2d 62 69 6e 2e  |......mysql-bin.|
00000090  30 30 30 30 35 34                                 |000054|
00000096

前面的内容跟之前的几乎一致,除了 format_desc event 的 flag 从 0x0001 变成了 0x0000。然后从 0x567fb3c2 开始是一个rotate event。依照前面的分析,前面 19 个字节为 event 的 header,其 event type 是 0x04,长度为 0x2b=43,下一个 event 起始位置为 0x96=150,然后是 flag 为 0x0000,接着是 event data 部分,首先的 8 个字节为Fixed data部分,记录的是下一个 binlog 的位置偏移 4,而余下来的 43-19-8=16 个字节为Variable data部分,记录的是下一个 binlog 的文件名 mysql-bin.000054。对照mysqlbinlog -vv mysql-bin.000053可以验证。

ssj@ubuntu:/var/log/mysql$ mysqlbinlog -vv mysql-bin.000053 
...
# at 4
#151227 17:43:20 server id 4  end_log_pos 107   Start: binlog v 4, server v 5.5.46-0ubuntu0.14.04.2-log created 151227 17:43:20
BINLOG '
uLJ/Vg8EAAAAZwAAAGsAAAAAAAQANS41LjQ2LTB1YnVudHUwLjE0LjA0LjItbG9nAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 107
#151227 17:47:46 server id 4  end_log_pos 150   Rotate to mysql-bin.000054  pos: 4
...

2.4 query event

刷新 binlog,设置binlog_format=statement,创建一个表CREATE TABLEtt(ivarchar(100) DEFAULT NULL) ENGINE=InnoDB, 然后在测试表 tt 中插入一条数据insert into tt values('abc'),会产生 3 个 event,包括 2 个 query event 和 1 个 xid event。其中 2 个 query event 分别是 BEGIN 以及 INSERT 语句,而 xid event 则是事务提交语句(xid event 是支持 XA 的存储引擎才有的,因为测试表 tt 是 innodb 引擎的,所以会有。如果是 myisam 引擎的表,也会有 BEGIN 和 COMMIT, 只不过 COMMIT 会是一个 query event 而不是 xid event)。

mysql> show binlog events in 'mysql-bin.000060';
+------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+
| Log_name         | Pos | Event_type  | Server_id | End_log_pos | Info                                                   |
+------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+
| mysql-bin.000060 |   4 | Format_desc |         4 |         107 | Server ver: 5.5.46-0ubuntu0.14.04.2-log, Binlog ver: 4 |
| mysql-bin.000060 | 107 | Query       |         4 |         175 | BEGIN                                                  |
| mysql-bin.000060 | 175 | Query       |         4 |         266 | use `test`; insert into tt values('abc')               |
| mysql-bin.000060 | 266 | Xid         |         4 |         293 | COMMIT /* xid=138 */                                   |
+------------------+-----+-------------+-----------+-------------+--------------------------------------------------

binlog 如下:

.......
0000006b  01 9d 82 56 02 04 00 00  00 44 00 00 00 af 00 00  |...V.....D......|
0000007b  00 08 00 26 00 00 00 00  00 00 00 04 00 00 1a 00  |...&............|
0000008b  00 00 00 00 00 01 00 00  00 00 00 00 00 00 06 03  |................|
0000009b  73 74 64 04 21 00 21 00  08 00 74 65 73 74 00 42  |std.!.!...test.B|
000000ab  45 47 49 4e                                       |EGIN|

000000af  01 9d 82 56 02 04 00 00  00 5b 00 00 00 0a 01 00  |...V.....[......|
000000bf  00 00 00 26 00 00 00 00  00 00 00 04 00 00 1a 00  |...&............|
000000cf  00 00 00 00 00 01 00 00  00 00 00 00 00 00 06 03  |................|
000000df  73 74 64 04 21 00 21 00  08 00 74 65 73 74 00 69  |std.!.!...test.i|
000000ef  6e 73 65 72 74 20 69 6e  74 6f 20 74 74 20 76 61  |nsert into tt va|
000000ff  6c 75 65 73 28 27 61 62  63 27 29                 |lues('abc')|

0000010a  01 9d 82 56 10 04 00 00  00 1b 00 00 00 25 01 00  |...V.........%..|
0000011a  00 00 00 8a 00 00 00 00  00 00 00                 |...........|

抛开 format_desc event,从 0000006b 开始分析第一个 query event。头部跟之前的 event 一样,只是 query event 的 type 为 0x02,长度为 0x44=64,下一个 event 位置为 0xaf=175。flag 为 8,接着是 data 部分,从 format_desc event 我们可以知道 query event 的Fixed data部分为 13 个字节,因此也可以算出Variable data部分为 64-19-13=32 字节。

  • Fixed data:首先的 4 个字节 0x00000026 为执行该语句的 thread id,接下来的 4 个字节是执行的时间 0(以秒为单位),接下来的 1 个字节 0x04 是语句执行时的默认数据库名字的长度,我这里数据库是 test,所以长度为 4. 接着的 2 个字节 0x0000 是错误码(注:通常情况下错误码是 0 表示没有错误,但是在一些非事务性表如 myisam 表执行INSERT...SELECT语句时可能插入部分数据后遇到 duplicate-key 错误会产生错误码 1062,或者是事务性表在 INSERT…SELECT 出错不会插入部分数据,但是在执行过程中 CTRL+C 终止语句也可能记录错误码。slave db 在复制时会执行后检查错误码是否一致,如果不一致,则复制过程会中止), 接着 2 个字节 0x001a 为状态变量块的长度 26。
  • Variable data:从 0x001a 之后的 26 个字节为状态变量块(这个暂时先不管),然后是默认数据库名 test,以 0x00 结尾,然后是 sql 语句 BEGIN,接下来就是第 2 个 query event 的内容了。

第二个 query event 与第一个格式一样,只是执行语句变成了insert into tt values('abc')。

第三个 xid event 为 COMMIT 语句。前 19 个字节是通用头部,type 是 16。data 部分中 Fixed data 为空,而 variable data 为 8 个字节,这 8 个字节 0x000000008a 是事务编号(注意事务编号不一定是小端字节序,因为是从内存中拷贝到磁盘的,所以这个字节序跟机器相关)。

2.5 table_map event & write_rows event

这两个 event 是在binlog_format=row的时候使用,设置 binlog_format=row,然后创建一个测试表

CREATE TABLE `trow` (
  `i` int(11) NOT NULL,
  `c` varchar(10) DEFAULT NULL,
  PRIMARY KEY (`i`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1`

执行语句INSERT INTO trow VALUES(1, NULL), (2, 'a'),这个语句会产生一个 query event,一个 table_map event、一个 write_rows event 以及一个 xid event。


mysql> show binlog events in 'mysql-bin.000074';
| Log_name         | Pos | Event_type  | Server_id | End_log_pos | Info                                                   |
+------------------+-----+-------------+-----------+-------------+--------------------------------------------------------+
| mysql-bin.000074 |   4 | Format_desc |         4 |         107 | Server ver: 5.5.46-0ubuntu0.14.04.2-log, Binlog ver: 4 |
| mysql-bin.000074 | 107 | Query       |         4 |         175 | BEGIN                                                  |
| mysql-bin.000074 | 175 | Table_map   |         4 |         221 | table_id: 50 (test.trow)                               |
| mysql-bin.000074 | 221 | Write_rows  |         4 |         262 | table_id: 50 flags: STMT_END_F                         |
| mysql-bin.000074 | 262 | Xid         |         4 |         289 | COMMIT /* xid=245 */

对应的 mysql-bin.000074 数据如下:

...
#query event (BEGIN)
0000006b  95 2a 85 56 02 04 00 00  00 44 00 00 00 af 00 00  |.*.V.....D......|
0000007b  00 08 00 26 00 00 00 00  00 00 00 04 00 00 1a 00  |...&............|
0000008b  00 00 00 00 00 01 00 00  00 00 00 00 00 00 06 03  |................|
0000009b  73 74 64 04 21 00 21 00  08 00 74 65 73 74 00 42  |std.!.!...test.B|
000000ab  45 47 49 4e                                       |EGIN|

#table_map event
000000af  95 2a 85 56 13 04 00 00  00 2e 00 00 00 dd 00 00  |.*.V............|
000000bf  00 00 00 32 00 00 00 00  00 01 00 04 74 65 73 74  |...2........test|
000000cf  00 04 74 72 6f 77 00 02  03 0f 02 0a 00 02        |..trow........|

#write_rows event
000000dd  95 2a 85 56 17 04 00 00  00 29 00 00 00 06 01 00  |.*.V.....)......|
000000ed  00 00 00 32 00 00 00 00  00 01 00 02 ff fe 01 00  |...2............|
000000fd  00 00 fc 02 00 00 00 01  61                       |........a|

#xid event
00000106  95 2a 85 56 10 04 00 00  00 1b 00 00 00 21 01 00  |.*.V.........!..|
00000116  00 00 00 f5 00 00 00 00  00 00 00                 |...........|

0x0000006b-0x000000ae 为 query event,语句是 BEGIN, 前面已经分析过。

table_map event

0x0000000af 开始为 table_map event。除去头部 19 个字节,Fixed data 为 8 个字节,前面 6 个字节 0x32=50 为 table id,接着 2 个字节 0x0001 为 flags。

Variable data 部分,首先 1 个字节 0x04 为数据库名 test 的长度,然后 5 个字节是数据库名 test + 结束符。接着 1 个字节 0x04 为表名长度,接着 5 个字节为表名 trow + 结束符。接着 1 个字节 0x02 为列的数目。而后是 2 个列的类型定义,分别是 0x03 和 0x0f(列的类型 MYSQL_TYPE_LONG 为 0x03,MYSQL_TYPE_VARCHAR 为 0x0f)。接着是列的元数据定义,首先 0x02 表示元数据长度为 2,因为 MYSQL_TYPE_LONG 没有元数据,而 MYSQL_TYPE_VARCHAR 元数据长度为 2。接着的 0x000a 就是 MYSQL_TYPE_VARCHAR 的元数据,表示我们在定义表时的 varchar 字段 c 长度为 10,最后一个字节 0x02 为掩码,表示第一个字段 i 不能为 NULL。关于列的类型以及元数据等更详细的信息可以参见http://dev.mysql.com/doc/internals/en/table-map-event.html。

write_rows event

从 0x000000dd 开始为 write_rows event,除去头部 19 个字节,前 6 个字节 0x32 也是 table id,然后两个字节 0x0001 为 flags。接着的 1 个字节 0x02 为表中列的数目。然后 1 个字节 0xff 各个 bit 标识各列是否存在值,这里表示都存在。

接着的就是插入的各行数据了。第 1 个字节 0xfe 的各个 bit 标识该行变化之后各列是否为 NULL,为 NULL 记为 1. 这里表示第 1 列不为 NULL,因为第一行数据插入的是 (1,NULL)。接下来是各列的数据,第一列是 MYSQL_TYPE_LONG, 长度为 4 个字节,所以 0x00000001 就是这个值。第二列是 NULL 不占字节。接下来是第二行,先是 0xfc 标识两列都不为 NULL,先读取第一列的 4 个字节 0x00000002 也就是我们插入的数字 2,然后读取第二列,先是一个字节的长度 0x01,然后是内容 0x61 也就是字符’a’。到此,write_rows event 也就分析完了。rows 相关的 event 还有 update_rows event 和 delete_rows event 等,欲了解更多可以参见官方文档。

最后是 xid event,之前已经分析过,不再赘述。

2.6 intvar event

intvar event 在 binlog_format=statement 时使用到,用于自增键类型 auto_increment,十分重要。intval event 的 Fixed data 部分为空,而 Variable data 部分为 9 个字节,第 1 个字节用于标识自增事件类型 LAST_INSERT_ID_EVENT = 1 or INSERT_ID_EVENT = 2,余下的 8 个字节为自增 ID。
创建一个测试表 create table tinc (i int auto_increment primary key, c varchar(10)) engine=innodb;,然后执行一个插入语句INSERT INTO tinc(c) values('abc');就可以看到 intvar event 了,这里的自增事件类型为 INSERT_ID_EVENT。而如果用语句INSERT INTO tinc(i, c) VALUES(LAST_INSERT_ID()+1, 'abc'),则可以看到自增事件类型为 LAST_INSERT_ID_EVENT 的 intvar event。

| Log_name         | Pos | Event_type  | Server_id | End_log_pos | Info                                                   |
+------------------+-----+-------------+-----------+-------------
| mysql-bin.000079 |   4 | Format_desc |         4 |         107 | Server ver: 5.5.46-0ubuntu0.14.04.2-log, Binlog ver: 4 |
| mysql-bin.000079 | 107 | Query       |         4 |         175 | BEGIN                                                  |
| mysql-bin.000079 | 175 | Intvar      |         4 |         203 | INSERT_ID=1                                            |
| mysql-bin.000079 | 203 | Query       |         4 |         299 | use `test`; insert into tinc(c) values('abc')          |
| mysql-bin.000079 | 299 | Xid         |         4 |         326 | COMMIT /* xid=263 */

3 简单总结

上面提到,binlog 有三种格式,各有优缺点:

  • statement:基于 SQL 语句的模式,某些语句和函数如 UUID, LOAD DATA INFILE 等在复制过程可能导致数据不一致甚至出错。
  • row:基于行的模式,记录的是行的变化,很安全。但是 binlog 会比其他两种模式大很多,在一些大表中清除大量数据时在 binlog 中会生成很多条语句,可能导致从库延迟变大。
  • mixed:混合模式,根据语句来选用是 statement 还是 row 模式。

不同版本的 mysql 在主从复制要慎重,虽然 mysql5.0 之后都用的 V4 版本的 binlog 了,估计还是会有些坑在里面,特别是高版本为主库,低版本为从库时容易出问题。在主从复制时最好还是主库从库版本一致,至少是大版本一致。mysql 复制是个大的话题,希望有时间能单独总结一篇笔记。

4 参考资料

http://dev.mysql.com/doc/internals/en/binary-log.html