DM在增量同步数据中，报插入主键冲突

Hacker_gYl9RI8v · 2021 年5 月 18 日 13:09

为提高效率，请提供以下信息，问题描述清晰能够更快得到解决：

【TiDB 版本】4.0.12 DM 2.0.3

【问题描述】dm增量数据过程中，突然报错主键冲突。

[2021/05/18 18:40:47.483 +08:00] [ERROR] [db.go:277] [“execute statements failed after retry”] [task=3302] [unit=“binlog replication”] [queries=“[INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user…”] [arguments=“[[1 100120512 100120512 100120600 1956 1 0 0 1 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [47 100120512 100120512 100120600 29245 2 1 0 2 0 0 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [48 100120512 100120512 100120601 1795 3 1 0 3 1 1 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [55 100120512 100120512 100120728 3983 2 1 0 2 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [63 100120512 100120512 100120597 3481 0 0 0 0 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [71 100120512 100120512 100120578 23618 1 0 0 0 0 8 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [80 100120512 100120512 100120775 2735 0 0 0 0 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [92 100120512 100120512 100120572 5845 0 0 0 0 1 1 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [107 100120512 100120512 100120586 5241 0 0 0 0 0 0 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [108 100120512 100120512 100120610 5891 4 2 0 4 3 0 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [115 100120512 10012…”] [error=“[code=10006:class=database:scope=not-set:level=high], Message: execute statement failed: commit, RawCause: Error 1062: Duplicate entry ‘1013’ for key ‘PRIMARY’”]
[2021/05/18 18:40:47.484 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1497 100120512 100120512 100120612 4473 2 1 0 2 2 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“invalid connection”]
[2021/05/18 18:40:47.484 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1518 100120512 100120512 100120597 3396 4 2 0 4 8 1 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“invalid connection”]
[2021/05/18 18:40:47.484 +08:00] [ERROR] [db.go:277] [“execute statements failed after retry”] [task=3302] [unit=“binlog replication”] [queries=“[INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user…”] [arguments=“[[7 100120512 100120512 100120621 1771 0 0 0 0 3 2 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [8 100120512 100120512 100120619 3757 0 0 0 0 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [41 100120512 100120512 100120601 2382 0 0 0 0 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [53 100120512 100120512 100120641 2087 41 21 0 38 53 55 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [65 100120512 100120512 100120576 4355 0 0 0 0 0 1 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [77 100120512 100120512 100120609 40488 0 0 0 0 0 0 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [78 100120512 100120512 100120578 3834 27 14 0 30 13 18 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [86 100120512 100120512 100120578 28784 0 0 0 0 0 0 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [89 100120512 100120512 100120592 594 1 0 0 1 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [94 100120512 100120512 100120576 4446 0 0 0 0 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2] [101 100120512…”] [error=“[code=10006:class=database:scope=not-set:level=high], Message: execute statement failed: commit, RawCause: Error 1062: Duplicate entry ‘934’ for key ‘PRIMARY’”]
[2021/05/18 18:40:47.485 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1552 100120512 100120512 100120612 3434 1 1 0 1 5 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“sql: transaction has already been committed or rolled back”]
[2021/05/18 18:40:47.484 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1372 100120512 100120512 100120601 23043 0 0 0 0 0 0 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“invalid connection”]
[2021/05/18 18:40:47.484 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1357 100120512 100120512 100120609 2077 0 0 0 0 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“sql: transaction has already been committed or rolled back”]
[2021/05/18 18:40:47.485 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1449 100120512 100120512 100120638 360 0 0 0 0 2 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“invalid connection”]
[2021/05/18 18:40:47.486 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1413 100120512 100120512 100120619 823 0 0 0 0 0 0 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“sql: transaction has already been committed or rolled back”]
[2021/05/18 18:40:47.486 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1551 100120512 100120512 100120597 2383 1 0 0 1 1 1 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“invalid connection”]
[2021/05/18 18:40:47.486 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1532 100120512 100120512 100120579 28739 0 0 0 0 0 0 1 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“sql: transaction has already been committed or rolled back”]
[2021/05/18 18:40:47.487 +08:00] [ERROR] [baseconn.go:191] [“rollback failed”] [task=3302] [unit=“binlog replication”] [query=“INSERT INTO h3_stock.t_stock_upper_lower (id,group_id,company_id,business_id,ware_inside_code,stock_upper_limit,stock_lower_limit,stock_min_display,last_thirty_days_sales,last_sixty_days_sales,last_ninety_days_sales,stock_ware_status,create_user,create_time,modify_user,modify_time,is_delete) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)”] [argument=“[1503 100120512 100120512 100120574 780 177 101 0 186 30 2 3 1 2021-05-18 00:00:00 1 2021-05-18 00:00:00 2]”] [error=“sql: transaction has already been committed or rolled back”]
[2021/05/18 18:40:47.501 +08:00] [ERROR] [subtask.go:308] [“unit process error”] [subtask=3302] [unit=Sync] [“error information”=“{"ErrCode":10006,"ErrClass":"database","ErrScope":"not-set","ErrLevel":"high","Message":"startLocation: [position: (, 0), gtid-set: ], endLocation: [position: (3302-binlog.000517, 113463720), gtid-set: ]: execute statement failed: commit","RawCause":"Error 1062: Duplicate entry ‘1013’ for key ‘PRIMARY’"}”]
[2021/05/18 18:40:47.501 +08:00] [ERROR] [subtask.go:308] [“unit process error”] [subtask=3302] [unit=Sync] [“error information”=“{"ErrCode":10006,"ErrClass":"database","ErrScope":"not-set","ErrLevel":"high","Message":"startLocation: [position: (, 0), gtid-set: ], endLocation: [position: (3302-binlog.000517, 113459256), gtid-set: ]: execute statement
failed: commit","RawCause":"Error 1062: Duplicate entry ‘934’ for key ‘PRIMARY’"}”]

DM配置

表结构
Create Table: CREATE TABLE t_stock_upper_lower (
id bigint(20) NOT NULL AUTO_INCREMENT COMMENT ‘主键id’,
group_id bigint(20) NOT NULL COMMENT ‘集团编码’,
company_id bigint(20) NOT NULL COMMENT ‘企业编码’,
business_id bigint(20) NOT NULL COMMENT ‘业务机构编码’,
ware_inside_code bigint(20) NOT NULL COMMENT ‘商品自编码’,
stock_upper_limit double(16,4) DEFAULT ‘0.0000’ COMMENT ‘库存上限’,
stock_lower_limit double(16,4) DEFAULT ‘0.0000’ COMMENT ‘库存下限’,
stock_min_display double(16,4) DEFAULT ‘0.0000’ COMMENT ‘最低陈列量’,
last_thirty_days_sales double(16,4) DEFAULT NULL COMMENT ‘最近30天销量’,
last_sixty_days_sales double(16,4) DEFAULT NULL COMMENT ‘最近60天销量’,
last_ninety_days_sales double(16,4) DEFAULT NULL COMMENT ‘最近90天销量’,
stock_ware_status tinyint(2) DEFAULT NULL COMMENT ‘库存商品状态’,
create_user bigint(20) DEFAULT NULL COMMENT ‘创建人’,
create_time datetime NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT ‘创建时间’,
modify_user bigint(20) DEFAULT NULL COMMENT ‘最终修改人’,
modify_time datetime NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT ‘最终修改时间’,
is_delete tinyint(2) DEFAULT ‘2’,
PRIMARY KEY (id) USING BTREE,
KEY stock (group_id,company_id,business_id,ware_inside_code) USING BTREE
) ENGINE=InnoDB AUTO_INCREMENT=108263 DEFAULT CHARSET=utf8mb4 ROW_FORMAT=DYNAMIC

是我配置有问题吗，如果不是，那这太不靠谱了？这个时间点业务都没压力。目前是resume-task恢复的。后面这种情况该如何处理呢？任务它自己又不能恢复。

zhenjiaogao · 2021 年5 月 18 日 14:33

DM 出现主键或者唯一键冲突时建议从下面的方式来定位下：

查看下上游同步的数据中是否存在主键或者唯一键冲突，尤其是分库分表到 TiDB 合库合表的场景
请使用 tidb 的 api 查看下出现冲突的 key 的 mvcc 版本信息，参考链接如下：
https://github.com/pingcap/tidb/blob/master/docs/tidb_http_api.md
如果方便请提供下出现报错的表的建表语句，对应时间段的 tidb.log，dm-worker 的 log 日志
pause 和 resume 后，前 5 分钟为 safe-mode 模式，故在作为此操作后任务恢复正常

https://docs.pingcap.com/zh/tidb-data-migration/stable/glossary#safe-mode

Hacker_gYl9RI8v · 2021 年5 月 19 日 01:48

1 不存在分库分表的场景
2 昨天出现的，今天还能通过API查看吗？？
3 建表语句在上面提供了。而且这是增量同步，DM从以前的1.0.4更换到2.0.3版本。
感觉1.0.4版本还稳定些。

Hacker_gYl9RI8v · 2021 年5 月 19 日 02:07

tidb.rar (745.2 KB) worker.rar (169.2 KB)

小王同学 · 2021 年5 月 19 日 02:09

想请问下，更换具体操作是什么样子的？是指 tiup import 导入升级到 2.0 吗？

这个无法查询到了，有现场时才可以查到之前数据的写入时间。当前已经恢复了的话，是覆盖写入了的。

Hacker_gYl9RI8v · 2021 年5 月 19 日 02:11

1.0.4版本是直接摧毁的。2.0.3版本是直接按照重新同步上游mysql数据库的。

小王同学 · 2021 年5 月 19 日 03:04

重新同步是清理下游数据库和 checkpoint 信息了吧。

目前没有现场无法排查了，后续如果复现问题希望拿一下下面信息，主要是冲突 key 的 mvcc 版本信息。

Hacker_gYl9RI8v · 2021 年5 月 19 日 08:20

重新同步的时候dm_meta 库都删除了。
建表语句及日志在4楼

小王同学 · 2021 年5 月 19 日 09:39

后续复现问题的时候再拿下信息吧，当前无法确认已存在的数据写入时间。