MySQL识别一个binlog中的一个事物

共计 7579 个字符，预计需要花费 19 分钟才能阅读完成。

MySQL 测试版本 5.7.14
设置 GTID_MODE=ON
ON(3): Both new and replicated transactions must be GTID transactions(生成的是 GTID 事物，slave 也只能应用 GTID 事物)
设置 binlog 格式为 row 模式
做如下操作
mysql> insert into test values(1,2);
Query OK, 1 row affected (0.01 sec)
mysql> insert into test values(2,3);
Query OK, 1 row affected (0.01 sec)
mysql> delete from test;
Query OK, 2 rows affected (0.01 sec)
mysql> select * from test;
Empty set (0.00 sec)

首先我通过自己的工具 infobin 找到了这段操作的 binlog，如果想获得这个工具学习可以参考文章最后
简单解释一下这里  Pos: 是当前位置对应 mysqlbinlog 的 # at 504 这里的 N_pos 是结束位置对应
mysqlbinlog 的 end_log_pos
>Gtid Event:Pos:504(0X1f8) N_pos:569(0X239) Time:1496993578 Event_size:65(bytes)
Gtid:89dfa8a4-cb13-11e6-b54-0c29a879a3:2
–>Query Event:Pos:569(0X239) N_Pos:641(0X281) Time:1496993578 Event_size:72(bytes)
Exe_time:0  Use_db:test Statment(35b-trun):BEGIN /*!Trx begin!*/ Gno:2
—->Map Event:Pos641(0X281) N_pos:689(0X2b1) Time:1496993578 Event_size:48(bytes)
TABLE_ID:142 DB_NAME:test TABLE_NAME:test Gno:2
——>Insert Event:Pos:689(0X2b1) N_pos:733(0X2dd) Time:1496993578 Event_size:44(bytes)
Dml on table: test.test  table_id:142 Gno:2
>Xid Event:Pos:733(0X2dd) N_Pos:764(0X2fc) Time:1496993578 Event_size:31(bytes)
COMMIT; /*!Trx end*/ Gno:2 – 注意这里以 N_Pos 为结尾及下一个 event 的开始位置
>Gtid Event:Pos:764(0X2fc) N_pos:829(0X33d) Time:1496993581 Event_size:65(bytes)
Gtid:89dfa8a4-cb13-11e6-b54-0c29a879a3:3
–>Query Event:Pos:829(0X33d) N_Pos:901(0X385) Time:1496993581 Event_size:72(bytes)
Exe_time:0  Use_db:test Statment(35b-trun):BEGIN /*!Trx begin!*/ Gno:3
—->Map Event:Pos901(0X385) N_pos:949(0X3b5) Time:1496993581 Event_size:48(bytes)
TABLE_ID:142 DB_NAME:test TABLE_NAME:test Gno:3
——>Insert Event:Pos:949(0X3b5) N_pos:993(0X3e1) Time:1496993581 Event_size:44(bytes)
Dml on table: test.test  table_id:142 Gno:3
>Xid Event:Pos:993(0X3e1) N_Pos:1024(0X400) Time:1496993581 Event_size:31(bytes)
COMMIT; /*!Trx end*/ Gno:3  – 注意这里以 N_Pos 为结尾及下一个 event 的开始位置
>Gtid Event:Pos:1024(0X400) N_pos:1089(0X441) Time:1496993584 Event_size:65(bytes)
Gtid:89dfa8a4-cb13-11e6-b54-0c29a879a3:4
–>Query Event:Pos:1089(0X441) N_Pos:1161(0X489) Time:1496993584 Event_size:72(bytes)
Exe_time:0  Use_db:test Statment(35b-trun):BEGIN /*!Trx begin!*/ Gno:4
—->Map Event:Pos1161(0X489) N_pos:1209(0X4b9) Time:1496993584 Event_size:48(bytes)
TABLE_ID:142 DB_NAME:test TABLE_NAME:test Gno:4
——>Delete Event:Pos:1209(0X4b9) N_pos:1262(0X4ee) Time:1496993584 Event_size:53(bytes)
Dml on table: test.test  table_id:142 Gno:4
>Xid Event:Pos:1262(0X4ee) N_Pos:1293(0X50d) Time:1496993584 Event_size:31(bytes)
COMMIT; /*!Trx end*/ Gno:4 – 注意这里以 N_Pos 为结尾及下一个 event 的开始位置

 显然这里包含了 3 个事物，
