MySQL从库延迟计算方式分析（Seconds_Behind_Master）

一、背景

在 MySQL 主备环境下，主备同步过程简单描述就是主库 sql 语句操作产生 binlog 发送给备库，备库 io 线程读取主库 binlog 生成 relay log；然后备库 sql 线程执行 relay log 从而保持和主库同步。

理论上主库有更新时，备库都存在延迟，且延迟时间为备库执行时间+网络传输时间，即 t4-t2。但实际情况是，我们一般都是通过在从库上执行 SHOW SLAVE STATUS 命令得到 Seconds_Behind_Master 列，理论上的显示了从库的延时。

先来看 show slave status 中的一些信息。

IO 线程拉取主库 binlog 的位置：

SQL 线程执行 relay log 的位置：

SQL 线程执行的 relay log 相对于主库 binlog 的位置：

二、源码实现

当我们每次发起 show slave status 命令的时候都会进行一次 Seconds_Behind_Master 的计算，其计算的方式主要在 show_slave_status_send_data 函数中。下面是一段源码中给的伪代码。

这里有一点需要注意，就是如何判断 SQL 线程应用完了所有 IO 线程写入的 event，下面我们可以看看这部分实际代码：

条件 “mi->get_master_log_pos() == mi->rli->get_group_master_log_pos()” 就是通过 IO 线程读取到主库 binary log 的位置和 SQL 线程应用到的主库 binary log 位置进行比较来进行判断。

如果主从之间的网络状态很糟糕的话，或者 IO 线程读取太慢，从库的 SQL 线程应用 event 的速度可能比 IO 线程读取 event 的速度更快。那么就会出现一种情况，虽然 SQL 线程应用完了所有的 event，并且 Seconds_Behind_Master 也为 0，但是并不代表没有延迟。这个时候的延迟主要在于 IO 线程读取 event 过慢。

这也是如果 Seconds_Behind_Master 为 0，但并不代表没有延迟的第一个原因。

接着，再来看看真正计算 Seconds_Behind_Master 的代码逻辑：

long time_diff = ((long)(time(nullptr) - mi->rli->last_master_timestamp) - mi->clock_diff_with_master);

分解一下：

(long)(time(nullptr)

取当前从库服务器系统时间。

mi->clock_diff_with_master)

这个值时从库服务器的系统时间和主库服务器的系统时间的差值。从库 IO 线程启动时会向主库发送“SELECT UNIX_TIMESTAMP()”语句，获取主库当前时间，然后用备库当前时间减去从主库获取的时间，得到的差值即为 clock_diff_with_master。

可以看出这个计算只在 IO 线程启动的时候进行一次，所以如果有用户中途修改了从库的系统时间，那么 Seconds_Behind_Master 计算出备库延迟必然有问题，更有可能出现负数，如果出现负数则 Seconds_Behind_Master 值依然为 0，在代码中可以看到逻辑。

mi->rli->last_master_timestamp)

这个值取自主库执行的 binlog event 的时间（可以简单理解为事务中第一条语句发起时间）。这个取值比较复杂，在 DML 和 DDL 下是不同的，如果 DML 在单 SQL 线程和 MTS 下又不一样，下面分开讨论。

其计算公式如下：

seconds_behind_master = SELECT UNIX_TIMESTAMP() on slave – timestamp of the master’s binary log event – (SELECT UNIX_TIMESTAMP() on slave – SELECT UNIX_TIMESTAMP() on master)

DML（单线程回放）

备库 SQL 线程读取了 relay log 中的 event，然后会在 event 未执行之前就会更新 last_master_timestamp，这里时间的更新是以 event 为单位。

简单看一下代码，SQL 线程入口函数 handle_slave_sql。

可以看到，关键就是循环不停的读取 event，然后调用 exec_relay_log_event 函数。

在 exec_relay_log_event 中，会根据一些条件选择是否更新 last_master_timestamp，比如在并行复制模式和非并行复制模式下，更新 last_master_timestamp 的逻辑是不同的。在这里先介绍下非并行复制模式下更新 last_master_timestamp 的步骤。

判断是否是并行复制是通过 is_parallel_exec 函数实现的，如果是并行复制模式则返回 True，否则返回 False。

