MySQL-Seconds_behind_master 的精度误差

前言

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

问题现场

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

网络问题

难道是网络问题？那我们 ping 一下吧，最多也就相差 1ms。那么还有 499ms 去哪里了呢，看来还得继续挖掘。

Seconds_behind_master 的取点数据

直觉上来说网络问题不可能导致 500ms 这么大的误差，而机器配置和 MySQL 版本又是一样的。这就让笔者不得不怀疑这个兼容数据的准确性。所以就先看看这个 500ms 是怎么计算出来的。

从监控取点数据来看从库 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 明显就是指时间差。但是，我们要考虑到一个很容易被忽略的常识，也就是不同机器的时间戳是不一样的！

那么很明显的，如果主从实际延迟是 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。

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

在上图中我们可以看到，在我们取从库时钟 [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，就可以构造出刚才说的现象，如下图所示：

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 之内。