程式師世界 >> 數據庫知識 >> MYSQL數據庫 >> MySQL綜合教程 >> 淺析MySQL二進制日志，淺析mysql二進制

淺析MySQL二進制日志，淺析mysql二進制

編輯：MySQL綜合教程

淺析MySQL二進制日志，淺析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 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.

參考

1. MariaDB原理與實現

2. MySQL 5.7 Reference Manual