MySQL binlog 物理回溯最佳實戰
0x01 前言
在平時的遷移或者其他維護場景中，我們需要利用備份的物理 binlog 做回溯。本篇文章根據真實案例進行講解，如何優雅地利用 binlog 進行物理回溯。
0x02 測試
測試環境 IP 如下：
- 192.168.1.101（主）
- 192.168.1.102（從）
- 192.168.1.103（從）
測試步驟如下：
1、192.168.1.101 和 192.168.1.102 建立主從，192.168.1.101 創建 sbtest 庫，然后使用 sysbench 插入 100 萬測試數據，相關命令如下：
sysbench --test=oltp --oltp-table-size=1000000 --oltp-read-only=off --init-rng=on \ --num-threads=16 --max-requests=0 --oltp-dist-type=uniform --max-time=1800 \ --mysql-user=root --mysql-socket=/tmp/mysql.sock \ --mysql-password=xxxx --db-driver=mysql --mysql-table-engine=innodb \ --oltp-test-mode=complex prepare
2、在 192.168.1.102 導出數據，然后拷貝到 192.168.1.103，在 192.168.1.103 導入數據。備份文件的 MASTER_LOG_FILE 和 MASTER_LOG_POS 信息如下：
-- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000104', \ -- MASTER_LOG_POS=3661463;
3、在 192.168.1.101 使用如下腳本再次導入 10 萬數據。
!/bin/bash
for i in $(seq 1 100000) do mysql -uroot -p'xxxx' --socket=/tmp/mysql.sock -e \ "INSERT INTO sbtest.sbtest(k, c, pad) VALUES(0, '1', \ 'qqqqqqqqqqwwwwwwwwwweeeeeeeeeerrrrrrrrrrtttttttttt');"</pre>
4、192.168.1.101 模擬 binlog 被清除。先備份 binlog，然后再 PURGE。
mysql> SELECT COUNT() FROM sbtest; +----------+ | COUNT() | +----------+ | 1100000 | +----------+ 1 row in set (0.19 sec)mysql> PURGE BINARY LOGS TO 'mysql-bin.000106'; Query OK, 0 rows affected (0.03 sec)</pre>
5、192.168.1.102 停掉同步。
6、192.168.1.101 修改 mysql-bin.index 文件，把備份的 binlog 文件拷貝到 binlog 目錄，然后手動執行 FLUSH LOGS。
pwd /data/mysql/binlog cp -v /data/backup/mysql-bin.00010{4,5} .cat mysql-bin.index /data/mysql/binlog/mysql-bin.000104 /data/mysql/binlog/mysql-bin.000105 /data/mysql/binlog/mysql-bin.000106 /data/mysql/binlog/mysql-bin.000107
注意修改權限
chown mysql:mysql -R mysql-bin.*</pre>
手動 FLUSH LOGS，可以看到前后 BINARY LOGS 列表發生變化。
mysql> SHOW BINARY LOGS; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000106 | 10485866 | | mysql-bin.000107 | 504130 | +------------------+-----------+ 2 rows in set (0.00 sec)mysql> FLUSH LOGS; Query OK, 0 rows affected (0.01 sec)
mysql> SHOW BINARY LOGS; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000104 | 10486051 | | mysql-bin.000105 | 10485866 | | mysql-bin.000106 | 10485866 | | mysql-bin.000107 | 504173 | | mysql-bin.000108 | 107 | +------------------+-----------+ 6 rows in set (0.00 sec)</pre>
7、192.168.1.103 利用備份文件的 MASTER_LOG_FILE 和 MASTER_LOG_POS 信息和 192.168.1.101 建立主從關系。
8、192.168.1.103 和 192.168.1.101 校驗數據。192.168.1.101 的增量數據已經完全同步到 192.168.1.103。
9、192.168.1.101 修改 mysql-bin.index 文件，將之前手動加入的 binlog 刪除，然后再 FLUSH LOGS。
10、192.168.1.102 打開同步，可以看到同步正常，再確認 192.168.1.103，同步也正常。
? cosgood1969/OIl_2/Pinterest
我們接下來測試下舊 DB 已有從庫不停掉同步的情況。
測試環境 IP 如下：
- 192.168.1.101（主）
- 192.168.1.102（從）
- 192.168.1.103（從）
測試步驟如下：
1、192.168.1.101 和 192.168.1.102 建立主從，192.168.1.101 創建 sbtest 庫，然后使用 sysbench 插入 100 萬測試數據，相關命令如下：
sysbench --test=oltp --oltp-table-size=1000000 --oltp-read-only=off --init-rng=on \ --num-threads=16 --max-requests=0 --oltp-dist-type=uniform --max-time=1800 \ --mysql-user=root --mysql-socket=/tmp/mysql.sock \ --mysql-password=xxxx --db-driver=mysql --mysql-table-engine=innodb \ --oltp-test-mode=complex prepare
2、在 192.168.1.102 導出數據，然后拷貝到 192.168.1.103，在 192.168.1.103 導入數據。備份文件的 MASTER_LOG_FILE 和 MASTER_LOG_POS 信息如下：
-- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000115', \ -- MASTER_LOG_POS=6102367;
3、在 192.168.1.101 使用如下腳本再次導入 10 萬數據。
!/bin/bash
for i in $(seq 1 100000) do mysql -uroot -p'xxxx' --socket=/tmp/mysql.sock -e \ "INSERT INTO sbtest.sbtest(k, c, pad) VALUES(0, '1', \ 'qqqqqqqqqqwwwwwwwwwweeeeeeeeeerrrrrrrrrrtttttttttt');"</pre>
4、192.168.1.101 模擬 binlog 被清除。先備份 binlog，然后再 PURGE。
mysql> SELECT COUNT() FROM sbtest; +----------+ | COUNT() | +----------+ | 1100000 | +----------+ 1 row in set (0.19 sec)mysql> PURGE BINARY LOGS TO 'mysql-bin.000118'; Query OK, 0 rows affected (0.03 sec)</pre>
5、192.168.1.102 不停同步。
6、192.168.1.101 修改 mysql-bin.index 文件，把備份的 binlog 文件拷貝到 binlog 目錄，然后手動執行 FLUSH LOGS。
pwd /data/mysql/binlog cp -v /data/backup/mysql-bin.00011{5,6,7} .cat mysql-bin.index /data/mysql/binlog/mysql-bin.000115 /data/mysql/binlog/mysql-bin.000116 /data/mysql/binlog/mysql-bin.000117 /data/mysql/binlog/mysql-bin.000118
注意修改權限
chown mysql:mysql -R mysql-bin.*</pre>
手動 FLUSH LOGS，可以看到前后 BINARY LOGS 列表發生變化。
mysql> SHOW BINARY LOGS; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000118 | 2945005 | +------------------+-----------+ 1 row in set (0.00 sec)mysql> FLUSH LOGS; Query OK, 0 rows affected (0.00 sec)
mysql> SHOW BINARY LOGS; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000115 | 10486080 | | mysql-bin.000116 | 10485866 | | mysql-bin.000117 | 10485866 | | mysql-bin.000118 | 2945048 | | mysql-bin.000119 | 107 | +------------------+-----------+ 5 rows in set (0.00 sec)</pre>
7、觀察 192.168.1.102，可以看到此時同步已經出錯。
Master_Log_File: mysql-bin.000119 Read_Master_Log_Pos: 107 Relay_Log_File: relaylog.000326 Relay_Log_Pos: 253 Relay_Master_Log_File: mysql-bin.000116 Exec_Master_Log_Pos: 107Last_Errno: 1062 Last_Error: Error 'Duplicate entry '1015491' for key 'PRIMARY'' on query. \ Default database: ''. Query: 'INSERT INTO sbtest.sbtest(k, c, pad) VALUES \ (0, '1', 'qqqqqqqqqqwwwwwwwwwweeeeeeeeeerrrrrrrrrrtttttttttt')'</pre>
再對比下出錯之前的從庫狀態：
Master_Log_File: mysql-bin.000118 Read_Master_Log_Pos: 2945005 Relay_Log_File: relaylog.000324 Relay_Log_Pos: 2945151 Relay_Master_Log_File: mysql-bin.000118 Exec_Master_Log_Pos: 2945005可以看到，192.168.1.102 從 mysql-bin.000116:107 的位置重現同步，就會導致主鍵沖突的問題。
8、192.168.1.103 利用備份文件的 MASTER_LOG_FILE 和 MASTER_LOG_POS 信息和 192.168.1.101 建立主從關系。
CHANGE MASTER TO MASTER_HOST='192.168.1.101', MASTER_PORT=3307, MASTER_USER='slave', \ MASTER_PASSWORD='xxxx', MASTER_LOG_FILE='mysql-bin.000115', MASTER_LOG_POS=6102367;9、192.168.1.103 和 192.168.1.101 校驗數據。192.168.1.101 的增量數據已經完全同步到 192.168.1.103。
10、192.168.1.101 修改 mysql-bin.index 文件，將之前手動加入的 binlog 刪除，然后再 FLUSH LOGS。
11、再次觀察 192.168.1.102
Master_Log_File: mysql-bin.000120 Read_Master_Log_Pos: 4 Relay_Log_File: relaylog.000326 Relay_Log_Pos: 253 Relay_Master_Log_File: mysql-bin.000116 Exec_Master_Log_Pos: 107 Last_IO_Errno: 1236 Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: \ 'could not find next log; the first event 'mysql-bin.000107' at 504130, \ the last event read from '/data/mysql/binlog/mysql-bin.000119' at 150, \ the last byte read from '/data/mysql/binlog/mysql-bin.000119' at 150.' Last_SQL_Errno: 1062 Last_SQL_Error: Error 'Duplicate entry '1015491' for key 'PRIMARY'' on query. \ Default database: ''. Query: 'INSERT INTO sbtest.sbtest(k, c, pad) VALUES \ (0, '1', 'qqqqqqqqqqwwwwwwwwwweeeeeeeeeerrrrrrrrrrtttttttttt')'此時 IO 線程和 SQL 線程均異常。
0x03 結論
結論如下：
- 拷貝回去的 binlog，需要將屬性改為 mysql
- mysql-bin.index 這個文件不管加一行減一行，在觸發 FLUSH LOGS 的時候原有的復制會被中斷。如果舊 Master 有從庫，恢復其他從庫數據的時候，需要暫時將已有的從庫同步停掉（執行 STOP SLAVE），就能避免中斷
- 任何線上操作，都要在完備的測試前提下再操作
- 遷移過程中，重要的一點是做好數據校驗，不管是用 pt，還是手動寫腳本，這個過程不能缺失
來自：https://dbarobin.com/2017/03/15/best-practices-of-recovering-via-binlog/