承蒙大家的支持，剛上市的《MySQL實戰》已經躍居京東自營資料庫圖書熱賣榜第 1 名，收到的反饋也普遍不錯。對該書感興趣的童鞋可通過右邊的鏈接購買。目前，京東自營有活動，只需 5 折。主從延遲作為 MySQL 的痛點已經存在很多年了，以至於大家都有一種錯覺：有 MySQL 複製的地方就有主從延遲。 ...

承蒙大家的支持，剛上市的《MySQL實戰》已經躍居京東自營資料庫圖書熱賣榜第 1 名，收到的反饋也普遍不錯。對該書感興趣的童鞋可通過右邊的鏈接購買。目前，京東自營有活動，只需 5 折。

主從延遲作為 MySQL 的痛點已經存在很多年了，以至於大家都有一種錯覺：有 MySQL 複製的地方就有主從延遲。

對於主從延遲的原因，很多人將之歸結為從庫的單線程重放。

但實際上，這個說法比較片面，因為很多場景，並行複製方案也解決不了，譬如從庫 SQL 線程被阻塞了，從庫磁碟 IO 存在瓶頸等。

很多童鞋在分析此類問題時缺乏一個系統的方法論，以致無法準確地定位出主從延遲的根本原因。

下麵就如何分析主從延遲做一個系統、全面的總結。

本文主要包括以下兩方面的內容。

如何分析主從延遲。
主從延遲的常見原因及解決方法。

下一篇文章會介紹如何監控主從延遲，包括如何解讀 Seconds_Behind_Master、Seconds_Behind_Master 的局限性、pt-heartbeat 及 MySQL 8.0 原生的解決方案，敬請留意。

如何分析主從延遲

分析主從延遲一般會採集以下三類信息。

從庫伺服器的負載情況

為什麼要首先查看伺服器的負載情況呢？因為軟體層面的所有操作都需要系統資源來支撐。

常見的系統資源有四類：CPU、記憶體、IO、網路。對於主從延遲，一般會重點關註 CPU 和 IO 。

分析 CPU 是否達到瓶頸，常用的命令是 top，通過 top 我們可以直觀地看到主機的 CPU 使用情況。以下是 top 中 CPU 相關的輸出。

Cpu(s):  0.2%us,  0.2%sy,  0.0%ni, 99.5%id,  0.0%wa,  0.0%hi,  0.2%si,  0.0%st

下麵我們看看各個指標的具體含義。

us：處理用戶態（ user ）任務的 CPU 時間占比。
sy：處理內核態（ system ）任務的 CPU 時間占比。
ni：處理低優先順序進程用戶態任務的 CPU 時間占比。

進程的優先順序由 nice 值決定，nine 的範圍是 -20 ～ 19 ，值越大，優先順序越低。其中，1 ～ 19 稱之為低優先順序。
id：處於空閑狀態（ idle ）的 CPU 時間占比。
wa：等待 IO 的 CPU 時間占比。
hi：處理硬中斷（ irq ）的 CPU 時間占比。
si：處理軟中斷（ softirq ）的 CPU 使用率。
st：當系統運行在虛擬機中的時候，被其它虛擬機占用（ steal ）的 CPU 時間占比。

一般來說，當 CPU 使用率（ 1 - 處於空閑狀態的 CPU 時間占比）超過 90% 時，需引起足夠關註。畢竟，對於資料庫應用來說，CPU 很少是瓶頸，除非有大量的慢 SQL 。

接下來看看 IO。

查看磁碟 IO 負載情況，常用的命令是 iostat 。

# iostat -xm 1
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           4.21    0.00    1.77    0.35    0.00   93.67

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sdb               0.00     0.00  841.00 3234.00    13.14    38.96    26.19     0.60    0.15    0.30    0.11   0.08  32.60

命令中指定了 3 個選項，其中，

-x：列印擴展信息。
-m：指定吞吐量的單位是 MB/s ，預設是 KB/s 。
1：每隔 1s 列印一次。

下麵看看輸出中各指標的具體含義。

