binlog解析1:statement
1、配置文件设置:
my.cnf
[mysqld] binlog_format='statement'
2、优缺点对比:
-
优点:
- binlog 文件小
日志中包含原始SQL,方便统计审计
- binlog 文件小
-
缺点:
- 导致主从不一致
对一些系统函数不能准确复制或不能复制,在不同server上执行,返回的结果是不同的,则会造成数据不一致。
- 导致主从不一致
3、测试:
- 查看事物隔离级别:设置事物隔离级别为默认RR
注意:5.7版本RC级别下不能设置为binlog_format=statement;
root@wjj 06:05:33>create table t1(id int, c1 varchar(200));
Query OK, 0 rows affected (0.06 sec)
root@wjj 06:06:16>insert into t1(id,c1) values(1,'abc');
ERROR 1665 (HY000): Cannot execute statement: impossible to write to binary log since BINLOG_FORMAT = STATEMENT and at least one table uses a storage engine limited to row-based logging. InnoDB is limited to row-logging when transaction isolation level is READ COMMITTED or READ UNCOMMITTED.
- 设置binlog_format:
- 插入测试数据,进行binlog解析观察:
-
使用SHOW BINLOG EVENTS [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count]进行解析:
MySQL binlog记录的所有操作实际上都有对应的事件类型的,比如STATEMENT格式中的DML操作对应的是QUERY_EVENT类型,ROW格式下的DML操作对应的是ROWS_EVENT类型。
root@wjj 06:19:20>SHOW BINLOG EVENTS in 'mysql-bin.000026';
+------------------+------+----------------+-----------+-------------+------------------------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+------------------+------+----------------+-----------+-------------+------------------------------------------------------+
| mysql-bin.000026 | 4 | Format_desc | 13307 | 123 | Server ver: 5.7.11-log, Binlog ver: 4 |
| mysql-bin.000026 | 123 | Previous_gtids | 13307 | 194 | 3f824a0c-b6d3-11e6-bcaa-0800279cc6a0:1-69 |
| mysql-bin.000026 | 194 | Anonymous_Gtid | 13307 | 259 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 259 | Query | 13307 | 371 | use `wjj`; create table t1(id int, c1 varchar(200)) |
| mysql-bin.000026 | 371 | Anonymous_Gtid | 13307 | 436 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 436 | Query | 13307 | 513 | BEGIN |
| mysql-bin.000026 | 513 | Query | 13307 | 622 | use `wjj`; insert into t1(id,c1) values(1,'abc') |
| mysql-bin.000026 | 622 | Xid | 13307 | 653 | COMMIT /* xid=25 */ |
| mysql-bin.000026 | 653 | Anonymous_Gtid | 13307 | 718 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 718 | Query | 13307 | 795 | BEGIN |
| mysql-bin.000026 | 795 | Query | 13307 | 905 | use `wjj`; insert into t1(id,c1) values(2,uuid()) |
| mysql-bin.000026 | 905 | Xid | 13307 | 936 | COMMIT /* xid=26 */ |
| mysql-bin.000026 | 936 | Anonymous_Gtid | 13307 | 1001 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 1001 | Query | 13307 | 1086 | BEGIN |
| mysql-bin.000026 | 1086 | Query | 13307 | 1203 | use `wjj`; insert into t1(id,c1) values(3,now()) |
| mysql-bin.000026 | 1203 | Xid | 13307 | 1234 | COMMIT /* xid=27 */ |
| mysql-bin.000026 | 1234 | Anonymous_Gtid | 13307 | 1299 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 1299 | Query | 13307 | 1384 | BEGIN |
| mysql-bin.000026 | 1384 | Query | 13307 | 1505 | use `wjj`; insert into t1(id,c1) values(4,sysdate()) |
| mysql-bin.000026 | 1505 | Xid | 13307 | 1536 | COMMIT /* xid=28 */ |
| mysql-bin.000026 | 1536 | Anonymous_Gtid | 13307 | 1601 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 1601 | Query | 13307 | 1678 | BEGIN |
| mysql-bin.000026 | 1678 | Query | 13307 | 1783 | use `wjj`; update t1 set c1='wjj' where id=2 |
| mysql-bin.000026 | 1783 | Xid | 13307 | 1814 | COMMIT /* xid=29 */ |
| mysql-bin.000026 | 1814 | Anonymous_Gtid | 13307 | 1879 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 1879 | Query | 13307 | 1956 | BEGIN |
| mysql-bin.000026 | 1956 | Query | 13307 | 2054 | use `wjj`; delete from t1 where id>=2 |
| mysql-bin.000026 | 2054 | Xid | 13307 | 2085 | COMMIT /* xid=30 */ |
| mysql-bin.000026 | 2085 | Anonymous_Gtid | 13307 | 2150 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000026 | 2150 | Query | 13307 | 2263 | use `wjj`; DROP TABLE `t1` /* generated by server */ |
| mysql-bin.000026 | 2263 | Rotate | 13307 | 2310 | mysql-bin.000027;pos=4
--是做日志的切换。指向下个日志在什么位置的。
解析:
- Log_name:此条log存在哪个文件中
- Pos:在bin_log中开始的位置
- EVENT_type:log类型的信息
- End_log_pos:log在bin-log中结束的位置
-
Info:log的一些备注信息,可以直观的看出进行了什么操作。
- 1.EVENT_TYPE:
-
2.Format_desc :格式描述事件
- a.Format_description_event是binlog version4中为了取代之前版本中START_EVENT_V3事件而引入的。它是binlog文件中的第一个事件,而且,该事件只会在binlog中出现一次。MySQL根据FORMAT_DESCRIPTION_EVENT的定义来解析其他事件。
- b.通常指定了MySQL server版本,binlog版本,该binlog文件的创建时间。
-
3.Query:查询事件
- a.Query_EVENT:以文本的形式来记录事物的操作
-
b.Query_EVENT:类型事件通常有以下几种情况使用:
- 1.事物开始,执行begin操作
- 2.statement格式中的DML(select,update,insert,delete),DDL操作
- 3.row格式中的DDL(create,alter,drop)操作
- 4.Table_map:表映射事件
-
5.Xid:自动提交事件
- 在事物提交时,不管是statement还是row格式的binlog,都会在末尾添加一个XID_EVENT事件代表事物的结束。该事件加了了该事物的ID,在MySQL进行崩溃恢复时,根据事物在binlog中提交的情况来决定是否提交存储引擎状态为prepared的事物
- 在事物提交时,不管是statement还是row格式的binlog,都会在末尾添加一个XID_EVENT事件代表事物的结束。该事件加了了该事物的ID,在MySQL进行崩溃恢复时,根据事物在binlog中提交的情况来决定是否提交存储引擎状态为prepared的事物
- 6.Rotate:flush logs是做日志的切换,指向下个日志在什么位置。
- 7.GTID_LOG_EVENT:在启用GTID模式后,MySQL实际上为每个事物都分配了个GTID
-
8.RoPrevious_gtids:开启GITD后,每个binlog开头都会有一个Pervious_gtid_log_event事件,它的值是上一个binlog的
- previous_gtid_log_event+gtid_log_event,实际上,在数据库重启的时候,需要重新填充gitd_executed的值,该值即是最新的binlogPrevious_gtid_log_event+gtid_log_event。
- 9.stop_event:当MySQL数据库停止时,会在当前的binlog末尾添加一个stop_event事件表示数据库停止
-
10.rows_event:
对于row格式的binlog,所有DML语句都是记录在rows_event中。
row_event分为中:WRITE_ROWS_EVENT,UPDATE_ROWS_EVENT,DELETE_ROWS_EVENT,分别对应insert,update,delete操作- insert:WRITE_ROWS_EVENT包含了要插入的数据
- update:update_ROWS_EVENT不仅包含了修改后的数据,还包含了修改前的值。
- delete:仅仅需要指定删除的主键(在没有主键的情况下,会给定所有列)
NOTE:对于QUERY_EVENT事件,以文本形式记录DML操作的。而对于ROWS_EVENT事件,并不是文本形式,所以通过mysqlbinlog查看基于ROW格式的binlog时,需要执行-vv --base64-output=decode-rows。
4、使用mysqlbinlog命令解析binlog文件:
[语句级记录]
[root@localhost logs]# /opt/mysql/mysql-5.7.11/bin/mysqlbinlog mysql-bin.000026
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4 --at 4-123是binlog的描述包。 从第4个字节开始,记录那台DB,版本时间
#161212 18:19:17 server id 13307 end_log_pos 123 CRC32 0xc602c6ee Start: binlog v 4, server v 5.7.11-log created 161212 18:19:17
BINLOG '
pXlOWA/7MwAAdwAAAHsAAAAAAAQANS43LjExLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
Ae7GAsY=
'/*!*/;
# at 123
#161212 18:19:17 server id 13307 end_log_pos 194 CRC32 0x96b04a1b Previous-GTIDs
# 3f824a0c-b6d3-11e6-bcaa-0800279cc6a0:1-69
# at 194
#161212 18:19:17 server id 13307 end_log_pos 259 CRC32 0xe55919aa Anonymous_GTID last_committed=0 sequence_number=1
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 259
#161212 18:19:17 server id 13307 end_log_pos 371 CRC32 0x0f871ba1 Query thread_id=88 exec_time=0 error_code=0
use `wjj`/*!*/;
SET TIMESTAMP=1481537957/*!*/;
SET @@session.pseudo_thread_id=88/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1436549152/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create table t1(id int, c1 varchar(200)) --statement语句格式以原始语句复制
/*!*/;
# at 371
#161212 18:19:17 server id 13307 end_log_pos 436 CRC32 0x1aaa4c98 Anonymous_GTID last_committed=1 sequence_number=2
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 436
#161212 18:19:17 server id 13307 end_log_pos 513 CRC32 0x8bb1a30c Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
BEGIN
/*!*/;
# at 513
#161212 18:19:17 server id 13307 end_log_pos 622 CRC32 0x6af61177 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
insert into t1(id,c1) values(1,'abc')
/*!*/;
# at 622
#161212 18:19:17 server id 13307 end_log_pos 653 CRC32 0x7e0b04ba Xid = 25
COMMIT/*!*/;
# at 653
#161212 18:19:17 server id 13307 end_log_pos 718 CRC32 0xd3591ccd Anonymous_GTID last_committed=2 sequence_number=3
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 718
#161212 18:19:17 server id 13307 end_log_pos 795 CRC32 0x572106a4 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
BEGIN
/*!*/;
# at 795
#161212 18:19:17 server id 13307 end_log_pos 905 CRC32 0xe4bd1c6a Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
insert into t1(id,c1) values(2,uuid()) --传输到不同的server底层,uuid返回的结果不同,造成数据不一致
/*!*/;
# at 905
#161212 18:19:17 server id 13307 end_log_pos 936 CRC32 0x64d5cc69 Xid = 26
COMMIT/*!*/;
# at 936
#161212 18:19:17 server id 13307 end_log_pos 1001 CRC32 0x75618bb0 Anonymous_GTID last_committed=3 sequence_number=4
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1001
#161212 18:19:17 server id 13307 end_log_pos 1086 CRC32 0x6efec932 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
SET @@session.time_zone='SYSTEM'/*!*/;
BEGIN
/*!*/;
# at 1086
#161212 18:19:17 server id 13307 end_log_pos 1203 CRC32 0x52105910 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
insert into t1(id,c1) values(3,now()) --now()函数记录准确,因为set simestamp函数
/*!*/;
# at 1203
#161212 18:19:17 server id 13307 end_log_pos 1234 CRC32 0xed54a371 Xid = 27
COMMIT/*!*/;
# at 1234
#161212 18:19:17 server id 13307 end_log_pos 1299 CRC32 0xa64bb140 Anonymous_GTID last_committed=4 sequence_number=5
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1299
#161212 18:19:17 server id 13307 end_log_pos 1384 CRC32 0xa07f9f94 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
BEGIN
/*!*/;
# at 1384
#161212 18:19:17 server id 13307 end_log_pos 1505 CRC32 0xd48c9b9f Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
insert into t1(id,c1) values(4,sysdate())
/*!*/;
# at 1505
#161212 18:19:17 server id 13307 end_log_pos 1536 CRC32 0xc2dbfff1 Xid = 28
COMMIT/*!*/;
# at 1536
#161212 18:19:17 server id 13307 end_log_pos 1601 CRC32 0x473a212e Anonymous_GTID last_committed=5 sequence_number=6
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1601
#161212 18:19:17 server id 13307 end_log_pos 1678 CRC32 0xd56efb02 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
BEGIN
/*!*/;
# at 1678
#161212 18:19:17 server id 13307 end_log_pos 1783 CRC32 0xadb46ffb Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
update t1 set c1='wjj' where id=2
/*!*/;
# at 1783
#161212 18:19:17 server id 13307 end_log_pos 1814 CRC32 0x4d975130 Xid = 29
COMMIT/*!*/;
# at 1814
#161212 18:19:17 server id 13307 end_log_pos 1879 CRC32 0x2b7935ad Anonymous_GTID last_committed=6 sequence_number=7
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 1879
#161212 18:19:17 server id 13307 end_log_pos 1956 CRC32 0x249a2ee7 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
BEGIN
/*!*/;
# at 1956
#161212 18:19:17 server id 13307 end_log_pos 2054 CRC32 0x5178bc92 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
delete from t1 where id>=2
/*!*/;
# at 2054
#161212 18:19:17 server id 13307 end_log_pos 2085 CRC32 0x33dfe289 Xid = 30
COMMIT/*!*/;
# at 2085
#161212 18:19:17 server id 13307 end_log_pos 2150 CRC32 0xefb1785a Anonymous_GTID last_committed=7 sequence_number=8
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 2150
#161212 18:19:17 server id 13307 end_log_pos 2263 CRC32 0x76370ce5 Query thread_id=88 exec_time=0 error_code=0
SET TIMESTAMP=1481537957/*!*/;
DROP TABLE `t1` /* generated by server */
/*!*/;
# at 2263
#161212 18:19:20 server id 13307 end_log_pos 2310 CRC32 0xd0981f74 Rotate to mysql-bin.000027 pos: 4
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;