一 引子

---

研發反應，有臺從庫和主庫不同步。由于業務讀操作是針對從庫的，數據不同步必定會帶來數據的不一致，業務獲取的結果會受影響，所以這個問題必須盡快解決。

登上服務器，查看 MySQL 的從庫狀態，并沒有任何報錯信息。刷新從庫狀態，發現狀態沒有任何變化，Exec_Master_Log_Pos?卡住不動。

二 故障分析

---

為了安全起見，此文略去 MySQL 版本以及其他可能會帶來安全問題的信息。

接下來逐步分析問題。

首先查看從庫狀態：

mysql> SHOW SLAVE STATUS \G *************************** 1. row ***************************Slave_IO_State: Queueing master event to the relay logMaster_Host: masterIPMaster_User: replUserMaster_Port: masterPortConnect_Retry: 60Master_Log_File: binlog.000296Read_Master_Log_Pos: 364027786Relay_Log_File: relaylog.000002Relay_Log_Pos: 250Relay_Master_Log_File: binlog.000283Slave_IO_Running: YesSlave_SQL_Running: YesReplicate_Do_DB:Replicate_Ignore_DB:Replicate_Do_Table:Replicate_Ignore_Table:Replicate_Wild_Do_Table:Replicate_Wild_Ignore_Table:Last_Errno: 0Last_Error:Skip_Counter: 0Exec_Master_Log_Pos: 594374863Relay_Log_Space: 13803486573Until_Condition: NoneUntil_Log_File:Until_Log_Pos: 0Master_SSL_Allowed: NoMaster_SSL_CA_File:Master_SSL_CA_Path:Master_SSL_Cert:Master_SSL_Cipher:Master_SSL_Key:Seconds_Behind_Master: 256219 Master_SSL_Verify_Server_Cert: NoLast_IO_Errno: 0Last_IO_Error:Last_SQL_Errno: 0Last_SQL_Error:Replicate_Ignore_Server_Ids:Master_Server_Id: masterID 1 row in set (0.00 sec)

此時的 Slave_IO_State 為 Queueing master event to the relay log，而不是正常狀態下的 Waiting for master to send event。刷新多次，狀態沒有任何變化，Exec_Master_Log_Pos?不變，從而導致?Seconds_Behind_Master?一直不變。

接下來查看 PROCESSLIST 狀態：

mysql> SHOW FULL PROCESSLIST; +--------+-------------+------------------+--------------------+---------+---------+---------------+------------------+ | Id | User | Host | db | Command | Time | State | Info | +--------+-------------+------------------+--------------------+---------+---------+---------------+------------------+ | 51378 | system user | | NULL | Connect | 1121183 | Waiting for master to send event | NULL | | 88917 | system user | | NULL | Connect | 245327 | Reading event from the relay log | NULL | | 106029 | userA | xxx.xxx.xxx.xxx:14057 | NULL | Sleep | 14504 | | NULL | | 106109 | userA | xxx.xxx.xxx.xxx:15077 | databaseA | Sleep | 79 | | NULL | | 106110 | userA | xxx.xxx.xxx.xxx:15081 | databaseA | Sleep | 13000 | | NULL | | 106116 | userB | xxx.xxx.xxx.xxx:15096 | databaseA | Sleep | 357 | | NULL | | 106117 | userB | xxx.xxx.xxx.xxx:15097 | NULL | Sleep | 12964 | | NULL | | 106119 | root | localhost | NULL | Query | 0 | NULL | SHOW FULL PROCESSLIST | | 106126 | userB | xxx.xxx.xxx.xxx:15173 | NULL | Sleep | 12856 | | NULL | | 106127 | userB | xxx.xxx.xxx.xxx:15180 | databaseA | Sleep | 12849 | | NULL | | 106766 | userA | xxx.xxx.xxx.xxx:17960 | databaseA | Sleep | 64 | | NULL | +--------+-------------+------------------+--------------------+---------+---------+---------------+------------------+ 11 rows in set (0.00 sec)

從以上的結果來看，沒有任何異常。