rrqm/s：每秒被合併的讀請求的數量。
wrqm/s：每秒被合併的寫請求的數量。
r/s：每秒發送給磁碟的讀請求的數量。
w/s：每秒寫入磁碟的寫請求的數量。註意，這裡的請求是合併後的請求。r/s + w/s 等於 IOPS 。
rMB/s：每秒從磁碟讀取的數據量。
wMB/s：每秒寫入磁碟的數據量。rMB/s + wMB/s 等於吞吐量。
avgrq-sz：I/O 請求的平均大小，單位是扇區，扇區的大小是 512 位元組。一般而言，I/O 請求越大，耗時越長。
avgqu-sz：隊列里的平均 I/O 請求數量。
await：I/O 請求的平均耗時，包括磁碟的實際處理時間及隊列中的等待時間，單位 ms 。

其中，r_await 是讀請求的平均耗時，w_await 是寫請求的平均耗時。
svctm：I/O 請求的平均服務時間，單位 ms 。註意，這個指標已棄用，在後續版本會移除。
%util：磁碟飽和度。反映了一個採樣周期內，有多少時間在做 I/O 操作。

一般來說，我們會重點關註 await 和 %util。

對於只能串列處理 I/O 請求的設備來說，%util 接近 100% ，就意味著設備飽和。但對於 RAID、SSD 等設備，因為它能並行處理，故該值參考意義不大，即使達到了 100% ，也不意味著設備出現了飽和。至於是否達到了性能上限，需參考性能壓測下的 IOPS 和吞吐量。

主從複製狀態

對於主庫，執行 SHOW MASTER STATUS 。

mysql> show master status;
+------------------+----------+--------------+------------------+---------------------------------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set                           |
+------------------+----------+--------------+------------------+---------------------------------------------+
| mysql-bin.000004 |  1631495 |              |                  | bd6b3216-04d6-11ec-b76f-000c292c1f7b:1-5588 |
+------------------+----------+--------------+------------------+---------------------------------------------+
1 row in set (0.00 sec)

SHOW MASTER STATUS 的輸出中重點關註 File 和 Position 這兩個指標的值。

對於從庫，執行 SHOW SLAVE STATUS 。

mysql> show slave status\G
*************************** 1. row ***************************
              ...
              Master_Log_File: mysql-bin.000004
          Read_Master_Log_Pos: 1631495
          ...
        Relay_Master_Log_File: mysql-bin.000004
          ...
          Exec_Master_Log_Pos: 1631495
          ...

SHOW SLAVE STATUS 的輸出中重點關註 Master_Log_File，Read_Master_Log_Pos，Relay_Master_Log_File，Exec_Master_Log_Pos 這四個指標的值。

接下來，重點比較以下兩對值。

第一對：( File , Position ) & ( Master_Log_File , Read_Master_Log_Pos )

這裡面，

( File , Position ) 記錄了主庫 binlog 的位置。
( Master_Log_File , Read_Master_Log_Pos ) 記錄了 IO 線程當前正在接收的二進位日誌事件在主庫 binlog 中的位置。

如果 ( File , Position ) 大於 ( Master_Log_File , Read_Master_Log_Pos ) ，則意味著 IO 線程存在延遲。

第二對：( Master_Log_File , Read_Master_Log_Pos ) & ( Relay_Master_Log_File , Exec_Master_Log_Pos )

這裡面，( Relay_Master_Log_File, Exec_Master_Log_Pos ) 記錄了 SQL 線程當前正在重放的二進位日誌事件在主庫 binlog 的位置。

如果 ( Relay_Master_Log_File, Exec_Master_Log_Pos ) < ( Master_Log_File, Read_Master_Log_Pos ) ，則意味著 SQL 線程存在延遲。

主庫 binlog 的寫入量

主要是看主庫 binlog 的生成速度，比如多少分鐘生成一個。

主從延遲的常見原因及解決方法

下麵分別從 IO 線程和 SQL 線程這兩個方面展開介紹。

IO 線程存在延遲

下麵看看 IO 線程出現延遲的常見原因及解決方法。

網路延遲。

