一 引子

---

研發(fā)反應(yīng)，有臺(tái)從庫(kù)和主庫(kù)不同步。由于業(yè)務(wù)讀操作是針對(duì)從庫(kù)的，數(shù)據(jù)不同步必定會(huì)帶來(lái)數(shù)據(jù)的不一致，業(yè)務(wù)獲取的結(jié)果會(huì)受影響，所以這個(gè)問(wèn)題必須盡快解決。

登上服務(wù)器，查看 MySQL 的從庫(kù)狀態(tài)，并沒(méi)有任何報(bào)錯(cuò)信息。刷新從庫(kù)狀態(tài)，發(fā)現(xiàn)狀態(tài)沒(méi)有任何變化，Exec_Master_Log_Pos?卡住不動(dòng)。

二 故障分析

---

為了安全起見(jiàn)，此文略去 MySQL 版本以及其他可能會(huì)帶來(lái)安全問(wèn)題的信息。

接下來(lái)逐步分析問(wèn)題。

首先查看從庫(kù)狀態(tài)：

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)

此時(shí)的 Slave_IO_State 為 Queueing master event to the relay log，而不是正常狀態(tài)下的 Waiting for master to send event。刷新多次，狀態(tài)沒(méi)有任何變化，Exec_Master_Log_Pos?不變，從而導(dǎo)致?Seconds_Behind_Master?一直不變。

接下來(lái)查看 PROCESSLIST 狀態(tài)：

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)

從以上的結(jié)果來(lái)看，沒(méi)有任何異常。

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

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

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

查看輸出結(jié)果，發(fā)現(xiàn)端倪了，以下是摘抄的部分結(jié)果：

/*!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

從以上輸出中，我們可以知道，從夯住的那個(gè)點(diǎn)開(kāi)始，binlog 記錄的信息就出現(xiàn)了異常，可以推測(cè)在主庫(kù)有大操作。另外，針對(duì)出現(xiàn)問(wèn)題庫(kù)，查看主庫(kù)和從庫(kù)的表數(shù)量，發(fā)現(xiàn)從庫(kù)的表數(shù)量多于主庫(kù)，有幾個(gè)臨時(shí)表出現(xiàn)。可以推測(cè)的，主庫(kù)有刪表的操作，從庫(kù)同步夯住，導(dǎo)致同步異常，主庫(kù)刪表的操作還沒(méi)來(lái)得及同步到從庫(kù)。

經(jīng)過(guò)和研發(fā)溝通，確認(rèn)了兩點(diǎn)。第一，確實(shí)有大操作，程序有大量的批量插入，而且是用的 LOAD DATA LOCAL INFILE；第二，主庫(kù)確實(shí)有刪表的操作，這幾張表都是臨時(shí)表。

三 故障解決

---

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

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

為了保險(xiǎn)起見(jiàn)，我們?cè)谥鲙?kù)加大 expire_logs_days 參數(shù)，避免 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)

接著修改從庫(kù)的配置文件：

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 從庫(kù)，查看從庫(kù)狀態(tài)，并定時(shí)刷新?tīng)顟B(tài)，我們可以看到的是，Exec_Master_Log_Pos?在遞增，Seconds_Behind_Master?在遞減，證明問(wèn)題已經(jīng)解決了。

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)

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

四 原理探討

---

在主庫(kù)運(yùn)行?LOAD DATA LOCAL INFILE，主庫(kù)和從庫(kù)時(shí)這樣同步的：

• 在主節(jié)點(diǎn)：
• 執(zhí)行 LOAD DATA LOCAL INFILE；
• 拷貝使用的整個(gè)文本文件內(nèi)容到二進(jìn)制日志；
• 添加 LOAD DATA LOCAL INFILE 到最新的二進(jìn)制日志。
• 復(fù)制所有主庫(kù)的二進(jìn)制日志到從庫(kù)的中繼日志；
• 在從節(jié)點(diǎn)：
• 檢查中繼日志中的文本文件；
• 從多個(gè)中繼日志文件中讀取所有的塊；
• 文本文件存放在 /tmp 文件夾中；
• 從中繼日志中讀取 LOAD DATA LOCAL INFILE；
• 在 SQL 線(xiàn)程中執(zhí)行 LOAD DATA LOCAL INFILE。

在從節(jié)點(diǎn)執(zhí)行的 1-4 步驟中，IO 線(xiàn)程會(huì)呈現(xiàn) Reading event from the relay log 狀態(tài)，持續(xù)地為下一個(gè) LOAD DATA LOCAL INFILE 命令提取 CSV 行。此時(shí)從庫(kù)會(huì)持續(xù)落后，一旦從庫(kù)落后時(shí)間較長(zhǎng)，會(huì)導(dǎo)致 SQL 線(xiàn)程阻塞，呈現(xiàn) Queueing master event to the relay log 狀態(tài)，從而復(fù)制夯住。

五 小結(jié)

---

這樣的故障，歸根結(jié)底還是研發(fā)寫(xiě)的程序還有優(yōu)化的余地。大批量的數(shù)據(jù)插入，這在 MySQL 中是不推薦使用的。我們可以這樣：第一，一條 SQL 語(yǔ)句插入多條數(shù)據(jù)；第二，在事務(wù)中進(jìn)行插入處理；第三，分批插入，在程序中設(shè)置 auto_commit 為 0，分批插入完成后，手動(dòng) COMMIT；第四，需要使用 LOAD DATA LOCAL INFILE 時(shí)，設(shè)置 sync_binlog 為 1。

總結(jié)

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

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。