MySQL中slave監控的延遲情況分析

dapan發表於2021-09-09

在MySQL複製環境中,我們通常只根據 Seconds_Behind_Master 的值來判斷SLAVE的延遲。這麼做大部分情況下尚可接受,但並不夠準確,而應該考慮更多因素。

首先,我們先看下SLAVE的狀態:


複製程式碼 程式碼如下:yejr@imysql.com [(none)]> show slave statusG
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
***
Master_Log_File: mysql-bin.000327
Read_Master_Log_Pos: 668711237
Relay_Log_File: mysql-relay-bin.002999
Relay_Log_Pos: 214736858
Relay_Master_Log_File: mysql-bin.000327
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
***
Skip_Counter: 0
Exec_Master_Log_Pos: 654409041
Relay_Log_Space: 229039311
***
Seconds_Behind_Master: 3296
***


可以看到 Seconds_Behind_Master 的值是 3296,也就是SLAVE至少延遲了 3296 秒。

我們再來看下SLAVE上的2個REPLICATION程式狀態:


複製程式碼 程式碼如下:yejr@imysql.com [(none)]> show full processlistG
*************************** 1. row ***************************
Id: 6
User: system user
Host:
db: NULL
Command: Connect
Time: 22005006
State: Waiting for master to send event
Info: NULL
*************************** 2. row ***************************
Id: 7
User: system user
Host:
db: NULL
Command: Connect
Time: 3293
State: Updating
Info: UPDATE ** SET ** WHERE **


可以看到SQL執行緒一直在執行UPDATE操作,注意到 Time 的值是 3293,看起來像是這個UPDATE操作執行了3293秒,一個普通的SQL而已,肯定不至於需要這麼久。
實際上,在REPLICATION程式中,Time 這列的值可能有幾種情況:
1、SQL執行緒當前執行的binlog(實際上是relay log)中的timestamp和IO執行緒最新的timestamp的差值,這就是通常大家認為的 Seconds_Behind_Master 值,並不是某個SQL的實際執行耗時;
2、SQL執行緒當前如果沒有活躍SQL在執行的話,Time值就是SQL執行緒的idle time;

而IO執行緒的Time值則是該執行緒自從啟動以來的總時長(多少秒),如果系統時間在IO執行緒啟動後發生修改的話,可能會導致該Time值異常,比如變成負數,或者非常大。

來看下面幾個狀態:

?

12345678910111213141516171819202122232425262728293031323334 #設定pager,只檢視關注的幾個status值yejr@imysql.com [(none)]> pager cat | egrep -i 'system user|Exec_Master_Log_Pos|Seconds_Behind_Master|Read_Master_Log_Pos' #這是沒有活躍SQL的情況,Time值是idle time,並且 Seconds_Behind_Master 為 0yejr@imysql.com [(none)]> show processlist; show slave statusG| 6 | system user | | NULL | Connect | 22004245 | Waiting for master to send event | NULL || 7 | system user | | NULL | Connect | 13 | Has read all relay log;**Read_Master_Log_Pos: 445167889Exec_Master_Log_Pos: 445167889Seconds_Behind_Master: 0 #和上面一樣yejr@imysql.com [(none)]> show processlist; show slave statusG| 6 | system user | | NULL | Connect | 22004248 | Waiting for master to send event | NULL || 7 | system user | | NULL | Connect | 16 | Has read all relay log;**Read_Master_Log_Pos: 445167889Exec_Master_Log_Pos: 445167889Seconds_Behind_Master: 0 #這時有活躍SQL了,Time值是和 Seconds_Behind_Master 一樣,即SQL執行緒比IO執行緒“慢”了1秒yejr@imysql.com [(none)]> show processlist; show slave statusG| 6 | system user | | NULL | Connect | 22004252 | Waiting for master to send event | NULL || 7 | system user | | floweradmin | Connect | 1 | Updating | update **Read_Master_Log_Pos: 445182239Exec_Master_Log_Pos: 445175263Seconds_Behind_Master: 1 #和上面一樣yejr@imysql.com [(none)]> show processlist; show slave statusG| 6 | system user | | NULL | Connect | 22004254 | Waiting for master to send event | NULL || 7 | system user | | floweradmin | Connect | 1 | Updating | update **Read_Master_Log_Pos: 445207174Exec_Master_Log_Pos: 445196837Seconds_Behind_Master: 1

好了,最後我們說下如何正確判斷SLAVE的延遲情況:
1、首先看 Relay_Master_Log_File 和 Master_Log_File 是否有差異;
2、如果Relay_Master_Log_File 和 Master_Log_File 是一樣的話,再來看Exec_Master_Log_Pos 和 Read_Master_Log_Pos 的差異,對比SQL執行緒比IO執行緒慢了多少個binlog事件;
3、如果Relay_Master_Log_File 和 Master_Log_File 不一樣,那說明延遲可能較大,需要從MASTER上取得binlog status,判斷當前的binlog和MASTER上的差距;

因此,相對更加嚴謹的做法是:
在第三方監控節點上,對MASTER和SLAVE同時發起SHOW BINARY LOGS和SHOW SLAVE STATUSG的請求,最後判斷二者binlog的差異,以及 Exec_Master_Log_Pos 和 Read_Master_Log_Pos 的差異。

例如:
在MASTER上執行SHOW BINARY LOGS 的結果是:

?

123456 +------------------+--------------+| Log_name | File_size |+------------------+--------------+| mysql-bin.000009 | 1073742063 || mysql-bin.000010 | 107374193 |+------------------+--------------+

而在SLAVE上執行SHOW SLAVE STATUSG 的結果是:

?

1234567891011 Master_Log_File: mysql-bin.000009 Read_Master_Log_Pos: 668711237Relay_Master_Log_File: mysql-bin.000009Slave_IO_Running: YesSlave_SQL_Running: Yes***Exec_Master_Log_Pos: 654409041 ***Seconds_Behind_Master: 3296***

這時候,SLAVE實際的延遲應該是:
mysql-bin.000009 這個binlog中的binlog position 1073742063 和 SLAVE上讀取到的binlog position之間的差異延遲,即:

1073742063 - 654409041 = 419333022 個binlog event

並且還要加上 mysql-bin.000010這個binlog已經產生的107374193個binlog event,共

107374193 + 419333022 = 526707215 個binlog event

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/758/viewspace-2811091/,如需轉載,請註明出處,否則將追究法律責任。

相關文章