如果它是一个手工构造事件（is_artificial_event，SQL 线程自行构造的事件），或一个 relay log 事件（is_relay_log_event，IO 线程生成的事件），或 ev->when 设置为 0，或来自主服务器的 FORMAT_DESCRIPTION_EVENT 事件，或 heartbeat 事件，或 server_id=0， 那么我们都不会更新 last_master_timestamp 值。

在并行执行时，last_master_timestamp 仅从 GAQ 队列中拿出来。因此，last_master_timestamp 为 0 时（这表示 GAQ 队列为空，并且所有 worker 线程都在等待来自协调线程的事件），我们需要初始化它的 timestamp 来自第一个要并行执行的事件。

Note

MySQL 5.7.22 版本之前 MTS 计算延迟有一个巨大 Bug，https://bugs.mysql.com/bug.php?id=84415

上面代码中 last_master_timestamp == 0 的逻辑就是修复这个 Bug 添加的。

MySQL：5.7.22以前MTS计算延迟的一个较大的BUG（已经修复）

代码中的主要计算方式：

其中 ev->when.tv_sec 表示 event 的开始时间，也就是 event header timestamp；而 exec_time 指 event 在主库的执行耗时，也就是说 last_master_timestamp 的值等于 event header timestamp+exec_time，类型为 timestamp。

但只有 QUERY_EVENT 和 LOAD_EVENT 才会有 exec_time，如果此 event 没有 exec_time，那么基本就是把 event header timestamp 赋值给 last_master_timestamp。这里重点就是 QUERY_EVENT，下面会详细说一下 QUERY_EVENT 在不同二进制日志格式下对 DDL 和 DML 的影响，因为这个影响着 seconds_behind_master 计算方式。

binlog 格式为 STATEMENT 格式时，DML 记录的是 SQL 语句本身，类型为 QUERY_EVENT，所以 exec_time 会记录语句实际执行耗时。

我们以一个 Update 语句为例，假设我们在主库执行语句耗时 30 秒，那么可能延迟计算如下（T1 为语句执行开始时间，T1+30 为事务提交时间，T2 为从库系统时间-主从时间差，T2 每次执行查询 Seconds_Behind_Master 可变，因为从库系统时间可变）。

这种情况，我们在从库执行 show slave status 能看到 Seconds_Behind_Master 的变化如下：

binlog 格式为 ROW 格式时，DML 中 QUERY_EVENT 的 exec_time 基本为 0，因为 QUERY_EVENT 中 exec_time 只记录第一条数据更改消耗的时间，且我们一般看到的是 BEGIN 语句。所以 last_master_timestamp 就基本等于各个 event 中 header 的 timestamp。但是对于一个事务而言，我们知道 GTID_EVENT 和 XID_EVENT 记录的时间都是事务 commit 时刻的时间（但 XID_EVENT 在显式事务和隐式事务下记录的时间是不同的，下面会提到），而对于其他 event 都是命令发起时刻的时间，因此如果一个长时间未提交的事务在 SQL 线程应用的时候，可能观察到 Seconds_Behind_Master 瞬间的跳动。

我们以一个 Update 语句为例，假设我们主库在 30 秒后才提交这个事务，注意这里并不是 SQL 执行耗时 30 秒。

那么可能延迟计算如下（T1 为语句执行开始时间，T1+30 为事务提交时间，T2 为从库系统时间-主从时间差，T2 每次执行查询 Seconds_Behind_Master 可变，因为从库系统时间可变）。

这种情况，我们在从库执行 show slave status 能看到 Seconds_Behind_Master 值突然跳到 30s，然后很快恢复正常。

假设我们在主库执行这个 SQL 耗时 30 秒，此时的 binlog 记录会与上面一样，那么可能延迟计算如下（T1 为语句执行开始时间，T1+30 为事务提交时间，T2 为从库系统时间-主从时间差，T2 每次执行查询 Seconds_Behind_Master 可变，因为从库系统时间可变）。

这种情况，我们在从库执行 show slave status 能看到 Seconds_Behind_Master 值突然跳到 30s，然后依次从 30s 增大至 60s，又跳到 30s，然后跌为 0。

需要注意，Xid event 记录的时间在显式事务（手动 begin…commit）和隐式事务（单个语句）下是不同的。

