MySQL에서 slave 모니터링의 지연 상황 분석

MySQL 복제 환경에서는 일반적으로 SecondsBehind_Master 값은 SLAVE 지연을 판단합니다.이렇게 하는 것은 대부분 받아들일 수 있지만 정확하지 않으니 더 많은 요소를 고려해야 한다.
먼저 SLAVE의 상태를 살펴보겠습니다.

   [email protected] [(none)]> 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_마스터의 값은 3296, 즉 SLAVE가 최소 3296초 지연된 것이다.
SLAVE에서 2개의 REPLICATION 프로세스 상태를 살펴보겠습니다.

   [email protected] [(none)]> 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 작업을 계속 수행하는 것을 볼 수 있다. 타임의 값이 3293이라는 것을 알 수 있다. 마치 이 UPDATE 작업이 3293초 동안 실행된 것처럼 보인다. 일반적인 SQL일 뿐이다. 이렇게 오래 걸리지 않을 것이다.실제로 REPLICATION 프로세스에서Time 이 열의 값은 몇 가지 상황이 있을 수 있다. 1. SQL 스레드가 현재 실행하고 있는binlog(실제로는 relay log) 중의timestamp과 IO 스레드의 최신 timestamp의 차이값. 이것이 바로 일반적으로 사람들이 생각하는 SecondsBehind_Master 값은 어떤 SQL의 실제 실행 소모 시간이 아니다.2. SQL 스레드가 현재 활성화된 SQL이 실행되지 않으면 Time 값은 SQL 스레드의 idle time입니다.
한편, IO 스레드의 타임 값은 이 스레드가 시작된 이래 총 시간(몇 초)이다. 만약에 시스템 시간이 IO 스레드가 시작된 후에 수정이 발생하면 이 타임 값은 마이너스가 되거나 매우 커질 수 있다.
다음 상태를 살펴보겠습니다.

#  pager，        status 
[email protected] [(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   0
[email protected] [(none)]> 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

#     
[email protected] [(none)]> 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 
[email protected] [(none)]> 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

#     
[email protected] [(none)]> 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、먼저 RelayMaster_Log_File 및 MasterLog_File에 차이가 있는지 여부2、RelayMaster_Log_File 및 MasterLog_File가 같으면 ExecMaster_Log_Pos 및 ReadMaster_Log_Pos의 차이로 SQL 스레드가 IO 스레드보다 몇 개의 binlog 이벤트가 느린 것을 비교한다.3、RelayMaster_Log_File 및 MasterLog_File가 다르면 지연이 비교적 클 수 있으므로 MASTER에서 binlog status를 얻어 현재의 binlog와 MASTER의 차이를 판단해야 한다.
따라서 비교적 엄격한 방법은 제3자 모니터링 노드에서 MASTER와 SLAVE에 대해 SHOW BINARY LOGS와 SHOW SLAVE STATUS\G의 요청을 동시에 실시하고 마지막으로 양자binlog의 차이와 Exec 를 판단하는 것이다.Master_Log_Pos 및 ReadMaster_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 이벤트, 총
107374193 + 419333022 = 526707215 binlog 이벤트