Logging related to SELECT... FOR UPDATE NOWAIT is too verbose

[dveeden]

Bug Report

1. Minimal reproduce step (Required)

T1:

CREATE TABLE t (id int primary key);
INSERT INTO t VALUES(1),(2),(3);
START TRANSACTION;
SELECT * FROM t FOR UPDATE NOWAIT;

T2:

START TRANSACTION;
SELECT * FROM t FOR UPDATE NOWAIT;

2. What did you expect to see? (Required)

The second transaction should fail with:

ERROR: 3572 (HY000): Statement aborted because lock(s) could not be acquired immediately and NOWAIT is set.

This is expected and should not result in much logging.

3. What did you see instead (Required)

ERROR: 3572 (HY000): Statement aborted because lock(s) could not be acquired immediately and NOWAIT is set.

[2021/08/03 10:04:28.124 +02:00] [WARN] [session.go:1653] ["run statement failed"] [conn=9] [schemaVersion=31] [error="[tikv:3572]Statement aborted because lock(s) could not be acquired immediately and NOWAIT is set."] [session="{\n  \"currDBName\": \"test\",\n  \"id\": 9,\n  \"status\": 3,\n  \"strictMode\": true,\n  \"txn\": \"426764559465316355\",\n  \"user\": {\n    \"Username\": \"root\",\n    \"Hostname\": \"127.0.0.1\",\n    \"CurrentUser\": false,\n    \"AuthUsername\": \"root\",\n    \"AuthHostname\": \"%\"\n  }\n}"]
[2021/08/03 10:04:28.124 +02:00] [INFO] [conn.go:995] ["command dispatched failed"] [conn=9] [connInfo="id:9, addr:127.0.0.1:38182 status:11, collation:utf8mb4_0900_ai_ci, user:root"] [command=Query] [status="inTxn:1, autocommit:1"] [sql="select * from t FOR UPDATE NOWAIT"] [txn_mode=PESSIMISTIC] [err="[tikv:3572]Statement aborted because lock(s) could not be acquired immediately and NOWAIT is set."]

4. What is your TiDB version? (Required)

5.7.25-TiDB-v5.2.0-alpha-455-gcb65b7a2f 127.0.0.1:4000  test  SQL  select tidb_version()\G
*************************** 1. row ***************************
tidb_version(): Release Version: v5.2.0-alpha-455-gcb65b7a2f
Edition: Community
Git Commit Hash: cb65b7a2f752c0bc19c2d8587b1f9782b076b655
Git Branch: master
UTC Build Time: 2021-08-02 09:58:24
GoVersion: go1.16.4
Race Enabled: false
TiKV Min Version: v3.0.0-60965b006877ca7234adaced7890d7b029ed1306
Check Table Before Drop: false
1 row in set (0.0011 sec)

[dveeden]

TiDB gets this error via client-go from TiKV:

https://github.com/tikv/client-go/blob/d535b62b62f97dc6513e0c41fefe009c6120807d/txnkv/transaction/pessimistic.go#L215

[github-actions]

Please check whether the issue should be labeled with 'affects-x.y' or 'backport-x.y.z',
and then remove 'needs-more-info' label.