判斷是否為網路帶寬限制。如果是，可開啟 slave_compressed_protocol 參數，啟用 binlog 的壓縮傳輸。或者從 MySQL 8.0.20 開始，通過 binlog_transaction_compression 參數開啟 binlog 事務壓縮。
磁碟 IO 存在瓶頸。

可調整從庫的雙一設置或關閉 binlog。

註意，在 MySQL 5.6 中，如果開啟了 GTID ，則會強制要求開啟 binlog ，MySQL 5.7 無此限制。
網卡存在問題。

這種情況不多見，但確實碰到過。當時是一主兩從的架構，發現一臺主機上的所有從庫都延遲了，但這些從庫對應集群的其它從庫卻沒有延遲，後來通過 scp 遠程拷貝文件進一步確認了該台主機的網路存在問題，最後經系統組確認，網卡存在問題。

一般情況下，IO 線程很少存在延遲。

SQL 線程存在延遲

下麵看看 SQL 線程出現延遲的常見原因及解決方法。

主庫寫入量過大，SQL 線程單線程重放

具體體現如下：

從庫磁碟 IO 無明顯瓶頸。
Relay_Master_Log_File , Exec_Master_Log_Pos 也在不斷變化。
主庫寫入量過大。如果磁碟使用的是 SATA SSD，當 binlog 的生成速度快於 5 分鐘一個時，從庫重放就會有瓶頸。

這個是 MySQL 軟體層面的硬傷。要解決該問題，可開啟 MySQL 5.7 引入的基於 LOGICAL_CLOCK 的並行複製。

關於 MySQL 並行複製方案，可參考：MySQL 並行複製方案演進歷史及原理分析

STATEMENT 格式下的慢 SQL

具體體現，在一段時間內 Relay_Master_Log_File , Exec_Master_Log_Pos 沒有變化。

看下麵這個示例，對 1 張千萬數據的表進行 DELETE 操作，表上沒有任何索引，在主庫上執行用了 7.52s，觀察從庫的 Seconds_Behind_Master，發現它最大達到了 7s 。

mysql> show variables like 'binlog_format';
+---------------+-----------+
| Variable_name | Value     |
+---------------+-----------+
| binlog_format | STATEMENT |
+---------------+-----------+
1 row in set (0.00 sec)

mysql> select count(*) from sbtest.sbtest1;
+----------+
| count(*) |
+----------+
| 10000000 |
+----------+
1 row in set (1.41 sec)

mysql> show create table sbtest.sbtest1\G
*************************** 1. row ***************************
       Table: sbtest1
