1
2
1
0
专栏/.../

多种方式告诉你如何计算DM同步数据到TiDB的延时时间

 hey-hoho  发表于  2021-11-09

【是否原创】是
【首发渠道】TiDB 社区

背景

用户在做技术选型的过程中,总是会对一些数据指标比较关心,特别是在和竞品相比较的时候,更加需要一些有说服力的数据。基于MySQL开发的项目在迁移到TiDB的时候,使用DM同步数据是必不可少的一个环节,我在最近的一次POC中就碰到了这样一个需求,需要评估一个具体的延时时间参考值,因为用户在迁移前期的过渡阶段是把TiDB作为MySQL的从库,有些场景对这个延时很敏感,如果延时太大会直接影响业务。

由于DM并不能直接看到整个链路的延时时间,所以我们必须另辟蹊径找一些办法来实现,以下是我实践过的几种办法,也希望能抛砖引玉,带出其他大佬给社区带来更好的方案。

我的思路比较简单,就是分别根据上下游事务的某个时间点来计算时间差,这个时间差应该要精确到毫秒级,可以从三个方向入手:

  • Binlog Position
  • TiDB General log
  • SQL自动记录时间

接下来就分别看一下如何实现。

基于Binlog Position

DM增量同步是基于订阅MySQL Binlog来实现的,所以首先考虑的办法就是通过Binlog Position来定位某一个事务,只要分别找到同一个Position在Binlog和DM-Worker Log中记录的时间,就可以大致计算出这个时间差。

我使用如下一张测试表来演示这个过程:

CREATE TABLE `table1` (
  `id` int(11) NOT NULL,
  `mysql_created` timestamp(3) NOT NULL DEFAULT CURRENT_TIMESTAMP(3),
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin

在DM Task完全启动成功之后,我们往MySQL里的table1插入一条数据:

insert into table1 values(1,null);

插入成功后我们找到这个事务第一个events的position,这个示例中是1422:

%E4%BC%81%E4%B8%9A%E5%BE%AE%E4%BF%A1%E6%88%AA%E5%9B%BE_20211031215105


接下来去binlog文件中解析出这段范围内的事务内容,里面有我们需要的时间:

%E4%BC%81%E4%B8%9A%E5%BE%AE%E4%BF%A1%E6%88%AA%E5%9B%BE_20211031215133


注意看里面的TIMESTAMP内容,意思是事务开始时的时间是21:45:38:572,原始内容精确到了微秒级别,我们这里只取毫秒来计算。

然后拿事务开始的position去dm-worker的日志中搜索相应的内容,当binlog被处理完成后会输出flushed checkpoint字样的内容,我们根据关键字去日志文件中搜索:

%E4%BC%81%E4%B8%9A%E5%BE%AE%E4%BF%A1%E6%88%AA%E5%9B%BE_20211031215022


从这里可以得到1422被写入完成的时间是21:45:38.603,前后相减一下大概时间差是31ms。

要注意的是,我理解整个链路的过程应该是:mysql(事务开始)->binlog->dm-master->dm-worker->tidb->dm-worker,相当于TiDB写完后多了一个通知dm-worker的过程。

基于TiDB General log

第二种与前一种类似,我希望能定位到事务实际被TiDB执行完成的时间,这时候可以借助TiDB的GENERAL_LOG功能,用事务号(TSO)去定位。

我们首先打开TiDB实例的General Log开关:

mysql> set tidb_general_log=1;
Query OK, 0 rows affected (0.08 sec)

前半部分和之前一样,还是去binlog文件中找到MySQL事务开始时间戳,这里是22:08:55:419

%E4%BC%81%E4%B8%9A%E5%BE%AE%E4%BF%A1%E6%88%AA%E5%9B%BE_20211031220931


然后打开TiBD的Dashboard页面,用如下关键字搜索TiDB节点的日志:

%E4%BC%81%E4%B8%9A%E5%BE%AE%E4%BF%A1%E6%88%AA%E5%9B%BE_20211031221304


虽然这个页面能看到日志的记录时间,但是存在两个问题,一个是不能精确到毫秒,第二个这并不是事务的提交时间,我们需要进一步根据事务号(TSO)去原始文件中搜索准确时间。

%E4%BC%81%E4%B8%9A%E5%BE%AE%E4%BF%A1%E6%88%AA%E5%9B%BE_20211031221729


这里的commit时间是22:08:55.434,前后相减的时间差大概15ms。

这里也可以一步到位直接去原始log文件去搜,省去Dashboard查询TSO的过程。

这个链路过程是:mysql(事务开始)->binlog->dm-master->dm-worker->tidb(事务提交)。

基于SQL自动记录时间

前面两种方法都要各种搜索日志稍微有点麻烦,本着将偷懒进行到底的精神,能不能直观地看出上下游各自的时间?最理想的情况是:一句SQL就能查出来。

从前面的测试中可以发现,时间字段设置当前时间为默认值只对上游生效,同步到TiDB的时候是把实际值传过去了,并不是根据字段定义生成新值。因此,我希望数据到TiBD的时候也能生成当前时间写入某个字段,但是这个字段不能在MySQL中存在,也就是说上下游数据结构不一样。

那DM可以支持这种同步吗?必然是可以的。

关于上下游异构同步官网文档有详细介绍,大家可以参考文档:https://docs.pingcap.com/zh/tidb-data-migration/stable/manage-schema。
我们要使用的带默认值异构同步其实更简单,DM不用做任何操作就能支持。

我们在前面的DM Task完全不动的情况下,只给下游TiDB的table1增加一个字段

alter table table1 add COLUMN tidb_created timestamp(3) NOT NULL  DEFAULT current_timestamp(3);

然后往上游插入一条测试数据:

insert into table1 values(3,null);

插入成功后去TiDB中查询这个表,两个创建时间都能看到了:
%E4%BC%81%E4%B8%9A%E5%BE%AE%E4%BF%A1%E6%88%AA%E5%9B%BE_20211031224558
是不是非常简单。

这个链路的过程是:mysql(事务开始)->binlog->dm-master->dm-worker->tidb(事务开始)。

总结

以上3种方式从不同维度计算了一次数据同步的延时情况,这个数据具有一定的参考性。但是使用的过程中要注意每一种的区别,选择你最适合最关心的指标来作为参考。

本文如有不正确的地方欢迎指出,当然了,也欢迎大家推荐更好的方案,一起交流~

1
2
1
0

版权声明:本文为 TiDB 社区用户原创文章,遵循 CC BY-NC-SA 4.0 版权协议,转载请附上原文出处链接和本声明。

评论
暂无评论