mysql很多有类型的日志,按照组件划分的话,可以分为 服务层日志 和 存储引擎层日志 : - 服务层日志:二进制日志、慢查日志、通用日志 - 存储引擎层日志:innodb(重做日志、回滚日志)
其中比较重要的就是服务器层的二进制日志,其中记录了所有对mysql数据库的修改事件,包括增删改查事件和对表结构的修改事件。要注意的一点是,只有成功执行了的事件才会记录在二进制日志中,未执行成功的不会保存在二进制日志中。
命令演示:
查看当前二进制日志记录格式
mysql> show variables like 'binlog_format'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | binlog_format | ROW | +---------------+-------+ 1 row in set (0.01 sec)修改记录格式为statement,即改为基于段的格式
mysql> set session binlog_format=statement; Query OK, 0 rows affected (0.00 sec)此时可用查看格式命令来确认一下,是否修改成功
mysql> show variables like 'binlog_format'; +---------------+-----------+ | Variable_name | Value | +---------------+-----------+ | binlog_format | STATEMENT | +---------------+-----------+ 1 row in set (0.01 sec)查看当前二进制日志信息
mysql> show binary logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000058 | 201 | | mysql-bin.000059 | 12721 | | mysql-bin.000060 | 201 | | mysql-bin.000061 | 201 | | mysql-bin.000062 | 1069 | | mysql-bin.000063 | 201 | | mysql-bin.000064 | 201 | | mysql-bin.000065 | 177 | | mysql-bin.000066 | 201 | | mysql-bin.000067 | 177 | | mysql-bin.000068 | 201 | | mysql-bin.000069 | 177 | | mysql-bin.000070 | 177 | | mysql-bin.000071 | 201 | | mysql-bin.000072 | 201 | | mysql-bin.000073 | 154 | +------------------+-----------+ 16 rows in set (0.00 sec)刷新日志,通过这个操作会产生一个新的log文件
mysql> flush logs; Query OK, 0 rows affected (0.02 sec) mysql> show binary logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000059 | 12721 | | mysql-bin.000060 | 201 | | mysql-bin.000061 | 201 | | mysql-bin.000062 | 1069 | | mysql-bin.000063 | 201 | | mysql-bin.000064 | 201 | | mysql-bin.000065 | 177 | | mysql-bin.000066 | 201 | | mysql-bin.000067 | 177 | | mysql-bin.000068 | 201 | | mysql-bin.000069 | 177 | | mysql-bin.000070 | 177 | | mysql-bin.000071 | 201 | | mysql-bin.000072 | 201 | | mysql-bin.000073 | 201 | | mysql-bin.000074 | 154 | +------------------+-----------+ 16 rows in set (0.00 sec)现在进行一个测试操作,创建一个新的数据库及表,并插入更新一些数据。
mysql> create database test; Query OK, 1 row affected (0.00 sec) mysql> use test; Database changed mysql> create table t(id int, c1 varchar(10)); Query OK, 0 rows affected (0.02 sec) mysql> insert into t values(1, 'aa'),(2, 'bb'); Query OK, 2 rows affected (0.02 sec) Records: 2 Duplicates: 0 Warnings: 0 mysql> update t set c1='dd' where id=1; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0这个时候可以进入存放日志的文件夹进行查看二进制日志的具体内容, 不同的操作系统存放路径不同。以ubuntu为例,路径为/var/log/mysql
刚才的操作已经写入新生成的binlog文件中,使用mysqlbinlog命令打开最新的log文件,在此文件中可以清晰的查看到我们所操作过的sql语句
# lee @ acer in /var/log/mysql [10:58:38] C:127 $ mysqlbinlog mysql-bin.000074 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #170713 10:40:30 server id 1 end_log_pos 123 CRC32 0x3bcc260d Start: binlog v 4, server v 5.7.18-0ubuntu0.16.04.1-log created 170713 10:40:30 # Warning: this binlog is either in use or was not closed properly. BINLOG ' nt1mWQ8BAAAAdwAAAHsAAAABAAQANS43LjE4LTB1YnVudHUwLjE2LjA0LjEtbG9nAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA AQ0mzDs= '/*!*/; # at 123 #170713 10:40:30 server id 1 end_log_pos 154 CRC32 0x004e07fa Previous-GTIDs # [empty] # at 154 #170713 10:42:47 server id 1 end_log_pos 219 CRC32 0x6d2f1e61 Anonymous_GTID last_committed=0 sequence_number=1 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 219 #170713 10:42:47 server id 1 end_log_pos 313 CRC32 0x182062d1 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499913767/*!*/; SET @@session.pseudo_thread_id=8/*!*/; 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 database test /*!*/; # at 313 #170713 10:43:14 server id 1 end_log_pos 378 CRC32 0x5af42684 Anonymous_GTID last_committed=1 sequence_number=2 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 378 #170713 10:43:14 server id 1 end_log_pos 490 CRC32 0x926e1454 Query thread_id=8 exec_time=0 error_code=0 use `test`/*!*/; SET TIMESTAMP=1499913794/*!*/; create table t(id int, c1 varchar(10)) /*!*/; # at 490 #170713 10:43:37 server id 1 end_log_pos 555 CRC32 0x571dd95f Anonymous_GTID last_committed=2 sequence_number=3 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 555 #170713 10:43:37 server id 1 end_log_pos 634 CRC32 0xea457c9c Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499913817/*!*/; BEGIN /*!*/; # at 634 #170713 10:43:37 server id 1 end_log_pos 747 CRC32 0x84b084e8 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499913817/*!*/; insert into t values(1, 'aa'),(2, 'bb') /*!*/; # at 747 #170713 10:43:37 server id 1 end_log_pos 778 CRC32 0xb4d17852 Xid = 25 COMMIT/*!*/; # at 778 #170713 10:45:32 server id 1 end_log_pos 843 CRC32 0x45fa3a6e Anonymous_GTID last_committed=3 sequence_number=4 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 843 #170713 10:45:32 server id 1 end_log_pos 922 CRC32 0x8fbf2543 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499913932/*!*/; BEGIN /*!*/; # at 922 #170713 10:45:32 server id 1 end_log_pos 1027 CRC32 0xd4bcab33 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499913932/*!*/; update t set c1='dd' where id=1 /*!*/; # at 1027 #170713 10:45:32 server id 1 end_log_pos 1058 CRC32 0x769f943d Xid = 26 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*/;命令演示:
切换日志格式并刷新日志
mysql> set session binlog_format=row; Query OK, 0 rows affected (0.00 sec) mysql> show variables like 'binlog_format'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | binlog_format | ROW | +---------------+-------+ 1 row in set (0.00 sec) mysql> flush logs; Query OK, 0 rows affected (0.02 sec)查看binlog_row_image参数默认值
mysql> show variables like 'binlog_row_image'; +------------------+-------+ | Variable_name | Value | +------------------+-------+ | binlog_row_image | FULL | +------------------+-------+ 1 row in set (0.00 sec)为方便演示noblob参数效果,修改数据库表信息,增加一列text字段
mysql> alter table t add c2 text; Query OK, 0 rows affected (0.06 sec) Records: 0 Duplicates: 0 Warnings: 0 mysql> select * from t; +------+------+------+ | id | c1 | c2 | +------+------+------+ | 1 | dd | NULL | | 2 | bb | NULL | +------+------+------+ 2 rows in set (0.01 sec)随意执行一些sql操作
mysql> insert into t values(3, 'haha', 'llala'); Query OK, 1 row affected (0.01 sec) mysql> delete from t where id=1; Query OK, 1 row affected (0.00 sec)查看binlog日志
# lee @ acer in /var/log/mysql [14:45:28] $ mysqlbinlog mysql-bin.000076 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #170713 14:35:53 server id 1 end_log_pos 123 CRC32 0xbf52e415 Start: binlog v 4, server v 5.7.18-0ubuntu0.16.04.1-log created 170713 14:35:53 # Warning: this binlog is either in use or was not closed properly. BINLOG ' yRRnWQ8BAAAAdwAAAHsAAAABAAQANS43LjE4LTB1YnVudHUwLjE2LjA0LjEtbG9nAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA ARXkUr8= '/*!*/; # at 123 #170713 14:35:53 server id 1 end_log_pos 154 CRC32 0xafecf53d Previous-GTIDs # [empty] # at 154 #170713 14:43:03 server id 1 end_log_pos 219 CRC32 0x491b5a7e Anonymous_GTID last_committed=0 sequence_number=1 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 219 #170713 14:43:03 server id 1 end_log_pos 318 CRC32 0x4acf1cd1 Query thread_id=8 exec_time=0 error_code=0 use `test`/*!*/; SET TIMESTAMP=1499928183/*!*/; SET @@session.pseudo_thread_id=8/*!*/; 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/*!*/; alter table t add c2 text /*!*/; # at 318 #170713 14:44:02 server id 1 end_log_pos 383 CRC32 0x8437eaf9 Anonymous_GTID last_committed=1 sequence_number=2 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 383 #170713 14:44:02 server id 1 end_log_pos 455 CRC32 0x57adaf15 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499928242/*!*/; BEGIN /*!*/; # at 455 #170713 14:44:02 server id 1 end_log_pos 504 CRC32 0xdba65133 Table_map: `test`.`t` mapped to number 498 # at 504 #170713 14:44:02 server id 1 end_log_pos 556 CRC32 0x19769a28 Write_rows: table id 498 flags: STMT_END_F BINLOG ' shZnWRMBAAAAMQAAAPgBAAAAAPIBAAAAAAEABHRlc3QAAXQAAwMP/AMeAAIHM1Gm2w== shZnWR4BAAAANAAAACwCAAAAAPIBAAAAAAEAAgAD//gDAAAABGhhaGEFAGxsYWxhKJp2GQ== '/*!*/; # at 556 #170713 14:44:02 server id 1 end_log_pos 587 CRC32 0x6184a9a1 Xid = 47 COMMIT/*!*/; # at 587 #170713 14:44:16 server id 1 end_log_pos 652 CRC32 0xc585d273 Anonymous_GTID last_committed=2 sequence_number=3 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 652 #170713 14:44:16 server id 1 end_log_pos 724 CRC32 0x63005380 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499928256/*!*/; BEGIN /*!*/; # at 724 #170713 14:44:16 server id 1 end_log_pos 773 CRC32 0x2c52eaa1 Table_map: `test`.`t` mapped to number 498 # at 773 #170713 14:44:16 server id 1 end_log_pos 816 CRC32 0xa80bd454 Delete_rows: table id 498 flags: STMT_END_F BINLOG ' wBZnWRMBAAAAMQAAAAUDAAAAAPIBAAAAAAEABHRlc3QAAXQAAwMP/AMeAAIHoepSLA== wBZnWSABAAAAKwAAADADAAAAAPIBAAAAAAEAAgAD//wBAAAAAmRkVNQLqA== '/*!*/; # at 816 #170713 14:44:16 server id 1 end_log_pos 847 CRC32 0x9d03bcd0 Xid = 48 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*/;单纯的使用mysqlbinlog命令,我们无法直观的看懂日志中保存的信息,所以加参数打开
# lee @ acer in /var/log/mysql [14:45:44] $ mysqlbinlog -vv mysql-bin.000076 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #170713 14:35:53 server id 1 end_log_pos 123 CRC32 0xbf52e415 Start: binlog v 4, server v 5.7.18-0ubuntu0.16.04.1-log created 170713 14:35:53 # Warning: this binlog is either in use or was not closed properly. BINLOG ' yRRnWQ8BAAAAdwAAAHsAAAABAAQANS43LjE4LTB1YnVudHUwLjE2LjA0LjEtbG9nAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA ARXkUr8= '/*!*/; # at 123 #170713 14:35:53 server id 1 end_log_pos 154 CRC32 0xafecf53d Previous-GTIDs # [empty] # at 154 #170713 14:43:03 server id 1 end_log_pos 219 CRC32 0x491b5a7e Anonymous_GTID last_committed=0 sequence_number=1 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 219 #170713 14:43:03 server id 1 end_log_pos 318 CRC32 0x4acf1cd1 Query thread_id=8 exec_time=0 error_code=0 use `test`/*!*/; SET TIMESTAMP=1499928183/*!*/; SET @@session.pseudo_thread_id=8/*!*/; 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/*!*/; alter table t add c2 text /*!*/; # at 318 #170713 14:44:02 server id 1 end_log_pos 383 CRC32 0x8437eaf9 Anonymous_GTID last_committed=1 sequence_number=2 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 383 #170713 14:44:02 server id 1 end_log_pos 455 CRC32 0x57adaf15 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499928242/*!*/; BEGIN /*!*/; # at 455 #170713 14:44:02 server id 1 end_log_pos 504 CRC32 0xdba65133 Table_map: `test`.`t` mapped to number 498 # at 504 #170713 14:44:02 server id 1 end_log_pos 556 CRC32 0x19769a28 Write_rows: table id 498 flags: STMT_END_F BINLOG ' shZnWRMBAAAAMQAAAPgBAAAAAPIBAAAAAAEABHRlc3QAAXQAAwMP/AMeAAIHM1Gm2w== shZnWR4BAAAANAAAACwCAAAAAPIBAAAAAAEAAgAD//gDAAAABGhhaGEFAGxsYWxhKJp2GQ== '/*!*/; ### INSERT INTO `test`.`t` ### SET ### @1=3 /* INT meta=0 nullable=1 is_null=0 */ ### @2='haha' /* VARSTRING(30) meta=30 nullable=1 is_null=0 */ ### @3='llala' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */ # at 556 #170713 14:44:02 server id 1 end_log_pos 587 CRC32 0x6184a9a1 Xid = 47 COMMIT/*!*/; # at 587 #170713 14:44:16 server id 1 end_log_pos 652 CRC32 0xc585d273 Anonymous_GTID last_committed=2 sequence_number=3 SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 652 #170713 14:44:16 server id 1 end_log_pos 724 CRC32 0x63005380 Query thread_id=8 exec_time=0 error_code=0 SET TIMESTAMP=1499928256/*!*/; BEGIN /*!*/; # at 724 #170713 14:44:16 server id 1 end_log_pos 773 CRC32 0x2c52eaa1 Table_map: `test`.`t` mapped to number 498 # at 773 #170713 14:44:16 server id 1 end_log_pos 816 CRC32 0xa80bd454 Delete_rows: table id 498 flags: STMT_END_F BINLOG ' wBZnWRMBAAAAMQAAAAUDAAAAAPIBAAAAAAEABHRlc3QAAXQAAwMP/AMeAAIHoepSLA== wBZnWSABAAAAKwAAADADAAAAAPIBAAAAAAEAAgAD//wBAAAAAmRkVNQLqA== '/*!*/; ### DELETE FROM `test`.`t` ### WHERE ### @1=1 /* INT meta=0 nullable=1 is_null=0 */ ### @2='dd' /* VARSTRING(30) meta=30 nullable=1 is_null=0 */ ### @3=NULL /* BLOB/TEXT meta=2 nullable=1 is_null=1 */ # at 816 #170713 14:44:16 server id 1 end_log_pos 847 CRC32 0x9d03bcd0 Xid = 48 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语句,同时这种格式的日志还记录了修改过的每一行数据的信息
修改binlog_row_image参数值,更新一条记录
mysql> set session binlog_row_image=minimal; Query OK, 0 rows affected (0.00 sec) mysql> update t set c2='this 2' where id=2; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0查看binlog文件记录内容(只截取新增部分操作) * 从记录内容可看出,日志只记录了修改那行数据的第三列,即c2的值,未变动的列并未记录*
### UPDATE `test`.`t` ### WHERE ### @1=2 /* INT meta=0 nullable=1 is_null=0 */ ### @2='bb' /* VARSTRING(30) meta=30 nullable=1 is_null=0 */ ### @3=NULL /* BLOB/TEXT meta=2 nullable=1 is_null=1 */ ### SET ### @3='this 2' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */ # at 1086 #170713 15:18:21 server id 1 end_log_pos 1117 CRC32 0xfdd198ec Xid = 50 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*/;继续修改binlog_row_image参数值,更新一条记录
mysql> set session binlog_row_image=noblob; Query OK, 0 rows affected (0.00 sec) mysql> update t set c1='woqu' where id=3; Query OK, 1 row affected (0.01 sec) Rows matched: 1 Changed: 1 Warnings: 0查看binlog文件记录内容(同上) 从记录内容可以发现,日志只记录了第一列和第二列的数据,并没有记录第三列text属性的值
### UPDATE `test`.`t` ### WHERE ### @1=3 /* INT meta=0 nullable=1 is_null=0 */ ### @2='fff' /* VARSTRING(30) meta=30 nullable=1 is_null=0 */ ### @3='llala' /* BLOB/TEXT meta=2 nullable=1 is_null=0 */ ### SET ### @1=3 /* INT meta=0 nullable=1 is_null=0 */ ### @2='woqu' /* VARSTRING(30) meta=30 nullable=1 is_null=0 */ # at 1640 #170713 15:24:28 server id 1 end_log_pos 1671 CRC32 0x429c269c Xid = 55 COMMIT/*!*/;总结一下binlog_row_format三种参数的记录差异 - FULL: 记录修改行的所有列数据 - MINIMAL: 仅记录修改行中有发生数据变化的列 - NOBOLB: 和FULL方式相似,仅仅是当blog或text这些列没有进行修改时,不会记录这些属性的列
总结:在选择二进制日志格式时,通常选择基于行或者混合日志格式。然而对于数据复制安全性要求高的情况下,更建议使用基于行的日志格式。另外,如果选择这种格式,务必设置binlog_row_image=minimal