作者：郭斌斌
愛可生 DBA 團隊成員，負責專案日常問題處理及公司平臺問題排查。
本文來源：原創投稿
*愛可生開源社群出品，原創內容未經授權不得隨意使用，轉載請聯絡小編並註明來源。
一、背景
客戶反饋生產環境中，MySQL 5.7 通過 xtrabackup+ Binlog 做基於時間點的恢復操作時，持續卡在 Binlog 的回放階段，曠日持久，久到離譜。他對於這種曠日持久的操作產生了懷疑，想要確認資料庫的這種行為是否合理，因此有了本文的 Binlog 回灌驗證操作。
二、復現前提
MySQL Version：5.7.22
Binlog format： Row
準備 Delete 800多萬記錄的 Binlog
三、復現準備
3.1 建立表、構造資料
mysql> create table t1(id int primary key,name varchar(10));
Query OK, 0 rows affected (0.02 sec)
mysql> insert into t1 values(1,repeat('a',10));
Query OK, 1 row affected (0.01 sec)
mysql> insert into t1 select (select count(1) from t1)+id,name from t1;
Query OK, 1 row affected (0.01 sec)
Records: 1 Duplicates: 0 Warnings: 0
………………
mysql> insert into t1 select (select count(1) from t1)+id,name from t1;
Query OK, 4194304 rows affected (57.75 sec)
Records: 4194304 Duplicates: 0 Warnings: 03.2 準備 Delete 800多萬記錄的 Binlog 檔案
MySQL Binlog mysql-bin.000003 用於回灌測試
3.3 由於 Binlog 的回灌和造數是在同一個例項上，之前為了構建 Delete 800多萬記錄的 Binlog ，已經將資料刪除，因此在進行 binlog 回灌前，需要使用之前造數的方法，重新造數
3.4 同一個例項上先進行了 Delete ，又重新構建新的資料。導致 Delete 操作的 GTID 要比重新造數操作的 GTID 小，為保證可以正常回灌，可以執行 reset master
四、復現測試
4.1 解析 MySQL Binlog mysql-bin.000003
4.2 匯入解析檔案
A Few Moment Later
4.3 檢視 processlist ，發現匯入執行緒一直處於 Sleep 狀態，現象跟客戶描述契合。
4.4 隨即中斷匯入操作，重新發起匯入同時使用 strace 記錄操作的行為。
4.5 通過觀測產生的 strace.log ，發現兩個 read 的時間間隔不固定，少的也需要140ms左右，而讀取的大小卻只有4k（4096），讀取效率偏低。
五、分析
通過 Google 檢索“MySQL Mem Load Slow”發現這是一個 BUG ，MySQL 5.7 Client 在讀取較大事務（涉及多行操作）時，由於記憶體分配效率比較低，導致消耗大量的時間，已在 MySQL 8.0.13 中修復。
六、複測
6.1 Mysql 8.0.18 客戶端進行 Binlog 解析檔案的回灌，提示 MySQL Server has gone away
6.2 導數報錯時資料庫沒觸發重啟，檢視 error 日誌，有如下報錯：
6.3 調大 max_allowed_packet 配置後重新測試
6.4 觀測 strace 日誌，每次讀取 Binlog 大小16M，遠高於原來的4k
6.5 觀測執行緒狀態
6.6 觀察執行耗時，MySQL 8.0.18 客戶端導數時間變短，效率提升明顯。
七、結論
目前官方在 MySQL 8.0.13 版本中，解決了“在使用 MySQL Client 進行批量導數時，記憶體分配效率低”的問題，因此 MySQL 8.0.18 客戶端在進行回灌 Binlog 解析後的檔案時，讀取檔案效率明顯高於5.7.22的客戶端，提升了 Binlog回放的效率。