你的位置:首页 > 数据库

[数据库]浅析MySQL二进制日志


查看MySQL二进制文件中的内容有两种方式

1.  mysqlbinlog

2.  SHOW BINLOG EVENTS [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count]

 

下面来测试一下,在mysql中执行如下操作

mysql> flush logs;Query OK, 0 rows affected (0.01 sec)mysql> insert into test.t1 values(1,'a');Query OK, 1 row affected (0.00 sec)mysql> use testReading table information for completion of table and column namesYou can turn off this feature to get a quicker startup with -ADatabase changedmysql> insert into test.t1 values(2,'b');Query OK, 1 row affected (0.00 sec)mysql> show master status;+------------------+----------+--------------+------------------+-------------------+| File       | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |+------------------+----------+--------------+------------------+-------------------+| mysql-bin.000021 |   546 |       |         |          |+------------------+----------+--------------+------------------+-------------------+1 row in set (0.00 sec)

 

对应二进制日志中的内容如下

通过mysqlbinlog查看

# mysqlbinlog mysql-bin.000021

/*!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#160817 4:53:02 server id 1 end_log_pos 120 CRC32 0xf9bbe803 Start: binlog v 4, server v 5.6.31-log created 160817 4:53:02# Warning: this binlog is either in use or was not closed properly.BINLOG 'Ln2zVw8BAAAAdAAAAHgAAAABAAQANS42LjMxLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAQPou/k='/*!*/;
# at 120#160817 4:53:06 server id 1 end_log_pos 195 CRC32 0x0182ee55 Query thread_id=3 exec_time=0 error_code=0SET TIMESTAMP=1471380786/*!*/;SET @@session.pseudo_thread_id=3/*!*/;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.lc_time_names=0/*!*/;SET @@session.collation_database=DEFAULT/*!*/;BEGIN/*!*/;
# at 195#160817 4:53:06 server id 1 end_log_pos 298 CRC32 0xf9049380 Query thread_id=3 exec_time=0 error_code=0SET TIMESTAMP=1471380786/*!*/;insert into test.t1 values(1,'a')/*!*/;
# at 298#160817 4:53:06 server id 1 end_log_pos 329 CRC32 0xdb58b5b4 Xid = 25COMMIT/*!*/;
# at 329#160817 4:53:15 server id 1 end_log_pos 408 CRC32 0xcc370a55 Query thread_id=3 exec_time=0 error_code=0SET TIMESTAMP=1471380795/*!*/;BEGIN/*!*/;
# at 408#160817 4:53:15 server id 1 end_log_pos 515 CRC32 0x4fa06a6e Query thread_id=3 exec_time=0 error_code=0use `test`/*!*/;SET TIMESTAMP=1471380795/*!*/;insert into test.t1 values(2,'b')/*!*/;
# at 515#160817 4:53:15 server id 1 end_log_pos 546 CRC32 0x5f51e8bd Xid = 33COMMIT/*!*/;
DELIMITER ;# End of log fileROLLBACK /* added by mysqlbinlog */;/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

 

解析如下:

1. at xxx,不仅仅是事件开始的位置,同样是二进制日志的物理大小

    譬如上述日志中,结束位置是end_log_pos 546,则二进制日志的大小也是546.

# ll mysql-bin.000021-rw-rw---- 1 mysql mysql 546 Aug 17 04:53 mysql-bin.000021

 

2. at 4,对应的事件类型是FORMAT_DESCRIPTION_EVENT,是所有binlog文件中的第一个事件,在一个binlog中仅出现一次,MySQL会根据FORMAT_DESCRIPTION_EVENT事件的定义来解析binlog中的其它事件。该事件类型定义了binlog版本,MySQL Server的版本,binlog的创建时间等。

 

3. at 120,是第一个事务开始的偏移量,对应的事件类型是QUERY_EVENT,实际上也只执行了一个BEGIN操作。

 

4. 下面来截取一个事件来看看

# at 195#160817 4:53:06 server id 1 end_log_pos 298 CRC32 0xf9049380   Query  thread_id=3  exec_time=0  error_code=0SET TIMESTAMP=1471380786/*!*/;insert into test.t1 values(1,'a')/*!*/;

   该事件对应的事件类型是QUERY_EVENT

   QUERY_EVENT类型的事件通常在以下几种情况下使用。

   1> 事务开始时的BEGIN操作

   2> 对于STATEMENT格式的DML操作

   3> 对于ROW格式的DDL操作。

   该事件会指明slave_proxy_id(会话的线程id),execution time(查询从开始执行到记录到binlog所花的时间,单位为秒),error-code(错误码),status-vars(status-vars是以键值对的形式保存起来的一系列由SET命令设置的上下文信息,譬如当前的时间戳),schema(当前选择的数据库),query(原生的DML语句,譬如insert into test.t1 values(1,'a'))

 

5. 同样是insert操作,一个没有切换schema,直接执行insert into test.t1 values(1,'a'),一个是先use test,再执行insert操作,反映在binlog中的内容也不一样,实际上,这会影响基于库的部分复制的判断逻辑。

 

6. 在执行基于binlog的部分恢复时,截止的时间点应该是commit操作的end_log_pos,而不是commit操作之前的的at xxx。

    譬如,针对上面的commit操作

# at 515#160817 4:53:15 server id 1 end_log_pos 546 CRC32 0x5f51e8bd   Xid = 33COMMIT/*!*/;

    如果要执行第二个insert语句,则--stop-position=546,而不是515。

 

7. 在用mysqlbinlog查看binlog后都会带上ROLLBACK操作,这个在执行基于binlog的部分恢复时,会有用处。

    # mysqlbinlog --stop-position=515 mysql-bin.000021

