本周在某次开会的时候,忽然收到了大量的 MySQL Seconds_Behind_Master 落后的报警轰炸(落后时间随机,几百到几万秒不等),但是当我们的值班 DBA 登录 MySQL 通过 show slave status\G 查看时,发现都是 0,通常我们认为这个时候复制是正常的。那么是什么情况导致了报警的发生呢?

DBA 值班同学也比较没有头绪,我们首先做了以下几件事情:

  1. 确认监控插件是否变更?收到的答复是没有;

  2. 我们自己是否有变更?收到的答复是没有。

事后打脸了,有一位同学做了报警策略的变更,从原 X 时间内只发送第 N 条报警修改成了 X 时间内只发送第 1 条报警。该策略的变更也会导致该报警的轰炸,但是他变更的时间是在报警轰炸之后,跟此次报警轰炸原因没有正相关;

  1. 登录多个实例确认都是误报后,先通告产品,明确是误报事件,让产品不用担心,等待 DBA 查明原因;

接下来我们会议正常进行,由某位 DBA 同学对此问题进行持续跟进,这个时候了解到某报警系统正在维护,猜测与他们有关系。但是即使是与他们有关系,这个落后的时间又是如何得来的呢?暂时 DBA 值班同学也没有很好的 GET 到头绪,DBA 老司机可能当时不是特别在状态,有点懵。

刚好会议环节进入非重点环节,偷偷转移精力排查了一下,做为 DBA 门外汉,首先想到的是我要确认是不是 MySQL show slave status 里真的出现了随机的落后数值,所以我做了最原始的一件事情:写了一个 2 秒执行一次 show slave status 的脚本对 Secons_Behind_Master 进行检查,果然在脚本执行了几分钟后出现了非 0 的数值,且是一个较大的超出实际线上情况的数值。(这里已经确认了是 MySQL 本身会有这个情况出现)

接下来怎么办呢?门外汉的第一反应当然是查手册啦(手册大多数时候都是解毒良药),几乎是没有耗费时间的,直接在 MySQL 官方文档里关于这个问题的非常重要的一句说明:

when the slave I/O thread is still queuing up a new event,
Seconds_Behind_Master may show a large value until the SQL thread 
finishes executing the new event.

MySQL Replication 通常情况下有两个工作线程,I/O 线程用于获取 MySQL Master 的 Binlog,SQL 线程用于将获取到的 Binlog Events 在 Slave 从库上进行回放。

MySQL Replication示意图

上面的描述我们通过字面简单进行了理解:当 I/O 线程仍在排队等待一件新事件时,Seconds_Behind_Master 有可能返回一个较大的随机值,直到 SQL 线程完成该事件的重放。

那么这里我们已经可以确认了,MySQL 是会出现这个情况的,并且是正常的,至少这个报警轰炸是不用特别担心了。那为什么忽然就炸出来了呢,在后面几分钟后我们得到了几个信息,确认了原因:

  1. 该报警原先的设置是 X 时间内只发送第 N 条报警:X 时间内并不一定总会出现 >= N 次的随机 Seconds_Behind_Master 飙升(并且被监控插件获取到);即使出现 >= N 次,在 X 时间内也只会发送一条报警,所以这个问题一直并没有被注意到;
  2. 从报警平台的同事了解到,确实在维护过程中,报警策略匹配有问题,导致 X 时间内只发送第 N 条 这个策略没有生效,所有报警都发了出来;
  3. 如前述,某同事确实做了策略变更,该变更可以明确是错的,但跟上述的轰炸没有正相关。

这个时候我们整体的原因已经比较清楚了,恢复生效的策略,并同步通告相关产品具体的情况,让产品安心是我们服务的目标之一。

但这里也暴露了几个问题:

  1. 报警平台维护变更出现了一定的问题,导致策略失效;
  2. 部分 DBA 同学在某些环节对系统的了解并不够完整、也不够专业(我们都需要不断学习积累的,我自己也是学习中,能理解);
  3. DBA 同学在做策略变更的时候也没有在团队内部进行同步,存在管理和规范遵守上的问题;

以上问题需要我们进行反思,并在团队内进行解决。但是 MySQL Seconds_Behind_Master 是否还有监控的价值呢?对可能导致 Seconds_Behind_Master 异常的情况这里做个简单的总结:

  1. Replication 启动时,Slave 会在主库执行 SELECT UNIX_TIMESTAMP() 并进行主库和从库的系统时间差值对比,以避免由于系统时间差异对于 Seconds_Behind_Master 的时间产生影响。但如果是 Replication 启动后的时间异常,还是会对 Seconds_Behind_Master 产生影响,因此确保系统时间的同步非常重要(ntpd);
  2. 当 Master 和 Slave 间的网络较差时,I/O 线程不能快速的获取 Binlog Events,SQL 线程处理速度是有可能超过 I/O 线程的,那么这个时候即使是 0,也不代表主从同步是正常的。(良好的网络环境是主从同步的基础保障)
  3. 当 I/O 线程被关闭时,该值可能为 NULL。(可以理解为特殊情况);

Seconds_Behind_Master 怎么用?

结合以上情况,我认为 Seconds_Behind_Master 还是一个很重要的同步是否落后的参考值的,只是可能我们可以做得更完善一些,比如在获取的时候,可以通过二次获取进行判断,当获取到较大值时,再次获取一次当前值进行确认。

另外,如果需要较为严格的同步监控,建议通过 Binglog 的位置:

  • Master_Log_file/Read_Master_Log_Pos
  • Relay_Master_Log_File/Exec_Master_Log_Pos

进行判断,如果(Relay_Master_Log_File, Exec_Master_Log_Pos) 和 (Relay_Master_Log_File, Read_Master_Log_Pos)位置相等且 Seconds_Behind_Master=0,那么我们可以认为目前的同步是「同步」的。(开启 gtid 的话,比对 Executed_Gtid_Set 我认为也是没有毛病的)

The End

后续相关技术内容的总结,也会逐步更新至微信平台(微信目前确实也是技术内容流转的一个好渠道),欢迎关注个人公众号(也算给自己立个 flag 吧,希望 flag 永不倒):

公众号二维码

您可能还喜欢以下文章


关于我


热爱开源、分享。目前主要从事 MongoDB、MySQL、Redis 等数据库私有云 SaaS 相关运维、开发工作。