MySql Binlog事件和二进制文件解析
START_EVENT_V3
每个binlog文件开始的时候写入的事件，此事件被用在MySQL3.23 – 4.1，MYSQL5.0以后已经被FORMAT_DESCRIPTION_EVENT取代。
QUERY_EVENT
执行更新语句时会生成此事件，包括：create，insert，update，delete；
手动触发：
insert into btest values(1,100,'zhaohui');
| bin-log.000001 | 432 | Query | 1 | 536 | use `test`; insert into btest values(1,100,'zhaohui') |
| bin-log.000001 | 536 | Xid | 1 | 563 | COMMIT /* xid=30 */
ROTATE_EVENT
当mysqld切换到新的binlog文件生成此事件，切换到新的binlog文件可以通过执行flush logs命令或者binlog文件大于max_binlog_size参数配置的大小；
mysql> flush logs;
Query OK, 0 rows affected (0.24 sec)
mysql> show binlog events in 'bin-log.000002';
+----------------+-----+-------------+-----------+-------------+---------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+----------------+-----+-------------+-----------+-------------+---------------------------------------+
| bin-log.000002 | 4 | Format_desc | 1 | 107 | Server ver: 5.5.29-log, Binlog ver: 4 |
| bin-log.000002 | 107 | Rotate | 1 | 148 | bin-log.000003;pos=4 |
+----------------+-----+-------------+-----------+-------------+---------------------------------------+
INTVAR_EVENT
当sql语句中使用了AUTO_INCREMENT的字段或者LAST_INSERT_ID()函数；此事件没有被用在binlog_format为ROW模式的情况下。
insert into btest (age,name)values(100,'zhaohui');
mysql> show binlog events in 'bin-log.000003';
+----------------+-----+-------------+-----------+-------------+---------------------------------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+----------------+-----+-------------+-----------+-------------+---------------------------------------------------------------+
| bin-log.000003 | 4 | Format_desc | 1 | 107 | Server ver: 5.5.29-log, Binlog ver: 4 |
| bin-log.000003 | 107 | Query | 1 | 175 | BEGIN |
| bin-log.000003 | 175 | Intvar | 1 | 203 | INSERT_ID=2 |
| bin-log.000003 | 203 | Query | 1 | 315 | use `test`; insert into btest (age,name)values(100,'zhaohui') |
| bin-log.000003 | 315 | Xid | 1 | 342 | COMMIT /* xid=32 */ |
+----------------+-----+-------------+-----------+-------------+---------------------------------------------------------------+
5 rows in set (0.00 sec)
btest表中的id为AUTO_INCREMENT，所以产生了INTVAR_EVENT
TABLE_MAP_EVENT
用在binlog_format为ROW模式下，将表的定义映射到一个数字，在行操作事件之前记录（包括：WRITE_ROWS_EVENT，UPDATE_ROWS_EVENT，DELETE_ROWS_EVENT）；
mysql> insert into btest values(998,88,'zhaohui');
Query OK, 1 row affected (0.09 sec)
mysql> show binlog events in 'bin-log.000004';
+----------------+-----+-------------+-----------+-------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+----------------+-----+-------------+-----------+-------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
...... |
| bin-log.000004 | 776 | Query | 1 | 844 | BEGIN |
| bin-log.000004 | 844 | Table_map | 1 | 892 | table_id: 33 (test.btest) |
| bin-log.000004 | 892 | Write_rows | 1 | 943 | table_id: 33 flags: STMT_END_F |
| bin-log.000004 | 943 | Xid | 1 | 970 | COMMIT /* xid=20 */ |
+----------------+-----+-------------+-----------+-------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
14 rows in set (0.00 sec)
WRITE_ROWS_EVENT、UPDATE_ROWS_EVENT和DELETE_ROWS_EVENT
以上三个事件都被用在binlog_format为ROW模式下，分别对应inset，update和delete操作；
XID_EVENT
支持XA的存储引擎才有，本地测试的数据库存储引擎是innodb，所有上面出现了XID_EVENT；innodb事务提交产生了QUERY_EVENT的BEGIN声明，QUERY_EVENT以及COMMIT声明，
如果是myIsam存储引擎也会有BEGIN和COMMIT声明，只是COMMIT类型不是XID_EVENT；
Binlog事件数据
1.QUERY_EVENT
执行更新语句时会生成此事件，包括：create，insert，update，delete；
Fixed data part，总长度13字节：
4字节：执行sql的线程id；
4字节：执行sql的时间；
1字节：数据库名称的长度；
2字节：执行sql产生的错误码；
2字节：状态变量的长度，具体内容在Variable part；
Variable part：
可变字节：状态变量，每个状态变量key为一个字节，后面跟着value，不同的key对应不同长度的value，但是总长度在Fixed data part中已经定义；
可变字节：数据库名称
可变字节：sql语句，通过事件的总长度-header长度-Fixed data-状态变量，剩余的字节数组通过utf-8编码即可获取；
TABLE_MAP_EVENT
| bin-log.000004 | 844 | Table_map | 1 | 892 | table_id: 33 (test.btest)
将表的定义映射到一个数字，在行操作事件之前记录（包括：WRITE_ROWS_EVENT，UPDATE_ROWS_EVENT，DELETE_ROWS_EVENT）；
Fixed data part：
6字节：表Id；
2字节：保留字段为将来使用；
Variable part：
1字节：数据库名字的长度；
可变字节：数据库名字，根据前一个字节记录的名字长度，获取的字节数组通过utf-8编码即可获取；
1字节：表名的长度；
可变字节：表名，根据前一个字节记录的名字长度，获取的字节数组通过utf-8编码即可获取；
Packed integer：用来记录表中字段的数量；
mysql事件太多，这里就不一一介绍。
binlog二进制文件
先说一下，binlog的结构。文件头由一个四字节Magic Number构成，其值为1852400382，在内存中就是"0xfe,0x62,0x69,0x6e"。这个Magic Number就是来验证这个binlog文件是否有效 。
在文件头之后，跟随的是一个一个事件依次排列。下面具体来看下：
binlog生成
在MySQL中执行flush logs，并执行以下操作。
mysql> create database abcd;
Query OK, 1 row affected (0.01 sec)
mysql> create table test (a1 int primary key not null auto_increment, a2 double not null, a3 timestamp, a4 datetime, a5 char(10), a6 varchar(4000), a7 text);
Query OK, 0 rows affected (0.21 sec)
mysql> insert into test values(1, 2.222222222, now(), now(), 'abc', 'abcdefghasdasdasd', 'qwetrhyokxocm3479thcms9q25hdr9ker8thcfisdrhoc');
Query OK, 1 row affected (0.08 sec)
mysql> update test set a1=10, a2=3.33333, a3=now(), a4=now(), a5='abcde', a6='a', a7='s' where a1=1;
Query OK, 1 row affected (0.06 sec)
Rows matched:1 Changed: 1 Warnings: 0
mysql> delete from test;
Query OK, 1 row affected (0.04 sec)
mysql> drop table test;
Query OK, 0 rows affected (0.22 sec)
mysql> flush logs;
Query OK, 0 rows affected (0.17 sec)
Binlog文件构成
对于该binlog而言，主要包括以下几种event。
FORMAT_DESCRIPTION_EVENT
GTID_LOG_EVENT/ANONYMOUS_GTID_LOG_EVENT
QUERY_EVENT
TABLE_MAP_EVENT
WRITE_ROW_EVENT/UPDATE_ROW_EVENT/DELETE_ROW_EVENT
XID_EVENT
ROTATE_EVENT
除这些外还有许多其他类型event，但多数不常见或随着binlog版本的升级而弃用。每个event包括Binlog event header，Post-Header和Body三部分。其中对于所有event而言，Binlog event header的长度与格式是相同的，之后会在FORMAT_DESCRIPTION_EVENT部分做统一介绍。Post-Header对于同类型的event是长度相同的，部分类型的event并没有Post-Header。Body则为event中的变量部分
下面将详细介绍每一种event在binlog中的解析方式。
FORMAT_DESCRIPTION_EVENT
该部分位于整个文件的头部，每个binlog文件都必定会有唯一一个该event。
二进制文件内容
image.png
解析的binlog
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#180321 18:00:32 server id 1813309 end_log_pos 123 CRC32 0x77f16c93 Start: binlog v 4, server v 5.7.17-log created 180321 18:00:32
BINLOG '
QC2yWg89qxsAdwAAAHsAAAAAAAQANS43LjE3LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AZNs8Xc=
'/*!*/;
Binlog event header部分：
fe 62 69 6e：文件前四位非Binlog event header部分，而是magic number，在这里指代.bin，代表文件的格式。
后面的Header总长固定为19个字节。
40 2d b2 5a：事件发生的时间戳。应用服务器是X86架构，在存储的时候为小端模式，即低位字节排放在内存的低地址端，也即实际是5a b2 2d 40代表一个数值(时间戳)，解析成时间为2018/3/21 18:00:32。
0f：type_code，代表该事件的类型，几个重要的事件类型为：
0x02 QUERY_EVENT
0x04 ROTATE_EVENT
0x0f FORMAT_DESCRIPTION_EVENT
0x10 XID_EVENT
0x13 TABLE_MAP_EVENT
0x1d ROWS_QUERY_EVENT
0x1e WRITE_ROWS_EVENTv2
0x1f UPDATE_ROWS_EVENTv2
0x20 DELETE_ROWS_EVENTv2
0x21 GTID_EVENT
0x22 ANONYMOUS_GTID_EVENT
0x23 PREVIOUS_GTIDS_EVENT
3d ab 1b 00：server_id，就是MySQL配置cnf文件中的server_id。这里是00 1b ab 3d，代表1813309。
77 00 00 00：代表整个event的长度，长度为119。
7b 00 00 00：下一个event开始的位置，可以看到与前一个值刚好差4，也就是魔数的长度。
00 00：flags，每个events中flags代表的意义大致相同。在此处 00 00 代表binlog已经关闭， 00 01代表binlog仍开启.
以上便是所有event的Binlog event header的固定形式，之后便不再解析。
Post-Header 对于每一类型的event都是相同的
FORMAT_DESCRIPTION_EVENT有Post-Header，并没有Body部分，因为并没有变量。
04 00：binlog的版本，mysql从5.0后日志都是v4版本的。
之后50位代表mysql-server的版本，5.7.17-log。
00 00 00 00：代表create timestamp，官网上解释为seconds since Unix epoch when the binlog was created。
13：代表Binlog event heade的长度，固定长度是19。
之后39位代表了39种类型事件的Post-Header的长度，从0x01开始，与上面所介绍的时间类型是对应的。其中FORMAT_DESCRIPTION_EVENT为0x0f，即长度对应5f。
image.png
详细的关系在 https://dev.mysql.com/doc/internals/en/format-description-event.html 上有部分的对应，虽然不全但是可以对应主要的event的Post-Header长度。
可以看到WRITE_ROWS_EVENT、UPDATE_ROWS_EVENT、DELETE_ROWS_EVENT这三种主要event长度都是0x0a，因为他们同属于ROWS_EVENT。
93 6c f1 77：最后四位为循环冗余校验码，与解析出的CRC32 0x77f16c93是一致的。注意，每一个event末尾都会有这样四个字节。
QUERY_EVENT
image.png
SET TIMESTAMP=1521626445/*!*/;
SET @@session.pseudo_thread_id=95906/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1437073442/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=45/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create database abcd
/*!*/;
# at 353
#180321 18:04:24 server id 1813309 end_log_pos 418 CRC32 0x8f20b94b GTID last_committed=1 sequence_number=2
在row格式的binlog中，所有的建库建表操作都是QUERY_EVENT。此处取出较短的建库操作做分析，建表操作与建库的binlog格式是完全相同的。
Post-Header的长度为0x0d。
00 01 76 a2：slave_proxy_id，代指一个用于临时表的进程号，为了避免创建临时表时重复。
00 00 00 00：表示语句执行时间，单位为秒。
04 ：代表当前数据库名字的长度，在这里为abcd。
00 00 ：两位错误码，若非0则代表有误，如果从库在复制时收到错误码将停止复制进程。
00 21 ：v4新特性，为status_vars的长度，这个之后会有介绍。
Body的长度根据DDL语句的长度而定。
TABLE_MAP_EVENT
image.png
SET TIMESTAMP=1521626714/*!*/;
SET @@session.time_zone='SYSTEM'/*!*/;
BEGIN
/*!*/;
# at 782
#180321 18:05:14 server id 1813309 end_log_pos 843 CRC32 0x98b87aed Table_map: `abcd`.`test` mapped to number 224
每个DML事务之前，都会有一个TABLE_MAP_EVENT，记录操作对应的表的信息。
Post-Header的长度为0x08。
e0 00 00 00 00 00：代表库的ID 224。
01 00 ：保留位数，Reserved for future use。
Body部分：
04：库名的长度，之后是库名的字符串61 62 63 64 00 abcd，与上文相同。
04：表名的长度，和对应的表名74 65 73 74 00 test。
07：代表字段的个数，我们建表时设立了7种不同类型的字段。
可以看出，binlog是完全不记录表的字段名称的，只记录对应的编号和类型。
让我们重新看一下建表的内容。
create table test (a1 int primary key not null auto_increment, a2 double not null, a3 timestamp, a4 datetime, a5 char(10), a6 varchar(4000), a7 text);
03 05 11 12 fe 0f fc 08 08 00 00 fe 28 80 3e 02 78
其中每个字节都有对应的含义。
03代表MYSQL_TYPE_LONG。
05代表MYSQL_TYPE_DOUBLE，后面会跟一位metadata。
11代表MYSQL_TYPE_TIME，这个官网写后面没有metadata，但是其实是有一个00站位的，而且跟是否有默认值无关。
12代表MYSQL_TYPE_DATETIME，跟MYSQL_TYPE_TIME情况相同。
Fe代表MYSQL_TYPE_STRING，后面会跟两位metadata
0f代表MYSQL_TYPE_VARCHAR，后面会跟两位metadata
Fc代表MYSQL_TYPE_BLOB，后面会跟一位metadata
之后的08代表metadata length：08 00 00 fe 28 80 3e 02
首先08对应的MYSQL_TYPE_DOUBLE的metadata，代表sizeof(double)，也就是8
之后00 00就跟上文说的一样，是MYSQL_TYPE_TIME和MYSQL_TYPE_DATETIME的metadata。
fe 28：在之后的insert语句的binlog中，可以看到有@5='abc' /* STRING(40) meta=65064 nullable=1 is_null=0 */的内容，其中的meta值便是0xfe28。
80 3e: 与第六列中@6='abcdefghasdasdasd' /* VARSTRING(16000) meta=16000 nullable=1 is_null=0 */中的meta值一致。
02：与第七列中@7='qwetrhyokxocm3479thcms9q25hdr9ker8thcfisdrhoc' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */中的meta值一致。
....
上面解析binlog文件中，将其分为三个部分:通用事件头（common-header）、私有事件头（post-header）和事件体（event-body）。本文修改了一下，只用两个Java类来修饰binlog中的事件，即EventHeader和EventData。可以理解为下述的对应关系：(mysql-binlog-connector就是这么做的)
EventHeader --> 通用事件头（common-header)
EventData ---> 私有事件头（post-header）和事件体（event-body）
于是，你们可以把Binlog的文件结构像下面这么理解
image.png
说一下这个Checksum,在获取event内容的时候，会增加4个额外字节做校验用。mysql5.6.5以后的版本中binlog_checksum=crc32,而低版本都是binlog_checksum=none。如果不想校验，可以使用set命令设置set binlog_checksum=none。说得再通俗一点，Checksum要么为4个字节，要么为0个字节。
下面说一下通用事件头的结构，如下所示
image.png
从上表可以看出，EventHeader固定为19个字节，为此我们构造下面的类，来解析这个通用事件头
public class EventHeader {
private long timestamp;
private int eventType;
private long serverId;
private long eventLength;
private long nextPosition;
private int flags;
//省略setter和getter方法
@Override
public String toString() {
final StringBuilder sb = new StringBuilder();
sb.append("EventHeader");
sb.append("{timestamp=").append(timestamp);
sb.append(", eventType=").append(eventType);
sb.append(", serverId=").append(serverId);
sb.append(", eventLength=").append(eventLength);
sb.append(", nextPosition=").append(nextPosition);
sb.append(", flags=").append(flags);
sb.append('}');
return sb.toString();
}
}
OK，接下来，我们来一段代码试着解析一下第一个事件的EventHeader,代码如下所示
public class HeaderParser {
public static final byte[] MAGIC_HEADER = new byte[]{(byte) 0xfe, (byte) 0x62, (byte) 0x69, (byte) 0x6e};
public static void main(String[] args)throws Exception {
String filePath = "D:\\mysql-bin.000001";
File binlogFile = new File(filePath);
ByteArrayInputStream inputStream = null;
inputStream = new ByteArrayInputStream(new FileInputStream(binlogFile));
byte[] magicHeader = inputStream.read(4);
if(!Arrays.equals(MAGIC_HEADER, magicHeader)){
throw new RuntimeException("binlog文件格式不对");
}
EventHeader eventHeader = new EventHeader();
eventHeader.setTimestamp(inputStream.readLong(4) * 1000L);
eventHeader.setEventType(inputStream.readInteger(1));
eventHeader.setServerId(inputStream.readLong(4));
eventHeader.setEventLength(inputStream.readLong(4));
eventHeader.setNextPosition(inputStream.readLong(4));
eventHeader.setFlags(inputStream.readInteger(2));
System.out.println(eventHeader);
}
}
EventHeader{timestamp=1536487335000, eventType=15, serverId=1, eventLength=119, nextPosition=123, flags=1}
注意看，两个参数
eventLength=119
nextPosition=123
下一个事件从123字节开始。这是怎么算的呢，当前事件长度是是119字节，算上最开始4个字节的魔数占位符，那么下一个事件自然是,119+4=123，从123字节开始。再强调一次，这个119字节，是包含EventHeader,EventData,Checksum,三个部分的长度为119。
最重要的一个参数
eventType=15
我们去下面的地址
https://dev.mysql.com/doc/internals/en/binlog-event-type.html
查询一下，15对应的事件类型为FORMAT_DESCRIPTION_EVENT。我们接下来，需要知道FORMAT_DESCRIPTION_EVENT所对应EventData的结构。在下面的地址https://dev.mysql.com/doc/internals/en/format-description-event.html
查询得到EventData的结构对应如下表所示
image.png
ps:这个n其实我们可以推算出，为39。事件长度为119字节，减去事件头19字节，减去末位的4字节(末位四个字节循环校验码)，减去2个字节的binlog版本，减去50个字节的服务器版本号，减去4个字节的时间戳，减去1个字节的事件头长度。得到如下算式
119−19−4−2−50−4−1=39
根据上表结构 ，我们给出一个JAVA类如下所示
public class FormatDescriptionEventData {
private int binlogVersion;
private String serverVersion;
private long timestamp;
private int headerLength;
private List headerArrays = new ArrayList<Integer>();
//省略setter和getter方法
@Override
public String toString() {
final StringBuilder sb = new StringBuilder();
sb.append("FormatDescriptionEventData");
sb.append("{binlogVersion=").append(binlogVersion);
sb.append(", serverVersion=").append(serverVersion);
sb.append(", timestamp=").append(timestamp);
sb.append(", headerLength=").append(headerLength);
sb.append(", headerArrays=").append(headerArrays);
sb.append('}');
return sb.toString();
}
}
那如何解析呢，如下所示
public class HeaderParser {
public static final byte[] MAGIC_HEADER = new byte[] { (byte) 0xfe,
(byte) 0x62, (byte) 0x69, (byte) 0x6e };
public static void main(String[] args) throws Exception {
String filePath = "D:\\mysql-bin.000001";
File binlogFile = new File(filePath);
ByteArrayInputStream inputStream = null;
inputStream = new ByteArrayInputStream(new FileInputStream(binlogFile));
byte[] magicHeader = inputStream.read(4);
if (!Arrays.equals(MAGIC_HEADER, magicHeader)) {
throw new RuntimeException("binlog文件格式不对");
}
EventHeader eventHeader = new EventHeader();
eventHeader.setTimestamp(inputStream.readLong(4) * 1000L);
eventHeader.setEventType(inputStream.readInteger(1));
eventHeader.setServerId(inputStream.readLong(4));
eventHeader.setEventLength(inputStream.readLong(4));
eventHeader.setNextPosition(inputStream.readLong(4));
eventHeader.setFlags(inputStream.readInteger(2));
System.out.println(eventHeader);
inputStream.enterBlock((int) (eventHeader.getEventLength() - 19 - 4));
FormatDescriptionEventData descriptionEventData = new FormatDescriptionEventData();
descriptionEventData.setBinlogVersion(inputStream.readInteger(2));
descriptionEventData.setServerVersion(inputStream.readString(50).trim());
descriptionEventData.setTimestamp(inputStream.readLong(4) * 1000L);
descriptionEventData.setHeaderLength(inputStream.readInteger(1));
int sums = inputStream.available();
for (int i = 0; i < sums; i++) {
descriptionEventData.getHeaderArrays().add(inputStream.readInteger(1));
}
System.out.println(descriptionEventData);
}
}
binlog是主动推还是拉
MySQL通过[向备库传送二进制日志来实现Replication，下面将通过二进制日志相关源代码的主要接口来解释：“MySQL如何传输二进制日志，是主库推，还是备库拉？MySQL日志传输的实时性如何？”。
在MySQL Replication结构中，备库端初次通过CHANGE MASTER TO完成Replication配置，再使用start slave命令开始复制。更细致的，备库通过IO Thread向主库发起读取binlog的请求（COM_BINLOG_DUMP命令），主库收到COM_BINLOG_DUMP请求后，使用单独线程（dump thread（按照dump协议传输数据））不断向备库IO Thread发送Binlog。示意图
image.png
在主库端一旦有新的日志产生后，立刻会发送一次广播，dump线程在收到广播后，则会读取二进制日志并通过网络向备库传输日志，所以这是一个主库向备库不断推送的过程；
新日志在产生后，只需一次广播和网络就会立刻（<1ms）向发送到备库，如果主备之间网络较好的话（例如RTT<1ms），备库端的日志也就小于2ms了。所以，一般的（依赖于RTT），备库的实时性都非常好。
到底是主库推送，还是备库请求的方式？这也是我之前困惑的问题。所以后来通过分析源码，发现：一旦连接建立，则是由主库主动推送的。（从mysql-binlog-connector源码debug也可以得到该结论）