• 显式事务，xid event 记录的时间为 commit 命令发起的时间。
• 隐式事务，xid event 记录的时间为语句发起的时间。

那么在计算延迟的时候，显式事务从 0 开始计数，隐式事务从主库 SQL 执行耗时开始计数。

同样我们以这个耗时 30 秒的 SQL 为例，此时的 binlog 记录都是一样的，那么可能延迟计算如下（T1 为语句执行开始时间，同样 T1 也为事务提交时间，T2 为从库系统时间-主从时间差，T2 每次执行查询 Seconds_Behind_Master 可变，因为从库系统时间可变）。

这种情况，我们在从库执行 show slave status 能看到 Seconds_Behind_Master 值从延迟 30s 开始，然后依次从 30s 增大至 60s，然后跌为 0。

DML（多线程回放）

在 MTS 多线程回放机制下，last_master_timestamp 的取值为检查点（checkpoint）位置事务 XID_EVENT 的 timestamp。

简单来说，last_master_timestamp 的取值并不每个 worker 线程执行事务时实时更新的，而是由 MTS 下的检查点机制来负责更新。这里简单描述一下 MTS 工作的机制，开启 MTS 后，SQL 线程将变为协调线程，负责读取 relay log 并分发到 worker 线程，协调线程（Relay_log_info->gaq）维护了一个非常重要的队列 GAQ（Global Assigned Queue），每次协调线程开始分发一个新的事务的时候都会将第一个 GTID EVENT 会分配 group 元素，并且放入 GAP 队列中，代表一个事务开始了。

因此 GAQ 中事务的顺序总是和 relay log 文件中事务的顺序一致的。检查点正是作用在 GAQ 队列上的，通过判断事务是否已经提交（判断 Slave_job_group->done 状态），把已经提交的事务移除 GAQ 队列，向前推进事务完成位置，每次推进的位置称为 LWM（Low-Water-Mark），就是把移除的事务信息赋值给 LWM，它在 GAQ 队列中进行维护，源码变量名称就叫 lwm，类型为 Slave_job_group。简单理解就是检查点把移除事务最大的 sequence_number 赋值给 lwm。

每次做检查点的时候，除了推进 lwm 位点，同时会更新 last_master_timestamp 为 lwm 所在事务结束的 event 的时间（worker 线程执行到一个事务 XID_EVENT 时会保存其 timestamp 值）。因此，并行复制是在事务执行完成后才更新 last_master_timestamp，更新是以事务为单位。

假设 worker 线程数为 2，现在协调线程已经分发了 8 个事务，那么 GAQ 队列中有 1、2、3、4、5、6、7、8 个事务。worker-1 已执行的事务为 1、4、6，woker-2 已执行的事务为 2、3，做检查点时会推进到 4 号事务结束，同理 lwm 为 4 号事务，last_master_timestamp 值也就是 4 号事务的结束时间。

普通的 binlog 事件下 last_master_timestamp 的更新逻辑

大概流程如下，当 SQL 协调线程分配到 XID_EVENT 事件的时候，会将这个 event 的 timestamp 赋予给 group->ts，也就是显式事务的提交时间（隐式事务的语句执行时间），作为计算延迟的标准。当进行检查点的时候会把最老未提交事务的前一个已提交事务 group->ts 赋值给 last_master_timestamp 变量。

因此 last_master_timestamp 就是检查点位置事务的 XID_EVENT header 中的 timestamp。如果不开启 slave_preserve_commit_order 参数，那么就可能出现 gap，检查点只能停留在 gap 之前的一个事务，可能后面的事务已经执行完成了。这种情况下延迟并不是那么准确，但是误差也不大，因为参数 slave_checkpoint_period 默认值为 300 毫秒，最少每 300 毫秒做一次检查点。

另外从代码中可以看出当 GAQ 队列为空，并且所有 worker 线程都在等待来自协调线程的事件时，会将 last_master_timestamp 设为 0，同样此时认为没有延迟，计算得出 Seconds_Behind_Master 为 0。此时，如果来一个新事务到来，第一个 GTID EVENT 会分配 group 元素，并且放入 GAP 队列，代表一个事务开始了，那么这个时候 GAP 队列就不为空了。这里有一个特殊情况（疑问）：事务较大，虽然 GTID EVENT 分发了，但是由于分发实际的数据 event 的时间较长，久久没来到 XID_EVENT，那么这个时候 group->ts 到底为何值，要看 group 结构的初始化是如何做的了。

