手机版
你好,游客 登录 注册 搜索
背景:
阅读新闻

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

[日期:2017-06-16] 来源:Linux社区  作者:gaopengtttt [字体: ]

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

linux
相关资讯       MySQL binlog 
本文评论   查看全部评论 (0)
表情: 表情 姓名: 字数

       

评论声明
  • 尊重网上道德,遵守中华人民共和国的各项有关法律法规
  • 承担一切因您的行为而直接或间接导致的民事或刑事法律责任
  • 本站管理人员有权保留或删除其管辖留言中的任意内容
  • 本站有权在网站内转载或引用您的评论
  • 参与本评论即表明您已经阅读并接受上述条款