关于 MySQL二进制日志

共计 8014 个字符，预计需要花费 21 分钟才能阅读完成。

查看 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 test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> 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 'Ln2zVw8BAAAAdAAAAHgAAAABAAQANS42LjMxLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAQPo
u/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=0
SET 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=0
SET 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 = 25
COMMIT/*!*/;

# at 329
#160817  4:53:15 server id 1  end_log_pos 408 CRC32 0xcc370a55     Query    thread_id=3    exec_time=0    error_code=0
SET 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=0
use `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 = 33
COMMIT/*!*/;

DELIMITER ;
# End of log file
ROLLBACK /* 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=0
SET TIMESTAMP=1471380786/*!*/;
insert into test.t1 values(1,'a')
/*!*/;

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

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

1> 事务开始时的 BEGIN 操作

2> 对于 STATEMENT 格式的 DML 操作

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

该事件会指明 server_id，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 = 33
COMMIT/*!*/;

如果要执行第二个 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=0
use `test`/*!*/;
SET TIMESTAMP=1471380795/*!*/;
insert into test.t1 values(2,'b')
/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* 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.

本文永久更新链接地址 ：http://www.linuxidc.com/Linux/2016-08/134341.htm