ROTATE_EVENT 事件下 last_master_timestamp 的更新模式

前文提到在并行复制模式下，普通的 binlog 事件会被协调线程（coordinator）进程分发到 worker 线程中去执行。并且在 mts_checkpoint_routine 中去推进 Low Water Mark 和更新 last_master_timestamp。但是如果执行的 binlog 是一个 ROTATE_EVENT 事件，则协调线程不会将事件分发到 worker 中，而是在协调线程中自己执行并更新 last_master_timestamp。

对于 ROTATE_EVENT 事件的执行逻辑，入口依然是 exec_relay_log_event 函数，在函数中调用了 apply_event_and_update_pos 函数执行 binlog 事件。

在 apply_event_and_update_pos 函数中，会首先调用 apply_event 去判断当前的 binlog 事件是否可以被分发到 worker 线程执行。在这里收到的 binlog 事件是 ROTATE_EVENT，因此 apply_event 返回的 exec_res 为 0，ev->worker==rli（rli 代表了协调线程），会直接有协调线程执行。

在此调用了 update_pos 进行更新。因为当前的 binlog 事件是 ROTATE_EVENT，因此会调用如下的代码：

在 do_update_pos 更新 last_master_timestamp 的关键逻辑如下：

至此，对于并行复制和非并行复制下收到 ROTATE_EVENT 事件时，更新 last_master_timestamp 的逻辑分析全部完成。

DDL

对于 DDL 语句而言，不管 binlog 格式是什么，记录在 binlog 中的事件都是 QUERY_EVENT，记录的都是实际的语句。这种情况下其 exec_time 就会记录整个语句执行耗时。因此实际上 DML 和 DDL 计算延迟的方式是有区别的，区别就在于这里的 exec_time 是否参与运算。

假设我们在主库执行一个 DDL，耗时 30 秒，下面是一个 DDL 语句在 binlog 中的记录：

那么可能延迟计算如下（T1 为语句执行时间，T2 为从库系统时间-主从时间差，T2 每次执行查询 Seconds_Behind_Master 可变，因为从库系统时间可变）。

server_id 相同时的运行逻辑

我们知道 event 是 binlog 日志的基本单位，每个 event 来源于主库，每个 event 都包含了 server_id，用于表示该 event 是哪个实例生成的。

前面分析了当 MySQL 收到一个 ROTATE_EVENT 事件的时候所运行的逻辑。本节将分析下在 MySQL 收到与自己的 server_id 一致的 binlog 事件的时候的运行逻辑，这在双主单写模式下会出现的情况。

IO 线程处理与本实例 server_id 一致的 binlog 事件

在 handle_slave_io 函数中，会在 while 循环中不断的调用 queue_event 函数。

在 queue_event 函数中，对于收到与自己 server_id 一致的 binlog 事件时，会将 event 进行过滤，不写入 relay log，同时会更新其 IO 线程读取的位置（Read_Master_Log_Pos），并且更新忽略到的位置（rli->ign_master_log_name_end[0]）。

存疑代码逻辑：queue_event 函数执行完以后，回到 handle_slave_io 函数，继续执行 write_ignored_events_info_to_relay_log 函数，会构造 server_id 为 0 的 ROTATE_EVENT 写入 relay log。

SQL 线程处理与本实例 server_id 一致的 binlog 事件

SQL 线程入口函数 handle_slave_sql，会调用 read_next_event 读取可用的 relay log，然后会调用 exec_relay_log_event 函数进行 event 处理。

Note

这里是 MySQL 8.0 的代码，在 8.0 之前读取可用的 relay log 函数在 exec_relay_log_event 函数中，同时之前的函数名字叫 next_event，在 8.0 中叫 read_next_event。

在 read_next_event 函数中还会调用 reset_seconds_behind_master 函数对于非并行复制或者 GAQ 为空时会有一个特殊的处理：

如果是非并行复制或者 GAQ 为空，当读取一个 binlog 事件的时候，都会把 last_master_timestamp 设置成 0 。因此在非并行复制或者 GAQ 为空时，收到与本实例 server_id 一致的 binlog 事件的时候，mysqld.trace 中可以观察到 rli->last_master_timestamp 的值会一直为 0。

