MySQL的二进制日志(binlog)使用分析(3)——使用show binlog events命令查看日志信息

    技术2025-04-19  24

    MySQL的二进制日志(binlog)使用分析(3)——使用show binlog events命令查看日志信息

    binlog文件中存储的内容称之为二进制事件,简称事件。我们的每一个数据库更新操作(Insert、Update、Delete等),都会对应的一个事件。使用show binlog events命令可以以列表的形式显示日志中的事件信息。

    一、show binlog events命令的格式

    show binlog events [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count];

    说明: (1)IN ‘log_name’:指定要查询的binlog文件名(如果省略此参数,则默认指定第一个binlog文件); (2)FROM pos:指定从哪个pos起始点开始查起(如果省略此参数,则从整个文件的第一个pos点开始算); (3)LIMIT【offset】:偏移量(默认为0); (4)row_count:查询总条数(如果省略,则显示所有行)。

    1、查看binlog文件信息

    mysql> show master logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 923 | | mysql-bin.000002 | 154 | +------------------+-----------+ 2 rows in set (0.00 sec)

    2、查询第一个binlog日志

    mysql> show binlog events; +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | mysql-bin.000001 | 4 | Format_desc | 1 | 123 | Server ver: 5.7.27-log, Binlog ver: 4 | | mysql-bin.000001 | 123 | Previous_gtids | 1 | 154 | | | mysql-bin.000001 | 154 | Anonymous_Gtid | 1 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 219 | Query | 1 | 291 | BEGIN | | mysql-bin.000001 | 291 | Table_map | 1 | 339 | table_id: 113 (hist.t2) | | mysql-bin.000001 | 339 | Write_rows | 1 | 413 | table_id: 113 flags: STMT_END_F | | mysql-bin.000001 | 413 | Xid | 1 | 444 | COMMIT /* xid=16 */ | | mysql-bin.000001 | 444 | Anonymous_Gtid | 1 | 509 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 509 | Query | 1 | 581 | BEGIN | | mysql-bin.000001 | 581 | Table_map | 1 | 629 | table_id: 113 (hist.t2) | | mysql-bin.000001 | 629 | Update_rows | 1 | 845 | table_id: 113 flags: STMT_END_F | | mysql-bin.000001 | 845 | Xid | 1 | 876 | COMMIT /* xid=17 */ | | mysql-bin.000001 | 876 | Rotate | 1 | 923 | mysql-bin.000002;pos=4 | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ 13 rows in set (0.00 sec)

    3、查询第二个binlog日志

    mysql> show binlog events in 'mysql-bin.000002'; +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | mysql-bin.000002 | 4 | Format_desc | 1 | 123 | Server ver: 5.7.27-log, Binlog ver: 4 | | mysql-bin.000002 | 123 | Previous_gtids | 1 | 154 | | | mysql-bin.000002 | 154 | Anonymous_Gtid | 1 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000002 | 219 | Query | 1 | 291 | BEGIN | | mysql-bin.000002 | 291 | Table_map | 1 | 336 | table_id: 112 (hist.t1) | | mysql-bin.000002 | 336 | Write_rows | 1 | 386 | table_id: 112 flags: STMT_END_F | | mysql-bin.000002 | 386 | Xid | 1 | 417 | COMMIT /* xid=39 */ | | mysql-bin.000002 | 417 | Anonymous_Gtid | 1 | 482 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000002 | 482 | Query | 1 | 554 | BEGIN | | mysql-bin.000002 | 554 | Table_map | 1 | 599 | table_id: 112 (hist.t1) | | mysql-bin.000002 | 599 | Write_rows | 1 | 649 | table_id: 112 flags: STMT_END_F | | mysql-bin.000002 | 649 | Xid | 1 | 680 | COMMIT /* xid=40 */ | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ 12 rows in set (0.00 sec)

    4、查询mysql-bin.000002文件,从pos点417开始查询

    mysql> show binlog events in 'mysql-bin.000002' from 417; +------------------+-----+----------------+-----------+-------------+--------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+--------------------------------------+ | mysql-bin.000002 | 417 | Anonymous_Gtid | 1 | 482 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000002 | 482 | Query | 1 | 554 | BEGIN | | mysql-bin.000002 | 554 | Table_map | 1 | 599 | table_id: 112 (hist.t1) | | mysql-bin.000002 | 599 | Write_rows | 1 | 649 | table_id: 112 flags: STMT_END_F | | mysql-bin.000002 | 649 | Xid | 1 | 680 | COMMIT /* xid=40 */ | +------------------+-----+----------------+-----------+-------------+--------------------------------------+ 5 rows in set (0.00 sec)

    5、查询mysql-bin.000002文件,从pos点219开始查询,查询5条记录

    mysql> show binlog events in 'mysql-bin.000002' from 219 limit 5; +------------------+-----+----------------+-----------+-------------+--------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+--------------------------------------+ | mysql-bin.000002 | 219 | Query | 1 | 291 | BEGIN | | mysql-bin.000002 | 291 | Table_map | 1 | 336 | table_id: 112 (hist.t1) | | mysql-bin.000002 | 336 | Write_rows | 1 | 386 | table_id: 112 flags: STMT_END_F | | mysql-bin.000002 | 386 | Xid | 1 | 417 | COMMIT /* xid=39 */ | | mysql-bin.000002 | 417 | Anonymous_Gtid | 1 | 482 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | +------------------+-----+----------------+-----------+-------------+--------------------------------------+ 5 rows in set (0.00 sec)

    6、查询mysql-bin.000002文件,从pos点219开始查询,查询5条记录,偏移2行

    mysql> show binlog events in 'mysql-bin.000002' from 219 limit 2,5; +------------------+-----+----------------+-----------+-------------+--------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+--------------------------------------+ | mysql-bin.000002 | 336 | Write_rows | 1 | 386 | table_id: 112 flags: STMT_END_F | | mysql-bin.000002 | 386 | Xid | 1 | 417 | COMMIT /* xid=39 */ | | mysql-bin.000002 | 417 | Anonymous_Gtid | 1 | 482 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000002 | 482 | Query | 1 | 554 | BEGIN | | mysql-bin.000002 | 554 | Table_map | 1 | 599 | table_id: 112 (hist.t1) | +------------------+-----+----------------+-----------+-------------+--------------------------------------+ 5 rows in set (0.00 sec)

    二、binlog管理事件

    使用show binlog events命令查询到的每一行数据就是一个binlog管理事件。当使用mysqlbinlog查看日志信息时,每两个【at 数字】之间的信息就对应一个管理事件。

    mysql> show binlog events in '/var/lib/mysql/mysql-bin.000002'; +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | mysql-bin.000002 | 4 | Format_desc | 2 | 123 | Server ver: 5.7.27-log, Binlog ver: 4 | | mysql-bin.000002 | 123 | Previous_gtids | 2 | 154 | | | mysql-bin.000002 | 154 | Anonymous_Gtid | 2 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000002 | 219 | Query | 2 | 298 | BEGIN | | mysql-bin.000002 | 298 | Query | 2 | 397 | use `hist`; update t2 set id=id+10000 | | mysql-bin.000002 | 397 | Xid | 2 | 428 | COMMIT /* xid=11 */ | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ 6 rows in set (0.00 sec)

    1、每一个管理事件对应的信息说明

    (1)Log_name:当前事件所在的binlog文件名称; (2)Pos:当前事件的开始位置,每个事件都占用固定的字节大小,结束位置(End_log_position)减去Pos,就是这个事件占用的字节数。第一个事件位置并不是从0开始,而是从4。Mysql通过文件中的前4个字节,来判断这是不是一个binlog文件。这种方式很常见,很多格式的文件,如pdf、doc、jpg等,都会通常前几个特定字符判断是否是合法文件。 (3)Event_type:表示事件的类型; (4)Server_id:表示产生这个事件的mysql server_id,通过设置my.cnf中的server-id选项进行配置; (5)End_log_position:下一个事件的开始位置; (6)Info:当前事件的描述信息。

    2、Statement模式下的事件说明

    以下是一个Statement日志格式的管理事件信息:

    mysql> show binlog events in '/var/lib/mysql/mysql-bin.000001'; +------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+ | mysql-bin.000001 | 4 | Format_desc | 2 | 123 | Server ver: 5.7.27-log, Binlog ver: 4 | | mysql-bin.000001 | 123 | Previous_gtids | 2 | 154 | | | mysql-bin.000001 | 154 | Anonymous_Gtid | 2 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 219 | Query | 2 | 298 | BEGIN | | mysql-bin.000001 | 298 | Intvar | 2 | 330 | INSERT_ID=2 | | mysql-bin.000001 | 330 | Query | 2 | 456 | use `hist`; insert into t2(name) values('zhang'),('wang'),('li') | | mysql-bin.000001 | 456 | Xid | 2 | 487 | COMMIT /* xid=31 */ | | mysql-bin.000001 | 487 | Anonymous_Gtid | 2 | 552 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 552 | Query | 2 | 631 | BEGIN | | mysql-bin.000001 | 631 | Intvar | 2 | 663 | INSERT_ID=5 | | mysql-bin.000001 | 663 | Query | 2 | 789 | use `hist`; insert into t2(name) values('jack'),('tom'),('rose') | | mysql-bin.000001 | 789 | Xid | 2 | 820 | COMMIT /* xid=32 */ | | mysql-bin.000001 | 820 | Anonymous_Gtid | 2 | 885 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 885 | Query | 2 | 964 | BEGIN | | mysql-bin.000001 | 964 | Query | 2 | 1063 | use `hist`; update t2 set id=id+10000 | | mysql-bin.000001 | 1063 | Xid | 2 | 1094 | COMMIT /* xid=33 */ | | mysql-bin.000001 | 1094 | Anonymous_Gtid | 2 | 1159 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 1159 | Query | 2 | 1250 | create database wgx | | mysql-bin.000001 | 1250 | Anonymous_Gtid | 2 | 1315 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 1315 | Query | 2 | 1451 | use `wgx`; create table t1(id int primary key auto_increment,name char(20)) | | mysql-bin.000001 | 1451 | Anonymous_Gtid | 2 | 1516 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 1516 | Query | 2 | 1593 | BEGIN | | mysql-bin.000001 | 1593 | Intvar | 2 | 1625 | INSERT_ID=1 | | mysql-bin.000001 | 1625 | Query | 2 | 1741 | use `wgx`; insert into t1(name) values('zhang'),('tom') | | mysql-bin.000001 | 1741 | Xid | 2 | 1772 | COMMIT /* xid=44 */ | | mysql-bin.000001 | 1772 | Stop | 2 | 1795 | | +------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+ 26 rows in set (0.01 sec)

    说明:

    (1)每个binlog文件总是以Format Description Event作为开始,以Rotate Event(Stop Event)作为结束。在开始和结束之间,穿插着其他各种事件。

    (2)每个事务都是以Query Event作为开始,其INFO列内容为BEGIN,以Xid Event表示结束,其INFO列内容为COMMIT。即使对于单条更新SQL我们没有开启事务,Mysql也会默认的帮我们开启事务。

    (3)Intvar Event事件:如果主键是自增(AUTO_INCREMENT)列,MySQL首先会自增一个值,这就是Intvar Event的作用。需要注意的是,该事件,只会在Statement模式下出现。

    (4)Query Event:记录的就是插入的SQL。这也体现了Statement模式的作用,就是记录执行的SQL。

    (5)Stop Event:表示日志文件的结束。

    2、Row模式下的事件说明

    以下是一个Row日志格式的管理事件信息:

    mysql> show binlog events; +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ | mysql-bin.000001 | 4 | Format_desc | 1 | 123 | Server ver: 5.7.27-log, Binlog ver: 4 | | mysql-bin.000001 | 123 | Previous_gtids | 1 | 154 | | | mysql-bin.000001 | 154 | Anonymous_Gtid | 1 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 219 | Query | 1 | 291 | BEGIN | | mysql-bin.000001 | 291 | Table_map | 1 | 339 | table_id: 113 (hist.t2) | | mysql-bin.000001 | 339 | Write_rows | 1 | 413 | table_id: 113 flags: STMT_END_F | | mysql-bin.000001 | 413 | Xid | 1 | 444 | COMMIT /* xid=16 */ | | mysql-bin.000001 | 444 | Anonymous_Gtid | 1 | 509 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000001 | 509 | Query | 1 | 581 | BEGIN | | mysql-bin.000001 | 581 | Table_map | 1 | 629 | table_id: 113 (hist.t2) | | mysql-bin.000001 | 629 | Update_rows | 1 | 845 | table_id: 113 flags: STMT_END_F | | mysql-bin.000001 | 845 | Xid | 1 | 876 | COMMIT /* xid=17 */ | | mysql-bin.000001 | 876 | Rotate | 1 | 923 | mysql-bin.000002;pos=4 | +------------------+-----+----------------+-----------+-------------+---------------------------------------+ 13 rows in set (0.00 sec)

    说明:

    (1)每个binlog文件总是以Format Description Event作为开始,以Rotate Event(Stop Event)作为结束。在开始和结束之间,穿插着其他各种事件。

    (2)TABLE_MAP EVENT:其作用是记录INSERT、DELETE、UPDATE操作的表结构。

    (3)Write_rows:插入记录。

    (4)Update_rows:更新记录。

    (5)Rotate Event:表示日志文件的结束。

    三、binlog日志的优化

    1、binlog_row_image参数

    在ROW模式下,即使我们只更新了一条记录的其中某个字段,也会记录每个字段变更前后的值,binlog日志就会变大,带来磁盘IO上的开销,以及网络开销。这个行为可以通过binlog_row_image参数控制,该参数的取值如下: FULL(默认值):记录列的所有修改,即使字段没有发生变更也会记录。 MINIMAL:只记录修改的列。 NOBLOB:如果是text类型或clob字段,不记录这些日志。

    (1)binlog_row_image参数为FULL的binlog日志信息

    [root@Mysql11 ~]# mysqlbinlog -v /var/lib/mysql/mysql-bin.000004 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; ............. '/*!*/; ### UPDATE `hist`.`stu` ### WHERE ### @1=3 ### @2='jack' ### @3=20 ### @4='Zhengzhou' ### @5='13675871454' ### @6=1 ### SET ### @1=3 ### @2='jack' ### @3=21 ### @4='Zhengzhou' ### @5='13675871454' ### @6=1 # at 464 #200704 11:04:54 server id 1 end_log_pos 495 CRC32 0xc311dbb6 Xid = 18 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*/;

    (2)binlog_row_image参数为MINIMAL的binlog日志信息

    [root@Mysql11 ~]# mysqlbinlog -v /var/lib/mysql/mysql-bin.000007 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; .............. '/*!*/; ### UPDATE `hist`.`stu` ### WHERE ### @1=1 ### SET ### @3=21 # at 394 #200704 11:14:45 server id 1 end_log_pos 425 CRC32 0x54f07b19 Xid = 17 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*/;

    3、在Row模式下记录sql语句

    在Statement模式下,直接记录SQL比较直观。在Row模式下,使用binlog_rows_query_log_events参数也可以记录SQL。参数的默认为值为FALSE,如果为true的情况下,会通过Rows Query Event来记录SQL。

    在my.cnf中添加以下配置,来开启row模式下的SQL记录:

    binlog-rows-query-log_events=1

    结果如下:

    mysql> show binlog events in '/var/lib/mysql/mysql-bin.000009'; +------------------+------+----------------+-----------+-------------+-------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+------+----------------+-----------+-------------+-------------------------------------------+ | mysql-bin.000009 | 4 | Format_desc | 1 | 123 | Server ver: 5.7.27-log, Binlog ver: 4 | | mysql-bin.000009 | 123 | Previous_gtids | 1 | 154 | | | mysql-bin.000009 | 154 | Anonymous_Gtid | 1 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000009 | 219 | Query | 1 | 291 | BEGIN | | mysql-bin.000009 | 291 | Rows_query | 1 | 354 | # insert into t2(name) values('zhangfei') | | mysql-bin.000009 | 354 | Table_map | 1 | 402 | table_id: 113 (hist.t2) | | mysql-bin.000009 | 402 | Write_rows | 1 | 451 | table_id: 113 flags: STMT_END_F | | mysql-bin.000009 | 451 | Xid | 1 | 482 | COMMIT /* xid=17 */ | | mysql-bin.000009 | 482 | Anonymous_Gtid | 1 | 547 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000009 | 547 | Query | 1 | 619 | BEGIN | | mysql-bin.000009 | 619 | Rows_query | 1 | 666 | # update t2 set id=id+100 | | mysql-bin.000009 | 666 | Table_map | 1 | 714 | table_id: 113 (hist.t2) | | mysql-bin.000009 | 714 | Update_rows | 1 | 850 | table_id: 113 flags: STMT_END_F | | mysql-bin.000009 | 850 | Xid | 1 | 881 | COMMIT /* xid=18 */ | | mysql-bin.000009 | 881 | Anonymous_Gtid | 1 | 946 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000009 | 946 | Query | 1 | 1018 | BEGIN | | mysql-bin.000009 | 1018 | Rows_query | 1 | 1069 | # delete from t2 where id=201 | | mysql-bin.000009 | 1069 | Table_map | 1 | 1117 | table_id: 113 (hist.t2) | | mysql-bin.000009 | 1117 | Delete_rows | 1 | 1157 | table_id: 113 flags: STMT_END_F | | mysql-bin.000009 | 1157 | Xid | 1 | 1188 | COMMIT /* xid=34 */ | +------------------+------+----------------+-----------+-------------+-------------------------------------------+ 20 rows in set (0.00 sec)
    Processed: 0.013, SQL: 9