Mysql主從同步之Slave延遲狀態監控實例講解

針對主從同步過程中slave延遲狀態的監控梳理如下:

在mysql日常維護工作中,對於主從復制的監控主要體現在:

1)檢查數據是否一致;

2)監控主從同步延遲,同步延遲的檢查工作主要從下面兩方面著手:

1.一般的做法就是根據Seconds_Behind_Master的值來判斷slave的延遲狀態。

可以通過監控show slave status\G命令輸出的Seconds_Behind_Master參數的值來判斷,是否有發生主從延時。

mysql> show slave status\G;  
*************************** 1. row ***************************  
Slave_IO_State: Waiting for master to send event  
Master_Host: 192.168.1.101  
Master_User: slave  
Master_Port: 3306  
Connect_Retry: 60  
Master_Log_File: mysql-bin.000004  
Read_Master_Log_Pos: 761249  
Relay_Log_File: mysql-relay-bin.000008  
Relay_Log_Pos: 761408  
Relay_Master_Log_File: mysql-bin.000004  
Slave_IO_Running: Yes  
Slave_SQL_Running: Yes  
Replicate_Do_DB: huanqiu,huanpc  
Replicate_Ignore_DB: mysql  
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: 761249  
Relay_Log_Space: 761620  
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: 0  
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: 101  
Master_UUID: b667a58f-d6e0-11e6-8c0a-fa163e2d66ac  
Master_Info_File: /data/mysql/data/master.info  
SQL_Delay: 0  
SQL_Remaining_Delay: NULL  
Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it  
Master_Retry_Count: 86400  
Master_Bind:  
Last_IO_Error_Timestamp:  
Last_SQL_Error_Timestamp:  
Master_SSL_Crl:  
Master_SSL_Crlpath:  
Retrieved_Gtid_Set:  
Executed_Gtid_Set:  
Auto_Position: 0  
1 row in set (0.00 sec)  
   
ERROR:  
No query specified  

以上是show slave status\G的輸出結果,需要監控下面三個參數:

   1)Slave_IO_Running:該參數可作為io_thread的監控項,Yes表示io_thread的和主庫連接正常並能實施復制工作,No則說明與主庫通訊異常,多數情況是由主從間網絡引起的問題;

   2)Slave_SQL_Running:該參數代表sql_thread是否正常,YES表示正常,NO表示執行失敗,具體就是語句是否執行通過,常會遇到主鍵重復或是某個表不存在。

   3)Seconds_Behind_Master:是通過比較sql_thread執行的event的timestamp和io_thread復制好的event的timestamp(簡寫為ts)進行比較,而得到的這麼一個差值;

        NULL—表示io_thread或是sql_thread有任何一個發生故障,也就是該線程的Running狀態是No,而非Yes。

        0 — 該值為零,是我們極為渴望看到的情況,表示主從復制良好,可以認為lag不存在。

        正值 — 表示主從已經出現延時,數字越大表示從庫落後主庫越多。

        負值 — 幾乎很少見,我隻是聽一些資深的DBA說見過,其實,這是一個BUG值,該參數是不支持負值的,也就是不應該出現。

—————————————————————————————————————————–

Seconds_Behind_Master的計算方式可能帶來的問題:

relay-log和主庫的bin-log裡面的內容完全一樣,在記錄sql語句的同時會被記錄上當時的ts,所以比較參考的值來自於binlog,其實主從沒有必要與NTP進行同步,也就是說無需保證主從時鐘的一致。其實比較動作真正是發生在io_thread與sql_thread之間,而io_thread才真正與主庫有關聯,於是,問題就出來瞭,當主庫I/O負載很大或是網絡阻塞,io_thread不能及時復制binlog(沒有中斷,也在復制),而sql_thread一直都能跟上io_thread的腳本,這時Seconds_Behind_Master的值是0,也就是我們認為的無延時,但是,實際上不是,你懂得。這也就是為什麼大傢要批判用這個參數來監控資料庫是否發生延時不準的原因,但是這個值並不是總是不準,如果當io_thread與master網絡很好的情況下,那麼該值也是很有價值的。之前,提到Seconds_Behind_Master這個參數會有負值出現,我們已經知道該值是io_thread的最近跟新的ts與sql_thread執行到的ts差值,前者始終是大於後者的,唯一的肯能就是某個event的ts發生瞭錯誤,比之前的小瞭,那麼當這種情況發生時,負值出現就成為可能。

—————————————————————————————————————————–

簡單來說,就是監控slave同步狀態中的:

1)Slave_IO_Running、Slave_SQL_Running狀態值,如果都為YES,則表示主從同步;反之,主從不同步。

2)Seconds_Behind_Master的值,如果為0,則表示主從同步不延時,反之同步延時。

2.上面根據Seconds_Behind_Master的值來判斷slave的延遲狀態,這麼做在大部分情況下尚可接受,但其實是並不夠準確的。對於Slave延遲狀態的監控,還應該做到下面的考慮:

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

mysql> show slave status\G;

*************************** 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進程狀態:

mysql> show full processlist\G;

*************************** 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值異常,比如變成負數,或者非常大。

來看下面幾個狀態:

設置pager,隻查看關註的幾個status值

mysql> pager cat | egrep -i 'system user|Exec_Master_Log_Pos|Seconds_Behind_Master|Read_Master_Log_Pos';

這是沒有活躍SQL的情況,Time值是idle time,並且 Seconds_Behind_Master 為 0

mysql> show processlist; show slave status\G;

| 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: 445167889

Exec_Master_Log_Pos: 445167889

Seconds_Behind_Master: 0

多執行幾次,看下是否有活躍的SQL

mysql> show processlist; show slave status\G;

| 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: 445167889

Exec_Master_Log_Pos: 445167889

Seconds_Behind_Master: 0

發現有活躍SQL瞭,Time值是和 Seconds_Behind_Master 一樣,即SQL線程比IO線程“慢”瞭1秒

mysql> show processlist; show slave status\G;

| 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: 445182239

Exec_Master_Log_Pos: 445175263

Seconds_Behind_Master: 1

再次查看下狀態

mysql> show processlist; show slave status\G;

| 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: 445207174

Exec_Master_Log_Pos: 445196837

Seconds_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 STATUS\G的請求,最後判斷二者binlog的差異,以及 Exec_Master_Log_Pos 和Read_Master_Log_Pos 的差異。

例如:

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

+——————+————–+

| Log_name | File_size |

+——————+————–+

| mysql-bin.000009 | 1073742063 |

| mysql-bin.000010 | 107374193 |

+——————+————–+

而在slave上執行SHOW slave STATUS\G 的結果是:

Master_Log_File: mysql-bin.000009

Read_Master_Log_Pos: 668711237

Relay_Master_Log_File: mysql-bin.000009

slave_IO_Running: Yes

slave_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

發佈留言