之后的逻辑中，如果发现 rli->ign_master_log_name_end[0] 不为空（对应了上一个小节中的第一项：将 mi->get_master_log_name() 拷贝到 rli->ign_master_log_name_end 中），则构造一个 server_id 为 0 的 Rotate event 并返回。

紧接着调用 apply_event_and_update_pos 函数，在 apply_event_and_update_pos 函数中，如前所述如果是 ROTATE_EVENT 则返回 0，不会被 worker 进程并行执行，并进入 update_pos 逻辑中，update_pos 会调用事件对应的 do_update_pos 函数。

在 do_update_pos 更新 last_master_timestamp 的关键逻辑如下：

可以见得 real_event 在 server_id 是 0 的时候为 false，因此当进入 reset_notified_checkpoint 函数后，因为 update_timestamp 条件（传入的值便是 real_event 的值）为 false 便不会更新 last_master_timestamp。

好了到这里我们知道了 server_id 相同时 event 是如何跳过的，但是注意 IO 线程和 SQL 线程在处理 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 的时候可能有一定的时间差，那么 Read_Master_Log_Pos 和 Exec_Master_Log_Pos 存在一定的差值，条件就可能会满足，则进入延迟计算环节。

三、位点信息维护

一般在从库经常会执行 SHOW SLAVE STATUS，总要的参数有这么几个：

• IO 线程拉取主库 Binlog 的位点

Master_Log_File：读取到主库 ROTATE_EVENT 时会更新（process_io_rotate）。

Read_Master_Log_Pos：IO 线程每取到一个 event 都会从 event 中读取 pos 信息并更新 mi->set_master_log_pos(mi->get_master_log_pos() + inc_pos)。

• SQL 线程执行 Relay log 的位点

Relay_Log_File：SQL 线程处理 ROTATE_EVENT 时更新（Rotate_log_event::do_update_pos）。

Relay_Log_Pos：单线程回放时，每个语句执行完成更新。多线程回放时，事务完成时更新（Rotate_log_event::do_update_pos/Xid_log_event::do_apply_event/stmt_done）。

• SQL 线程执行的 Relay log 相对于主库 Binlog 的位置

Relay_Master_Log_File：SQL 线程处理 ROTATE_EVENT 时更新（Rotate_log_event::do_update_pos）。

Exec_Master_Log_Pos 和 Relay_Log_Pos 同时更新：非并行复制时，每个语句执行完成更新（stmt_done）并行复制时，事务完成时更新（Rotate_log_event::do_update_pos/ Xid_log_event::do_apply_event/stmt_done）。

谈到位点更新就有必要说到两个事件，分别是 HEARTBEAT_LOG_EVENT 和 ROTATE_EVENT。

• HEARTBEAT_LOG_EVENT

HEARTBEAT_LOG_EVENT 我们的了解一般作用是，在主库没有更新的时候，每隔 master_heartbeat_period 时间都发送此事件保持主库与备库的连接。而 HEARTBEAT_LOG_EVENT 另一个作用是，在 GTID 模式下，主库有些 GTID 备库已经执行，这些事件虽然不需要再备库执行，但读取和应用 binlog 的位点还是要推进。因此，这里将这类 event 转化为 HEARTBEAT_LOG_EVENT，由 HEARTBEAT_LOG_EVENT 帮助我们推进位点。

• ROTATE_EVENT

主库 binlog 切换产生的 ROTATE_EVENT，备库 IO 线程收到时会也有切换 relay log。此 ROTATE_EVENT 也会记入 relay log，SQL 线程执行 ROTATE_EVENT 只更新位点信息。备库 IO 线程接受主库的 HEARTBEAT_LOG_EVENT，一般不处理。前面提到，GTID 模式下，当 HEARTBEAT_LOG_EVENT 的位点大于当前记录的位点时，会构建一个 ROTATE_EVENT（属于手工造事件），从而让 SQL 线程推进位点信息。

另外，在 replicate_same_server_id 为 0 时，备库接收到的 binlog 与主库 sever_id 相同时，备库会忽略此 binlog，但位点仍然需要推进。为了效率，此 binlog 不需要记入 relay log。而是替换为 ROTATE_EVENT 来推进位点。

