资讯专栏INFORMATION COLUMN

DM同步主键冲突原因及排查恢复

IT那活儿 / 3499人阅读
DM同步主键冲突原因及排查恢复

点击上方“IT那活儿”,关注后了解更多内容,不管IT什么活儿,干就完了!!!



报错现象

主键冲突:


报错分析



情况1:上游数据存在冲突的情况,例如上游两套Mysql库,分别都有store_bj表,通过DM将上游两张表的数据汇总到下游一张表中,在同步的过程中上游两张表都有id=12的主键的数据,上游mysql中均插入成功,但在同步Tidb进行中出现主键冲突。
-- 解决方法:从上游数据入手,避免重复主键数据,出现主键冲突的报错之后,同步Task任务将被终止,通过重启Task任务可以恢复同步状态。
在任务终止期间,如果上游Mysql继续有相同主键数据更新的操作会在重启Task任务后再次出现主键冲突报错,需要再次进行Task任务的重启。
建议对于报错的主键冲突情况,需要业务开发人员对报错的表操作以及数据进行排查,会存在主键冲突的数据未同步成功的情况。
-- 测试报错及恢复案例:
1)store_bj表结构:
create table store_bj (id int primary key,name varchar(20));
mysql1:

mysql> insert into store_bj values (12,store_bj_11);
Query OK, 1 row affected (0.01 sec)

mysql2:

