Slave latency monitoring in MySQL replication

The slave is usually judged based on the value of the Seconds_behind_master. This is acceptable in most cases, but is not accurate enough and should be considered for more factors.

View the status of slave

Mysql> Show slave status\g*************************** 1. Row *************************** slave_io_state:waiting for master to send event Master_hos              t:192.168.0.20 Master_user:repl master_port:3306 connect_retry:60 master_log_file:mysql-bin.000150 read_master_log_pos:226326418 Relay_log_file:abce-rel ay-bin.000003 relay_log_pos:77106856 relay_master_log_file:mysql-bin.000149 Slave_io_r Unning:yes Slave_sql_running:yes Replicate_Do_DB:Replicate_Ignore_DB:Repl                    Icate_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:104629291          3 relay_log_space:330964012 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:30510master_ssl_verify_server_cert:no last_io_errno:0 Last_io_ error:last_sql_errno:0 Last_SQL_Error:Replicate_Ignore_Server_Ids:Master_S  Erver_id:11 row in Set (0.00 sec) mysql>

As can be seen from the query results, slave is 30,510 seconds behind the master (that is, the value of Seconds_behind_master)

Check out what the replication process on slave is doing:

mysql> show full processlist\g*************************** 1. Row ************ Id:4 user:system User Host:db:NULLCommand:Connect time:6018 state:waiting for Maste R to send event info:null*************************** 2. Row *************************** id:5 user:system User Host:db:abceCommand:Connect time:30501 State: Updating info:delete from s_item_e where (ng_user_id = 23880 and DT _shift_date in (' 2017-10-30 00:00:00 ', ' 2017-10-29 00:00:00              ') or (ng_user_id = 24853 and dt_shift_date in            (' 2017-10-30 00:00:00 ', ' 2017-10-29 00:00:00 ') )......

The SQL thread is doing the updating operation by deleting the data from the table. The value of time is 30501. Normally simple SQL does not execute for 30,501 seconds.

In the replication process, the value of the time column may also have several situations:
1, SQL thread currently executing binlog (actually relay log) in the timestamp and IO thread the latest timestamp difference, this is usually considered seconds_behind_master value, Not the actual execution time of some SQL;
2, SQL thread currently if there is no active SQL execution, the time value is the SQL thread idle time;

The time value of the IO thread, however, is the total length of time (in seconds) since the thread was started, which can cause the timing value to be abnormal, such as a negative number, or very large if the system is modified after the IO thread has started.

Delayed monitoring can be performed in the following order:

1. First compare the difference between Read_master_log_pos and Master_log_file 2. If Relay_master_log_file and Master_log_file are the same, look at Exec_master_log. The difference between _pos and read_master_log_pos, compared to how many binlog events the SQL thread slows than the IO thread; 3. If Relay_master_log_file and master_log_file are not the same, the delay may be large, Need to obtain Binlog status from master, judge the difference between the current binlog and master;

　　

To view binary logs for the main library:

mysql> SHOW BINARY logs;+------------------+------------+| Log_name         | File_size  |+------------------+------------+| mysql-bin.000142 | 1073778812 | | mysql-bin.000143 | 1073798740 | | mysql-bin.000144 | 1073910052 | | mysql-bin.000145 | 1073781405 | | mysql-bin.000146 | 1073845859 | | mysql-bin.000147 | 1073746199 | | mysql-bin.000148 | 1073863295 | | mysql-bin.000149 | 1073822822 | | mysql-bin.000150 |  

The calculation delay should be the maximum number of events mysql-bin.000149 minus the number of events that have been executed.
That is, 1073822822-1046292913 = 27,529,909 binlog event, plus mysql-bin.000150 this binlog has produced 226,343,255 Binlog event, A total of 226,343,255 Binlog event. namely: 1073822822-1046292913 + 226343255

You can also set pager during the viewing process to see only a few of the status values that follow:

Mysql> Pager Cat | Egrep-i ' System user| exec_master_log_pos| seconds_behind_master| Read_master_log_pos ' PAGER set to ' cat | Egrep-i ' System user| exec_master_log_pos| seconds_behind_master| Read_master_log_pos ' mysql> at this time has an active Sql,time value is 30583,seconds_behind_master is 30565 mysql>  show processlist; Show slave status\g|  4 | System user |           | NULL   | Connect |  7168 | Waiting for Master to send event | NULL                                                                                                 | |  5 | System user |           | ABCE   | Connect | 30583 | Updating                         | Delete from S_item_e3 rows in Set (0.00 sec)          read_master_log_pos:226364447          Exec_master_log_ pos:1057661705        

　　

Slave latency monitoring in MySQL replication