MySQL:级联从库延迟数据库的延迟计算问题

2023年 12月 28日 55.6k 0

本文主要讨论的还是5.7,8.0没有实际测试,这里简单记录。

一、问题说明

最近在处理一个主从问题的时候,发现一个比较奇怪的现象,这个主从是级联的也就是A->B->C库,B库问题处理后先启动了B库追数据,然后修复C库启动追延迟,这个时候观察到的B库和C库的延迟分别为20000多秒和900多秒,显然这个差距是非常大的,而级联又是平时用得很多的一种方式。 这里实际上C库的延迟应该比B库更大,那么级联从库中C库的延迟计算到底是怎么样的呢?

这里我们简单探讨一下,未考虑清楚的地方还请见谅,下面我们也用A B C来代表主库、从库1、从库2。

二、延迟计算和级联从库C

一般来讲我们在讨论延迟的时候,延迟的计算公式大概如下,当然准确来说是单SQL线程(非MTS)下计算延迟的公式。

其中在主库row格式的binlog其query event中exec time的时间基本为0,因此B库在计算延迟的时候基本可以在公式中简化掉。

而在级联从库C中,其binlog来自B库,那么在B库中的binlog如何记录的就成了关键,那么其有2个关键就是:

(1) Event中header中timestamp的时间:这个时间实际上还是主库的timestamp时间,并不会因为在B库执行过就是B库产生binlog的时间。如下:

    thd->set_time(&(common_header->when));
    thd->set_query(query_arg, q_len_arg);
    thd->set_query_id(next_query_id());
    thd->variables.pseudo_thread_id= thread_id;  // for temp tables

这里在B库应用event的时候,设置了线程的start_time,也就是来自event
header,这个实际上就是主库执行命令的时间,因此B库中记录的binlog的event header的timestamp 依旧来自主库。

(2) query event中exec time的时间:这个时间虽然在主库几乎为0,但是B库在记录的时候为当前时间 -
线程的start_time,而线程的start_time来自主库执行命令的时间,因此这个时间大概就是,B库当前时间-主库A执行命令的时间,基本就是B库的在执行query
event时刻的延迟时间,如下:

  ulonglong micro_end_time= my_micro_time();//这里获取当前服务器时间时间
  my_micro_time_to_timeval(micro_end_time, &end_time);

  exec_time= end_time.tv_sec - thd_arg->start_time.tv_sec; //计算exec time

那么级联从库C的延迟实际上就是:

从库C当前时间-(主库执行命令的时间+B库的在执行query event时刻的延迟时间)- 主从服务器时间差

好了回到开头的问题,总结为2点:

  • 当B库延迟很大的时候显然根据这个公式可以计算出C库的延迟是比较小的,因为B库在执行query event时刻的延迟非常大,那么记录的exec
    time就很大,到了C库计算延迟的时候就直接扣除了这部分。
  • 当B库没什么延迟的时候,C库计算的延迟基本上就是相对于主库的延迟,因为这个时候B库在执行query
    event时刻的延迟非常小,不会产生太大的误差。

当然整个逻辑还是说的是时钟同步的情况下。

三、观察B库中的exec time

这里很容易观察到这种现象,只需要稍微做一下延迟就可以了。 主库A:

# at 1097
#230518 15:50:04 server id 333900  end_log_pos 1174 CRC32 0xab4d2adc    Query   thread_id=4     exec_time=0     error_code=0
SET TIMESTAMP=1684396204/*!*/;

从库B:

# at 1069
#230518 15:50:04(timestampm是主库的) server id 333900  end_log_pos 1132 CRC32 0x483e49b5    Query   thread_id=4     exec_time=48(这里)    error_code=0
SET TIMESTAMP=1684396204/*!*/;

在测试期间还发现B库,可能 exec_time很大的情况这里简单描述一下,如下,

#230517 15:33:05 server id 1623306  end_log_pos 1558 CRC32 0x2d7d12fc   Query   thread_id=17    exec_time=4283165634(这里)    error_code=0
SET TIMESTAMP=1684308785/*!*/;

显然这个是B库服务器时间落后于A库的时候,出现相减负数的情况,然后转非负整数,得到了一个很大的值。这种情况下C的延迟计算也会受到影响。

相关文章

Oracle如何使用授予和撤销权限的语法和示例
Awesome Project: 探索 MatrixOrigin 云原生分布式数据库
下载丨66页PDF,云和恩墨技术通讯(2024年7月刊)
社区版oceanbase安装
Oracle 导出CSV工具-sqluldr2
ETL数据集成丨快速将MySQL数据迁移至Doris数据库

发布评论