Loader 导入时主键冲突

为提高效率,提问时请尽量提供详细背景信息,问题描述清晰可优先响应。以下信息点请尽量提供:

  • 系统版本 & kernel 版本:
  • TiDB 版本:v3.0.3
  • 磁盘型号:
  • 集群节点分布:1TIDB,1PD,3TIKV
  • 数据量 & region 数量 & 副本数:
  • 集群 QPS、.999-Duration、读写比例:
  • 问题描述(我做了什么): 按照TIDB官方ansible部署,因为测试环境跳过了系统检测,所有参数都是默认配置 然后从开发环境导出数据 导出语句 ./bin/mydumper -h 172.18.8.30 -P 3400 -u xxx -p ‘xxx’ -t 16 -F 64 -B xxx --skip-tz-utc -o /DATA1/xxx
    然后使用loader导入 /DATA1/tools/tidb-tools/tidb-enterprise-tools-latest-linux-amd64/bin/loader -d /DATA1/xxx/ -h 127.0.0.1 -u root -P 4000 问题: 再倒入部分数据后,报错 2019/09/23 18:04:31 loader.go:124: [fatal] Error 1062: Duplicate entry ‘18855454’ for key ‘PRIMARY’ 重试 删除tidb-loader库和已经导入数据的库后还是会有相同问题 有时候重试还会有2019/09/23 16:39:39 loader.go:190: [error] init sale_vip.t_collect_honey.000000010.sql checkpoint error:initialize checkpoint: invalid connection这种报错

查看表的批量sql文件,确认只有这一个主键值并且在数据库中已经插入 求大佬解答

麻烦完整的 loader 日志打包也传一个,多谢。

