在使用RBR也就是行格式的時候，去解析binlog，需要逆向才能分析出對應的原始SQL是什么，而且，里面對應的是每一條具體行變更的內容。當然，你可以開啟general log,但如果我們需要的只是記錄對應的行變更，而不需要記錄這些select普通的查詢，因為general log 會將線上所有的操作都記錄下來，這種功能適合於我們審核統計，但是不適合我們對事務進行判斷，故此，我們使用binlog_rows_query_log_events進行查看。在官網中的解析如下
binlog_rows_query_log_events
The binlog_rows_query_log_events system variable affects row-based logging only. When enabled, it causes a MySQL 5.6.2 or later server
to write informational log events such as row query log events into its binary log. This information can be used for debugging and related purposes;
such as obtaining the original query issued on the master when it cannot be reconstructed from the row updates.
These events are normally ignored by MySQL programs reading the binary log and so cause no issues when replicating or restoring from backup.
To view them, increase the verbosity level by using mysqlbinlog's --verbose option twice, either as "-vv" or "--verbose --verbose".
可以看到，它是一個動態的，全局，會話型的變量，即可以通過SQL模式進行關閉開啟。
在未開啟狀態中的使用
[root@localhost][boss]> flush logs; Query OK, 0 rows affected (0.90 sec) [root@localhost][boss]> flush logs; Query OK, 0 rows affected (0.18 sec) [root@gzx-master-01 logs]# ll total 8977656 -rw-r----- 1 mysql mysql 79405 Apr 24 08:42 error.log -rw-r----- 1 mysql mysql 217 Mar 10 10:42 mysql_bin.000013 -rw-r----- 1 mysql mysql 658363086 Apr 24 08:43 mysql_bin.000027 -rw-r----- 1 mysql mysql 241 Apr 24 08:43 mysql_bin.000028 -rw-r----- 1 mysql mysql 194 Apr 24 08:43 mysql_bin.000029
-rw-r----- 1 mysql mysql 194 Apr 24 08:53 mysql_bin.000030
-rw-r----- 1 mysql mysql 132 Apr 24 08:43 mysql_bin.index
-rw-r----- 1 mysql mysql 8534643198 Apr 24 08:43 slow.log
目前最新的binlog切換到30的文件中，做對應的DML
[root@localhost][boss]> select * from t; +------+ | id | +------+ | 1 | | 1 | | 1 | | 1 | | 1 | | 2 | | 2 | | 2 | | 3 | | 3 | | 7 | +------+ 11 rows in set (0.00 sec) [root@localhost][boss]> update t set id = 8 where id=7; Query OK, 1 row affected (0.07 sec) Rows matched: 1 Changed: 1 Warnings: 0 [root@localhost][boss]> select * from t; +------+ | id | +------+ | 1 | | 1 | | 1 | | 1 | | 1 | | 2 | | 2 | | 2 | | 3 | | 3 | | 8 | +------+ 11 rows in set (0.00 sec)
查看binlog
[root@gzx-master-01 logs]# mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS mysql_bin.000030 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #170424 8:58:35 server id 37306 end_log_pos 123 CRC32 0x48e80ee3 Start: binlog v 4, server v 5.7.17-log created 170424 8:58:35 # Warning: this binlog is either in use or was not closed properly. # at 123 #170424 8:58:35 server id 37306 end_log_pos 194 CRC32 0xaf41def6 Previous-GTIDs # a0c06ec7-fef0-11e6-9f85-525400a7d662:1-812 # at 194 #170424 8:58:52 server id 37306 end_log_pos 259 CRC32 0xac26b3b1 GTID last_committed=sequence_number=1 SET @@SESSION.GTID_NEXT= 'a0c06ec7-fef0-11e6-9f85-525400a7d662:813'/*!*/; # at 259 #170424 8:58:52 server id 37306 end_log_pos 331 CRC32 0xb56db594 Query thread_id=34 exec_time=0 error_code=0 SET TIMESTAMP=1492995532/*!*/; SET @@session.pseudo_thread_id=34/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1436549120/*!*/; 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/*!*/; BEGIN /*!*/; # at 331 #170424 8:58:52 server id 37306 end_log_pos 385 CRC32 0x88acf1be Rows_query # at 429 #170424 8:58:52 server id 37306 end_log_pos 475 CRC32 0xf2505403 Update_rows: table id 118 flags: STMT_END_F ### UPDATE `boss`.`t` ### WHERE ### @1=7 /* INT meta=0 nullable=1 is_null=0 */ ### SET ### @1=8 /* INT meta=0 nullable=1 is_null=0 */ # at 475 #170424 8:58:52 server id 37306 end_log_pos 506 CRC32 0xefebd387 Xid = 2444 COMMIT/*!*/; 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*/;
這里只會詳細記錄對應變更行的每一條信息，那么如果我們開啟
[root@localhost][(none)]> set global binlog_rows_query_log_events=on;
再次執行大致的SQL，查詢日志發現
[root@localhost][boss]> set global binlog_rows_query_log_events=on; Query OK, 0 rows affected (0.00 sec) [root@localhost][boss]> flush logs; Query OK, 0 rows affected (0.41 sec) [root@localhost][boss]> update t set id = 9 where id=8; Query OK, 1 row affected (0.06 sec) Rows matched: 1 Changed: 1 Warnings: 0 [root@gzx-master-01 logs]# mysqlbinlog --no-defaults -v -v --base64-output=DECODE-ROWS mysql_bin.000031 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #170424 9:03:47 server id 37306 end_log_pos 123 CRC32 0xa04cc14a Start: binlog v 4, server v 5.7.17-log created 170424 9:03:47 # Warning: this binlog is either in use or was not closed properly. # at 123 #170424 9:03:47 server id 37306 end_log_pos 194 CRC32 0xc3c3b085 Previous-GTIDs # a0c06ec7-fef0-11e6-9f85-525400a7d662:1-813 # at 194 #170424 9:03:55 server id 37306 end_log_pos 259 CRC32 0xbf9d2c93 GTID last_committed=sequence_number=1 SET @@SESSION.GTID_NEXT= 'a0c06ec7-fef0-11e6-9f85-525400a7d662:814'/*!*/; # at 259 #170424 9:03:55 server id 37306 end_log_pos 331 CRC32 0xeddbf07c Query thread_id=34 exec_time=0 error_code=0 SET TIMESTAMP=1492995835/*!*/; SET @@session.pseudo_thread_id=34/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1436549120/*!*/; 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/*!*/; BEGIN /*!*/; # at 331 #170424 9:03:55 server id 37306 end_log_pos 385 CRC32 0x912f4086 Rows_query # update t set id = 9 where id=8 # at 385 #170424 9:03:55 server id 37306 end_log_pos 429 CRC32 0x16eec7d7 Table_map: `boss`.`t` mapped to number 118 # at 429 #170424 9:03:55 server id 37306 end_log_pos 475 CRC32 0x920862af Update_rows: table id 118 flags: STMT_END_F ### UPDATE `boss`.`t` ### WHERE ### @1=8 /* INT meta=0 nullable=1 is_null=0 */ ### SET ### @1=9 /* INT meta=0 nullable=1 is_null=0 */ # at 475 #170424 9:03:55 server id 37306 end_log_pos 506 CRC32 0xa37b82e5 Xid = 2447 COMMIT/*!*/; 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*/;
看下划線的地方，可以比較清楚的知道，對應的SQL是什么。