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 | 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 秒
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: 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 | 1 | Updating | update **
Read_Master_Log_Pos: 445207174
Exec_Master_Log_Pos: 445196837
Seconds_Behind_Master: 1

好了,最后我们说下如何正确判断 SLAVE 的延迟情况:

1、首先看 Relay_Master_Log_FileMaster_Log_File 是否有差异;

2、如果 Relay_Master_Log_FileMaster_Log_File 是一样的话,再来看 Exec_Master_Log_PosRead_Master_Log_Pos 的差异,对比 SQL 线程比 IO 线程慢了多少个 binlog 事件;

3、如果 Relay_Master_Log_FileMaster_Log_File 不一样,那说明延迟可能较大,需要从 MASTER 上取得 binlog status,判断当前的 binlog 和 MASTER 上的差距;

因此,相对更加严谨的做法是:

在第三方监控节点上,对 MASTER 和 SLAVE 同时发起 SHOW BINARY LOGSSHOW SLAVE STATUS\G 的请求,最后判断二者 binlog 的差异,以及 Exec_Master_Log_PosRead_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 - 654409041 = 419333022 个 binlog event

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

107374193 + 419333022 = 526707215 个 binlog event

后记更新:

1、可以在 MASTER 上维护一个监控表,它只有一个字段,存储这最新最新时间戳(高版本可以采用 event_scheduler 来更新,低版本可以用 cron 结合自动循环脚本来更新),在 SLAVE 上读取该字段的时间,只要 MASTER 和 SLAVE 的系统时间一致,即可快速知道 SLAVE 和 MASTER 延迟差了多少。不过,在高并发的系统下,这个时间戳可以细化到毫秒,否则哪怕时间一致,也是有可能会延迟数千个 binlog event 的。

2、网友(李大玉,QQ:407361231)细心支出上面的计算延迟有误,应该是 mysql-bin.000009 的最大事件数减去已经被执行完的事件数,即 1073742063 – 654409041= 419333022 个 binlog event,再加上 mysql-bin.000010 这个 binlog 已经产生的 107374193 个 binlog event,共 526707215 个 binlog event。

原创声明,本文系作者授权云+社区-专栏发表,未经许可,不得转载。

如有侵权,请联系 yunjia_community@tencent.com 删除。

编辑于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏MYSQL轻松学

MYSQL RR隔离级别下MVCC及锁解读

MVCC(Multi-Version Concurrent Control):多版本并发控制,只作用于RC和RR隔离级别,主要是为了避免脏读、非重复读,而非幻读...

3918
来自专栏java达人

数据库事务与隔离级别

事务(transaction)是数据库管理系统的执行单位,可以是一个数据库操作(如Select操作)或者是一组操作序列。事务ACID属性,即原子性(Atomic...

1836
来自专栏Clive的技术分享

Mysql锁相关锁的分类锁的适用场景MyISAM表锁MyISAM写阻塞读的例子MyISAM读阻塞写例子MyISAM并发插入MyISAM读写并发MyISAM锁调度调节MyISAM锁调度行为解决读写冲突的

锁类型/引擎 行锁 表锁 页锁 MyISAM 有 InnoDB 有 有 BDB(被InnoDB取代) 有 有 锁的分类 表...

3615
来自专栏数据库

记一次排查DB死锁的分析

文章摘要 在线上环境遇到数据库死锁问题该如何分析并解决问题呢? 虽然很多童鞋在学数据库课程时都了解数据库隔离级别、死锁和事务等概念,但在测试/线上环境遇到死锁却...

1808
来自专栏李明的专栏

主从复制延迟排查

目前生产环境中主从延迟常见于 RO 实例及备库中,由于历史原因目前部分用户的备库开启了只读服务,后续这块我们会逐步推荐客户使用 RO 实例。

1491
来自专栏散尽浮华

mysql主从同步(4)-Slave延迟状态监控

之前部署了mysql主从同步环境(Mysql主从同步(1)-主从/主主环境部署梳理),针对主从同步过程中slave延迟状态的监控梳理如下: 在mysql日常维护...

2487
来自专栏杨建荣的学习笔记

归档和非归档模式下ORA-01145错误的解决方法(87天)

总结了一下,在归档和非归档的场景下,ora-01145这个错误可能有如下三种情况: 1.off line tablespace --在非归档模式下尝试ofli...

2996
来自专栏magicsoar

Mysql Innodb 锁机制 select * from table where?insert?delete?update?3个insert的死锁2个update的死锁3个以上delete的死

latch与lock latch 可以认为是应用程序中的锁,可以称为闩锁(轻量级的锁) 因为其要求锁定的时间必须要非常短,若持续时间长,则会导致应用性能非常差,...

2648
来自专栏码农二狗

数据库事务隔离级别

1414
来自专栏MYSQL轻松学

insert事务产生duplicate key error引发的死锁分析

先看程序报错: 2017-06-12 21:18:40.856 [ForkJoinPool.commonPool-worker-12] ERROR com....

3974

扫码关注云+社区