MySQL 解密 --> 如何查看二进制日志ROW模式下最原始的SQL语句

MySQL的binlog的ROW模式解析

 

       在mysql5.6以后，对主从数据一致性要求变高了，statement格式逐渐不太适合业务的需求了，所以生产环境大家都采用了row模式，row模式是传输最底层的数据变化的insert的模块来进行主从数据的传输，那么在binlog里面就和普通的statement模式有何差别？能否看到最原始的sql语句呢？

 

1、准备录入数据

 

mysql> create table test1(id int,c1 varchar(20),type int,address varchar(20),create_time datetime);
Query OK, 0 rows affected (0.00 sec)
 
mysql> insert into test1 select 1,'zhangsan','1','zhangsan road No 870,floor 602',now();
ERROR 1406 (22001): Data too long for column 'address' at row 1
mysql>
mysql> show create table test1;
+-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table                                                                                                                                                                                                                         |
+-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| test1 | CREATE TABLE `test1` (
  `id` int(11) DEFAULT NULL,
  `c1` varchar(20) DEFAULT NULL,
  `type` int(11) DEFAULT NULL,
  `address` varchar(20) DEFAULT NULL,
  `create_time` datetime DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |
+-------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
 
mysql> alter table test1 modify  `address` varchar(200) DEFAULT NULL;
Query OK, 0 rows affected (0.03 sec)
Records: 0  Duplicates: 0  Warnings: 0
 
mysql> insert into test1 select 1,'zhangsan','1','zhangsan road No 870,floor 602',now();
Query OK, 1 row affected (0.00 sec)
Records: 1  Duplicates: 0  Warnings: 0
 
mysql> insert into test1 select 2,'lisi','1','zhangsan road No 870,floor 602',now();
Query OK, 1 row affected (0.01 sec)
Records: 1  Duplicates: 0  Warnings: 0
 
mysql>

2、Row模式binlog是乱码

Row模式下面，binlog里面的ddl语句是正常显示的，但是dml是乱码，如下所示：

[root@hch_test_dbm1_121_63 binlog]# /usr/local/mysql/bin/mysqlbinlog mysql-bin.000215

…… # 这里前面的省略

#160722 17:02:38 server id 62 end_log_pos 4291 CRC32 0x369e3244 Query thread_id=60 exec_time=4294967271 error_code=0

SET TIMESTAMP=1469178158/*!*/;

CREATE DATABASE IF NOT EXISTS `percona` /* pt-table-checksum */

/*!*/;

# at 4291

#160722 17:02:38 server id 62 end_log_pos 5079 CRC32 0x8abc6e67 Query thread_id=60 exec_time=4294967271 error_code=0

use `percona`/*!*/;

SET TIMESTAMP=1469178158/*!*/;

CREATE TABLE IF NOT EXISTS `percona`.`checksums` (

db char(64) NOT NULL,

tbl char(64) NOT NULL,

chunk int NOT NULL,

chunk_time float NULL,

chunk_index varchar(200) NULL,

lower_boundary text NULL,

upper_boundary text NULL,

this_crc char(40) NOT NULL,

this_cnt int NOT NULL,

master_crc char(40) NULL,

master_cnt int NULL,

ts timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,

PRIMARY KEY (db, tbl, chunk),

INDEX ts_db_tbl (ts, db, tbl)

) ENGINE=InnoDB

/*!*/;

# at 5079

#160820 10:21:10 server id 63 end_log_pos 5280 CRC32 0xd147bd8e Query thread_id=16 exec_time=0 error_code=0

SET TIMESTAMP=1471659670/*!*/;

SET @@session.sql_mode=1075838976/*!*/;

GRANT ALL PRIVILEGES ON *.* TO 'tim'@'192.168%' IDENTIFIED BY PASSWORD '*2976819BD2CCD13612E03F812A2CD297C1A18B23'

/*!*/;

# at 5280

#160820 10:22:40 server id 63 end_log_pos 5445 CRC32 0x85811be7 Query thread_id=18 exec_time=0 error_code=0

use `test`/*!*/;

SET TIMESTAMP=1471659760/*!*/;

create table test1(id int,c1 varchar(20),type int,address varchar(20),create_time datetime)

/*!*/;

# at 5445

#160820 10:24:34 server id 63 end_log_pos 5580 CRC32 0x2626220c Query thread_id=18 exec_time=0 error_code=0

SET TIMESTAMP=1471659874/*!*/;

alter table test1 modify `address` varchar(200) DEFAULT NULL

/*!*/;

# at 5580

#160820 10:24:36 server id 63 end_log_pos 5660 CRC32 0x7b7c645f Query thread_id=18 exec_time=0 error_code=0

SET TIMESTAMP=1471659876/*!*/;

SET @@session.time_zone='SYSTEM'/*!*/;

BEGIN

/*!*/;

# at 5660

# at 5764

#160820 10:24:36 server id 63 end_log_pos 5821 CRC32 0x08bc94c3 Table_map: `test`.`test1` mapped to number 74

# at 5821

#160820 10:24:36 server id 63 end_log_pos 5911 CRC32 0x2f577f52 Write_rows: table id 74 flags: STMT_END_F

BINLOG '

ZL+3VxM/AAAAOQAAAL0WAAAAAEoAAAAAAAEABHRlc3QABXRlc3QxAAUDDwMPEgU8AFgCAB/DlLwI

ZL+3Vx4/AAAAWgAAABcXAAAAAEoAAAAAAAEAAgAF/+ABAAAACHpoYW5nc2FuAQAAAB4Aemhhbmdz

YW4gcm9hZCBObyA4NzAsZmxvb3IgNjAymZoopiRSf1cv

'/*!*/;

# at 5911

#160820 10:24:36 server id 63 end_log_pos 5942 CRC32 0xb26af81b Xid = 199

COMMIT/*!*/;

# at 5942

#160820 10:24:48 server id 63 end_log_pos 6022 CRC32 0x09eab31d Query thread_id=18 exec_time=0 error_code=0

SET TIMESTAMP=1471659888/*!*/;

BEGIN

/*!*/;

# at 6022

# at 6122

#160820 10:24:48 server id 63 end_log_pos 6179 CRC32 0xdc6dc34b Table_map: `test`.`test1` mapped to number 74

# at 6179

#160820 10:24:48 server id 63 end_log_pos 6265 CRC32 0x5f7ad700 Write_rows: table id 74 flags: STMT_END_F

BINLOG '

cL+3VxM/AAAAOQAAACMYAAAAAEoAAAAAAAEABHRlc3QABXRlc3QxAAUDDwMPEgU8AFgCAB9Lw23c

cL+3Vx4/AAAAVgAAAHkYAAAAAEoAAAAAAAEAAgAF/+ACAAAABGxpc2kBAAAAHgB6aGFuZ3NhbiBy

b2FkIE5vIDg3MCxmbG9vciA2MDKZmiimMADXel8=

'/*!*/;

# at 6265

#160820 10:24:48 server id 63 end_log_pos 6296 CRC32 0xf6833d28 Xid = 200

COMMIT/*!*/;

# at 6296

#160820 10:31:30 server id 63 end_log_pos 6343 CRC32 0xcfcdd344 Rotate to mysql-bin.000216 pos: 4

DELIMITER ;

# End of log file

ROLLBACK /* added by mysqlbinlog */;

/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

[root@hch_test_dbm1_121_63 binlog]#

3、通过--base64-output=decode-rows -v来查看dml语句

执行命令是：/usr/local/mysql/bin/mysqlbinlog --base64-output=decode-rows -v mysql-bin.000215

可以看到如下效果，不过都是最原始的dml块sql语句：

[root@hch_test_dbm1_121_63 binlog]# /usr/local/mysql/bin/mysqlbinlog --base64-output=decode-rows -v mysql-bin.000215

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;

/*!40019 SET @@session.max_insert_delayed_threads=0*/;

/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;

DELIMITER /*!*/;

……

#160820 10:24:36 server id 63 end_log_pos 5821 CRC32 0x08bc94c3 Table_map: `test`.`test1` mapped to number 74

# at 5821

#160820 10:24:36 server id 63 end_log_pos 5911 CRC32 0x2f577f52 Write_rows: table id 74 flags: STMT_END_F

### INSERT INTO `test`.`test1`

### SET

### @1=1

### @2='zhangsan'

### @3=1

### @4='zhangsan road No 870,floor 602'

### @5='2016-08-20 10:24:36'

# at 5911

#160820 10:24:36 server id 63 end_log_pos 5942 CRC32 0xb26af81b Xid = 199

COMMIT/*!*/;

# at 5942

#160820 10:24:48 server id 63 end_log_pos 6022 CRC32 0x09eab31d Query thread_id=18 exec_time=0 error_code=0

SET TIMESTAMP=1471659888/*!*/;

BEGIN

/*!*/;

# at 6022

# at 6122

#160820 10:24:48 server id 63 end_log_pos 6179 CRC32 0xdc6dc34b Table_map: `test`.`test1` mapped to number 74

# at 6179

#160820 10:24:48 server id 63 end_log_pos 6265 CRC32 0x5f7ad700 Write_rows: table id 74 flags: STMT_END_F

### INSERT INTO `test`.`test1`

### SET

### @1=2

### @2='lisi'

### @3=1

### @4='zhangsan road No 870,floor 602'

### @5='2016-08-20 10:24:48'

# at 6265

#160820 10:24:48 server id 63 end_log_pos 6296 CRC32 0xf6833d28 Xid = 200

COMMIT/*!*/;

# at 6296

#160820 10:31:30 server id 63 end_log_pos 6343 CRC32 0xcfcdd344 Rotate to mysql-bin.000216 pos: 4

DELIMITER ;

# End of log file

ROLLBACK /* added by mysqlbinlog */;

/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

[root@hch_test_dbm1_121_63 binlog]#

PS：这样是可以看到了dml的insert语句，但是只看到了最终的insert块，而看不到原始的过来的insert语句，很多时候排查问题需要原始的insert语句而不是底层的insert块。所以问题来了，如何看到最原始的insert sql语句呢？

4、通过binlog_rows_query_log_events参数来查看最原始的insert sql

（4.1）先在线设置全局的binlog_rows_query_log_events参数，刷新日志：

mysql> set binlog_rows_query_log_events=1;

Query OK, 0 rows affected (0.01 sec)

mysql>

mysql> flush logs;

Query OK, 0 rows affected (0.01 sec)

mysql>exit

（4.2）然后重新登录录入新的数据记录：

[root@hch_test_dbm1_121_63 ~]# mysql -utim -ptimgood -h192.168.121.63

Warning: Using a password on the command line interface can be insecure.

Welcome to the MySQL monitor. Commands end with ; or \g.

Your MySQL connection id is 19

Server version: 5.6.12-log Source distribution

Copyright (c) 2000, 2013, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its

affiliates. Other names may be trademarks of their respective

owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql>

mysql> use test;

Database changed

mysql> insert into test1 select 3,'wanger','3','zhangsan road No 870,floor 603',now();

Query OK, 1 row affected (0.00 sec)

Records: 1 Duplicates: 0 Warnings: 0

mysql>

（4.3）解析binlog，没有看到原始的insert语句

[root@hch_test_dbm1_121_63 binlog]# /usr/local/mysql/bin/mysqlbinlog --base64-output=decode-rows -v mysql-bin.000216 >1.sql

[root@hch_test_dbm1_121_63 binlog]# more 1.sql

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;

/*!40019 SET @@session.max_insert_delayed_threads=0*/;

/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;

DELIMITER /*!*/;

# at 4

#160820 10:31:30 server id 63 end_log_pos 120 CRC32 0x1e4d0366 Start: binlog v 4, server v 5.6.12-log created 160820 10:31:30

# Warning: this binlog is either in use or was not closed properly.

# at 120

#160820 10:32:04 server id 63 end_log_pos 200 CRC32 0xab0e625e Query thread_id=19 exec_time=0 error_code=0

SET TIMESTAMP=1471660324/*!*/;

SET @@session.pseudo_thread_id=19/*!*/;

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=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;

SET @@session.time_zone='SYSTEM'/*!*/;

SET @@session.lc_time_names=0/*!*/;

SET @@session.collation_database=DEFAULT/*!*/;

BEGIN

/*!*/;

# at 200

# at 302

#160820 10:32:04 server id 63 end_log_pos 359 CRC32 0x41bf2876 Table_map: `test`.`test1` mapped to number 74

# at 359

#160820 10:32:04 server id 63 end_log_pos 447 CRC32 0x1a3ab3d8 Write_rows: table id 74 flags: STMT_END_F

### INSERT INTO `test`.`test1`

### SET

### @1=3

### @2='wanger'

### @3=3

### @4='zhangsan road No 870,floor 603'

### @5='2016-08-20 10:32:04'

# at 447

#160820 10:32:04 server id 63 end_log_pos 478 CRC32 0xc5081021 Xid = 208

COMMIT/*!*/;

DELIMITER ;

# End of log file

ROLLBACK /* added by mysqlbinlog */;

/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

[root@hch_test_dbm1_121_63 binlog]#

（4.4）通过mysql的命令行查看最原始的insert sql语句，如下所示：

mysql>  show binlog events in 'mysql-bin.000216';
+------------------+-----+-------------+-----------+-------------+----------------------------------------------------------------------------------+
| Log_name         | Pos | Event_type  | Server_id | End_log_pos | Info                                                                             |
+------------------+-----+-------------+-----------+-------------+----------------------------------------------------------------------------------+
| mysql-bin.000216 |   4 | Format_desc |        63 |         120 | Server ver: 5.6.12-log, Binlog ver: 4                                            |
| mysql-bin.000216 | 120 | Query       |        63 |         200 | BEGIN                                                                            || mysql-bin.000216 | 200 | Rows_query  |        63 |         302 | # insert into test1 select 3,'wanger','3','zhangsan road No 870,floor 603',now() || mysql-bin.000216 | 302 | Table_map   |        63 |         359 | table_id: 74 (test.test1)                                                        |
| mysql-bin.000216 | 359 | Write_rows  |        63 |         447 | table_id: 74 flags: STMT_END_F                                                   |
| mysql-bin.000216 | 447 | Xid         |        63 |         478 | COMMIT /* xid=208 */                                                             |
+------------------+-----+-------------+-----------+-------------+----------------------------------------------------------------------------------+
6 rows in set (0.00 sec)
 
mysql>

 

 

 

 

5、试验总结

基于以上的试验，可以得出在row模式下，可以通过mysqlbinlog --base64-output=decode-rows –v查看最底层的insert数据模块，也可以通过命令行show binlog events in 'mysql-bin.000216';来实时查看最原始的insertsql记录。

 

我们可以在搭建数据库的时候，在启动参数文件my.cnf里面事先设置好，如下所示：

# vim my.cnf

[mysqld]

binlog_format=row  # binlog 日志格式

binlog_rows_query_log_events = 1  # 将原始的操作sql记录写入事件中              

 

 以上就是MySQL 解密 --> 如何查看二进制日志ROW模式下最原始的SQL语句的内容，更多相关内容请关注PHP中文网（www.php.cn）！