MySQL中slave监控的延迟情况分析
在MySQL复制环境中，我们通常只根据Seconds_Behind_Master的值来判断SLAVE的延迟。这么做大部分情况下尚可接受，但并不够准确，而应该考虑更多因素。
首先，我们先看下SLAVE的状态：
yejr@imysql.com[(none)]>showslavestatus\G ***************************1.row*************************** Slave_IO_State:Waitingformastertosendevent *** 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)]>showfullprocesslist\G ***************************1.row*************************** Id:6 User:systemuser Host: db:NULL Command:Connect Time:22005006 State:Waitingformastertosendevent Info:NULL ***************************2.row*************************** Id:7 User:systemuser 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（实际上是relaylog）中的timestamp和IO线程最新的timestamp的差值，这就是通常大家认为的Seconds_Behind_Master值，并不是某个SQL的实际执行耗时；
2、SQL线程当前如果没有活跃SQL在执行的话，Time值就是SQL线程的idletime；
而IO线程的Time值则是该线程自从启动以来的总时长（多少秒），如果系统时间在IO线程启动后发生修改的话，可能会导致该Time值异常，比如变成负数，或者非常大。
来看下面几个状态：
#设置pager，只查看关注的几个status值 yejr@imysql.com[(none)]>pagercat|egrep-i'systemuser|Exec_Master_Log_Pos|Seconds_Behind_Master|Read_Master_Log_Pos' #这是没有活跃SQL的情况，Time值是idletime，并且Seconds_Behind_Master为0 yejr@imysql.com[(none)]>showprocesslist;showslavestatus\G |6|systemuser||NULL|Connect|22004245|Waitingformastertosendevent|NULL| |7|systemuser||NULL|Connect|13|Hasreadallrelaylog;** Read_Master_Log_Pos:445167889 Exec_Master_Log_Pos:445167889 Seconds_Behind_Master:0 #和上面一样 yejr@imysql.com[(none)]>showprocesslist;showslavestatus\G |6|systemuser||NULL|Connect|22004248|Waitingformastertosendevent|NULL| |7|systemuser||NULL|Connect|16|Hasreadallrelaylog;** Read_Master_Log_Pos:445167889 Exec_Master_Log_Pos:445167889 Seconds_Behind_Master:0 #这时有活跃SQL了，Time值是和Seconds_Behind_Master一样，即SQL线程比IO线程“慢”了1秒 yejr@imysql.com[(none)]>showprocesslist;showslavestatus\G |6|systemuser||NULL|Connect|22004252|Waitingformastertosendevent|NULL| |7|systemuser||floweradmin|Connect|1|Updating|update** Read_Master_Log_Pos:445182239 Exec_Master_Log_Pos:445175263 Seconds_Behind_Master:1 #和上面一样 yejr@imysql.com[(none)]>showprocesslist;showslavestatus\G |6|systemuser||NULL|Connect|22004254|Waitingformastertosendevent|NULL| |7|systemuser||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上取得binlogstatus，判断当前的binlog和MASTER上的差距；
因此，相对更加严谨的做法是：
在第三方监控节点上，对MASTER和SLAVE同时发起SHOWBINARYLOGS和SHOWSLAVESTATUS\G的请求，最后判断二者binlog的差异，以及Exec_Master_Log_Pos和Read_Master_Log_Pos的差异。
例如：
在MASTER上执行SHOWBINARYLOGS的结果是：
+------------------+--------------+ |Log_name|File_size| +------------------+--------------+ |mysql-bin.000009|1073742063| |mysql-bin.000010|107374193| +------------------+--------------+
而在SLAVE上执行SHOWSLAVESTATUS\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中的binlogposition1073742063和SLAVE上读取到的binlogposition之间的差异延迟，即：
1073742063-654409041=419333022个binlogevent
并且还要加上mysql-bin.000010这个binlog已经产生的107374193个binlogevent，共
107374193+419333022=526707215个binlogevent