When receive "Lock wait timeout exceeded; try restarting transaction" errors, it is not easy to locate the problem
- Dominant language
- Go
- Stars
- 40.5k
- Forks
- 6.2k
- PR merge metrics
- PR metrics pending
Description
## Background
Users complain that query latency increases and receive execution error: "Lock wait timeout exceeded; try restarting transaction", hoping to know the cause of the problem.
## Reproduce
Prepare:
```sql
create table t (id varchar(100), v int, unique index(id));
```
session-A: Execute following SQL in a loop.
```sql
begin;
insert into t (id, v) values ('A',1) on duplicate key update v =v + 1;
commit;
```
session-B: execute following SQL:
```sql
begin;
insert into t (id, v) values ('A',1) on duplicate key update v =v + 1;
-- sleep 120s
commit;
```
then, session-A will receive error: `Error 1205: Lock wait timeout exceeded; try restarting transaction`
the related error log in TiDB is:
```
tidb.log
[2023/10/07 08:57:01.948 +08:00] [INFO] [2pc.go:1163] ["send TxnHeartBeat"] [startTS=444764045974175763] [newTTL=51900]
[2023/10/07 08:57:11.949 +08:00] [INFO] [2pc.go:1163] ["send TxnHeartBeat"] [startTS=444764045974175763] [newTTL=61900]
[2023/10/07 08:57:21.949 +08:00] [INFO] [2pc.go:1163] ["send TxnHeartBeat"] [startTS=444764045974175763] [newTTL=71900]
[2023/10/07 08:57:21.958 +08:00] [WARN] [session.go:2252] ["run statement failed"] [conn=1785932338950046109] [schemaVersion=40] [error="[tikv:1205]Lock wait timeout exceeded; try restarting transaction"] [session="{\n \"currDBName\": \"test\",\n \"id\": 1785932338950046109,\n \"lastInsertID\": 12881,\n \"status\": 3,\n \"strictMode\": true,\n \"txn\": \"444764046472249350\",\n \"user\": {\n \"Username\": \"root\",\n \"Hostname\": \"127.0.0.1\",\n \"CurrentUser\": false,\n \"AuthUsername\": \"root\",\n \"AuthHostname\": \"%\"\n }\n}"]
[2023/10/07 08:57:21.958 +08:00] [INFO] [conn.go:1181] ["command dispatched failed"] [conn=1785932338950046109] [connInfo="id:1785932338950046109, addr:127.0.0.1:52053 status:11, collation:utf8mb4_general_ci, user:root"] [command=Query] [status="inTxn:1, autocommit:1"] [sql="begin;insert into t (id, v) values ('A', last_insert_id(1)) on duplicate key update v = last_insert_id(v + 1);commit;"] [txn_mode=PESSIMISTIC] [timestamp=444764046472249350] [err="[tikv:1205]Lock wait timeout exceeded; try restarting transaction"]
```
## Enhancement
Currently, when receive "Lock wait timeout exceeded; try restarting transaction" errors, it is not easy to locate who holds the lock, only knowing who holds the lock can help the user modify the business logic.
We need to log more information in this situation.
## Version
```sql
***************************[ 1. row ]***************************
tidb_version() | Release Version: v6.5.5
Edition: Community
Git Commit Hash: 71bcc44f77a37cfb0a6dc3660e092c78c1e46acb
Git Branch: heads/refs/tags/v6.5.5
UTC Build Time: 2023-09-18 10:13:45
GoVersion: go1.19.12
Race Enabled: false
TiKV Min Version: 6.2.0-alpha
Check Table Before Drop: false
Store: tikv
```
master a3bafcdffb1008d224fe06af717e231c82b8f6b1 also has this issue too.
Contributor guide
Assessment
This issue has not been assessed yet.