性能文章>MySQL-Seconds_behind_master 的精度误差>

MySQL-Seconds_behind_master 的精度误差原创

1年前
357158

前言

Seconds_behind_master 是我们观察主从延迟的一个重要指标。但任何指标所能表示的精度都是有限的。例如用精度只能到秒的指标去衡量毫秒级的表现就会产生非常大的误差。如果再以此误差去分析问题,就会让思维走上弯路。例如用 Seconds_behind_master 去评估 1s 内的主从延迟就是一个典型的例子。
 

问题现场

在一些问题的排查中,我们注意到一个很奇怪的现象。那就是相同配置的从库表现出来的主从延迟差距有将近 500ms。而这两个从库之间的差别就是所在的机房不一样 (和主库都不在同一个机房)。如下图所示:

70312513-CCBF-4BCF-9998-5C2CFE3E8F7D.png

 
 

网络问题

难道是网络问题?那我们 ping 一下吧,最多也就相差 1ms。那么还有 499ms 去哪里了呢,看来还得继续挖掘。
 
Seconds_behind_master 的取点数据
 
直觉上来说网络问题不可能导致 500ms 这么大的误差,而机器配置和 MySQL 版本又是一样的。这就让笔者不得不怀疑这个兼容数据的准确性。所以就先看看这个 500ms 是怎么计算出来的。 

A05CF236-1F64-4FF2-A923-50434205C45C.png

从监控取点数据来看从库 C 确实有主从延迟,不然为什么有那么多取点为 0 呢。
 
Seconds_behind_master 什么时候计算出来为 1
 
这时候笔者突然想到一个点,如果主从延迟一个是 501ms 一个是 499ms,那么 Seconds_behind_master 计算的时候会不会采用四舍五入法。501ms (>=500ms) 的就是 1,499 (<500ms) 的就是 0?为了了解这一问题,笔者就去翻了翻源码。 ###Seconds_behind_master 在 MySQL 中的计算源码 计算这个指标的代码有很多微妙的分支,应对了各种 corner case。在此笔者只列出和当前问题相关的源码。
 
long time_diff= ((long)(time(0) - mi->rli->last_master_timestamp)
                       - mi->clock_diff_with_master);
 
前面 time (0) - mi->rli->last_master_timestamp 明显就是指时间差。但是,我们要考虑到一个很容易被忽略的常识,也就是不同机器的时间戳是不一样的!

132FF2E1-7D72-4273-A1BF-74CEAE452742.png

 
那么很明显的,如果主从实际延迟是 0,但是计算的时候没有剔除掉机器时钟的差异。那么主从延迟就是 6s。源码中的 mi->clock_diff_with_master 就是去修正这个差距!而计算这个 clock_diff_with_master 就会引起不小的误差。
 

什么时候计算 clock_diff_with_master

 
笔者在源码中翻阅时候注意到 clock_diff_with_master 不是每次都去计算的,而是在主从连接上或者重连 (reconnect) 的那一刻去计算一次。
 
handle_slave_io
	/* 建立主从连接 */
	|->safe_connect(thd, mysql, mi)) 
	/* connected: 主从连接成功后,计算一下主从clock_diff_with_master */
	|->get_master_version_and_clock
 
这就自然会导致下面的现象,假设一旦 clock_diff_with_master 计算有了误差。那么这个误差就会一直存在,直到下次重连为止!
 

clock_diff_with_master 跨秒误差

 
接着笔者又注意到 clock_diff_with_master 精度只能到秒。那么自然就会出现下面这几种现象。为了简单起见,我们假设绝对时钟是从 0 开始,而且我们假设主从延迟是 0。只看精度误差所能造成的影响。
 
在实际主从延迟为 0 的情况下 clock_diff_with_master 计算出来是 - 1,Seconds_behind_master 计算为 1
 
尽管有 NTP,我们也不可能做到两台机器的时间戳在完全一致 (除非两台机器有铯原子钟,那基本就没有毫秒级的误差了)。两台机器之间出现几百毫秒甚至数秒的延迟非常正常。例如假设我当前从库的 clock 是 0.5s,主库的 clock 是 1s。那么由于计算精度 (只能到秒) 的原因,实际实际只有 0.5s 的时间差会放大到 1s。 