既然從上述信息中得不到任何對排查問題有幫助的信息，那么我們可以試著分析 MySQL 的 binlog，看 Pos 為 594374863 的點發生了什么操作。

分析日志我們可以使用 mysqlbinlog 命令，指定 start-position 為夯住的那個點，并重定向到文件。

/usr/local/mysql/bin/mysqlbinlog --no-defaults -v --start-position="594374863" \ binlog.000283 > /XXX/binlog.sql

查看輸出結果，發現端倪了，以下是摘抄的部分結果：

/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #150814 17:43:15 server id 21 end_log_pos 107 Start: binlog v 4, server v x.x.xx-log created 150814 17:43:15 BINLOG ' M7jNVQ8VAAAAZwAAAGsAAAAAAAQANS41LjE5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA== '/*!*/; # at 594374863 #150814 18:09:36 server id 21 end_log_pos 594374945 Query thread_id=210702841 exec_time=43 error_code=0 SET TIMESTAMP=1439546976/*!*/; SET @@session.pseudo_thread_id=210702841/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=0/*!*/; 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 594374945 # at 594375036 # at 594376047 # at 594377085 # at 594378123 # at 594379152 # at 594380187 # at 594381165 # at 594382194 # at 594383223 # at 594384252 # at 594385269 # at 594386307 # at 594387282 # at 594388299 # at 594389265 # at 594390270 # at 594391299 # at 594392310 # at 594393327 # at 594394344 # at 594395340 # at 594396336 # at 594397332

從以上輸出中，我們可以知道，從夯住的那個點開始，binlog 記錄的信息就出現了異常，可以推測在主庫有大操作。另外，針對出現問題庫，查看主庫和從庫的表數量，發現從庫的表數量多于主庫，有幾個臨時表出現。可以推測的，主庫有刪表的操作，從庫同步夯住，導致同步異常，主庫刪表的操作還沒來得及同步到從庫。

經過和研發溝通，確認了兩點。第一，確實有大操作，程序有大量的批量插入，而且是用的 LOAD DATA LOCAL INFILE；第二，主庫確實有刪表的操作，這幾張表都是臨時表。

三 故障解決

---

既然問題找到了，那解決辦法自然就有了。既然從庫的表多于主庫，而且這幾張表是臨時數據，我們可以過濾掉對這幾張表的同步操作。具體思路如下：在主庫備份臨時表（雖然研發說數據不重要，但還是以防萬一，DBA 還是謹慎為好），然后通知研發臨時切走從庫的流量，修改配置文件，指定?replicate-ignore-table?參數，重啟 MySQL。

接下來就是具體的解決步驟，首先備份數據。備份時不加 –master-data 參數和 –single-transaction。究其原因，–master-data 禁用 –lock-tables 參數，在和 –single-transaction 一起使用時會禁用 –lock-all-tables。在備份開始時，會獲取全局 read lock。 –single-transaction 參數設置默認級別為 REPEATABLE READ，并且在開始備份時執行 START TRANSACTION。在備份期間， 其他連接不能執行如下語句：ALTER TABLE、CREATE TABLE、DROP TABLE、RENAME TABLE、TRUNCATE TABLE。MySQL 同步夯住，如果加了上述參數，mysqldump 也會夯住。mysqldump 會 FLUSH TABLES、LOCK TABLES，如果有 –master-data 參數，會導致 Waiting for table flush。同樣，有 –single-transaction 參數，仍然會導致 Waiting for table flush。另外，還可以看到 Waiting for table metadata lock，此時做了 DROP TABLE 的操作。此時可以停掉 MySQL 同步來避免這個問題。

為了保險起見，我們在主庫加大 expire_logs_days 參數，避免 binlog 丟失。

mysql> SHOW VARIABLES LIKE '%expire%'; +------------------+-------+ | Variable_name | Value | +------------------+-------+ | expire_logs_days | 3 | +------------------+-------+ 1 row in set (0.00 sec)mysql> SET GLOBAL expire_logs_days=5; Query OK, 0 rows affected (0.00 sec)mysql> SHOW VARIABLES LIKE '%expire%'; +------------------+-------+ | Variable_name | Value | +------------------+-------+ | expire_logs_days | 5 | +------------------+-------+ 1 row in set (0.00 sec)

