[MySQL 5.7]：binlog --statement-白红宇

binlog解析1：statement

1、配置文件设置：

my.cnf

[mysqld] binlog_format='statement'

2、优缺点对比：

优点：
- binlog 文件小
  日志中包含原始SQL，方便统计审计

缺点：
- 导致主从不一致
  对一些系统函数不能准确复制或不能复制，在不同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的事物
- 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:17BINLOG 'pXlOWA/7MwAAdwAAAHsAAAAAAAQANS43LjExLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQAAe7GAsY='/*!*/;# 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=1SET @@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=0use `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=2SET @@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=0SET 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=0SET 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 = 25COMMIT/*!*/;# at 653#161212 18:19:17 server id 13307  end_log_pos 718 CRC32 0xd3591ccd     Anonymous_GTID    last_committed=2    sequence_number=3SET @@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=0SET 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=0SET 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 = 26COMMIT/*!*/;# at 936#161212 18:19:17 server id 13307  end_log_pos 1001 CRC32 0x75618bb0     Anonymous_GTID    last_committed=3    sequence_number=4SET @@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=0SET 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=0SET 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 = 27COMMIT/*!*/;# at 1234#161212 18:19:17 server id 13307  end_log_pos 1299 CRC32 0xa64bb140     Anonymous_GTID    last_committed=4    sequence_number=5SET @@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=0SET 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=0SET 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 = 28COMMIT/*!*/;# at 1536#161212 18:19:17 server id 13307  end_log_pos 1601 CRC32 0x473a212e     Anonymous_GTID    last_committed=5    sequence_number=6SET @@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=0SET 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=0SET 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 = 29COMMIT/*!*/;# at 1814#161212 18:19:17 server id 13307  end_log_pos 1879 CRC32 0x2b7935ad     Anonymous_GTID    last_committed=6    sequence_number=7SET @@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=0SET 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=0SET TIMESTAMP=1481537957/*!*/;delete from t1 where id>=2/*!*/;# at 2054#161212 18:19:17 server id 13307  end_log_pos 2085 CRC32 0x33dfe289     Xid = 30COMMIT/*!*/;# at 2085#161212 18:19:17 server id 13307  end_log_pos 2150 CRC32 0xefb1785a     Anonymous_GTID    last_committed=7    sequence_number=8SET @@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=0SET 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: 4SET @@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*/;