MySQLbinlog日志04binlog日志字节码解析之二Write_Rows事件
本系列博客主要介绍mysql数据库的binlog日志的相关内容，这个系列的主题包括：
mysqlbinlog日志04binlog日志字节码解析之二write_rows事件
本篇博客是第1篇，主要介绍binlog日志基本操作。内容包括：
binlog日志的作用
binlog日志相关的配置参数
binlog相关的sql语句
binlog日志内容查看
以下是本博客的正文：
binlog日志的作用
binlog日志记录了一段时间内数据库上的所有写数据操作的完整数据。因此在数据不一致或者误操作删除数据后，可以用于某个时间段或者某个binlog位置范围内的操作数据的恢复工作。
binlog日志的另外一个工作能用于mysql主从复制体系。主机上产生binlog日志数据，并且发送到从机上。从机上的io线程接收到事件数据后保存到本地的relay event日志中，从机的sql线程随后将这些relay event日志中的事件数据在从机上执行，从而达到主从一致的状态。
binlog日志相关的配置参数
比较重要的几个参数：
log_bin=mysql_binlog
binlog日志文件的文件名前缀
sync_binlog=1
执行多个事务后同步binlog日志文件。
0：不同步，仅仅写入binlog缓存。
1：1个事务后同步。
n(n>1)：n个事务后同步。
max_binlog_size=10m
一个binlog日志文件的最大大小。 最小值为4096字节。
binlog_format=row
binlog事件的格式。
row：记录行数据，默认不记录用户sql，对于ddl语句，仍然记录sql。
statement：记录用户sql语句。当执行一些函数时导致复制机制产生问题，数据不一致。
mixed：主要记录sql语句，当用到了特定的函数时记录行数据。
在row模式下，如果delete语句实际没有删除任何记录，则不会记录到binlog日志中。
对于一个update语句修改了多条记录，则每一条记录会作为一个binlog事件记录到binlog日志中。
binlog_row_image=full
记录行数据(row模式)时，是否记录没有使用到的字段的值。
full：记录所有字段，包括没有使用的字段。
minimal：只记录被更改的字段和能够唯一识别记录的字段的值。
noblob：基本跟full相同，但是没有使用到的text和blob字段除外。
binlog_rows_query_log_events=1
是否记录用户的原始sql，用于row模式。
0：不记录。
1：记录。
全部的参数如下所示：
mysql> show variables like '%binlog%'
-> ;
+--------------------------------------------+----------------------+
| variable_name | value |
+--------------------------------------------+----------------------+
| binlog_cache_size | 32768 |
| binlog_checksum | crc32 |
| binlog_direct_non_transactional_updates | off |
| binlog_error_action | abort_server |
| binlog_format | row |
| binlog_group_commit_sync_delay | 0 |
| binlog_group_commit_sync_no_delay_count | 0 |
| binlog_gtid_simple_recovery | on |
| binlog_max_flush_queue_time | 0 |
| binlog_order_commits | on |
| binlog_row_image | full |
| binlog_rows_query_log_events | on |
| binlog_stmt_cache_size | 32768 |
| binlog_transaction_dependency_history_size | 25000 |
| binlog_transaction_dependency_tracking | commit_order |
| innodb_api_enable_binlog | off |
| innodb_locks_unsafe_for_binlog | off |
| log_statements_unsafe_for_binlog | on |
| max_binlog_cache_size | 18446744073709547520 |
| max_binlog_size | 10485760 |
| max_binlog_stmt_cache_size | 18446744073709547520 |
| sync_binlog | 1 |
+--------------------------------------------+----------------------+
22 rows in set (0.01 sec)
binlog相关的sql语句
清除全部的binlog文件。
o reset master
deletes all binary logs listed in the index file, resets the binary
log index file to be empty, and creates a new binary log file.
mysql> reset master;
query ok, 0 rows affected (0.01 sec)
查看当前全部binlog文件的名字和大小。
mysql> show binary logs;
+---------------------+-----------+
| log_name | file_size |
+---------------------+-----------+
| mysql_binlog.000001 | 154 |
+---------------------+-----------+
1 row in set (0.00 sec)
file_size列出的就是binlog文件的字节数大小。
[root@101 data]# ls -l mysql_binlog.*
-rw-r-----. 1 mysql mysql 154 sep 20 20:46 mysql_binlog.000001
-rw-r-----. 1 mysql mysql 22 sep 20 20:46 mysql_binlog.index
查看binlog的最新位置，也是154，就是这个位置(position)实际上是文件的字节偏移量。
mysql> help show master status
name: 'show master status'
description:
syntax:
show master status
this statement provides status information about the binary log files
of the master. it requires either the super or replication client
privilege.
mysql> show master status;
+---------------------+----------+--------------+------------------+-------------------+
| file | position | binlog_do_db | binlog_ignore_db | executed_gtid_set |
+---------------------+----------+--------------+------------------+-------------------+
| mysql_binlog.000001 | 154 | | | |
+---------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
mysql> show binlog events in 'mysql_binlog.000001';
+---------------------+-----+----------------+-----------+-------------+---------------------------------------+
| log_name | pos | event_type | server_id | end_log_pos | info |
+---------------------+-----+----------------+-----------+-------------+---------------------------------------+
| mysql_binlog.000001 | 4 | format_desc | 101 | 123 | server ver: 5.7.22-log, binlog ver: 4 |
| mysql_binlog.000001 | 123 | previous_gtids | 101 | 154 | |
+---------------------+-----+----------------+-----------+-------------+---------------------------------------+
2 rows in set (0.00 sec)
刷新binlog文件，即新建立一个binlog日志文件。
mysql> show binary logs;
+---------------------+-----------+
| log_name | file_size |
+---------------------+-----------+
| mysql_binlog.000001 | 154 |
+---------------------+-----------+
1 row in set (0.00 sec)
mysql> flush binary logs;
query ok, 0 rows affected (0.00 sec)
mysql> flush binary logs;
query ok, 0 rows affected (0.00 sec)
mysql> show binary logs;
+---------------------+-----------+
| log_name | file_size |
+---------------------+-----------+
| mysql_binlog.000001 | 204 |
| mysql_binlog.000002 | 204 |
| mysql_binlog.000003 | 154 |
+---------------------+-----------+
3 rows in set (0.00 sec)
flush logs, flush tables with read , flush tables for export这些命令不会写binlog日志，因为如果写了binlog，可能会在主从复制时产生问题。
flush logs, flush tables with read lock (with or without a table list),
and flush tables tbl_name ... for export are not written to the binary
log in any case because they would cause problems if replicated to a
slave.
show binlog events 语句用于查看指定的binlog日志文件中记录的binlog事件。
binlog日志内容查看
假定目前binlog_format=row。
先用flush logs创建一个新的binlog文件。
mysql> flush logs;
query ok, 0 rows affected (0.01 sec)
mysql> show master status;
+---------------------+----------+--------------+------------------+-------------------+
| file | position | binlog_do_db | binlog_ignore_db | executed_gtid_set |
+---------------------+----------+--------------+------------------+-------------------+
| mysql_binlog.000046 | 154 | | | |
+---------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
使用mysqlbinlog程序查看文件内容，decode-rows选项表示解析原始输出信息中的base64数据块为sql语句，否则将看到base64数据块。
[root@101 data]# mysqlbinlog -v --base64-output=decode-rows mysql_binlog.000046
/*!50530 set @@session.pseudo_slave_mode=1*/;
/*!50003 set @old_completion_type=@@completion_type,completion_type=0*/;
delimiter /*!*/;
# at 4
#180920 0:09:37 server id 101 end_log_pos 123 crc32 0xc5c14f6f start: binlog v 4, server v 5.7.22-log created 180920 0:09:37
# warning: this binlog is either in use or was not closed properly.
# at 123
#180920 0:09:37 server id 101 end_log_pos 154 crc32 0xa91b6a91 previous-gtids
# [empty]
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输出中的注释语句，使得输出的日志信息更容易观察。
root@101 data]# mysqlbinlog -v --base64-output=decode-rows mysql_binlog.000046 |grep -e -v "^\/\*"
delimiter /*!*/;
# at 4
#180920 0:09:37 server id 101 end_log_pos 123 crc32 0xc5c14f6f start: binlog v 4, server v 5.7.22-log created 180920 0:09:37
# warning: this binlog is either in use or was not closed properly.
# at 123
#180920 0:09:37 server id 101 end_log_pos 154 crc32 0xa91b6a91 previous-gtids
# [empty]
set @@session.gtid_next= 'automatic' /* added by mysqlbinlog */ /*!*/;
delimiter ;
# end of log file
mysql_binlog.000046文件的日志从position=4的位置开始，到end_log_pos=154结束，这个文件是mysql当前产生的最新的一个binlog文件，end_log_pos与show master status的输出信息的position的值相同。由此可见，show master status输出的position是最新的binlog文件的末尾位置。
在搭建主从复制架构时，从机的change master to语句中的master_log_position=xxxxx，这个xxxxx值不能简单的赋值为show master status的position值。应该考虑实际情况再决定使用什么数值。
如果从机是按照主机的最新的备份制作的数据库，那么可以使用show master status的position值,此时master_log_file也应该是这里输出的file的值。
如果从机不是按照最新的备份制作的数据库，那么需要仔细分析后根据位置信息和文件信息以及具体时间点进行设置。
执行一个sql语句。
mysql> show master status;
+---------------------+----------+--------------+------------------+-------------------+
| file | position | binlog_do_db | binlog_ignore_db | executed_gtid_set |
+---------------------+----------+--------------+------------------+-------------------+
| mysql_binlog.000046 | 154 | | | |
+---------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
mysql> insert into t2 (name) values ('a1'),('b1');
query ok, 2 rows affected (0.01 sec)
records: 2 duplicates: 0 warnings: 0
mysql> show master status;
+---------------------+----------+--------------+------------------+-------------------+
| file | position | binlog_do_db | binlog_ignore_db | executed_gtid_set |
+---------------------+----------+--------------+------------------+-------------------+
| mysql_binlog.000046 | 421 | | | |
+---------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
binlog position从154变成了421。
查看新的binlog日志：
root@101 data]# mysqlbinlog -v --base64-output=decode-rows mysql_binlog.000046 |grep -e -v "^\/\*"
delimiter /*!*/;
# at 4
#180920 0:09:37 server id 101 end_log_pos 123 crc32 0xc5c14f6f start: binlog v 4, server v 5.7.22-log created 180920 0:09:37
# warning: this binlog is either in use or was not closed properly.
# at 123
#180920 0:09:37 server id 101 end_log_pos 154 crc32 0xa91b6a91 previous-gtids
# [empty]
# at 154
#180920 0:23:30 server id 101 end_log_pos 219 crc32 0xc8b9a40f anonymous_gtidlast_committed=0 sequence_number=1 rbr_only=yes
set @@session.gtid_next= 'anonymous'/*!*/;
# at 219
#180920 0:23:30 server id 101 end_log_pos 291 crc32 0xb2d919c9 query thread_id=2 exec_time=0 error_code=0
set timestamp=1537374210/*!*/;
set @@session.pseudo_thread_id=2/*!*/;
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/*!*/;
set @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
set @@session.lc_time_names=0/*!*/;
set @@session.collation_database=default/*!*/;
begin
# at 291
#180920 0:23:30 server id 101 end_log_pos 339 crc32 0x097d51d0 table_map: `test`.`t2` mapped to number 110
# at 339
#180920 0:23:30 server id 101 end_log_pos 390 crc32 0x025373f6 write_rows: table id 110 flags: stmt_end_f
### insert into `test`.`t2`
### set
### @1=1
### @2='a1'
### insert into `test`.`t2`
### set
### @1=2
### @2='b1'
# at 390
#180920 0:23:30 server id 101 end_log_pos 421 crc32 0x077fb982 xid = 26
commit/*!*/;
set @@session.gtid_next= 'automatic' /* added by mysqlbinlog */ /*!*/;
delimiter ;
# end of log file
在position=339的地方写入一个事务的2条新记录，然后执行了提交操作，end_log_pos=421。
执行2条update语句：
mysql> update t2 set name='aaaa1' where id=1;
query ok, 1 row affected (0.01 sec)
rows matched: 1 changed: 1 warnings: 0
mysql> update t2 set name='aaaa2' where id=2;
query ok, 1 row affected (0.01 sec)
rows matched: 1 changed: 1 warnings: 0
继续查看binlog日志信息，使用--start-position选项指定从position=421(之前的binlog日志前面已经查看过了）开始查看binlog日志。
[root@101 data]# mysqlbinlog --start-position=421 -v --base64-output=decode-rows mysql_binlog.000046 |grep -e -v "^\/\*"
delimiter /*!*/;
# at 421
#180920 0:30:38 server id 101 end_log_pos 486 crc32 0x45344b55 anonymous_gtidlast_committed=1 sequence_number=2 rbr_only=yes
set @@session.gtid_next= 'anonymous'/*!*/;
# at 486
#180920 0:30:38 server id 101 end_log_pos 558 crc32 0xdb968326 query thread_id=2 exec_time=0 error_code=0
set timestamp=1537374638/*!*/;
set @@session.pseudo_thread_id=2/*!*/;
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/*!*/;
set @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
set @@session.lc_time_names=0/*!*/;
set @@session.collation_database=default/*!*/;
begin
# at 558
#180920 0:30:38 server id 101 end_log_pos 606 crc32 0xe179cc2d table_map: `test`.`t2` mapped to number 110
# at 606
#180920 0:30:38 server id 101 end_log_pos 661 crc32 0x26f63b69 update_rows: table id 110 flags: stmt_end_f
### update `test`.`t2`
### where
### @1=1
### @2='a1'
### set
### @1=1
### @2='aaaa1'
# at 661
#180920 0:30:38 server id 101 end_log_pos 692 crc32 0x2dcc1cd6 xid = 29
commit/*!*/;
# at 692
#180920 0:30:53 server id 101 end_log_pos 757 crc32 0x07b40b05 anonymous_gtidlast_committed=2 sequence_number=3 rbr_only=yes
set @@session.gtid_next= 'anonymous'/*!*/;
# at 757
#180920 0:30:53 server id 101 end_log_pos 829 crc32 0xbbb5f160 query thread_id=2 exec_time=0 error_code=0
set timestamp=1537374653/*!*/;
begin
# at 829
#180920 0:30:53 server id 101 end_log_pos 877 crc32 0x96ab4362 table_map: `test`.`t2` mapped to number 110
# at 877
#180920 0:30:53 server id 101 end_log_pos 932 crc32 0x9b9c8a78 update_rows: table id 110 flags: stmt_end_f
### update `test`.`t2`
### where
### @1=2
### @2='b1'
### set
### @1=2
### @2='aaaa2'
# at 932
#180920 0:30:53 server id 101 end_log_pos 963 crc32 0x1c975da3 xid = 30
commit/*!*/;
set @@session.gtid_next= 'automatic' /* added by mysqlbinlog */ /*!*/;
delimiter ;
# end of log file
mysqlbinlog程序输出的日志信息中，可以看到数据库中执行的写操作的sql语句的基本原型,不包含字段名称。字段名全部都使用@1,@2等代替了，这里@1表示第1个字段，@2表示第2个字段，依次类推。由于这些sql中已经包含了表名，可以很容易取到字段的顺序以及名称。因此，可以根据这些sql语句还原出真实的包含了字段名的sql语句。
mysql> desc t2;
+-------+--------------+------+-----+---------+----------------+
| field | type | null | key | default | extra |
+-------+--------------+------+-----+---------+----------------+
| id | int(11) | no | pri | null | auto_increment |
| name | varchar(100) | no | | null | |
+-------+--------------+------+-----+---------+----------------+
2 rows in set (0.00 sec)
### update `test`.`t2`
### where
### @1=2
### @2='b1'
### set
### @1=2
### @2='aaaa2'
这个语句中的@1就是id，@2就是name。
-v参数的效果：
### insert into `test`.`t2`
### set
### @1=3
### @2='3'
### @3=0
### @4=null
当使用-vv参数时，将包含每个字段的详细元数据信息。
### insert into `test`.`t2`
### set
### @1=3 /* int meta=0 nullable=0 is_null=0 */
### @2='3' /* varstring(100) meta=100 nullable=0 is_null=0 */
### @3=0 /* int meta=0 nullable=0 is_null=0 */
### @4=null /* int meta=0 nullable=1 is_null=1 */
在使用-vv参数，同时配置参数binlog_rows_query_log_events=1的效果：
binlog中将会包含用户执行的原始sql语句。
# at 291
#180920 6:56:10 server id 101 end_log_pos 355 crc32 0x24cd5468 rows_query
# insert into t2 (name) values ('3'),('4')
# at 355
#180920 6:56:10 server id 101 end_log_pos 405 crc32 0x6d5e9163 table_map: `test`.`t2` mapped to number 108
# at 405
#180920 6:56:10 server id 101 end_log_pos 462 crc32 0x3d3d565b write_rows: table id 108 flags: stmt_end_f
### insert into `test`.`t2`
### set
### @1=3 /* int meta=0 nullable=0 is_null=0 */
### @2='3' /* varstring(100) meta=100 nullable=0 is_null=0 */
### @3=0 /* int meta=0 nullable=0 is_null=0 */
### @4=null /* int meta=0 nullable=1 is_null=1 */
### insert into `test`.`t2`
### set
### @1=4 /* int meta=0 nullable=0 is_null=0 */
### @2='4' /* varstring(100) meta=100 nullable=0 is_null=0 */
### @3=0 /* int meta=0 nullable=0 is_null=0 */
### @4=null /* int meta=0 nullable=1 is_null=1 */
上一篇： CDR X8快速绘制漂亮的八瓣花