....# at 408#160817 4:53:15 server id 1 end_log_pos 515 CRC32 0x4fa06a6e   Query  thread_id=3  exec_time=0  error_code=0use `test`/*!*/;SET TIMESTAMP=1471380795/*!*/;insert into test.t1 values(2,'b')/*!*/;DELIMITER ;# End of log fileROLLBACK /* added by mysqlbinlog */;/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

   我只应用到binlog偏移量为515的位置,这个时候只有insert操作,而没有针对该操作的commit,所以mysqlbinlog会显式增加一个rollback操作,直接回滚事务。

 

通过SHOW BINLOG EVENTS查看

通过这种方式查看还是蛮直观的

mysql> show binlog events in 'mysql-bin.000021';+------------------+-----+-------------+-----------+-------------+-----------------------------------------------+| Log_name     | Pos | Event_type | Server_id | End_log_pos | Info                     |+------------------+-----+-------------+-----------+-------------+-----------------------------------------------+| mysql-bin.000021 |  4 | Format_desc |     1 |     120 | Server ver: 5.6.31-log, Binlog ver: 4     || mysql-bin.000021 | 120 | Query    |     1 |     195 | BEGIN                     || mysql-bin.000021 | 195 | Query    |     1 |     298 | insert into test.t1 values(1,'a')       || mysql-bin.000021 | 298 | Xid     |     1 |     329 | COMMIT /* xid=25 */              || mysql-bin.000021 | 329 | Query    |     1 |     408 | BEGIN                     || mysql-bin.000021 | 408 | Query    |     1 |     515 | use `test`; insert into test.t1 values(2,'b') || mysql-bin.000021 | 515 | Xid     |     1 |     546 | COMMIT /* xid=33 */              |+------------------+-----+-------------+-----------+-------------+-----------------------------------------------+7 rows in set (0.00 sec)

 

事务的操作是何时写入到binlog中的?

MySQL使用binlog_cache_mngr结构来缓存一个事务的所有操作,如果用户执行commit操作,则将binlog_cache_mngr中的内容写入到binlog中;如果用户执行rollback操作,则直接丢弃binlog_cache_mngr中的内容。否则的话,如果事务中的操作立刻写入到binlog中,那么在回滚时就相当麻烦。

当时有一点需要注意的是,对于非事务的存储引擎,所有的修改会立刻写入到binlog中。

譬如下面的测试中,t_myisam是myisam表,t1是innodb表,在两张表中分别插入一条记录,再执行回滚。

mysql> set autocommit=0;Query OK, 0 rows affected (0.05 sec)mysql> insert into t_myisam values(1,'a');Query OK, 1 row affected (0.07 sec)mysql> insert into t1 values(4,'d');Query OK, 1 row affected (0.06 sec)mysql> rollback;Query OK, 0 rows affected, 1 warning (0.00 sec)mysql> show warnings;+---------+------+---------------------------------------------------------------+| Level  | Code | Message                            |+---------+------+---------------------------------------------------------------+| Warning | 1196 | Some non-transactional changed tables couldn't be rolled back |+---------+------+---------------------------------------------------------------+

但通过查看binlog日志的内容,即便该事务回滚了,针对t_myisam表的操作还是写入到binlog中了

mysql> show binlog events in 'mysql-bin.000017';+------------------+-----+-------------+-----------+-------------+------------------------------------------------+| Log_name     | Pos | Event_type | Server_id | End_log_pos | Info                      |+------------------+-----+-------------+-----------+-------------+------------------------------------------------+| mysql-bin.000017 |  4 | Format_desc |     1 |     120 | Server ver: 5.6.31-log, Binlog ver: 4     || mysql-bin.000017 | 120 | Query    |     1 |     199 | BEGIN                     || mysql-bin.000017 | 199 | Query    |     1 |     307 | use `test`; insert into t_myisam values(1,'a') || mysql-bin.000017 | 307 | Query    |     1 |     387 | COMMIT                     |+------------------+-----+-------------+-----------+-------------+------------------------------------------------+4 rows in set (0.00 sec)

 

binlog的相关参数

max_binlog_size

指定binlog文件的大小,如果当前binlog文件的大小达到了参数指定的阀值,则会创建一个新的binlog文件。

注意:binlog文件的大小可能会超过max_binlog_size的值,因为一个事务所产生的所有事件都必须要记录在同一个binlog文件中,所以即使binlog文件的大小超过max_binlog_size的值,也会等到当前事务的所有操作全部写入到binlog文件中才能切换。

 

sql_log_bin

会话变量,设置sql_log_bin=0表示禁用当前会话的binlog功能。

 

sync_binlog

MySQL 5.7.7之前,默认为0,即binlog文件在每次写入内容后并不会立即持久化到磁盘中,具体的持久化操作交给操作系统去处理。如果操作系统崩溃,可能导致对binlog的修改丢失。

为了避免这种情况,可将sync_binlog设置为1,这样在每次事务提交时,该事务的操作写入到binlog后,都会调用fsync操作将binlog的修改同步到磁盘中。但这样会降低MySQL的性能,所以可将sync_binlog设置为N,代表N个事务后才执行一次fsync操作。

实际上,在引入binlog group commit后,上述持久化的单位并不是事务了,而是一组事务。

官档解释如下:

Controls the number of binary log commit groups to collect before synchronizing the binary log to disk. When sync_binlog=0, the binary log is never synchronized to disk, and when sync_binlog is set to a value greater than 0 this number of binary log commit groups is periodically synchronized to disk. When sync_binlog=1, all transactions are synchronized to the binary log before they are committed.

 

参考

1. MariaDB原理与实现

2. MySQL 5.7 Reference Manual