F4A132BB-4E8D-4DDF-AD2C-72EE7CE8C761.png

那么我们现在可以计算出来在这种情况下 Seconds_behind_master 的平均值,在这里有一个预先假设就是我们取监控点的时间是随机的。

0B9AB93B-1EA9-4670-ABB1-442D4E6EF610.png

 
在上图中我们可以看到,在我们取从库时钟 [0.5,1.5) 这个 1s 的时间段范围内。在前 0.5s,也就是 [0.5,1) 这个区间中我们计算出来的
Seconds_behind_master 是 0,而在 [1,1.5) 区间计算的确是 1 。那我们的平均值就可以计算出来为 (0.5*0+0.5*1)/(1.5-0.5)=0.5=500ms!
也就是说,在没有任何实际主从延迟的情况下,仅仅跨秒这一个因素就能造成好几百毫秒的误差。
 
实际主从延迟为 0 的情况下 clock_diff_with_master 计算为 0,Seconds_behind_master 计算为 - 1 并被校正为 0
 
另外一个有意思的点是,既然误差能加 1,自然也能减 1。也就是 Seconds_behind_master 计算为 - 1。这就会给观察人员造成一个错觉,从库比主库快!当然了 MySQL 源码考虑到了这一点,强制校正为 0。
 
在这里,笔者将主从连接的那一刻稍微往前偏移 0.1s,就可以构造出刚才说的现象,如下图所示: 
 

3846D14C-20F3-4F94-85E8-820BED0BB2E5.png

MySQL 中的源码注释和强行校正逻辑如下所示:
 
    
 long time_diff= ((long)(time(0) - mi->rli->last_master_timestamp)
                       - mi->clock_diff_with_master);
      /*
        Apparently on some systems time_diff can be <0. Here are possible
        reasons related to MySQL:
        - the master is itself a slave of another master whose time is ahead.
        - somebody used an explicit SET TIMESTAMP on the master.
        Possible reason related to granularity-to-second of time functions
        (nothing to do with MySQL), which can explain a value of -1:
        assume the master's and slave's time are perfectly synchronized, and
        that at slave's connection time, when the master's timestamp is read,
        it is at the very end of second 1, and (a very short time later) when
        the slave's timestamp is read it is at the very beginning of second
        2. Then the recorded value for master is 1 and the recorded value for
        slave is 2. At SHOW SLAVE STATUS time, assume that the difference
        between timestamp of slave and rli->last_master_timestamp is 0
        (i.e. they are in the same second), then we get 0-(2-1)=-1 as a result.
        This confuses users, so we don't go below 0: hence the max().

        last_master_timestamp == 0 (an "impossible" timestamp 1970) is a
        special marker to say "consider we have caught up".
      */
      protocol->store((longlong)(mi->rli->last_master_timestamp ?
                                   max(0L, time_diff) : 0));
 

如何获得精确的毫秒级的主从延迟

 
由于 Seconds_behind_master 精度的原因,完全无法衡量毫秒级的主从延迟,所以出现了 pt-heartbeat 这样的工具去精确的计算主从间毫秒级的延迟。在后续采用 pt-heartbeat 对两个库进行监控后,这两个看上去平均延迟相差 500ms 的从库实际主从延迟差距在 10ms 之内。
 

总结

 
任何指标都有其表示的精度,而在其精度表示范围之外就会产生相当大的误差,以至于能够误导我们的判断。当对某一项的指标感到很反常识的时候,可以考虑是不是本身指标并不能描述当前我们想要观察的现象。例如本文中的阐述就表明 Seconds_behind_master 对 1s 的主从延迟的刻画没有太大的意义。
 

公众号

关注笔者公众号,获取更多干货文章:

57B9FC03-F81B-4DD9-892D-D999B161B928.png

💥看到这里的你,如果对于我写的内容很感兴趣,有任何疑问,欢迎在下面留言📥,会第一次时间给大家解答,谢谢!

 

点赞收藏
巡山小汪

关注微信公众号《解Bug之路》,有问题请在公众号中咨询:) 无论多么艰苦的时刻,都不要忘记,辉煌的未来,在你的眼中闪耀!

请先登录,查看5条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步
8
5