1、504 到 764 为一个事物，工具显示这个 event 为 Insert Event，在表 test.test
2、764 到 1024 为一个事物，工具显示这个 event 为 Insert Event，在表 test.test
3、1024 到 1293 为一个事物，工具显示这个 event 为 Delete Event，在表 test.test

这就是我做的操作，这个工具主要是通过分析 binlog event 方便寻找事物，当然 mysqlbinlog 也可以只是输出有点不直观。
在通过 mysqlbinlog 分析的时候一定要注意一个事物的开始和结束。
(mysqlbinlog testsla.000003  -vv –start-postions=504 –stop-postions=1024 –base64-output=decode-rows 查看不通过 base64 算法显示二进制内容)
(mysqlbinlog testsla.000003  -vv –start-postions=504 –stop-postions=1024 查看通过 base64 算法显示二进制内容）

 下面我们通过 mysqlbinlog 来分析上面的事物 1 504 到 764 为
# at 473
#170609 15:20:45 server id 933310  end_log_pos 504 CRC32 0x609296d7    Xid = 161
COMMIT/*!*/; — 注意这里上一个事物的结束叫做 xid event
# at 504    — 这里是事物 1 的起点没叫做 gtid event
#170609 15:32:58 server id 933310  end_log_pos 569 CRC32 0xf7eebfc7    GTID [commit=yes]
SET @@SESSION.GTID_NEXT= ’89dfa8a4-cb13-11e6-b504-000c29a879a3:2’/*!*/;
# at 569    — 这段 event 是 query event
#170609 15:32:58 server id 933310  end_log_pos 641 CRC32 0xb4caa78c    Query  thread_id=4    exec_time=0    error_code=0
SET TIMESTAMP=1496993578/*!*/;
BEGIN
/*!*/;
# at 641    — 这段 event 是 map event
#170609 15:32:58 server id 933310  end_log_pos 689 CRC32 0xb055655f    Table_map: `test`.`test` mapped to number 142
# at 689    — 这段 event 是 insert event
#170609 15:32:58 server id 933310  end_log_pos 733 CRC32 0xd907a353    Write_rows: table id 142 flags: STMT_END_F
### INSERT INTO `test`.`test`
### SET
###  @1=1 /* INT meta=0 nullable=1 is_null=0 */
###  @2=2 /* INT meta=0 nullable=1 is_null=0 */
# at 733    – 这段 event 是 xid event
#170609 15:32:58 server id 933310  end_log_pos 764 CRC32 0x9dbe0a6b    Xid = 323
COMMIT/*!*/;  — 这里是一个事物的结尾叫做 xid event，但是注意不是 733 而是下一个 event 开始的位置 764 或者是 xid event 的 end_log_pos，否则将会被回滚掉
# at 764
#170609 15:33:01 server id 933310  end_log_pos 829 CRC32 0x82aac64c    GTID [commit=yes]
SET @@SESSION.GTID_NEXT= ’89dfa8a4-cb13-11e6-b504-000c29a879a3:3’/*!*/;

所以我们认为一个事物的 binlog 是 504 到 764
如果写为 733 会出现这种情况
mysqlbinlog testsla.000003  –start-position=504 –stop-position=733 -vv  –base64-output=decode-rows

 ……..
# at 689
#170609 15:32:58 server id 933310  end_log_pos 733 CRC32 0xd907a353    Write_rows: table id 142 flags: STMT_END_F
### INSERT INTO `test`.`test`
### SET
###  @1=1 /* INT meta=0 nullable=1 is_null=0 */
###  @2=2 /* INT meta=0 nullable=1 is_null=0 */
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;  – 很明显没有 xid event 没有 commit 而 mysqlbinlog 自己家了一个 rollback 而回滚掉了
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETI

好这里我们简单介绍一个事物 binlog event 的流程，正如我工具所展示的
>Gtid Event：事物开始
–>Query Event：begin
—->Map Event：表映射
——>Insert Event：正真的数据二进制格式
>Xid Event: commit
这事一个事物需要经历的 event，在 5.7 中不开启 GTID，GTID EVENT 任然存在那叫匿名 gtid event 及 NONYMOUS_GTID_LOG_EVENT，在 5.6 中
最多 gtid event 有变动，因为 5.6 的并行 slave 不依靠 binlog group commit。
如果想了解这些 event 和 infobin 工具请参考的文章：
http://blog.itpub.net/7728585/viewspace-2133188/ 解析 MYSQL BINLOG 二进制格式(1)– 准备工作
http://blog.itpub.net/7728585/viewspace-2133189/ 解析 MYSQL BINLOG 二进制格式(2)–FORMAT_DESCRIPTION_EVENT
http://blog.itpub.net/7728585/viewspace-2133321/ 解析 MYSQL BINLOG 二进制格式(3)–QUERY_EVENT
http://blog.itpub.net/7728585/viewspace-2133429/ 解析 MYSQL BINLOG 二进制格式(4)–TABLE_MAP_EVENT
http://blog.itpub.net/7728585/viewspace-2133463/ 解析 MYSQL BINLOG 二进制格式(5)–WRITE_ROW_EVENT
http://blog.itpub.net/7728585/viewspace-2133469/ 解析 MYSQL BINLOG 二进制格式(6)–UPDATE_ROW_EVENT/DELETE_ROW_EVENT 
http://blog.itpub.net/7728585/viewspace-2133502/ 解析 MYSQL BINLOG 二进制格式(7)–Xid_log_event/XID_EVENT
http://blog.itpub.net/7728585/viewspace-2133506/ 解析 MYSQL BINLOG 二进制格式(8)–GTID_LOG_EVENT/ANONYMOUS_GTID_LOG_EVENT 及其他
http://blog.itpub.net/7728585/viewspace-2133534/ 解析 MYSQL BINLOG 二进制格式(9)–infobin 解析 binlog 帮助文档
http://blog.itpub.net/7728585/viewspace-2133537/ 解析 MYSQL BINLOG 二进制格式(10)– 问题解答

最后看看语句模式的一个事物，虽然很少人用但是我们做一个对比
>Gtid Event:Pos:194(0Xc2) N_pos:259(0X103) Time:1496998879 Event_size:65(bytes)
Gtid:89dfa8a4-cb13-11e6-b54-0c29a879a3:5
–>Query Event:Pos:259(0X103) N_Pos:338(0X152) Time:1496998879 Event_size:79(bytes)
Exe_time:0  Use_db:test Statment(35b-trun):BEGIN /*!Trx begin!*/ Gno:5
–>Query Event:Pos:338(0X152) N_Pos:428(0X1ac) Time:1496998879 Event_size:90(bytes)
Exe_time:0  Use_db:test Statment(35b-trun):delete from test Gno:5
>Xid Event:Pos:428(0X1ac) N_Pos:459(0X1cb) Time:1496998879 Event_size:31(bytes)
COMMIT; /*!Trx end*/ Gno:5
及
>GTID EVENT : 事物开始
–>Query Event :begin
–>Query Event : 正真的语句
>Xid Event: commit
没有 Map Event 和 Insert Event，当然记录的是语句就节约空间了。
下面是 mysqlbinlog 输出

# at 194 –GTID EVENT 开始
#170609 17:01:19 server id 933310  end_log_pos 259 CRC32 0x6a408c33    GTID [commit=yes]
SET @@SESSION.GTID_NEXT= ’89dfa8a4-cb13-11e6-b504-000c29a879a3:5’/*!*/;
# at 259  –Query Event BEGIN
#170609 17:01:19 server id 933310  end_log_pos 338 CRC32 0x9b25b2af    Query  thread_id=2    exec_time=0    error_code=0
SET TIMESTAMP=1496998879/*!*/;
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=83,@@session.collation_connection=83,@@session.collation_server=83/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 338  –Query Event 正真的语句
#170609 17:01:19 server id 933310  end_log_pos 428 CRC32 0x4e4230f8    Query  thread_id=2    exec_time=0    error_code=0
use `test`/*!*/;
SET TIMESTAMP=1496998879/*!*/;
delete from test
/*!*/;
# at 428 — XID EVENT 结束
#170609 17:01:19 server id 933310  end_log_pos 459 CRC32 0x38079d60    Xid = 159
COMMIT/*!*/;

本文永久更新链接地址：http://www.linuxidc.com/Linux/2017-06/144813.htm