MTS 中 Second_Behind_Master 计算误差测试

这里我们来验证一下，先将参数 slave_checkpoint_period 设置为 1 分钟左右，让 MTS 的 checkpoint 周期为 1 分钟，用于证明 MTS 中的 Second_Behind_Master 计算和检查点有关。

从库操作如下：

然后我们在主库手动做几个事务，然后查看 Executed_Gtid_Set 如下：

下面是从库 show slave status 的信息：

我们会发现 Second_Behind_Master 一直增长到 60，然后跳回为 0。但是检查主库和从库的 Executed_Gtid_Set，我们发现这些事务早就已经在从库做完了，最后一个事务的 gno 是 168。但是因为没有做 MTS 检查点，因此延迟的计算会出现了问题，如果要用上面的公式来套的话就是 mi->rli->last_master_timestamp 由于 MTS 没有做检查点而一直没有变化，直到 60 秒后才做了一次检查点，mi->rli->last_master_timestamp 信息才得到更新。

但是这种问题一般不需要担心，因为默认情况下参数 slave_checkpoint_period 为 300 毫秒，检查点非常频繁。

四、延迟原因总结

有了前面的知识，我们就能够从本质上了解造成延迟的可能有哪些，先总结一下 Seconds_Behind_Master 为 0 或 NULL 的情况。

• 如果备库 IO/SQL 线程没有运行，则 Seconds_Behind_Master=NULL。
• 即使备库 IO/SQL 正在运行，备库有时候可能无法计算延迟，如果发生这种情况，Seconds_Behind_Master 会报 0 或者 NULL。
• 如果网络延迟，导致从库拉取日志速度跟不上主库；但此时从库 IO 线程跟 SQL 线程在同一位点，那么 Seconds_Behind_Master=0，误以为没有延迟。

总结一下造成延迟的原因，大致分为以下两类。

第一类延迟情况可能造成服务器有较高的负载，可能是 CPU/IO 的负载。因为从库在实际执行 event，如果我们服务器的负载比较高应该考虑这几种情况（查看线程的负载，通过 top -H 命令）。

• 在 binlog 为 row 格式下，由大事务造成的延迟，其延迟不会从 0 开始增加，而是直接从主库执行了多久开始。比如主库执行这个事务耗时 20 秒，那么延迟就会从 20 开始，逐渐升到 40，然后回到 0。这是因为 QUERY_EVENT 中没有实际的 SQL 执行时间。
• 在 binlog 为 statement 格式下，由大事务造成的延迟，其延迟会从 0 开始增加。比如主库执行这个事务耗时 20 秒，那么延迟就会从 0 逐渐上升到 20，然后回到 0。这是因为 QUERY_EVENT 中有实际的 SQL 执行时间。
• 大表 DDL 造成的延迟，其延迟也会从 0 开始增加。因为 QUERY_EVENT 记录了准确的执行时间。
• 当表上无主键或唯一键时会造成主从延迟，那么对于在该表上做的 DML，如果是以 ROW 模式复制，在从库回放时则每一个行记录前镜像都需要执行一遍，这是与主库不同的地方。在从库回放行记录时，遵循先找主键定位数据，其次是唯一键或二级索引；但唯一键或二级索引都需要回表，比主键要慢。在无主键或索引情况下，在备库每一个行记录都会产生一次全表扫描（也就是说一条 delete，如果删了10条，从库会做 10 次全表扫），大多数情况下，这种开销都是非常不可接受的，并且产生大量的延迟。但有二级索引的情况下会比无主键无索引情况要好一些。
• 一个大事务可能会导致延迟波动，例如一个事务更新数据长达 1 个小时，最后提交；这条更新语句将比它实际发生时间要晚一个小时才记录到二进制日志中（Binlog 记录开始执行时间以及执行时间），当备库执行这条语句时，会临时报告备库延迟 1 小时，然后又很快变为 0。
• 由于参数 sync_relay_log、sync_master_info、sync_relay_log_info 不合理导致，特别是 sync_relay_log 会极大的影响从库的性能，因为 sync_relay_log 设置为 1 会导致大量 relay log 刷盘操作。同时会导致 IO 线程读取 binlog 滞后，这时虽然 SQL 线程执行位点看上去比 IO 读取位点小不了多少，但延迟会变大，因为从库系统时间一致在增长（系统时间 – SQL 读取 event header timestamp）。
• 是否从库开启了记录 binlog 功能，即 log_slave_update 参数开启，如果不是必要刻意关闭掉。

