近期由于特殊原因有一台主库宕机了一个小时没有处理,说起来这是个挺不好啥意思的事情,但是由于这个事情反而发现个比较诡异的情况,那就是在主库宕机一个小时候后,监控才发出从库IO thread中断的报警,也就是说在那一个小时内,从库的同步状态是双Yes的。这是多么诡异的现象,那么这是因为什么原因呢?我们下来分析一下。
众所周知,MySQL的同步是异步完成的,其中IO thread负责接收从主库dump的binlog到从库上生成relay log,然后SQL thead负责解析relay log后在从库上进行重放来完成同步。这个2步是完全异步的,单独停止其中一个,并不会影响另一个的正行工作。当这两个thread都正常工作的时候,show slave status会显示双Yes状态,表示同步正常。
提到这2个状态就不得不提另外一个非常重要的状态,那就是seconds_behind_master,一般意义上说代表着从库和主库的延迟时间,数值越高意味着延迟越大,但是当SBM为0的时候,并不真正意味着从库已经追上主库了。相信大家都遇到过,从监控图上看,SBM一直都是0,在某一个时间点之后突然就变得非常高。这是由于在主库上执行了一个非常大的event,在这个event在主库上没执行完毕的时候,从库的SBM会显示为0,而当主库执行完毕传到从库上开始执行的时候,就会显示SBM非常巨大了。官方的文档解释如下:
It is also possible that transient values for Seconds_Behind_Master may not reflect the situation accurately. When the slave SQL thread has caught up on I/O, Seconds_Behind_Master displays 0; but 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. This is especially likely when the events have old timestamps; in such cases, if you execute SHOW SLAVE STATUS several times in a relatively short period, you may see this value change back and forth repeatedly between 0 and a relatively large value.
想要验证的同学可以按照如下的方式进行测试,可以100%复现。
1、首先搭建一个主从关系的数据库集群2、在主库上随便建立一个表。3、执行如下语句
insert into aaaselect 1 from aaa where x = 1 or sleep(10);
以上语句会在主库上执行一段时间4、在执行时间内,在从库上show slave status会看到SBM全部都是0。(但是这时候其实已经是不同步的了)5、等待在主库执行完毕之后,我们就会看到SBM变成一个较大的数字了。
那么这个seconds_behind_master的值到底是怎么计算出来的呢?官方的解释如下:
Seconds_Behind_Master: The number of seconds that the slave SQL thread is behind processing the master binary log
也就是说,是SQL thread在执行IO thread dump下来的relay log的时间差。大家都知道relay log中event记录的时间戳是主库上的时间戳,而SQL thread的时间戳是从库上的,也就是说,如果主库和从库的时间是一致的,那么这个SBM代表的确实是从库延后主库的一个时间差。但是如果主库和从库的时间不是一致的,那么这个SBM的意义就基本不存在了。我们可以做如下的测试。
1、还是上的测试环境2、在从库上修改时间设置date -s“+1hour”3、执行上面带有sleep的语句4、等待主库执行完毕之后在从库执行
show slave status5、可以看到,这时候的SBM的数值至少是一个大于3600的数值
这也就验证了我们上面的观点。
说完了seconds_behind_master,我们继续来说IO thread和SQL thread的双Yes假象的问题。
我们进行了如下实验:
1、正常shutdown,结果状态单no2、killmysqld,结果状态单no3、kill -9mysqld,结果状态双Yes4、reboot 服务器,结果状态双Yes
可以看出,只有在重启服务器的时候(也就是我们今天越到的这个场景),从库的状态是双Yes的。推测在服务器重启的时候,作为从库是不知道主库是已经宕机还是并没有写入,所以一直保持双Yes状态,一直等待到一定时间点(预估一个小时)之后重试的时候才会真正发现主库已经宕机了。
有如下3个重要参数控制着这个过程slave-net-timeout,master-connect-retry,master-retry-count。根据官方文档解释如下
slave-net-timeout意味着在没有得到更多数据之后slave等待的时间,默认值3600s
master-connect-retry意味着每次和主库建立链接重试的等待时间,默认值为60s
master-retry-count意味着从库同主库建立链接的重试次数,默认86400次
而这个重试机制是按照如下方法运行的,当从库发现从主库上无法获得更多的暑假了,就会等待slave-net-timeout时间,然后将IO thread置为no状态,接着开始尝试重建建立连接,每次建立失败之后等待master-connect-retry时间,一直重试master-retry-count次。
所以,由于以上的原因,就造成了我们今天遇到的双Yes状态假象,其实当时主库已经宕机了很久了。
解决的办法其实很简单,将slave-net-timeout降低即可,比如修改成5分钟或者1分钟,这样可以缩短进入重试机制的等待时间,可以尽早发现问题。
另,感谢@zolker提醒, MySQL5.5之后增加了relication的heartbeat机制,可以在从库上通过执行show global status like 'Slave_received_heartbeats'进行查看。
当主库没有写入的时候会按照间隔时间跳动,可以依据此进行一定的health-check。
STOP SLAVE;
CHANGE MASTER TO master_heartbeat_period= milliseconds;
START SLAVE;
SHOW STATUS like 'slave_heartbeat period'
SHOW STATUS like 'slave_received_heartbeats'
参考文档: