batch dml 有概率出现 主键重复

🌞 建议反馈 产品缺陷
1

【6.5.0】
sysbench 初始化1亿条数据

image
image1883×587 17.5 KB

image
image713×261 4.95 KB

2

:dotted_line_face: 这就很尴尬啊。

3

能不能看一下 tidb.log ，关键字 nontransactional.go 类似这样的日志，有没有出现边界重复。
tidb.log 日志例举如下：

[2022/12/30 09:45:53.436 +08:00] [INFO] [nontransactional.go:423] [“start a Non-transactional DML”] [conn=3074535777447707195] [job=“job id: 1, estimated size: 1000, sql: INSERT INTO `test_order`.`test_order_target` SELECT * FROM `test_order`.`test_order` WHERE `id` BETWEEN 5 AND 100902”] [totalJobCount=30319]

[2022/12/30 12:05:55.725 +08:00] [INFO] [nontransactional.go:445] [“Non-transactional DML SQL finished successfully”] [conn=3074535777447707195] [jobID=30319] [jobSize=907] [dmlSQL=“INSERT INTO `test_order`.`test_order_target` SELECT * FROM `test_order`.`test_order` WHERE `id` BETWEEN 119960228 AND 119961136”]

4

我在6.5.0环境测试了1000万左右的数据，并没有复现

5

按 nontransactional 关键字过滤的日志，3个tidb节点 k8s上部署的，kubectl logs 查看日志 有2个节点有数据。
实际上我这个动作是做了3次，第一次 因为会话超时被终止了，然后truncate了表 开始的第二次，第二次时报了主键重复的报错，之后再次truncate后执行没有报错。

log.rar (278.7 KB)

6

我感觉我碰上这个问题原因不是在任务的切分范围上，而是tidb本身，可能有某些数据没有被及时清理

7

应该还是遗留数据的问题，从切分上看，没问题。batch.txt 这个子任务前后有没有别的错误。因为执行多次，可以检查一下，truncate 前是不是上一个任务是不是确认结束了。

[2023/02/23 11:57:16.391 +08:00] [INFO] [nontransactional.go:423] [“start a Non-transactional DML”] [conn=4581018440105527369] [job=“job id: 17031, estimated size: 5000, sql: INSERT INTO sbtest.sbtestbak SELECT * FROM sbtest.sbtest1 WHERE sbtest1.id BETWEEN 85820988 AND 85825987”] [totalJobCount=20000]
[2023/02/23 11:57:16.501 +08:00] [INFO] [nontransactional.go:445] [“Non-transactional DML SQL finished successfully”] [conn=4581018440105527369] [jobID=17031] [jobSize=5000] [dmlSQL=“INSERT INTO sbtest.sbtestbak SELECT * FROM sbtest.sbtest1 WHERE sbtest1.id BETWEEN 85820988 AND 85825987”]

8

没法检查了，有可能是虽然执行操作终端会话被断开了，但实际之前的任务并没有被终止，针对异常退出会有什么处理吗

9

日志不太全，还是得看一下两个 batch 语句 start a Non-transactional DML做为起始时间 ，最后一个 jobid 做为结束时间 。
admin show ddl jobs 的 truncate 时间 ，看一下各个时间 有没有交叉。

10

还有看一下，tidb.log 在 duplicate key 报错期间的上下日志。

11

image
image1187×239 9.34 KB

找不到了，我猜测原因就是第一次会话被终止后，但系统内没有被及时终止，导致truncate后还有一段时间原来的任务运行， 日志里是不是可以加点信息来标识每次唯一的执行，类似于一个事务ID。

12

truncate 没执行完成，就开始 新版本数据的批量插入了？ :+1: 这个测试有价值

13

是中断的会话没有及时停止或清理

14

除了一个会话内相同操作多次，基本上 conn id + job id 可以定位分段的唯一执行。
BTW: K8S 环境的 POD 日志，最好用其他手段持久化一下。