关于MySQL binlog中的内容分析
关于MySQL binlog中的内容解析
在实际的工作过程中，我们经常会解析binlog文件，解析文件的时候，通常有下面三种方法，这里我们简单介绍一下：
mysqlbinlog -v mysqlbin.0000x > aa.sql
mysqlbinlog -vv mysqlbin.0000x > bb.sql
mysqlbinlog -vv --base64-output=decode-rows mysqlbin.0000x > cc.sql01
-v和-vv的区别
首先我们说说-v和-vv参数的区别，使用--help可以看出：
-v是解析出行信息来，-vv是在-v的基础上添加了列数据类型的注释信息，对比如下。
### UPDATE `yeyz`.`yeyz` ### UPDATE `yeyz`.`yeyz`
### WHERE ### WHERE
### @1=2 | ### @1=2 /* INT meta=0 nullable=1 is_null=0 */
### SET ### SET
### @1=1 | ### @1=1 /* INT meta=0 nullable=1 is_null=0 */
# at 1710 # at 171002
-vv和--base64-output=decode-rows的区别
先来看看--base64-output的意思：
--base64-output=name
Determine when the output statements should be
base64-encoded BINLOG statements: 'never' disables it and
works only for binlogs without row-based events;
'decode-rows' decodes row events into commented
pseudo-SQL statements if the --verbose option is also
given; 'auto' prints base64 only when necessary (i.e.,
for row-based events and format description events). If
no --base64-output[=name] option is given at all, the
default is 'auto'.看着很绕口，其实本质就是使用了这个参数，会将二进制的内容进行屏蔽，我们看看效果吧：
#191112 21:20:28 server id 201 end_log_pos 1710 CRC32 0x167a #191112 21:20:28 server id 201 end_log_pos 1710 CRC32 0x167a
<
BINLOG ' <
nLHKXR3JAAAANwAAAFEGAACAAB91cGRhdGUgeWV5eiBzZXQgaWQ9MSB3aGVyZ <
nLHKXRPJAAAALwAAAIAGAAAAAFBgFQAAAAEABHlleXoABHlleXoAAQMAATzB6 <
nLHKXR/JAAAALgAAAK4GAAAAAFBgFQAAAAEAAgAB///+AgAAAP4BAAAAZ1h6F <
'/*!*/; <
### UPDATE `yeyz`.`yeyz` ### UPDATE `yeyz`.`yeyz`
### WHERE ### WHERE
### @1=2 /* INT meta=0 nullable=1 is_null=0 */ ### @1=2 /* INT meta=0 nullable=1 is_null=0 */
### SET ### SET
### @1=1 /* INT meta=0 nullable=1 is_null=0 */ ### @1=1 /* INT meta=0 nullable=1 is_null=0 */
# at 1710 # at 1710其实左边和右边的差距就在于左侧的-vv参数解析出来的结果包含一些二进制的内容，而右侧的--base64-output=decode-rows结合-vv参数，没有这些二进制的内容。
03
binlog解析出的内容
首先我们需要了解，binlog是由一个一个event组成的，之前讲过我们可以使用show binlog events in binlog.xxxx的语法来查看这些事件，如下：
1mysql :(none) 22:12:27>>show binlog events in 'mysqlbin.000078';
2+-----------------+------+----------------+-----------+-------------+--------------------------------------------------------------------------+
3| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
4| mysqlbin.000078 | 1710 | Xid | 201 | 1741 | COMMIT /* xid=1518891605 */ |
5| mysqlbin.000078 | 1741 | Gtid | 201 | 1806 | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686013' |
6| mysqlbin.000078 | 1806 | Query | 201 | 1923 | use `yeyz`; DROP TABLE `yeyz` /* generated by server */ |
7| mysqlbin.000078 | 1923 | Gtid | 201 | 1988 | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686014' |我们注意到，上面的每个event，都有一个event_type列，这个event_type列标注了它是什么类型的事件。下面会详细分析。
再先来看对应的SQL和binlog解析的结果(截取一小块)：
1mysql :yeyz 21:19:09>>create table yeyz (id int);
2Query OK, 0 rows affected (0.02 sec)
3mysql :yeyz 21:20:28>>drop table yeyz;
4Query OK, 0 rows affected (0.01 sec)
5
6# at 1741
7#191112 21:20:38 server id 201 end_log_pos 1806 CRC32 0xfcf0c09d GTID last_committed=6 sequence_number=7
8SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686013'/*!*/;
9# at 1806
10#191112 21:20:38 server id 201 end_log_pos 1923 CRC32 0x88d88717 Query thread_id=473068 exec_time=0 error_code=0
11SET TIMESTAMP=1573564838/*!*/;
12DROP TABLE `yeyz` /* generated by server */
13/*!*/;
14# at 1923 看看上面这段SQL语句产生的binlog解析出来的结果。
第6行：
at 1741 这是binlog中event事件发生时候的位置信息
第7行：
#191112 21:20:38 binlog中event事件发生的时间
server id，指得是应用服务器的id值，我们可以通过下面的方法查看某个服务器的server_id值，经过对比，我们发现和binlog中的值是一致的，都是201
1mysql :(none) 21:58:14>>show variables like '%server_id%';
2+------------------+-------+
3| Variable_name | Value |
4+------------------+-------+
5| pseudo_server_id | 0 |
6| server_id | 201 |
7| server_id_bits | 32 |
8+------------------+-------+
93 rows in set (0.00 sec)
10end_log_pos binlog中event事件结束的时间
GTID 表明这是一个gtid类型的event
last_committed、sequence_number 这两个是多线程复制的相关参数
第8行：对应的设置下一个GTID的语句
第9行的内容和第6行一样，事件位置是1806，不再赘述。
第10行：可以看到，event_type变成了Query，跟我们使用show binlog events语句看到的相同。
exec_time=0 值得是执行时间
error_code=0 指的是返回的错误码是0
到这里，我们可以看到，binlog中是由一个一个event组成的，而每个event都可能是不同的类型，这里我们挑几个重要的说一下：
QUERY_EVENT
QUERY_EVENT以文本的形式来记录事务的操作。
QUERY_EVENT类型的事件通常在以下几种情况下使用：
1. 事务开始时，执行的BEGIN操作。
2. STATEMENT格式中的DML操作
3. ROW格式中的DDL操作
FORMAT_DESCRIPTION_EVENT
FORMAT_DESCRIPTION_EVENT是binlog version 4中为了取代之前版本中的START_EVENT_V3事件而引入的。它是binlog文件中的第一个事件，而且，该事件只会在binlog中出现一次。MySQL根据FORMAT_DESCRIPTION_EVENT的定义来解析其它事件。
它通常指定了MySQL Server的版本，binlog的版本，该binlog文件的创建时间。
ROWS_EVENT
对于ROW格式的binlog，所有的DML语句都是记录在ROWS_EVENT中。
ROWS_EVENT分为三种：WRITE_ROWS_EVENT，UPDATE_ROWS_EVENT，DELETE_ROWS_EVENT，分别对应insert，update和delete操作。
对于insert操作，WRITE_ROWS_EVENT包含了要插入的数据
对于update操作，UPDATE_ROWS_EVENT不仅包含了修改后的数据，还包含了修改前的值。
对于delete操作，仅仅需要指定删除的主键（在没有主键的情况下，会给定所有列）
对于QUERY_EVENT事件，是以文本形式记录DML操作的。而对于ROWS_EVENT事件，并不是文本形式，所以在通过mysqlbinlog查看基于ROW格式的binlog时，需要指定-vv --base64-output=decode-rows。
XID_EVENT
在事务提交时，不管是STATEMENT还是ROW格式的binlog，都会在末尾添加一个XID_EVENT事件代表事务的结束。该事件记录了该事务的ID，在MySQL进行崩溃恢复时，根据事务在binlog中的提交情况来决定是否提交存储引擎中状态为prepared的事务。
ROTATE_EVENT
当binlog文件的大小达到max_binlog_size的值或者执行flush logs命令时，binlog会发生切换，这个时候会在当前的binlog日志添加一个ROTATE_EVENT事件，用于指定下一个日志的名称和位置。
PREVIOUS_GTIDS_LOG_EVENT
开启GTID模式后，每个binlog开头都会有一个PREVIOUS_GTIDS_LOG_EVENT事件，它的值是上一个binlog的PREVIOUS_GTIDS_LOG_EVENT+GTID_LOG_EVENT，实际上，在数据库重启的时候，需要重新填充gtid_executed的值，该值即是最新一个binlog的PREVIOUS_GTIDS_LOG_EVENT+GTID_LOG_EVENT。
GTID_LOG_EVENT
在启用GTID模式后，MySQL实际上为每个事务都分配了个GTID
STOP_EVENT
当MySQL数据库停止时，会在当前的binlog末尾添加一个STOP_EVENT事件表示数据库停止。
说了这么多，最后给出小的binlog的事件类型，供大家参考不同类型的binlog事件分别对应什么操作：
1+----------------+--------------------------------------------------------------------------+
2| Event_type | Info |
3+----------------+--------------------------------------------------------------------------+
4| Format_desc | Server ver: 5.7.16-10-log, Binlog ver: 4 |
5| Previous_gtids | af9fc718-542d-11e8-b1a6-0050568fd097:1-64686006 |
6| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686007' |
7| Query | create database yeyz |
8| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686008' |
9| Query | use `yeyz`; create table yeyz (id int) |
10| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686009' |
11| Query | BEGIN |
12| Rows_query | # insert into yeyz values (1) |
13| Table_map | table_id: 1400912 (yeyz.yeyz) |
14| Write_rows | table_id: 1400912 flags: STMT_END_F |
15| Xid | COMMIT /* xid=1518891576 */ |
16| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686010' |
17| Query | BEGIN |
18| Rows_query | # delete from yeyz |
19| Table_map | table_id: 1400912 (yeyz.yeyz) |
20| Delete_rows | table_id: 1400912 flags: STMT_END_F |
21| Xid | COMMIT /* xid=1518891590 */ |
22| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686011' |
23| Query | BEGIN |
24| Rows_query | # insert into yeyz values (2) |
25| Table_map | table_id: 1400912 (yeyz.yeyz) |
26| Write_rows | table_id: 1400912 flags: STMT_END_F |
27| Xid | COMMIT /* xid=1518891591 */ |
28| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686012' |
29| Query | BEGIN |
30| Rows_query | # update yeyz set id=1 where id=2 |
31| Table_map | table_id: 1400912 (yeyz.yeyz) |
32| Update_rows | table_id: 1400912 flags: STMT_END_F |
33| Xid | COMMIT /* xid=1518891605 */ |
34| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686013' |
35| Query | use `yeyz`; DROP TABLE `yeyz` /* generated by server */ |
36| Gtid | SET @@SESSION.GTID_NEXT= 'af9fc718-542d-11e8-b1a6-0050568fd097:64686014' |
37| Query | drop database yeyz |
38| Rotate | mysqlbin.000079;pos=4 |
39+----------------+--------------------------------------------------------------------------+