Latency of slave monitoring in MySQL _ MySQL

This article mainly introduces the latency analysis of slave monitoring in MySQL, which is mainly used in the MySQL replication environment. If you need it, you can refer to the MySQL replication environment, we usually only judge the SLAVE latency based on the value of Seconds_Behind_Master. This is acceptable in most cases, but not accurate enough. More factors should be considered.

First, let's take a look at the SLAVE status:

The Code is as follows:

Yejr@imysql.com [(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
***

We can see that the value of Seconds_Behind_Master is 3296, that is, the SLAVE delay is at least 3296 seconds.

Let's take a look at the two REPLICATION process statuses on the SLAVE:

The Code is as follows:

Yejr@imysql.com [(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 **

We can see that the SQL thread has been executing the UPDATE operation, and noticed that the value of Time is 3293. It seems that this UPDATE operation has been executed for 3293 seconds, just a common SQL statement. It certainly won't take so long.
In fact, in the REPLICATION process, the value of the Time column may have several situations:
1. The difference between the timestamp in the current binlog (actually the relay log) executed by the SQL thread and the latest timestamp in the IO thread. This is the Seconds_Behind_Master value that we generally think, it is not the actual execution time of an SQL statement;
2. If no active SQL statement is being executed by the SQL thread, the Time value is the idle time of the SQL thread;

The Time value of the IO thread is the total Time (in seconds) of the thread since it was started. If the system Time is modified after the IO thread is started, this Time value may be abnormal, for example, negative or very large.

Let's look at the following statuses:

# Set pager to only view the following status values yejr@imysql.com [(none)]> pager cat | egrep-I 'System user | Exec_Master_Log_Pos | Seconds_Behind_Master | Read_Master_Log_Pos '# This is the case where there is no active SQL, the Time value is idle time, And Seconds_Behind_Master is the 0yejr@imysql.com 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: 445167889Exec_Master_Log_Pos: 445167889Seconds_Behind_Master: 0 # The same yejr@imysql.com as above [(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: 445167889Exec_Master_Log_Pos: 445167889Seconds_Behind_Master: 0 # There is an active SQL statement. The Time value is the same as Seconds_Behind_Master, that is, the SQL thread is "slower" than the IO thread for 1 second yejr@imysql.com [(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: 445182239Exec_Master_Log_Pos: 445175263Seconds_Behind_Master: 1 # Same yejr@imysql.com as above [(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: 445207174Exec_Master_Log_Pos: 445196837Seconds_Behind_Master: 1

Now, let's talk about how to correctly judge the latency of SLAVE:
1. check whether there are differences between Relay_Master_Log_File and Master_Log_File;
2. If Relay_Master_Log_File is the same as Master_Log_File, let's look at the differences between Exec_Master_Log_Pos and Read_Master_Log_Pos to compare the number of binlog events that the SQL thread is slower than the IO thread;
3. If Relay_Master_Log_File is different from Master_Log_File, the latency may be large. You need to obtain the binlog status from the MASTER to determine the gap between the current binlog and the MASTER;

Therefore, a more rigorous approach is:
On a third-party monitoring node, the MASTER and SLAVE both initiate the show binary logs and show slave status \ G requests, and finally determine the differences between the binlog and Exec_Master_Log_Pos and Read_Master_Log_Pos.

For example:
The result of executing show binary logs on the MASTER is:

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

The result of executing show slave status \ G on SLAVE is:

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***

At this time, the actual latency of SLAVE should be:
The difference delay between binlog position 1073742063 in the binlog of the mysql-bin.000009 and the binlog position read on the SLAVE, namely:

1073742063-654409041 = 419333022 binlog events

And also add the mysql-bin.000010 this binlog has generated 107374193 binlog events, a total

107374193 + 419333022 = 526707215 binlog events