MySQL 复制延迟 Seconds_Behind_Master 究竟是如何计算的
导读：
作者：罗小波
参考链接
https://dev.mysql.com/doc/refman/5.7/en/show-slave-status.html
https://wemp.app/posts/33881a28-ba27-4908-994e-29440455d5be https://blog.csdn.net/innobase/article/details/51302138
欢迎转载，转载请注明出处！
目录
"口口相传" 的计算方法
探寻 "正确" 的计算方法
验证
我们想确认什么
提前确认一些信息
执行验证
总结
背景说明
在使用主从复制的拓扑中，监控复制延迟时间是必不可少的功课，如果应用场景对复制延迟并不敏感，那么，大多数时候通过采集 SHOW SLAVE STATUS 语句输出信息中的 Seconds_Behind_Master 字段值来监控复制延迟就已经足够了，相信有MySQL使用经验的人对通过这种方法来查看复制延迟并不陌生，我们都知道 Seconds_Behind_Master 的值在某些场景下并不是那么可靠，也或多或少都知道一些 Seconds_Behind_Master 字段值计算方法。但这些计算方法真的正确么？
本着钻研的精神，今天我就较真一回，搜罗一些关于计算方法的传说，并进行一些简单的验证，整理出来，洋洋洒洒写了一大篇，在这里分享给大家
一、"口口相传" 的计算方法
►方法一：从库 I/O 线程读取的主库 binlog event 时间戳与 SQL 线程正在执行的 binlog event 的时间戳之间的时间差，单位为秒
该方法其实就是在计算两个线程处理日志的时间差，这也是目前最为 "流行" 的一种说法。基于这个算法，如果主从之间的网络存在很大延迟的时候，主库中就可能存在着大量的binlog还没来得及发送给从库，那么这个时候其实使用该方法计算出来的延迟时间，跟主从之间数据真正的延迟就没有太大关系了
▶方法二：从库的系统（主机）时间与 I/O 线程读取的主库 binlog event 的时间差之间的时间差，单位为秒
这种说法没那么 "流行" ，基于这个算法，如果从库的操作系统时间被更改了，或者主库的操作系统时间被修改了，即主从库的主机时间差本身就比较大的时候，那么计算出来的结果也毫无参考意义
▶ 结论，看起来这两种算法都不太靠谱，正确的算法真的是这样的吗？为了一探究竟，我们需要找到可靠的信息源进行确认。
那么从哪里可以获得可靠的信息源呢？
二、探寻 "正确" 的计算方法
▶ 信息源一：MySQL 官方手册
为了不占篇幅、也为了避免本人英文理解错误，下面直接贴出官方手册中关于 Seconds_Behind_Master 字段值计算描述的原文
大概的含义：
* 当从库正在不断地处理更新时（持续不断有event被SQL线程或者I/O线程处理时），此字段显示从库主机当前时间戳和来自主库（原始）的二进制日志中记录的时间戳之间的差异
* 当从库没有任何需要处理的更新时，如果I/O和SQL线程状态都为Yes，则此字段显示为0，如果有任意一个线程状态不为Yes，则此字段显示为NULL
* 实际上，这个字段是度量从库SQL线程和I/O线程之间的时间差，单位为秒，如果主备之间的网络非常快，那么从库的I/O线程读取的主库binlog会与主库中最新的binlog非常接近，所以这样计算得来得值就可以作为主备之间的数据延迟时间，但是如果主备之间的网络非常慢，可能导致从库SQL线程正在重放的主库binlog 非常接近从库I/O线程读取的主库binlog，而I/O线程因为网络慢的原因可能读取的主库binlog远远落后于主库最新的binlog，此时，这么计算得来的值是不可靠的，尽管这个时候有可能该字段显示为0，但实际上可能从库已经落后于主库非常多了。所以，对于网络比较慢的情况，该值并不可靠
* 如果主库与从库的server自身的时间不一致，那么，只要从库复制线程启动之后，没有做过任何时间变更，那么这个字段的值也可以正常计算，但是如果修改了server的时间，则可能导致时钟偏移，从而导致这个计算值不可靠
* 如果从库的SQL线程没运行、SQL线程正在运行且已经消费完了所有的relay log且I/O线程没有运行，则该字段显示为NULL（如果I/O线程已经停止，但还存在着relay log未重放完成时，仍然会显示出复制延迟时间，直到所有relay log被重放完成之后，显示为NULL），如果SQL线程和I/O线程都运行着，但是处于空闲状态（SQL线程已经重放完了I/O线程产生的
relay log），则该字段显示为0
* 该字段的值是基于存储在主库binlog event中的时间戳，保留这个时间戳并通过复制架构同步到从库进行计算得来，那就意味着正常的复制情况下（排除人为在从库写入数据的情况）主库与从库上的binlog event的时间戳都来自主库，在目前的计算该字段值的算法中有一个问题，在单线程复制场景下，即如果从库上通过客户端连接进入并直接更新数据，这可能导致该字段的值随机波动，因为有时候event来源于主库，有时候来源于从库直接更新产生的event，而这个字段的值会受到直接更新产生的event的影响。但如果是多线程复制，则此值是基于Exec_Master_Log_Pos点的event时间戳来计算的，因此可能不会反映从库最近提交的事务的位置
▶ 信息源二：源码
以下是源码中关于延迟时间计算方法的注释说明
# 位于rpl_mi.h中定义clock_diff_with_master附近（翻阅了5.6.34和5.7.22 两个版本，对于复制延迟的计算公式两者一致）
# 从源码注释上来看，复制延迟的计算公式为 clock_of_slave - last_timestamp_executed_by_SQL_thread - clock_diff_with_master
# 该公式的含义为：从库的当前系统（主机）时间 - 从库 SQL 线程正在执行的event的时间戳 - 主从库的系统（主机）之间的时间差
/*
The difference in seconds between the clock of the master and the clock of
the slave (second - first). It must be signed as it may be <0 or >0.
clock_diff_with_master is computed when the I/O thread starts; for this the
I/O thread does a SELECT UNIX_TIMESTAMP() on the master.
"how late the slave is compared to the master" is computed like this:
clock_of_slave - last_timestamp_executed_by_SQL_thread - clock_diff_with_master
*/
# clock_diff_with_master 值为主从服务器的主机时间差，该值只在I/O线程启动时计算一次，后续每次计算Seconds_Behind_Master字段值时，是直接复用这个计算结果，每次重启I/O线程时该值会重新计算
long clock_diff_with_master;
# master_row[0] 为从库在主库上执行SELECT UNIX_TIMESTAMP()的操作，clock_diff_with_master为主从库主机的时间差计算结果
mi->clock_diff_with_master=
(long) (time((time_t*) 0) - strtoul(master_row[0], 0, 10));
# 从rpl_slave.cc 文件中启动 I/O 线程时可以看出：
start_slave_thread-> # 启动start slave
handle_slave_io-> # 启动start io thread
get_master_version_and_clock # 获取当前slave和主机之间的时间差(clock_diff_with_master)
以下是源码中关于Seconds_Behind_Master 计算结果的一些判定值
/*
The pseudo code to compute Seconds_Behind_Master: # 阐明这是一段注释关于如何计算Seconds_Behind_Master的伪代码
if (SQL thread is running) # 如果SQL线程正在运行，则进入这个if判断内，假设这里标记为if one
{
if (SQL thread processed all the available relay log) # 如果SQL线程应用完成了所有可用的relay log，则进入这个if判断内，假设这里标记为if two
{
if (IO thread is running) # 如果I/O线程正在运行，则进入这个if判断内，假设这里标记为if three
print 0; # 如果if one/two/three三个条件都为真，则延迟值判定为0
else
print NULL; # 如果if one/two为真，if three为假，则延迟值判定为NULL
}
else
compute Seconds_Behind_Master; # 如果if one为真，if two为假，则执行公式计算延迟值
}
else
print NULL; # 如果if one为假，则延迟值判定为NULL
*/
if (mi->rli->slave_running)
{
/*
Check if SQL thread is at the end of relay log
Checking should be done using two conditions
condition1: compare the log positions and
condition2: compare the file names (to handle rotation case)
*/
if ((mi->get_master_log_pos() == mi->rli->get_group_master_log_pos()) &&
(!strcmp(mi->get_master_log_name(), mi->rli->get_group_master_log_name())))
{
if (mi->slave_running == MYSQL_SLAVE_RUN_CONNECT)
protocol->store(0LL);
else
protocol->store_null();
}
else
{
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)); # time_diff这里其实就是最终计算的Seconds_Behind_Master 值，如果为负数，则直接归零
}
}
三、验证
1、我们想确认什么
正所谓 "尽信书不如无书" ，我们不能 "它说是这样我们就信了" ，所以，我们这里简单对官方手册和源码中提及的计算公式、场景进行简单的验证，看看实际的表现如何
根据上文源码中的注释，我们找到了计算复制延迟的 "正确" 方法（公式）为：
* clock_of_slave - last_timestamp_executed_by_SQL_thread - clock_diff_with_master，该公式含义为 "从库的当前系统（主机）时间 - 从库 SQL 线程正在执行的event的时间戳 - 主从库的系统（主机）之间的时间差"
* 计算公式中的clock_diff_with_master值，也就是主从库的主机时差只在I/O线程启动的时候计算一次（后续会复用该计算结果来计算复制延迟，直到下次重启I/O线程时才会重新计算）
根据上文官方手册中的描述，主从库系统时间不一致也支持正确计算复制延迟：
* 如果主从库的系统时间不一致，那么如果在复制线程（I/O线程）启动之后，没有对主库或者从库的系统时间再次进行修改，那么根据公式是可以正确计算复制延迟时间的，除非在复制启动之后再次修改了主从库的系统时间，就会导致复制延迟时间不可靠（因为计算公式中的clock_diff_with_master 只在I/O线程启动时才会进行计算，后续计算复制延迟时会复用该计算结果）
根据上文源码中的描述，当Seconds_Behind_Master计算结果为负数的时候，直接归零
2、提前确认一些信息
首先：我们需要确认当I/O线程启动之后，会在主库上执行一些什么动作？
然后：我们需要确认直接修改主机时间之后，在数据库中执行一些时间函数是返回的时间信息是否会跟着改变，写入到二进制日志中的时间信息是否会跟着改变？
我们先来看第一个问题，当I/O线程启动之后，会在主库上执行一些什么动作？
先在主库打开general_log
root@localhost : (none) 10:09:47> set global general_log=1;
Query OK, 0 rows affected (0.01 sec)
从库启动 I/O 线程
root@localhost : (none) 10:16:33> start slave io_thread;
Query OK, 0 rows affected (0.00 sec)
查看主库general_log中记录的内容
2019-04-18T10:16:36.414222+08:00 8 Connect qbench@10.10.30.162 on using TCP/IP
2019-04-18T10:16:36.414632+08:00 8 Query SELECT UNIX_TIMESTAMP() # 在主库查询系统时间语句，这里可以证实I/O线程启动的时候会获取主库的系统时间，当从库拿到主库的系统时间之后，就可以计算主从库的系统时间之差
2019-04-18T10:16:36.415401+08:00 8 Query SELECT @@GLOBAL.SERVER_ID # 查询主库的SERVER_ID
2019-04-18T10:16:36.415638+08:00 8 Query SET @master_heartbeat_period= 5000000000 # 对dump线程在会话级别设置心跳间隔时间
2019-04-18T10:16:36.415814+08:00 8 Query SET @master_binlog_checksum= @@global.binlog_checksum
2019-04-18T10:16:36.416129+08:00 8 Query SELECT @master_binlog_checksum
2019-04-18T10:16:36.416335+08:00 8 Query SELECT @@GLOBAL.GTID_MODE # 查询主库的GTID模式值
2019-04-18T10:16:36.416527+08:00 8 Query SELECT @@GLOBAL.SERVER_UUID # 查询主库的UUID
2019-04-18T10:16:36.416693+08:00 8 Query SET @slave_uuid= '2d623f55-2111-11e8-9cc3-0025905b06da' # 会话级别设置从库自己的UUID
2019-04-18T10:16:36.417224+08:00 8 Binlog Dump GTID Log: '' Pos: 4 GTIDs: '06188301-b333-11e8-bdfe-0025905b06da:1-270852,
2d623f55-2111-11e8-9cc3-0025905b06da:1,
f3372787-0719-11e8-af1f-0025905b06da:1-21'
现在，我们来看第二个问题。修改主机时间之后（数据库进程不重启），在数据库中执行一些时间函数时返回的时间信息是否会跟着改变，写入到二进制日志中的时间信息是否会跟着改变
在主库的主机中修改时间
# 修改之前先查询一下主机和数据库中的时间，都为2019-04-19 16:14附近
[root@localhost ~]# date
2019年 04月 19日 星期五 16:14:19 CST
# 修改之前先查看数据库中的时间
mysql > select now(),unix_timestamp(),from_unixtime(unix_timestamp());
+---------------------+------------------+---------------------------------+
| now() | unix_timestamp() | from_unixtime(unix_timestamp()) |
+---------------------+------------------+---------------------------------+
| 2019-04-19 16:14:20 | 1555661660 | 2019-04-19 16:14:20 |
+---------------------+------------------+---------------------------------+
# 修改主机时间为2020-04-19 17:15:00
[root@localhost ~]# date -s '2020-04-19 17:15:00'
2020年 04月 19日 星期日 17:15:00 CST
# 发现在数据库中使用unix_timestamp()函数查询到的时间跟随着主机时间变化了，也变为了2020-04-19
mysql > select now(),unix_timestamp(),from_unixtime(unix_timestamp());
+---------------------+------------------+---------------------------------+
| now() | unix_timestamp() | from_unixtime(unix_timestamp()) |
+---------------------+------------------+---------------------------------+
| 2020-04-19 17:15:03 | 1587287703 | 2020-04-19 17:15:03 |
+---------------------+------------------+---------------------------------+
# 插入一点测试数据，解析binlog，发现binlog中的时间戳也跟着发生了变化，也变为了2020-04-19 ，这里就可以证实主机时间的修改将直接影响数据库中时间函数获取的时间以及binlog的时间戳
......
# at 468
#190419 16:14:29 server id 3306154 end_log_pos 499 CRC32 0x80c44c50 Xid = 74
COMMIT/*!*/;
# at 499
#200419 17:15:08 server id 3306154 end_log_pos 564 CRC32 0xc2794ccb GTID last_committed=1 sequence_number=2 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'c413c893-56b0-11e9-a705-000c29c10fa5:35'/*!*/;
......
3、执行验证
验证场景
验证结果
1、在主库持续每秒有数据写入的情况下（脚本持续的每隔一秒插入10行数据）验证主库和从库各自向前和向后修改主机时间、主从库同时向前和向后修改主机时间时，从库的复制延迟时间如何变化（脚本持续每秒钟获取一次Seconds_Behind_Master字段值）
2、sysbench 加压到从库存在复制延迟的情况下，突然停止主库压力或突然停止从库 I/O线程时，从库复制延迟时间如何变化
4、总结
根据以上可靠的信息来源以及测试验证过程可以简单得出如下一些结论
对于主从库主机时间不一致的情况，在I/O线程第一次启动时，会计算主从之间的主机时间差，在后续计算复制延迟时，会把这个时间差减掉，这样就可以保证正确获取到复制延迟时间，但是该时间差只在I/O线程启动时才会进行计算，所以，当I/O线程启动之后修改了主从库的主机时间，则根据计算公式，会导致复制延迟时间不可靠，但是当I/O线程重启之后就可以恢复（因为I/O线程重启时，主从之间的时间差重新计算了）
在计算复制延迟时（执行 SHOW SLAVE STATUS语句时会进行计算），对Seconds_Behind_Master计算结果做一些判定（上文源码介绍部分的伪代码注释里有讲解过，这里再啰嗦一下）：
* 如果 I/O 和 SQL线程同时为 Yes，且SQL线程没有做任何事情（没有需要被执行的event），此时直接判定复制延迟结果为0，不会走公式计算延迟时间，否则会走公式计算延迟时间（所以，在该前置条件下不会出现当主库没有写任何binlog event时，从库延迟不断加大的情况）
* 如果 SQL线程为Yes，且还存在着 I/O 线程已经读取的relay log未应用完成的，则会走公式计算延迟时间，而不管 I/O线程是否正在运行，但当SQL线程重放完成了所有relay log时，如果 I/O线程不为Yes，直接判定复制延迟结果为NULL
* 任何时候，如果SQL线程不为Yes，直接判定复制延迟结果为NULL。当计算出的复制延迟为负数时，直接归零
补充说明：
1、当SQL线程重放大事务时，SQL线程的时间戳更新相当于被暂停了（因为一个大事务的event在重放时需要很长时间才能完成，虽然这个大事务也可能会有很多event，但是这些event的时间戳可能全都相同），此时，根据计算公式可以得出，无论主库是否有新的数据写入，从库复制延迟仍然会持续增大（也就是说此时的复制延迟值是不可靠的）。所以就会出现主库停止写入之后，从库复制延迟逐渐增大到某个最高值之后突然变为0的情况
2、官方手册中对主从拓扑处在一个慢速网络中表现行为描述不太准确（个人推理观点）：
* 根据公式计算，如果主库持续不断产生二进制日志（持续不断有数据变更），则复制延迟的计算结果不会出现误差（或者说误差可以忽略不计，因为从库的系统时钟是正常向后推进的，除非主从库的系统时间被改动了），如果在慢速网络中主库断断续续写入数据，甚至主库突然停止任何数据写入，之后实际上主库并没有新的数据写入（也就不会有新的binlog event时间戳产生），但是由于计算公式中并不感知这个变化，所以随着从库的系统时钟继续向前推进，就会导致在追赶上主库的数据之前，计算出的延迟时间值越来越大（也就是说此时的复制延迟值是不可靠的）
作者寄语：最后，感谢沃趣科技的同事 @刘云 帮忙做场景验证，感谢 @沈刚 帮忙查看源码
加入知数堂
挑战40万+年薪！
知数堂
叶金荣与吴炳锡联合打造
领跑IT精英培训
行业资深专家强强联合，倾心定制
MySQL的实战/ MySQL的优化/ MongoDB的/
Python / SQL优化/ Hadoop + ELK
数门精品课程
“阅读原文”可获更多正课试听视频
密码：hg3h
紧随技术发展趋势，定期优化培训教案
融入大量生产案例，贴合企业一线需求
社群陪伴学习，一次报名，可学1年
DBA，开发工程师必修课
上千位学员已华丽转身，薪资翻番，职位提升
改变已悄然发生，你还在等什么？
扫码加入QQ技术交流群
MySQL的入门到精通-ZST
（QQ群号：793818397）