mysql slave 定时器_[MySQL FAQ]系列 — MySQL复制中slave延迟监控

在MySQL复制环境中，我们通常只根据 Seconds_Behind_Master 的值来判断SLAVE的延迟。这么做大部分情况下尚可接受，但并不够准确，而应该考虑更多因素。

首先，我们先看下SLAVE的状态：

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

***

可以看到 Seconds_Behind_Master 的值是 3296，也就是SLAVE至少延迟了 3296 秒。

我们再来看下SLAVE上的2个REPLICATION进程状态：

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

可以看到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值

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

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

#和上面一样

yejr@imysql.com [(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 | | 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秒

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

Read_Master_Log_Pos: 445182239

Exec_Master_Log_Pos: 445175263

Seconds_Behind_Master: 1

#和上面一样

yejr@imysql.com [(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 | | 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 - 668711237 = 405030826 个binlog event

并且还要加上 mysql-bin.000010这个binlog已经产生的107374193个binlog event，共

107374193 + 405030826 = 512405019 个binlog event

===============================================================================

如果还有什么问题，欢迎加入我的QQ群(125572178、272675472)讨论。

===============================================================================

题图：徐庶

徐庶，字元直。东汉末年刘备帐下人物，后归曹操，并仕于曹魏。徐庶本名福，寒门子弟，早年为人报仇，被同党救出后改名徐庶，求学于儒家学舍。后中州兵起，与同郡石广元避难于荆州，与司马徽、诸葛亮、崔州平等人为友。刘备屯驻新野时，徐庶前往投奔，并向刘备推荐诸葛亮。曹操南下时因母亲被曹操所掳获，徐庶不得已辞别刘备，进入曹营。后来这件事被艺术加工，“身在曹营心在汉”、“徐庶进曹营，一言不发”等被广为流传。而徐庶也成为孝子的典范被称赞。

徐庶对刘备最大的帮助就是推荐了师弟诸葛亮，向明主推荐比自己更高明的能人，这种胸怀并不是一般人所具备，而更多的人是刻意在领导面前表现自己，利用职权打压比自己更有能力的人。单就这点，徐庶就值得我们当今很多人学习。