在 Percona MySQL 支持團隊中，我們經常看到客戶抱怨復制延遲的問題。當然，這對 MySQL 用戶來說并不是什么新鮮事，多年來我們在 MySQL 性能博客上發表過一些關于這個主題的文章（過去有兩篇特別受歡迎的文章："Reasons for MySQL Replication Lag" 和 “Managing Slave Lag with MySQL Replication"），兩篇文章均由 Percona 首席執行官 Peter ZAItsev 撰寫）。
譯者注：Percona 公司是做 MySQL 發行版的，MySQL 有三大發行版，MySQL、MariaDB、Percona，《高性能 MySQL》這本神作就是出自 Percona 的專家團隊。
在今天的文章中，我將分享一些發現復制延遲的新方法，包括從服務器滯后的可能原因以及如何解決這個問題。
如何發現復制延遲
MySQL 復制有兩個線程：IO_THREAD 和 SQL_THREAD。
IO_THREAD 連接到 master，從 master 讀取 binlog 事件，并將其復制到名為 relay log 的本地日志文件中。
另一方面，SQL_THREAD 在從節點上讀取 relay log，然后盡可能快地處理這些日志。每當復制出現延遲時，首先要弄清延遲發生在 IO_THREAD 還是 SQL_THREAD。
通常情況下，I/O 線程不會造成巨大的復制延遲，因為它只是從主服務器讀取 binlog。不過，這取決于網絡連接、網絡延遲……即服務器之間的速度有多快。Slave 的 I/O 線程可能會因為帶寬擁塞而變慢。
通常，當 Slave IO_THREAD 能夠足夠快地讀取 binlog 時，就容易在 Slave 上堆積 relay log – 此時表明 Slave IO_THREAD 是沒問題的。
另一方面，如果是 Slave SQL_THREAD 導致延遲，大概率是因為來自 replication stream 的 queries 在 Slave 上執行的時間太長。可能的原因包括 Master、Slave 之間的硬件不同、索引不同、工作負載不同。
此外，Slave OLTP 工作負載有時會因為“鎖”而導致復制延遲。例如，對 MyISAM 表的長久讀請求會阻塞 SQL 線程，或對 InnoDB 表的任何事務都會創建 IX 鎖并阻塞 SQL 線程中的 DDL。此外，還要考慮到在 MySQL 5.6 之前，slave 是單線程的，這也是導致 Slave SQL_THREAD 出現延遲的另一個原因。
MySQL 復制延遲的例子
讓我通過 master status / slave status 示例向您展示，以確定 Slave 延遲問題到底是由于 IO_THREAD 還是由于 SQL_THREAD。
mysql-master> SHOW MASTER STATUS;
+------------------+--------------+------------------+------------------------------------------------------------------+
File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+--------------+------------------+------------------------------------------------------------------+
mysql-bin.018196 | 15818564 | | bb11b389-d2a7-11e3-b82b-5cf3fcfc8f58:1-2331947 |
+------------------+--------------+------------------+------------------------------------------------------------------+
mysql-slave> SHOW SLAVE STATUSGG
*************************** 1. row ***************************
Slave_IO_State: Queueing master event to the relay log
Master_Host: master.example.com
Master_User: repl
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.018192
Read_Master_Log_Pos: 10050480
Relay_Log_File: mysql-relay-bin.001796
Relay_Log_Pos: 157090
Relay_Master_Log_File: mysql-bin.018192
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 5395871
Relay_Log_Space: 10056139
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 230775
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 2
Master_UUID: bb11b389-d2a7-11e3-b82b-5cf3fcfc8f58:2-973166
Master_Info_File: /var/lib/mysql/i1/data/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Reading event from the relay log
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp:
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set: bb11b389-d2a7-11e3-b82b-5cf3fcfc8f58:2-973166
Executed_Gtid_Set: bb11b389-d2a7-11e3-b82b-5cf3fcfc8f58:2-973166,
ea75c885-c2c5-11e3-b8ee-5cf3fcfc9640:1-1370
Auto_Position: 1
這清楚地表明，Slave IO_THREAD 滯后，顯然 Slave SQL_THREAD 也因此滯后，從而導致復制延遲。正如你所看到的，Master 日志文件是 mysql-bin.018196（來自 SHOW MASTER STATUS），而 Slave IO_THREAD 在 mysql-bin.018192（來自 Slave status 的 Master_Log_File）上，這表明 Slave IO_THREAD 正在從該文件讀取數據，而在 Master 上，它正在寫入 mysql-bin.018196，因此 Slave IO_THREAD 落后了 4 個 binlog。
與此同時，Slave SQL_THREAD 正在讀取同一個文件，即 mysql-bin.018192（Slave status 中的 Relay_Master_Log_File），這表明 Slave SQL_THREAD 正在以足夠快的速度應用事件，但它也滯后了，這可以從顯示 Slave status 輸出中的 Read_Master_Log_Pos 與 Exec_Master_Log_Pos 之間的差值觀察到。
show slave status 的輸出中 Master_Log_File 和 Relay_Master_Log_File 值相同，我們可以根據 Read_Master_Log_Pos - Exec_Master_Log_Pos 計算 Slave SQL_THREAD 的滯后時間。這樣就能大致了解 Slave SQL_THREAD 應用事件(Apply event)的速度。
如上所述，如果 Slave IO_THREAD 滯后，那么 Slave SQL_THREAD 當然也會滯后。有關顯示 Slave 狀態輸出字段的詳細說明，請點擊此處。
此外，Seconds_Behind_Master 顯示了以秒為單位的巨大延遲。不過，這可能會產生誤導，因為它只度量最近執行的 relay log 與最近被 IO_THREAD 下載的 relay log 條目之間的時間戳差異。如果 Master 上有更多的 relay log，Slave 并不會將它們計入 Seconds_behind_master 的計算中。你可以使用 Percona 工具包中的 pt-heartbeat 更準確地測量 Slave 日志的滯后情況。
至此，我們學會了如何檢查復制延遲——無論是 Slave IO_THREAD 還是 Slave SQL_THREAD。現在，讓我來提供一些提示和建議，看看到底是什么原因導致了這種延遲。
提示和建議 - 導致復制延遲的原因及可能的修復方法
通常，Slave IO_THREAD 滯后是因為主/從之間的網絡速度太慢。大多數情況下，啟用 Slave 壓縮協議（slave_compressed_protocol）有助于緩解 Slave IO_THREAD 的滯后。還有一個建議是禁用 Slave 上的 binlog 記錄，因為它也是 IO 密集型的，除非你需要它來進行時間點恢復。
要盡量減少 Slave SQL_THREAD 的滯后，重點是優化查詢。我的建議是啟用配置選項 log_slow_slave_statements，這樣 Slave 執行的耗時超過 long_query_time 的查詢就會被記錄到慢日志中。為了收集更多有關查詢性能的信息，我還建議將配置選項 log_slow_verbosity 設置為"full”。
這樣，我們就能看到是否有 Slave SQL_thread 執行的查詢需要很長時間才能完成。關于如何在特定時間段內使用上述選項啟用慢查詢日志，你可以點擊這里查看我之前的文章。需要提醒的是，log_slow_slave_statements 變量是在 Percona Server 5.1 中首次引入的，現在從 5.6.11 版起已成為 Vanilla MySQL 的一部分。在上游版本的 MySQL 中，log_slow_slave_statements 被作為命令行選項引入，而 log_slow_verbosity 是 Percona Server 的特定功能。
如果使用基于行的 binlog 格式，在 Slave SQL_THREAD 上出現延遲的另一個原因是：如果任何數據庫表缺少主鍵或唯一鍵，就會在 Slave SQL_THREAD 上掃描表的所有行進行 DML，從而導致復制延遲，因此要確保所有表都有主鍵或唯一鍵。有關詳細信息，請查看此錯誤報告 http://bugs.mysql.com/bug.php?id=53375 您可以在 Slave 上使用以下查詢來確定哪些數據庫表缺少主鍵或唯一鍵。
mysql> SELECT t.table_schema,t.table_name,engine
FROM information_schema.tables t INNER JOIN information_schema .columns c
on t.table_schema=c.table_schema and t.table_name=c.table_name
GROUP BY t.table_schema,t.table_name
HAVING sum(if(column_key in ('PRI','UNI'), 1,0)) =0;
在 MySQL 5.6 中，針對這種情況進行了一項改進，在使用內存散列的情況下，slave_rows_search_algorithms 可以解這個問題。
請注意，當我們讀取巨大的 RBR 事件時，Seconds_Behind_Master 并沒有更新，因此 “滯后” 可能僅僅與此有關 – 我們還沒有完成對事件的讀取。例如，在基于行的復制中，龐大的事務可能會導致 Slave 端出現延遲，比如，如果你有一個 1000 萬行的表，而你執行了 DELETE FROM table WHERE id < 5000000 操作，500 萬行將被發送到 Slave 端，每一行都是單獨的，速度會慢得令人痛苦。
因此，如果必須不時地從龐大的表中刪除最舊的行，那么使用分區可能是一個不錯的選擇，在某些工作負載中，使用 DROP 舊分區可能比使用 DELETE 更好，而且只有語句會被復制，因為這將是 DDL 操作。
為了更好地解釋這個問題，假設分區 1 保存的行的 ID 從 1 到 1000000，分區 2 的 ID 從 1000001 到 2000000，以此類推，所以與其通過語句 DELETE FROM table WHERE ID<=1000000 進行刪除，不如執行 ALTER TABLE DROP partition1。有關更改分區操作，請查閱手冊 - 也請查閱我的同事 Roman 的這篇精彩文章，其中解釋了復制延遲的可能原因。
pt-stalk 是 Percona 工具包中最優秀的工具之一，它可以在出現問題時收集診斷數據。你可以按如下方式設置 pt-stalk，這樣只要出現 Slave 滯后，它就能記錄診斷信息，我們隨后就可以對這些信息進行分析，看看到底是什么原因導致了滯后。
------- pt-plug.sh contents
#!/bin/bash
trg_plugin() {
mysqladmin $EXT_ARGV ping &> /dev/null
mysqld_alive=$?
if [[ $mysqld_alive == 0 ]]
then
seconds_behind_master=$(mysql $EXT_ARGV -e "show slave status" --vertical | grep Seconds_Behind_Master | awk '{print $2}')
echo $seconds_behind_master
else
echo 1
fi
}
# Uncomment below to test that trg_plugin function works as expected
#trg_plugin
-------
-- That's the pt-plug.sh file you would need to create and then use it as below with pt-stalk:
$ /usr/bin/pt-stalk --function=/root/pt-plug.sh --variable=seconds_behind_master --threshold=300 --cycles=60 --notify-by-email=muhammad@example.com --log=/root/pt-stalk.log --pid=/root/pt-stalk.pid --daemonize
你可以調整閾值，目前是 300 秒，結合 -cycles 選項，這意味著如果 seconds_behind_master 值大于等于 300，持續 60 秒或更長時間，pt-stalk 就會開始捕獲數據。添加 --notify-by-email 選項后，pt-stalk 捕獲數據時就會通過電子郵件通知。你可以相應調整 pt-stalk 的閾值，這樣它就會在問題發生時觸發采集診斷數據。
結論
滯后 Slave 是一個棘手的問題，但也是 MySQL 復制中的常見問題。在這篇文章中，我試圖涵蓋 MySQL 復制 Slave 延遲的大多數方面。如果你知道復制延遲的其他原因，請在評論區與我分享。
作者丨Muhammad Irfan 編譯丨公眾號：SRETalk（ID：SRETalk）
來源丨percona.com/blog/how-to-identify-and-cure-mysql-replication-slave-lag/
