MySQL中binlog参数:binlog_rows_query_log_events

在使用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是什么。