Create Table: CREATE TABLE `sbtest1` (
  `id` int NOT NULL,
  `k` int NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT ''
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
1 row in set (0.00 sec)

mysql> delete from sbtest.sbtest1 where id <= 100;
Query OK, 100 rows affected (7.52 sec)

對於這種執行較慢的 SQL ，並行複製實際上也是無能為力的，此時只能優化 SQL。

在 MySQL 5.6.11 中，引入了參數 log_slow_slave_statements ，可將 SQL 重放過程中執行時長超過 long_query_time 的操作記錄在慢日誌中。

表上沒有任何索引，且二進位日誌格式為 ROW

同樣，在一段時間內，Relay_Master_Log_File , Exec_Master_Log_Pos 不會變化。

如果表上沒有任何索引，對它進行操作，在主庫上只是一次全表掃描。但在從庫重放時，因為是 ROW 格式，對於每條記錄的操作都會進行一次全表掃描。

還是上面的表，同樣的操作，只不過二進位日誌格式為 ROW ，在主庫上執行用了 7.53s ，但 Seconds_Behind_Master 最大卻達到了 723s ，是 STATEMENT 格式下的 100 倍。

mysql> show variables like 'binlog_format';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | ROW   |
+---------------+-------+
1 row in set (0.00 sec)

mysql> delete from sbtest.sbtest1 where id <= 100;
Query OK, 100 rows affected (7.53 sec)

如果因為表上沒有任何索引，導致主從延遲過大，常見的優化方案如下：

在從庫上臨時創建個索引，加快記錄的重放。註意，儘量選擇一個區分度高的列添加索引，列的區分度越高，重放的速度就越快。
將參數 slave_rows_search_algorithms 設置為 INDEX_SCAN,HASH_SCAN 。

設置後，對於同樣的操作，Seconds_Behind_Master 最大隻有 53s 。

大事務

這裡的大事務，指的是二進位日誌格式為 ROW 的情況下，操作涉及的記錄數較多。

還是上面的測試表，只不過這次 id 列是自增主鍵，執行批量更新操作。更新操作如下，其中，N 是記錄數，M 是一個隨機字元，每次操作的字元均不一樣。

update sbtest.sbtest1 set c=repeat(M,120) where id<=N

接下來我們看看不同記錄數下對應 Seconds_Behind_Master 的最大值。

記錄數	主庫執行時長(s)	Seconds_Behind_Master最大值(s)
50000	0.76	1
200000	3.10	8
500000	17.32	39
1000000	63.47	122

可見，隨著記錄數的增加，Seconds_Behind_Master 也是不斷增加的。

所以對於大事務操作，建議分而治之，每次小批量執行。

判斷一個 binlog 是否存在大事務，可通過我之前寫的一個 binlog_summary.py 的工具來分析，該工具的具體用法可參考：Binlog分析利器-binlog_summary.py

從庫上有查詢操作

從庫上有查詢操作，通常會有兩方面的影響：

1. 消耗系統資源。

2. 鎖等待。

常見的是從庫的查詢操作堵塞了主庫的 DDL 操作。看下麵這個示例。

mysql> show processlist;
+----+-----------------+-----------------+------+---------+------+----------------------------------+----------------------------------------+
| Id | User            | Host            | db   | Command | Time | State                            | Info                                   |
+----+-----------------+-----------------+------+---------+------+----------------------------------+----------------------------------------+
|  5 | event_scheduler | localhost       | NULL | Daemon  | 2239 | Waiting on empty queue           | NULL                                   |
| 17 | root            | localhost       | NULL | Query   |    0 | init                             | show processlist                       |
| 18 | root            | localhost       | NULL | Query   |   19 | User sleep                       | select id,sleep(1) from sbtest.sbtest1 |
| 19 | system user     | connecting host | NULL | Connect |  243 | Waiting for source to send event | NULL                                   |
| 20 | system user     |                 |      | Query   |   13 | Waiting for table metadata lock  | alter table sbtest.sbtest1 add c2 int  |
+----+-----------------+-----------------+------+---------+------+----------------------------------+----------------------------------------+
5 rows in set (0.00 sec)

從庫上存在備份

常見的是備份的全局讀鎖阻塞了 SQL 線程的重放。看下麵這個示例。

mysql> show processlist;
+----+-----------------+-----------------+------+---------+------+----------------------------------+----------------------------------------+
| Id | User            | Host            | db   | Command | Time | State                            | Info                                   |
+----+-----------------+-----------------+------+---------+------+----------------------------------+----------------------------------------+
|  5 | event_scheduler | localhost       | NULL | Daemon  | 4177 | Waiting on empty queue           | NULL                                   |
| 17 | root            | localhost       | NULL | Query   |    0 | init                             | show processlist                       |
| 18 | root            | localhost       | NULL | Query   |   36 | User sleep                       | select id,sleep(1) from sbtest.sbtest2 |
| 19 | system user     | connecting host | NULL | Connect | 2181 | Waiting for source to send event | NULL                                   |
| 20 | system user     |                 |      | Query   |    2 | Waiting for global read lock     | alter table sbtest.sbtest1 add c1 int  |
| 28 | root            | localhost       | NULL | Query   |   17 | Waiting for table flush          | flush tables with read lock            |
+----+-----------------+-----------------+------+---------+------+----------------------------------+----------------------------------------+
6 rows in set (0.00 sec)

磁碟 IO 存在瓶頸

這個時候可調整從庫的雙一設置或關閉 binlog。

總結

綜合上面的分析，主從延遲的常見原因及解決方法如下圖所示。

MySQL 主從延遲的常見原因及解決方法