mysql> insert into store_bj values (12,store_bj_12)
;
Query OK, 1 row affected (0.01 sec)
2)在上游两套Mysql中,均正常插入id=12的数据,但在Tidb中只有成功插入其中一条数据插入,查询Task状态报错:
[tidb@tidb1 ~]$ tiup dmctl --master-addr ***.**.***.134:8261 query-status two_tidb_slave
………
"subTaskStatus": [
{
"name": "two_tidb_slave",
"stage": "Paused",
"unit": "Sync",
"result": {
"isCanceled": false,
"errors": [
{
"ErrCode": 100*6,
"ErrClass": "database",
"ErrScope": "not-set",
"ErrLevel": "high",
"Message": "startLocation: [position: (, 0), gtid-set: ], endLocation: [position: (mysql-bin.000002, 12368), gtid-set: ]: execute statement failed: commit",
                               "RawCause": "Error 1062: Duplicate entry 12 for key PRIMARY",
"Workaround": ""
}
],
"detail": null
…………
3)排查DM日志,可以找到对应的主键冲突的报错以及对应表的操作:
[tidb@tidb1 ~]$ cat /home/tidb/dm/deploy/dm-worker-8262/log/dm-worker.log
………
[2021/12/03 16:54:39.773 +08:00] [INFO] [syncer.go:1902] ["meet heartbeat event and then flush jobs"] [task=two_tidb_slave] [unit="binlog replication"]
[2021/12/03 16:54:39.773 +08:00] [INFO] [syncer.go:3016] ["
flush all jobs"] [task=two_tidb_slave] [unit="binlog replication"] ["global checkpoint"="position: (mysql-bin.000002, 12123), gtid-set: (flushed position: (mysql-bin.000002, 12123), gtid-set: )"]
[2021/12/03 16:54:39.773 +08:00] [INFO] [syncer.go:1119] ["
flushed checkpoint"] [task=two_tidb_slave] [unit="binlog replication"] [checkpoint="position: (mysql-bin.000002, 12123), gtid-set: (flushed position: (mysql-bin.000002, 12123), gtid-set: )"]
[2021/12/03 16:54:39.773 +08:00] [INFO] [syncer.go:1127] ["
after last flushing checkpoint, DM has ignored row changes by expression filter"] [task=two_tidb_slave] [unit="binlog replication"] ["number of filtered insert"=0] ["number of filtered update"=0] ["number of filtered delete"=0]

[2021/12/03 16:54:41.794 +08:00] [ERROR] [db.go:201] ["
execute statements failed after retry"] [task=two_tidb_slave] [unit="binlog replication"] [queries="[INSERT INTO `store`.`store_bj` (`id`,`name`) VALUES (?,?)]"] [arguments="[[12 store_bj_12]]"] [error="[code=10006:class=database:scope=not-set:level=high], Message: execute statement failed: commit, RawCause: Error 1062: Duplicate entry 12 for key PRIMARY"]
[2021/12/03 16:54:41.794 +08:00] [INFO] [syncer.go:2854] ["
print status routine exits"] [task=two_tidb_slave] [unit="binlog replication"] [error="context canceled"]
[2021/12/03 16:54:41.794 +08:00] [INFO] [syncer.go:1696] ["
binlog replication main routine quit(context canceled)!"] [task=two_tidb_slave] [unit="binlog replication"] ["last location"="position: (mysql-bin.000002, 12399), gtid-set: "]
[2021/12/03 16:54:41.828 +08:00] [INFO] [syncer.go:1602] ["
flush checkpoints when exit task"] [task=two_tidb_slave] [unit="binlog replication"]
[2021/12/03 16:54:41.837 +08:00] [INFO] [checkpoint.go:694] ["
rollback checkpoint"] [task=two_tidb_slave] [unit="binlog replication"] [component="remote checkpoint"] [schema=store] [table=store_shenzhen] [from="position: (mysql-bin.000002, 10712), gtid-set: "] [to="position: (mysql-bin.000002, 10712), gtid-set: "]
[2021/12/03 16:54:41.837 +08:00] [WARN] [checkpoint.go:697] ["
failed to drop table from schema tracker"] [task=two_tidb_slave] [unit="binlog replication"] [component="remote checkpoint"] [schema=store] [table=store_shenzhen] [error="[schema:1146]Table store.store_shenzhen doesnt exist"]
[2021/12/03 16:54:41.844 +08:00] [WARN] [syncer.go:681] ["something wrong with rollback global checkpoint"] [task=two_tidb_slave] [unit="binlog replication"] ["previous position"="position: (mysql-bin.000002, 12399), gtid-set: "] ["current position"="position: (mysql-bin.000002, 12123), gtid-set: "]
[2021/12/03 16:54:41.844 +08:00] [INFO] [subtask.go:292] ["unit process returned"] [subtask=two_tidb_slave] [unit=Sync] [stage=Paused] [status="{"totalEvents":1,"syncerBinlog":"(mysql-bin.000002, 12123)","binlogType":"remote"}"]
[2021/12/03 16:54:41.844 +08:00] [ERROR] [subtask.go:311] ["unit process error"] [subtask=two_tidb_slave] [unit=Sync] ["error information"="{"ErrCode":10006,"ErrClass":"database","ErrScope":"not-set","ErrLevel":"high","Message":"startLocation: [position: (, 0), gtid-set: ], endLocation: [position: (mysql-bin.000002, 12368), gtid-set: ]: execute statement failed: commit","RawCause":"Error 1062: Duplicate entry
12 for key PRIMARY"}"]
[2021/12/03 16:54:45.961 +08:00] [WARN] [task_checker.go:390] ["task can
t auto resume"] [component="task checker"] [task=two_tidb_slave]
…………
对于报错的同步,建议业务开发人员对DM失败的操作进行排查,对同步的表上游源端和下游成功插入的数据是否有效,未同步成功的数据是否需要进行主键的调整,均需要进行排查。当调整完成后,再次重启Task任务,并检查同步状态。
4)再次重启task任务:
[tidb@tidb1 ~]$ tiup dmctl -master-addr ***.**.***.134:8261 stop-task task3637.yaml
[tidb@tidb1 ~]$ tiup dmctl -master-addr ***.**.***.134:8261 start-task task3637.yaml
5)检查同步状态:
[tidb@tidb1 ~]$ tiup dmctl --master-addr ***.**.***.134:8261 query-status two_tidb_slave
情况2:
全量导入数据之前,该主键数据已经存在于下游数据库中。
判断依据:主键写入数据库的时间即(MVCC时间)早于 load 的时间(min(create_time)),查询时间点可以参考情况3。
解决方法:如仅出现一次主键冲突的情况,可以将下游主键数据删掉,恢复同步任务即可;如多次出现主键冲突,建议删除下游数据以及为位点信息后,重新进行全量数据的导入。
情况3:
由于位点信息被清理导致 sql 文件被重复导入(未重现,需要根据情况进行判断,BUG情况需要提交AskTUG专家进行分析)。
判断依据:根据以下信息可了解到在全量迁移阶段开始后,因某种原因导致 sql 文件位点被删除,sql 文件被重复导入,导致主键冲突。
同步任务全量迁移阶段开始时间为:2020-03-17 11:57:36
该数据插入数据库的时间为:2020-03-17 11:57:37
该文件 test.sbtest5.000000005.sql 记录的创建时间以及更新时间都是 2020-03-17 12:20:29
从 dm-worker.log 中 grep test.sbtest5.000000005.sql 发现同步任务开始后,有两次导入该文件。
解决方法:建议清空下游数据,重新导入。
根据冲突主键的 MVCC 版本以及 dm_meta 中的位点信息具体分析:
1)利用 tidb API 查看主键冲突的行的 mvcc 版本,以此来确认该行数据插入数据库的时间
注意:该操作需要保留现场,该操作是从下游 TiDB 中查询。
#主键为 int 类型,handle 即 int 类型主键。
curl http://{TiDBIP}:1**80/mvcc/key/{db}/{table}/{handle}
#主键为非整数类型。
select _tidb_rowid from xxx where trade_no=‘190606LI8OODRTZA5XX1’;
curl http://{TiDBIP}:1**80/mvcc/key/{db}/{table}/{_tidb_rowid}
根据上述命令得到如下结果:
下一步操作为根据 pd-ctl 将 commit_ts 转化为对应的时间,即解析 tso。
注:也可以在 TiDB 中调用 select TIDB_PARSE_TSO(415345529804292097); 获取对应时间。
2)在 dm_meta 查询 min(create_time) 来获得 load 第一个文件时的时间,可以认为是 全量迁移阶段的开始时间。
3)在 dm_meta 中查看 xxx_loadder_checkpoint 表查看该文件 test.sbtest5.000000005.sql 的详细信息!
4)从 dm-worker 中 grep 查看该主键所在的 .sql 文件出现的时间以及次数
冲突的主键(1292790)所在的文件为 test.sbtest5.000000005.sql
grep test.sbtest5.000000005.sql dm-worker.log



本文作者:陈聪

本文来源:IT那活儿(上海新炬王翦团队)

文章版权归作者所有,未经允许请勿转载,若此文章存在违规行为,您可以联系管理员删除。

转载请注明本文地址:https://www.ucloud.cn/yun/129629.html

相关文章

  • TiDB Ecosystem Tools 原理解读系列(三)TiDB-DM 架构设计与实现原理

    摘要:合库合表数据同步在使用支撑大量数据时,经常会选择使用分库分表的方案。但当将数据同步到后,通常希望逻辑上进行合库合表。为支持合库合表的数据同步,主要实现了以下的一些功能。 作者:张学程 简介 TiDB-DM(Data Migration)是用于将数据从 MySQL/MariaDB 迁移到 TiDB 的工具。该工具既支持以全量备份文件的方式将 MySQL/MariaDB 的数据导入到 Ti...

    legendaryedu 评论0 收藏0
  • DM 源码阅读系列文章(七)定制化数据同步功能的实现

    摘要:作者王相本文为源码阅读系列文章的第七篇,在上篇文章中我们介绍了的实现,主要包括目录结构定义数据的处理流程主从切换支持的读取等逻辑。本篇文章我们将会对的定制化数据同步功能进行详细的讲解。 作者:王相 本文为 DM 源码阅读系列文章的第七篇,在 上篇文章 中我们介绍了 relay log 的实现,主要包括 relay log 目录结构定义、relay log 数据的处理流程、主从切换支持、...

    leo108 评论0 收藏0

发表评论

0条评论

IT那活儿

|高级讲师

TA的文章

阅读更多
最新活动
阅读需要支付1元查看
<