[DNM]*: test stale read

[crazycs520]

What is changed and how it works?

This PR contains following PR:

• infoschema: refine info cache logic to reduce the impact of DDL on information schema cache #48293
• domain: add resolve lock logic for mvcc get key loading schema diff #48282

And this PR add debug log and injected sleep before commit secondaries for DDL transaction.

Test

workload

stale read and write

sysbench --config-file=sysbench.conf stale_read.lua --threads=20 --read_staleness=-60 --kv_read_timeout=100 --max_execution_time=400 --mysql-ignore-errors=all run

DDL workload:

bin/loadgen bench --sql="create database test0;create table test0.t0 (a int);drop table test0.t0;drop database test0;select sleep(2);" --thread 1 

And TiDB have many following lock, indicate that get schema diff mvcc info meet lock.

> rg 'encoded key encounter lock'
tidb.log:[2023/11/04 10:44:49.559 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a323033ff3800000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 29, ver: 7, confVer: 17 },startKey:6d446966663a313930ff3100000000000000f80000000000000073,endKey:748000000000000004"] [lock="start_ts:445399928546263069 primary:\"mDB:1579\\000\\376\\000\\000\\000\\000\\000\\000\\000hTable:15\\37781\\000\\000\\000\\000\\000\\000\\371\" short_value:\"{\\\"version\\\":2038,\\\"type\\\":3,\\\"schema_id\\\":1579,\\\"table_id\\\":1581,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
tidb.log:[2023/11/04 10:44:49.716 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a323034ff3000000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 29, ver: 7, confVer: 17 },startKey:6d446966663a313930ff3100000000000000f80000000000000073,endKey:748000000000000004"] [lock="start_ts:445399928585584664 primary:\"mDB:1579\\000\\376\\000\\000\\000\\000\\000\\000\\000hTable:15\\37781\\000\\000\\000\\000\\000\\000\\371\" short_value:\"{\\\"version\\\":2040,\\\"type\\\":4,\\\"schema_id\\\":1579,\\\"table_id\\\":1581,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
tidb.log:[2023/11/04 10:44:49.784 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a323034ff3100000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 29, ver: 7, confVer: 17 },startKey:6d446966663a313930ff3100000000000000f80000000000000073,endKey:748000000000000004"] [lock="start_ts:445399928598691882 primary:\"mDB:1579\\000\\376\\000\\000\\000\\000\\000\\000\\000hTable:15\\37781\\000\\000\\000\\000\\000\\000\\371\" short_value:\"{\\\"version\\\":2041,\\\"type\\\":4,\\\"schema_id\\\":1579,\\\"table_id\\\":1581,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
tidb.log:[2023/11/04 10:44:49.962 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a323034ff3300000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 29, ver: 7, confVer: 17 },startKey:6d446966663a313930ff3100000000000000f80000000000000073,endKey:748000000000000004"] [lock="start_ts:445399928651120663 primary:\"mDBs\\000\\000\\000\\000\\000\\372\\000\\000\\000\\000\\000\\000\\000hDB:1579\\000\\376\" short_value:\"{\\\"version\\\":2043,\\\"type\\\":2,\\\"schema_id\\\":1579,\\\"table_id\\\":0,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
...
58900:[2023/11/04 11:07:39.227 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a353935ff3600000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 2105, ver: 9, confVer: 17 },startKey:6d446966663a313936ff3400000000000000f80000000000000073,endKey:6d536368656d615665ff7273696f6e4b6579ff0000000000000000f70000000000000073"] [lock="start_ts:445400287591792688 primary:\"mDBs\\000\\000\\000\\000\\000\\372\\000\\000\\000\\000\\000\\000\\000hDB:4513\\000\\376\" short_value:\"{\\\"version\\\":5956,\\\"type\\\":2,\\\"schema_id\\\":4513,\\\"table_id\\\":0,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
58941:[2023/11/04 11:07:41.636 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a353935ff3900000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 2105, ver: 9, confVer: 17 },startKey:6d446966663a313936ff3400000000000000f80000000000000073,endKey:6d536368656d615665ff7273696f6e4b6579ff0000000000000000f70000000000000073"] [lock="start_ts:445400288221200431 primary:\"mDB:4519\\000\\376\\000\\000\\000\\000\\000\\000\\000hTable:45\\37721\\000\\000\\000\\000\\000\\000\\371\" short_value:\"{\\\"version\\\":5959,\\\"type\\\":4,\\\"schema_id\\\":4519,\\\"table_id\\\":4521,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
58948:[2023/11/04 11:07:41.738 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a353936ff3000000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 2105, ver: 9, confVer: 17 },startKey:6d446966663a313936ff3400000000000000f80000000000000073,endKey:6d536368656d615665ff7273696f6e4b6579ff0000000000000000f70000000000000073"] [lock="start_ts:445400288247152696 primary:\"mDB:4519\\000\\376\\000\\000\\000\\000\\000\\000\\000hTable:45\\37721\\000\\000\\000\\000\\000\\000\\371\" short_value:\"{\\\"version\\\":5960,\\\"type\\\":4,\\\"schema_id\\\":4519,\\\"table_id\\\":4521,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
58956:[2023/11/04 11:07:41.839 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a353936ff3100000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 2105, ver: 9, confVer: 17 },startKey:6d446966663a313936ff3400000000000000f80000000000000073,endKey:6d536368656d615665ff7273696f6e4b6579ff0000000000000000f70000000000000073"] [lock="start_ts:445400288273367101 primary:\"mDB:4519\\000\\376\\000\\000\\000\\000\\000\\000\\000hTable:45\\37721\\000\\000\\000\\000\\000\\000\\371\" short_value:\"{\\\"version\\\":5961,\\\"type\\\":4,\\\"schema_id\\\":4519,\\\"table_id\\\":4521,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
58971:[2023/11/04 11:07:41.992 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a353936ff3200000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 2105, ver: 9, confVer: 17 },startKey:6d446966663a313936ff3400000000000000f80000000000000073,endKey:6d536368656d615665ff7273696f6e4b6579ff0000000000000000f70000000000000073"] [lock="start_ts:445400288312688719 primary:\"mDBs\\000\\000\\000\\000\\000\\372\\000\\000\\000\\000\\000\\000\\000hDB:4519\\000\\376\" short_value:\"{\\\"version\\\":5962,\\\"type\\\":2,\\\"schema_id\\\":4519,\\\"table_id\\\":0,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
58979:[2023/11/04 11:07:42.094 +08:00] [INFO] [helper.go:155] ["get MVCC by encoded key encounter lock"] [encodeKey=6d446966663a353936ff3300000000000000f80000000000000073] [region={}] [keyLocation="region { region id: 2105, ver: 9, confVer: 17 },startKey:6d446966663a313936ff3400000000000000f80000000000000073,endKey:6d536368656d615665ff7273696f6e4b6579ff0000000000000000f70000000000000073"] [lock="start_ts:445400288352010242 primary:\"mDBs\\000\\000\\000\\000\\000\\372\\000\\000\\000\\000\\000\\000\\000hDB:4519\\000\\376\" short_value:\"{\\\"version\\\":5963,\\\"type\\\":2,\\\"schema_id\\\":4519,\\\"table_id\\\":0,\\\"old_table_id\\\":0,\\\"old_schema_id\\\":0,\\\"affected_options\\\":null}\" "]
...
...
...
>  rg 'encoded key encounter lock' | wc
   1967   55076 1406522

And there is no failed to get schema version log:

# rg 'failed to get schema version' | rg -v 'version=0'
# rg 'failed to get schema version' | rg -v 'version=0' | wc
      0       0       0
#

The metrics is:

[ti-chi-bot]

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by:
Once this PR has been reviewed and has the lgtm label, please ask for approval from crazycs520. For more information see the Kubernetes Code Review Process.

The full list of commands accepted by this bot can be found here.

Needs approval from an approver in each of these files:

• OWNERS

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[tiprow]

Hi @crazycs520. Thanks for your PR.

PRs from untrusted users cannot be marked as trusted with /ok-to-test in this repo meaning untrusted PR authors can never trigger tests themselves. Collaborators can still trigger tests on the PR using /test all.

I understand the commands that are listed here.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.