接著修改從庫的配置文件：

vim /xxx/xxxx/xxx/my.cnf

在 mysqld 后，加入如下配置：

replicate-ignore-table=databaseA.tableA
replicate-ignore-table=databaseA.tableB
replicate-ignore-table=databaseA.tableC
replicate-ignore-table=databaseA.tableD

然后重啟 MySQL：

/xxx/xxx/xxx/xxx/mysqld restart

登錄 MySQL 從庫，查看從庫狀態，并定時刷新狀態，我們可以看到的是，Exec_Master_Log_Pos?在遞增，Seconds_Behind_Master?在遞減，證明問題已經解決了。

mysql> SHOW SLAVE STATUS \G *************************** 1. row ***************************Slave_IO_State: Waiting for master to send eventMaster_Host: masterIPMaster_User: replUserMaster_Port: masterPortConnect_Retry: 60Master_Log_File: binlog.000319Read_Master_Log_Pos: 985656691Relay_Log_File: relaylog.000004Relay_Log_Pos: 709043542Relay_Master_Log_File: binlog.000284Slave_IO_Running: YesSlave_SQL_Running: YesReplicate_Do_DB:Replicate_Ignore_DB:Replicate_Do_Table:Replicate_Ignore_Table: databaseA.tableA,databaseA.tableB,databaseA.tableC,databaseA.tableDReplicate_Wild_Do_Table:Replicate_Wild_Ignore_Table:Last_Errno: 0Last_Error:Skip_Counter: 0Exec_Master_Log_Pos: 709043399Relay_Log_Space: 38579192969Until_Condition: NoneUntil_Log_File:Until_Log_Pos: 0Master_SSL_Allowed: NoMaster_SSL_CA_File:Master_SSL_CA_Path:Master_SSL_Cert:Master_SSL_Cipher:Master_SSL_Key:Seconds_Behind_Master: 258490 Master_SSL_Verify_Server_Cert: NoLast_IO_Errno: 0Last_IO_Error:Last_SQL_Errno: 0Last_SQL_Error:Replicate_Ignore_Server_Ids:Master_Server_Id: masterID 1 row in set (0.00 sec)

需要注意的是，待同步完成后，需要把從庫配置文件中增加的?replicate-ignore-table參數注釋，并重啟 MySQL。

四 原理探討

---

在主庫運行?LOAD DATA LOCAL INFILE，主庫和從庫時這樣同步的：

• 在主節點：
• 執行 LOAD DATA LOCAL INFILE；
• 拷貝使用的整個文本文件內容到二進制日志；
• 添加 LOAD DATA LOCAL INFILE 到最新的二進制日志。
• 復制所有主庫的二進制日志到從庫的中繼日志；
• 在從節點：
• 檢查中繼日志中的文本文件；
• 從多個中繼日志文件中讀取所有的塊；
• 文本文件存放在 /tmp 文件夾中；
• 從中繼日志中讀取 LOAD DATA LOCAL INFILE；
• 在 SQL 線程中執行 LOAD DATA LOCAL INFILE。

在從節點執行的 1-4 步驟中，IO 線程會呈現 Reading event from the relay log 狀態，持續地為下一個 LOAD DATA LOCAL INFILE 命令提取 CSV 行。此時從庫會持續落后，一旦從庫落后時間較長，會導致 SQL 線程阻塞，呈現 Queueing master event to the relay log 狀態，從而復制夯住。

五 小結

---

這樣的故障，歸根結底還是研發寫的程序還有優化的余地。大批量的數據插入，這在 MySQL 中是不推薦使用的。我們可以這樣：第一，一條 SQL 語句插入多條數據；第二，在事務中進行插入處理；第三，分批插入，在程序中設置 auto_commit 為 0，分批插入完成后，手動 COMMIT；第四，需要使用 LOAD DATA LOCAL INFILE 時，設置 sync_binlog 為 1。

總結

以上是生活随笔為你收集整理的MySQL 复制夯住排查以及原理探讨的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。