2019/09/23 18:04:14 db.go:76: [warning] exec sql retry 4 - [USE sale_vip; INSERT INTO qa_log_honey VALUES(41705279,69665354,’’,’’,0,98,1,‘2017-07-22 13:57:43’,0,‘22610828’, UPDATE tidb_loader.checkpoint SET offset=4999885 WHERE id =‘bcc433’ AND filename=‘sale_vip] 2019/09/23 18:04:14 db.go:111: [error] exec sqls[[USE sale_vip; INSERT INTO qa_log_honey VALUES(2631778,58063636,’’,’’,0,37,3,‘2015-08-22 08:51:36’,0,‘0’,2,3,’{" UPDATE tidb_loader.checkpoint SET offset=16999459 WHERE id =‘bcc433’ AND filename=‘sale_vi]] begin failed dial tcp 127.0.0.1:4000: connect: connection refused 2019/09/23 18:04:14 db.go:76: [warning] exec sql retry 4 - [USE sale_vip; INSERT INTO qa_log_honey VALUES(2631778,58063636,’’,’’,0,37,3,‘2015-08-22 08:51:36’,0,‘0’,2,3,’{" UPDATE tidb_loader.checkpoint SET offset=16999459 WHERE id =‘bcc433’ AND filename=‘sale_vi] 2019/09/23 18:04:14 db.go:111: [error] exec sqls[[USE sale_vip; INSERT INTO t_collect_honey VALUES(18158965,36994652,91703574,’’,’’,’’,1,‘2019-07-31 08:37:08’,0,’ UPDATE tidb_loader.checkpoint SET offset=17998918 WHERE id =‘bcc433’ AND filename=‘sale_vi]] begin failed dial tcp 127.0.0.1:4000: connect: connection refused 2019/09/23 18:04:14 db.go:76: [warning] exec sql retry 4 - [USE sale_vip; INSERT INTO t_collect_honey VALUES(18158965,36994652,91703574,’’,’’,’’,1,‘2019-07-31 08:37:08’,0,’ UPDATE tidb_loader.checkpoint SET offset=17998918 WHERE id =‘bcc433’ AND filename='sale_vi] 2019/09/23 18:04:17 status.go:32: [info] [loader] finished_bytes = 953233802, total_bytes = GetAllRestoringFiles4261909137, progress = 22.37 % 2019/09/23 18:04:22 status.go:32: [info] [loader] finished_bytes = 953233802, total_bytes = GetAllRestoringFiles4261909137, progress = 22.37 % 2019/09/23 18:04:27 db.go:137: [warning] update checkpoint affected rows 0 2019/09/23 18:04:27 status.go:32: [info] [loader] finished_bytes = 953233802, total_bytes = GetAllRestoringFiles4261909137, progress = 22.37 % 2019/09/23 18:04:27 db.go:137: [warning] update checkpoint affected rows 0 2019/09/23 18:04:30 db.go:105: [warning] transaction execution costs 8.169627 seconds 2019/09/23 18:04:30 db.go:105: [warning] transaction execution costs 8.339114 seconds 2019/09/23 18:04:30 db.go:105: [warning] transaction execution costs 8.339362 seconds 2019/09/23 18:04:31 db.go:105: [warning] transaction execution costs 8.917922 seconds 2019/09/23 18:04:31 loader.go:124: [fatal] Error 1062: Duplicate entry ‘18855454’ for key ‘PRIMARY’ /home/jenkins/workspace/build_tidb_enterprise_tools_master/go/src/github.com/pingcap/tidb-enterprise-tools/loader/db.go:144: /home/jenkins/workspace/build_tidb_enterprise_tools_master/go/src/github.com/pingcap/tidb-enterprise-tools/loader/db.go:84: /home/jenkins/workspace/build_tidb_enterprise_tools_master/go/src/github.com/pingcap/tidb-enterprise-tools/loader/loader.go:124: file sale_vip.qa_log_honey.000000017.sql

这是报错前的部分日志,完整日志我需要重新跑一遍,磁盘不行,现在只是测试功能

2019/09/23 18:04:14 db.go:111: [error] exec sqls[[USE sale_vip; INSERT INTO qa_log_honey VALUES(2631778,58063636,’’,’’,0,37,3,‘2015-08-22 08:51:36’,0,‘0’,2,3,’{" UPDATE tidb_loader.checkpoint SET offset=16999459 WHERE id =‘bcc433’ AND filename=‘sale_vi]] begin failed dial tcp 127.0.0.1:4000: connect: connection refused

通过日志看到在导入过程中出现连接被拒绝的现象。先排查一下网络以及目标集群是否稳定。另外,把Loader 完整日志贴一下

loader.log.tar.gz (9.7 KB) 这是全部的loader日志,即使网络或者机器性能瓶颈应该都不会出现主键冲突才对吧,不是会将断点写入tidb_loader库吗

loader.log.tar.gz (9.7 KB) 这是完整的日志,但是无论网络或者目标集群是否稳定,不应该主键冲突吧,不是会将断点写入tidb_loader库吗

查看日志里面 发现大量的 begin failed dial tcp 127.0.0.1:4000: connect: connection refused 报错,另外 Duplicate entry ‘17629583’ for key ‘PRIMARY’ 麻烦在上下游查下这个 key 对应的数据情况。

上下游是指哪里,在mysql里面数据正常,每次报错都是不同的主键值

这个是主键信息,上游如果数据重复在mysql里面也会报冲突,并且查看了备份文件没有重复数据,就是不知道为什么做了重复导入

目前 loader 导入过程中如果出现网络问题或者下游服务繁忙,因为重试策略,可能会出现数据重复导入的问题。有两点建议:

  1. 检查网络状况和下游负载,适当减少导入并发度尝试重新导入
  2. 使用 DM 进行数据全量导入(DM 已经对这类问题进行了修复)

重试策略不基于tidb_loader这个库里面的那个点吗,为什么会重试失败呢

loader 向下游执行一个事务的过程中,可能因为网络问题导致执行返回结果出错,但实际数据已经写入到下游,重试时就会出现 Duplicate entry for key ‘PRIMARY’ 的报错。可以测试一下出错后不删除下游 tidb_loader 和下游数据,从新使用 loader 导入,是否可以恢复导入

试过,删除不删除数据都可以继续执行,只不过一会还会报错

loader也是将文件拉到本地,在本地进行导入的,测试环境应该不用要求网络那么高吧

导入的时候有检查下游负载么,loader 使用的并发度是多少?

没有增加额外并发,使用的是默认值,导入过程中看磁盘IO只有一个TIKV节点变为50%以上,内存占用70%,cpu占用50%以上,没有到很饱和

  1. 检查 loader 的日志 2019/09/25 09:29:45 db.go:125: [error] [exec][sql][USEsale_vip; INSERT INTO xxxxxxxx][error]invalid connection 这种报错会导致数据写入但仍会在 loader 中重试
  2. 后续有很多 2019/09/25 09:29:47 db.go:111: [error] exec sqls[[USEsale_vip; INSERT INTO xxxxxxxx] begin failed dial tcp 127.0.0.1:4000: connect: connection refused 这种报错,是下游数据库连接无法建立,需要检查下游数据库服务是否正常
  3. 可以先检查一下出错时候下游 TiDB 有哪些报错,从 loader 的日志看是下游繁忙导致的

这个具体报错看哪里,TIDB的日志?

tidb.tar.gz (3.1 MB) 我看现在没有任何操作以及数据写入也在报 [error=“rpc error: code = Canceled desc = grpc: the client connection is closing”]这种error,这次导入是上午9点多导入的

loader 的日志和 tidb 日志的时间点不太对的上,两台机器是否有时间差 有尝试过降低 loader 并发度导入么