第二类延迟情况往往不会造成服务器有较高的负载，它们要么没有实际的执行 event，要么就是做了特殊的操作造成的。

• 长时间事务未提交的延迟（如 begin…dml…wait…commit），会造成延迟的瞬时跳跃。因为 GTID_EVENT 和 XID_EVENT 记录的时间是事务提交时间，而其他 event 记录的是 SQL 语句的发起时间。
• InnoDB 层的行锁造成的延迟，这种是在从库有修改操作，并且和 SQL 线程修改的数据有冲突的情况下造成的，SQL 线程执行 event 也会开启事务和获取行锁。这时查看 SQL 线程（或 worker 线程）会看到状态为 System Lock。
• MySQL 层的 MDL LOCK 造成的延迟，这种情况可能是由于 SQL 线程执行某些 DDL 操作，但是从库上做了锁表操作造成，比如备份操作。这时查看 SQL 线程（或 worker 线程）会看到状态为 Waiting for table metadata lock。
• 开启并行复制（MTS）时，参数 slave_checkpoint_period 设置不合理导致。这个参数的时间决定 MTS 检查点运行周期，而计算延迟的核心变量就是在检查点运行时才进行更新。
• 在从库运行期间手动改大了从库服务器时间，延迟计算依赖服务器时间，重启 IO 线程会恢复正常。

五、总结

有了上面的分析，我们知道 Seconds_Behind_Master 的计算并不准确和可靠。因此当我们判断备库是否延迟时，如果是 GTID AUTO_POSITION 模式下，我们应该通过比较主库和从库的 Executed_Gtid_Set 来确保没有主从延迟。

如果非 GTID 模式，也应该通过比较（Relay_Master_Log_File, Exec_Master_Log_Pos）和（Master_Log_File, Read_Master_Log_Pos）来判断主从是否存在延迟，但这种情况如果出现网络问题导致 IO 线程读取主库 binlog 延迟，也是没办法保证同步数据一致。最好就是获取主库的 binlog 位点信息来与（Master_Log_File, Read_Master_Log_Pos）做比较。

BUG#72376

主要是说 Seconds_Behind_Master 值由于 PREVIOUS_GTIDS_LOG_EVENT 事件而失真，PREVIOUS_GTIDS_LOG_EVENT 事件在每个 binlog 的开头，表示先前所有文件的 gtid 集合。relay log 本身 event 记录是主库的时间，但 relay log 开头的 PREVIOUS_GTIDS_LOG_EVENT 事件，是在 slave 端生成的，时间也是以 slave 为准的。因此不能用此时间计算 last_master_timestamp。修复方法是在 relay log 写 PREVIOUS_GTIDS_LOG_EVENT 事件时标记是 relay log 产生的，在统计 last_master_timestamp 时，发现是 relay log 产生的事件则忽略统计。

即使我们不执行此事件，我们保留主时间戳，以便主时间戳后面的秒显示正确的增量（没有事件应用， 所以我们一直落后） 。

如果是人工事件或中继日志事件（IO 线程生成的事件）或 ev->when 设置为 0，或来自主服务器的 FD 事件，或 heartbeat 事件，或 server_id=0， 那么我们不会更新 last_master_timestamp 值。

在并行执行时，last_master_timestamp 仅从 GAQ 队列中拿出来。因此，last_master_timestamp 为 0 时（这表示 GAQ 队列为空，并且所有 worker 线程都在等待来自协调线程的事件），我们需要初始化它的 timestamp 来自第一个要并行执行的事件。

<参考>

https://www.jianshu.com/nb/43148932

MySQL 双主单写，主库偶尔出现大量延迟的原因

MySQL 复制那点事 – Seconds_behind_Master 参数调查笔记

MySQL · 答疑解惑 · 备库Seconds_Behind_Master计算

喜欢 (4)赏

[资助本站您就扫码 谢谢]

分享 (0)