【TiDB 版本】：
3.0.5
【与此问题相关的资料】：
异常：TxnLockNotFound 引发的原因：
这个报错是因为第一个事务一直没有提交，在等待一定时间之后后面的事务会清理掉之前事务的锁信息，等到第一个事务再去提交的时候发现锁没了，就会报错 TxnLockNotFound。
【问题描述】：
使用**REPLACE INTO**批量插入数据, 刚开始插入数据时，没有问题，虽着数据量的增多，出现了如下问题：
- [WARN] [pd.go:109] [“get timestamp too slow”]
- [WARN] [session.go:446] [“commit failed”] [conn=67956] [“finished txn”=“Txn{state=invalid}”]
- [WARN] [session.go:964] [“run statement error”] [conn=67956] [schemaVersion=11638]
- [error="[executor:5]BatchInsert failed with error:
- [error="[kv:6]Error: KV error safe to retry tikv restarts txn: Txn(Mvcc(TxnLockNotFound
详情请看 tidb.log
tidb.log
[2020/01/06 09:14:17.831 +08:00] [INFO] [coprocessor.go:743] ["[TIME_COP_PROCESS] resp_time:527.478167ms txnStartTS:413734864303685633 region_id:45309 store_addr:192.168.180.52:20160 kv_process_ms:487 scan_total_write:0 scan_processed_write:0 scan_total_data:0 scan_processed_data:0 scan_total_lock:0 scan_processed_lock:0"]
[2020/01/06 09:14:17.995 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=tx_read_only] [val=0]
[2020/01/06 09:14:17.995 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=transaction_read_only] [val=0]
[2020/01/06 09:14:18.035 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=tx_read_only] [val=1]
[2020/01/06 09:14:18.035 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=transaction_read_only] [val=1]
[2020/01/06 09:14:18.358 +08:00] [INFO] [coprocessor.go:743] ["[TIME_COP_PROCESS] resp_time:473.771127ms txnStartTS:413734864303685633 region_id:45309 store_addr:192.168.180.52:20160 kv_process_ms:441 scan_total_write:0 scan_processed_write:0 scan_total_data:0 scan_processed_data:0 scan_total_lock:0 scan_processed_lock:0"]
[2020/01/06 09:14:18.464 +08:00] [WARN] [pd.go:109] ["get timestamp too slow"] ["cost time"=33.398166ms]
[2020/01/06 09:14:18.464 +08:00] [WARN] [pd.go:109] ["get timestamp too slow"] ["cost time"=33.418478ms]
[2020/01/06 09:14:18.720 +08:00] [INFO] [coprocessor.go:743] ["[TIME_COP_PROCESS] resp_time:516.293349ms txnStartTS:413734864972152837 region_id:43958 store_addr:192.168.180.52:20160"]
[2020/01/06 09:14:18.720 +08:00] [INFO] [coprocessor.go:743] ["[TIME_COP_PROCESS] resp_time:11.667046254s txnStartTS:413734862062354433 region_id:42622 store_addr:192.168.180.52:20160"]
[2020/01/06 09:14:18.720 +08:00] [INFO] [coprocessor.go:743] ["[TIME_COP_PROCESS] resp_time:5.141018788s txnStartTS:413734863766290433 region_id:43958 store_addr:192.168.180.52:20160"]
[2020/01/06 09:14:18.720 +08:00] [INFO] [coprocessor.go:743] ["[TIME_COP_PROCESS] resp_time:12.94245714s txnStartTS:413734861590495236 region_id:45309 store_addr:192.168.180.52:20160 kv_process_ms:457 scan_total_write:248397 scan_processed_write:229394 scan_total_data:248351 scan_processed_data:229394 scan_total_lock:6 scan_processed_lock:0"]
[2020/01/06 09:14:18.748 +08:00] [WARN] [session.go:446] ["commit failed"] [conn=67956] ["finished txn"="Txn{state=invalid}"] [error="[kv:6]Error: KV error safe to retry tikv restarts txn: Txn(Mvcc(TxnLockNotFound { start_ts: 413734862848786436, commit_ts: 413734865129439233, key: [116, 128, 0, 0, 0, 0, 0, 52, 197, 95, 105, 128, 0, 0, 0, 0, 0, 0, 1, 1, 51, 49, 52, 53, 51, 100, 52, 56, 255, 57, 102, 101, 51, 52, 50, 97, 50, 255, 56, 57, 100, 55, 53, 51, 56, 99, 255, 98, 57, 56, 101, 53, 98, 53, 52, 255, 0, 0, 0, 0, 0, 0, 0, 0, 247] })) [try again later]"]
[2020/01/06 09:14:18.748 +08:00] [INFO] [tidb.go:169] ["rollbackTxn for ddl/autocommit error."]
[2020/01/06 09:14:18.758 +08:00] [WARN] [session.go:964] ["run statement error"] [conn=67956] [schemaVersion=11638] [error="[executor:5]BatchInsert failed with error: [kv:6]Error: KV error safe to retry tikv restarts txn: Txn(Mvcc(TxnLockNotFound { start_ts: 413734862848786436, commit_ts: 413734865129439233, key: [116, 128, 0, 0, 0, 0, 0, 52, 197, 95, 105, 128, 0, 0, 0, 0, 0, 0, 1, 1, 51, 49, 52, 53, 51, 100, 52, 56, 255, 57, 102, 101, 51, 52, 50, 97, 50, 255, 56, 57, 100, 55, 53, 51, 56, 99, 255, 98, 57, 56, 101, 53, 98, 53, 52, 255, 0, 0, 0, 0, 0, 0, 0, 0, 247] })) [try again later]"]
[errorVerbose="[executor:5]BatchInsert failed with error: [kv:6]Error: KV error safe to retry tikv restarts txn: Txn(Mvcc(TxnLockNotFound { start_ts: 413734862848786436, commit_ts: 413734865129439233, key: [116, 128, 0, 0, 0, 0, 0, 52, 197, 95, 105, 128, 0, 0, 0, 0, 0, 0, 1, 1, 51, 49, 52, 53, 51, 100, 52, 56, 255, 57, 102, 101, 51, 52, 50, 97, 50, 255, 56, 57, 100, 55, 53, 51, 56, 99, 255, 98, 57, 56, 101, 53, 98, 53, 52, 255, 0, 0, 0, 0, 0, 0, 0, 0, 247] })) [try again later]
github.com/pingcap/errors.AddStack
github.com/pingcap/errors@v0.11.4/errors.go:174
github.com/pingcap/parser/terror.(*Error).GenWithStack
github.com/pingcap/parser@v0.0.0-20191018040038-555b97093a2a/terror/terror.go:231
github.com/pingcap/tidb/executor.(*InsertValues).doBatchInsert
github.com/pingcap/tidb@/executor/insert_common.go:368
github.com/pingcap/tidb/executor.(*InsertValues).insertRows
github.com/pingcap/tidb@/executor/insert_common.go:213
github.com/pingcap/tidb/executor.(*ReplaceExec).Next
github.com/pingcap/tidb@/executor/replace.go:194
github.com/pingcap/tidb/executor.Next
github.com/pingcap/tidb@/executor/executor.go:191
github.com/pingcap/tidb/executor.(*ExecStmt).handleNoDelayExecutor
github.com/pingcap/tidb@/executor/adapter.go:431
github.com/pingcap/tidb/executor.(*ExecStmt).Exec
github.com/pingcap/tidb@/executor/adapter.go:295
github.com/pingcap/tidb/session.runStmt
github.com/pingcap/tidb@/session/tidb.go:238
github.com/pingcap/tidb/session.(*session).executeStatement
github.com/pingcap/tidb@/session/session.go:961
github.com/pingcap/tidb/session.(*session).execute
github.com/pingcap/tidb@/session/session.go:1076
github.com/pingcap/tidb/session.(*session).Execute
github.com/pingcap/tidb@/session/session.go:999
github.com/pingcap/tidb/server.(*TiDBContext).Execute
github.com/pingcap/tidb@/server/driver_tidb.go:246
github.com/pingcap/tidb/server.(*clientConn).handleQuery
github.com/pingcap/tidb@/server/conn.go:1195
github.com/pingcap/tidb/server.(*clientConn).dispatch
github.com/pingcap/tidb@/server/conn.go:913
github.com/pingcap/tidb/server.(*clientConn).Run
github.com/pingcap/tidb@/server/conn.go:666
github.com/pingcap/tidb/server.(*Server).onConn
github.com/pingcap/tidb@/server/server.go:440
runtime.goexit
runtime/asm_amd64.s:1357"] [session="{
\"currDBName\": \"pressure_pfizer\",
\"id\": 67956,
\"status\": 2,
\"strictMode\": true,
\"user\": {
\"Username\": \"root\",
\"Hostname\": \"192.168.181.55\",
\"CurrentUser\": false,
\"AuthUsername\": \"root\",
\"AuthHostname\": \"%\"
}
}"]
[2020/01/06 09:14:18.759 +08:00] [WARN] [conn.go:682] ["dispatch error"] [conn=67956] [connInfo="id:67956, addr:192.168.181.55:37374 status:10, collation:utf8_general_ci, user:root"] [command=Query] [status="inTxn:0, autocommit:1"]
[sql="replace into dc_table_1(a,b,c,.............,paas_id) values
('DI00007963',null,null,'DI00007963','烟台毓璜顶医院','HO00001522',null,null,'115965','********','10502',25,25,null,null,null,'1',null,null,null,'null','2019-12-30 00:00:00','1',null,845.null,null,342.0,8561.0,null,null,'烟台市********','1mg*14片',null,'000010','AX9640',null,'0','后台接口','2020-01-06 09:13:50.718','后台接口','2020-01-06 09:13:50.718',null,'0','151bcb3d5b724025bc5c51fb37372787')
,('DI00007963',null,null,'DI00007963','济宁新华********有限公司','DS0074183',null,null,'115965','********','10502',5,5,null,null,null,'1',null,null,null,'null','2019-12-30 00:00:00','1',null,829.null,null,342.0,1712.0,null,null,'山东省济宁市********','1mg*14片',null,'000020','AX9640',null,'0','后台接口','2020-01-06 09:13:50.718','后台接口','2020-01-06 09:13:50.718',null,'0','27c1ba4933eb486ca9d688b549cc29c0')
,('DI00007963',null,null,'DI00007963','济宁********','HO00024124',null,null,'115967','********','10502',1,1,null,null,null,'1',null,null,null,'null','2019-12-30 00:00:00','1',null,5796,null,342.null,342.null,null,null,'济宁市市中********','34rfd',null,'000010','********',null,'0','后台接口','2020-01-06 09:13:50.718','后台接口','2020-01-06 09:13:50.718',null,'0','c4bf2d8a661e4a0a9456c5bc9d1c9388')
,('DI00007963',null,null,'DI00007963','山东大学********','HO00001404',null,null,'115967','********','10502',18,18,null,null,null,'1',null,null,null,'null','2019-12-30 00:00:00','1',null,5796,null,342.null,6164.0,null,null,'济南市********','asdf',null,'000010','********',null,'0','后台接口','2020-01-06 09:13:50.718','后台接口','2020-01-06 09:13:50.718',null,'0','1979b25f3c484b1caf37cb7f4d0bfb8f')
,('DI00007963',null,null,'DI00007963','华润德州********','DI00015380',null,null,'115967','********','10502',10,10,null,null,null,'1',null,null,null,'null','2019-12-30 00:00:00','1',null,5553.0,null,342.0,3424.0,null,null,'山东省德州市********','asdf',null,'000010','********',null,'0','后>台接口','2020-01-06 09:13:50.718','后台接口','2020-01-06 09:1(len: 720114)"]
[err="[executor:5]BatchInsert failed with error: [kv:6]Error: KV error safe to retry tikv restarts txn: Txn(Mvcc(TxnLockNotFound { start_ts: 413734862848786436, commit_ts: 413734865129439233, key: [116, 128, 0, 0, 0, 0, 0, 52, 197, 95, 105, 128, 0, 0, 0, 0, 0, 0, 1, 1, 51, 49, 52, 53, 51, 100, 52, 56, 255, 57, 102, 101, 51, 52, 50, 97, 50, 255, 56, 57, 100, 55, 53, 51, 56, 99, 255, 98, 57, 56, 101, 53, 98, 53, 52, 255, 0, 0, 0, 0, 0, 0, 0, 0, 247] })) [try again later]
github.com/pingcap/errors.AddStack
github.com/pingcap/errors@v0.11.4/errors.go:174
github.com/pingcap/parser/terror.(*Error).GenWithStack
github.com/pingcap/parser@v0.0.0-20191018040038-555b97093a2a/terror/terror.go:231
github.com/pingcap/tidb/executor.(*InsertValues).doBatchInsert
github.com/pingcap/tidb@/executor/insert_common.go:368
github.com/pingcap/tidb/executor.(*InsertValues).insertRows
github.com/pingcap/tidb@/executor/insert_common.go:213
github.com/pingcap/tidb/executor.(*ReplaceExec).Next
github.com/pingcap/tidb@/executor/replace.go:194
github.com/pingcap/tidb/executor.Next
github.com/pingcap/tidb@/executor/executor.go:191
github.com/pingcap/tidb/executor.(*ExecStmt).handleNoDelayExecutor
github.com/pingcap/tidb@/executor/adapter.go:431
github.com/pingcap/tidb/executor.(*ExecStmt).Exec
github.com/pingcap/tidb@/executor/adapter.go:295
github.com/pingcap/tidb/session.runStmt
github.com/pingcap/tidb@/session/tidb.go:238
github.com/pingcap/tidb/session.(*session).executeStatement
github.com/pingcap/tidb@/session/session.go:961
github.com/pingcap/tidb/session.(*session).execute
github.com/pingcap/tidb@/session/session.go:1076
github.com/pingcap/tidb/session.(*session).Execute
github.com/pingcap/tidb@/session/session.go:999
github.com/pingcap/tidb/server.(*TiDBContext).Execute
github.com/pingcap/tidb@/server/driver_tidb.go:246
github.com/pingcap/tidb/server.(*clientConn).handleQuery
github.com/pingcap/tidb@/server/conn.go:1195
github.com/pingcap/tidb/server.(*clientConn).dispatch
github.com/pingcap/tidb@/server/conn.go:913
github.com/pingcap/tidb/server.(*clientConn).Run
github.com/pingcap/tidb@/server/conn.go:666
github.com/pingcap/tidb/server.(*Server).onConn
github.com/pingcap/tidb@/server/server.go:440
runtime.goexit
runtime/asm_amd64.s:1357"]
[2020/01/06 09:14:18.783 +08:00] [INFO] [2pc.go:1039] ["2PC clean up done"] [conn=67956] [txnStartTS=413734862848786436]
[2020/01/06 09:14:18.830 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=tx_read_only] [val=0]
[2020/01/06 09:14:18.830 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=transaction_read_only] [val=0]
[2020/01/06 09:14:18.854 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=tx_read_only] [val=1]
[2020/01/06 09:14:18.854 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67960] [name=transaction_read_only] [val=1]
[2020/01/06 09:14:19.069 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=tx_read_only] [val=0]
[2020/01/06 09:14:19.069 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=transaction_read_only] [val=0]
[2020/01/06 09:14:19.103 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=tx_read_only] [val=1]
[2020/01/06 09:14:19.103 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=transaction_read_only] [val=1]
[2020/01/06 09:14:19.104 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67977] [name=tx_read_only] [val=1]
[2020/01/06 09:14:19.104 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67977] [name=transaction_read_only] [val=1]
[2020/01/06 09:14:19.392 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=tx_read_only] [val=0]
[2020/01/06 09:14:19.392 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67977] [name=tx_read_only] [val=0]
[2020/01/06 09:14:19.392 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=transaction_read_only] [val=0]
[2020/01/06 09:14:19.392 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67977] [name=transaction_read_only] [val=0]
[2020/01/06 09:14:19.420 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=tx_read_only] [val=1]
[2020/01/06 09:14:19.420 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=transaction_read_only] [val=1]
[2020/01/06 09:14:19.473 +08:00] [WARN] [pd.go:109] ["get timestamp too slow"] ["cost time"=51.675798ms]
[2020/01/06 09:14:19.473 +08:00] [WARN] [pd.go:109] ["get timestamp too slow"] ["cost time"=42.0153ms]
[2020/01/06 09:14:19.473 +08:00] [WARN] [pd.go:109] ["get timestamp too slow"] ["cost time"=42.024573ms]
[2020/01/06 09:14:19.784 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=tx_read_only] [val=0]
[2020/01/06 09:14:19.784 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=transaction_read_only] [val=0]
[2020/01/06 09:14:19.814 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=tx_read_only] [val=1]
[2020/01/06 09:14:19.814 +08:00] [INFO] [set.go:192] ["set session var"] [conn=67968] [name=transaction_read_only] [val=1]
上面的资料中说明了是因为事务的冲突和select超时，但是我是向一张空表中插入数据，为什么也会有这样的问题呢？
【我期望的】：
- 这个异常的引发原因
- 如何避免这样的问题发生
- 这个异常对数据的影响