当前位置: 移动技术网 > IT编程>数据库>Mysql > MySQLbinlog日志04binlog日志字节码解析之二Write_Rows事件

MySQLbinlog日志04binlog日志字节码解析之二Write_Rows事件

2018年09月24日  | 移动技术网IT编程  | 我要评论

 

本系列博客主要介绍mysql数据库的binlog日志的相关内容,这个系列的主题包括:

mysqlbinlog日志01binlog日志基本操作

mysqlbinlog日志02binlog日志用于数据恢复

mysqlbinlog日志03binlog日志字节码解析

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缓存。

11个事务后同步。

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相同,但是没有使用到的textblob字段除外。

 

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_posshow master status的输出信息的position的值相同。由此可见,show master status输出的position是最新的binlog文件的末尾位置。

 

在搭建主从复制架构时,从机的change master to语句中的master_log_position=xxxxx,这个xxxxx值不能简单的赋值为show master statusposition值。应该考虑实际情况再决定使用什么数值。

 

如果从机是按照主机的最新的备份制作的数据库,那么可以使用show master statusposition,此时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 position154变成了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

 

 

执行2update语句:

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 */

 

如对本文有疑问, 点击进行留言回复!!

相关文章:

验证码:
移动技术网