Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

domain: record latest schema version after syncer restarted #49929

Merged
merged 5 commits into from
Jan 10, 2024

Conversation

tangenta
Copy link
Contributor

@tangenta tangenta commented Dec 29, 2023

What problem does this PR solve?

Issue Number: close #49773

Problem Summary:

// tidb-0
[2024/01/02 09:38:06.869 +08:00] [INFO] [ddl.go:1063] ["start DDL job"] [category=ddl] [job="ID:415, Type:add index, State:queueing, SchemaState:none, SchemaID:102, TableID:245, RowCount:0, ArgLen:6, start time: 2024-01-02 09:38:06.845 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"] [query="alter table sbtest1 add index index_test_1704159486844 (c)"]
[2024/01/02 09:38:07.145 +08:00] [INFO] [ddl_worker.go:1030] ["run DDL job"] [worker="worker 6, tp add index"] [category=ddl] [jobID=415] [conn=3644851860] [category=ddl] [job="ID:415, Type:add index, State:running, SchemaState:write only, SchemaID:102, TableID:245, RowCount:0, ArgLen:0, start time: 2024-01-02 09:38:06.845 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, UniqueWarnings:0"]
[2024/01/02 09:38:07.200 +08:00] [INFO] [domain.go:873] ["mdl gets lock, update to owner"] [jobID=415] [version=55]
...
[2024/01/02 09:39:02.947 +08:00] [INFO] [ddl_worker.go:1030] ["run DDL job"] [worker="worker 5, tp add index"] [category=ddl] [jobID=415] [conn=3644851860] [category=ddl] [job="ID:415, Type:add index, State:running, SchemaState:write reorganization, SchemaID:102, TableID:245, RowCount:0, ArgLen:0, start time: 2024-01-02 09:38:06.845 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:446735184611246206, UniqueWarnings:0"]
[2024/01/02 09:41:57.281 +08:00] [WARN] [repeatable_read.go:282] ["UpdateForUpdateTS failed"] [conn=3644851824] [session_alias=] [error="[tikv:9001]PD server timeout: "]
[2024/01/02 09:41:57.281 +08:00] [INFO] [conn.go:1132] ["command dispatched failed"] [conn=3644851824] [session_alias=] [connInfo="id:3644851824, addr:10.233.71.65:48912 status:11, collation:latin1_swedish_ci, user:root"] [command=Execute] [status="inTxn:1, autocommit:1"] [sql="UPDATE sbtest31 SET k=k+1 WHERE id=? [arguments: 35056900]"] [txn_mode=PESSIMISTIC] [timestamp=446735200326778960] [err="[tikv:9001]PD server timeout: \ngithub.com/pingcap/errors.AddStack\n\t/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20231212100244-799fae176cfb/errors.go:174\ngithub.com/pingcap/errors.(*Error).GenWithStackByArgs\n\t/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20231212100244-799fae176cfb/normalize.go:164\ngithub.com/pingcap/tidb/pkg/store/driver/error.ToTiDBErr\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/store/driver/error/error.go:112\ngithub.com/pingcap/tidb/pkg/store/driver/txn.extractKeyErr\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/store/driver/txn/error.go:164\ngithub.com/pingcap/tidb/pkg/store/driver/txn.(*tikvTxn).extractKeyErr\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/store/driver/txn/txn_driver.go:322\ngithub.com/pingcap/tidb/pkg/store/driver/txn.(*tikvTxn).LockKeysFunc\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/store/driver/txn/txn_driver.go:93\ngithub.com/pingcap/tidb/pkg/session.(*LazyTxn).LockKeysFunc\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/session/txn.go:483\ngithub.com/pingcap/tidb/pkg/session.(*LazyTxn).LockKeys\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/session/txn.go:458\ngithub.com/pingcap/tidb/pkg/executor.doLockKeys\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/executor.go:1279\ngithub.com/pingcap/tidb/pkg/executor.(*PointGetExecutor).lockKeyBase\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/point_get.go:409\ngithub.com/pingcap/tidb/pkg/executor.(*PointGetExecutor).lockKeyIfNeeded\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/point_get.go:384\ngithub.com/pingcap/tidb/pkg/executor.(*PointGetExecutor).getAndLock\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/point_get.go:369\ngithub.com/pingcap/tidb/pkg/executor.(*PointGetExecutor).Next\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/point_get.go:310\ngithub.com/pingcap/tidb/pkg/executor/internal/exec.Next\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/internal/exec/executor.go:309\ngithub.com/pingcap/tidb/pkg/executor.(*UpdateExec).updateRows\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/update.go:266\ngithub.com/pingcap/tidb/pkg/executor.(*UpdateExec).Next\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/update.go:240\ngithub.com/pingcap/tidb/pkg/executor/internal/exec.Next\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/internal/exec/executor.go:309\ngithub.com/pingcap/tidb/pkg/executor.(*ExecStmt).next\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/adapter.go:1245\ngithub.com/pingcap/tidb/pkg/executor.(*ExecStmt).handleNoDelayExecutor\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/adapter.go:990\ngithub.com/pingcap/tidb/pkg/executor.(*ExecStmt).handlePessimisticDML\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/adapter.go:1051\ngithub.com/pingcap/tidb/pkg/executor.(*ExecStmt).handleNoDelay\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/adapter.go:813\ngithub.com/pingcap/tidb/pkg/executor.(*ExecStmt).Exec\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/executor/adapter.go:597\ngithub.com/pingcap/tidb/pkg/session.runStmt\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/session/session.go:2386\ngithub.com/pingcap/tidb/pkg/session.(*session).ExecuteStmt\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/session/session.go:2228\ngithub.com/pingcap/tidb/pkg/server.(*TiDBContext).ExecuteStmt\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/server/driver_tidb.go:293\ngithub.com/pingcap/tidb/pkg/server.(*clientConn).executePreparedStmtAndWriteResult\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/server/conn_stmt.go:305\ngithub.com/pingcap/tidb/pkg/server.(*clientConn).executePlanCacheStmt\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/server/conn_stmt.go:233\ngithub.com/pingcap/tidb/pkg/server.(*clientConn).handleStmtExecute\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/server/conn_stmt.go:224\ngithub.com/pingcap/tidb/pkg/server.(*clientConn).dispatch\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/server/conn.go:1349\ngithub.com/pingcap/tidb/pkg/server.(*clientConn).Run\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/server/conn.go:1101\ngithub.com/pingcap/tidb/pkg/server.(*Server).onConn\n\t/home/jenkins/agent/workspace/build-common/go/src/github.com/pingcap/tidb/pkg/server/server.go:701\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1650\nUPDATE sbtest31 SET k=k+1 WHERE id=? [arguments: 35056900]"]
[2024/01/02 09:41:57.282 +08:00] [INFO] [txn.go:55] ["Try to create a new txn inside a transaction auto commit"] [conn=3644851824] [session_alias=] [schemaVersion=55] [txnStartTS=446735200326778960] [txnScope=global]

// tidb-1
[2024/01/02 09:42:24.022 +08:00] [INFO] [domain.go:873] ["mdl gets lock, update to owner"] [jobID=415] [version=56]
[2024/01/02 09:42:24.092 +08:00] [INFO] [index.go:911] ["index backfill state ready to merge"] [category=ddl] ["job ID"=415] [table=sbtest1] [index=index_test_1704159486844]
[2024/01/02 09:42:24.225 +08:00] [INFO] [domain.go:873] ["mdl gets lock, update to owner"] [jobID=415] [version=57]
[2024/01/02 09:42:24.318 +08:00] [INFO] [index.go:1959] ["start to merge temp index"] [category=ddl] [job="ID:415, Type:add index, State:running, SchemaState:write reorganization, SchemaID:102, TableID:245, RowCount:70000034, ArgLen:6, start time: 2024-01-02 09:38:06.845 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:446735251995361348, UniqueWarnings:0"] [reorgInfo="CurrElementType:_idx_,CurrElementID:2,StartKey:7480000000000000f55f69ffff000000000002,EndKey:7480000000000000f55f69ffff000000000002ff,First:false,PhysicalTableID:245,Ingest mode:false"]
[2024/01/02 09:42:25.610 +08:00] [INFO] [index.go:742] ["run add index job done"] [category=ddl] [charset=utf8mb4] [collation=utf8mb4_general_ci]
[2024/01/02 09:42:25.653 +08:00] [INFO] [domain.go:873] ["mdl gets lock, update to owner"] [jobID=415] [version=58]

// tidb-0
[2024/01/02 09:42:27.559 +08:00] [INFO] [domain.go:915] ["reload schema in loop, schema syncer need restart"]
[2024/01/02 09:42:27.559 +08:00] [INFO] [schema_validator.go:98] ["the schema validator stops"]
[2024/01/02 09:42:27.573 +08:00] [INFO] [schema_validator.go:129] ["the schema validator stopped before updating"]
[2024/01/02 09:42:27.573 +08:00] [INFO] [domain.go:973] ["mustReload succeed"]
[2024/01/02 09:42:27.573 +08:00] [INFO] [schema_validator.go:109] ["the schema validator restarts"]
[2024/01/02 09:42:27.573 +08:00] [INFO] [domain.go:936] ["schema syncer restarted"]
[2024/01/02 09:42:27.573 +08:00] [INFO] [domain.go:272] ["diff load InfoSchema success"] [currentSchemaVersion=55] [neededSchemaVersion=58] ["start time"=7.716326ms] [gotSchemaVersion=58] [phyTblIDs="[245,245,245]"] [actionTypes="[7,7,7]"] [diffTypes="[\"add index\",\"add index\",\"add index\"]"]
[2024/01/02 09:42:30.123 +08:00] [INFO] [ddl.go:1165] ["DDL job is finished"] [category=ddl] [jobID=415]
// tidb-0
[2024/01/02 09:42:30.135 +08:00] [INFO] [session.go:3925] [GENERAL_LOG] [conn=3644851796] [session_alias=] [user=root@10.233.71.65] [schemaVersion=58] [txnStartTS=446735253528903767] [forUpdateTS=446735253528903767] [isReadConsistency=false] [currentDB=sysbench_64_7000w] [isPessimistic=true] [sessionTxnMode=PESSIMISTIC] [sql="SELECT SUM(k) FROM sbtest1 WHERE id BETWEEN ? AND ? [arguments: (34975499, 34975598)] [arguments: (34975499, 34975598)]"]
[2024/01/02 09:42:30.135 +08:00] [INFO] [session.go:3925] [GENERAL_LOG] [conn=3644851824] [session_alias=] [user=root@10.233.71.65] [schemaVersion=55] [txnStartTS=446735253528903726] [forUpdateTS=446735253528903726][isReadConsistency=false] [currentDB=sysbench_64_7000w] [isPessimistic=true] [sessionTxnMode=PESSIMISTIC] [sql="DELETE FROM sbtest1 WHERE id=? [arguments: 45356626] [arguments: 45356626]"]

The start ts of two DML txns is close, but the schema version differs(55 v.s. 58). The txn with schemaVersion = 55 first obtains the info schema from the cache before the restoration of network partition (that is, the domain has not been successfully reloaded). When it commit later, because MDL is enabled, the schema validator check will be skipped, resulting in the commit of data under an old schema (index state is write-reorg, backfilling state is BackfillStateRunning, the write is redirected to temporary index), which further leads to inconsistent data indexes.

Here is the timeline:

  1. Add index to tidb-0, change index status to delete-only.
  2. Network partitioned between tidb-0 and PD, and tidb-1 is elected as the DDL owner.
  3. tidb-1 continues to add indexes until public, schema version advances from 55 to 58.
  4. tidb-0 network partition disappears, schema version is still 55.
  5. tidb-0 executes DML using schema version 55 and commits.

What changed and how does it work?

  • When tidb-0 comes back, record the latest schema version in cache.
  • Check version in schema validator, return an error if a txn's schema version is too small.

Check List

Tests

  • Unit test
  • Integration test
  • Manual test (add detailed scripts or steps below)
  • No need to test
    • I checked and no code files have been changed.

Side effects

  • Performance regression: Consumes more CPU
  • Performance regression: Consumes more Memory
  • Breaking backward compatibility

Documentation

  • Affects user behaviors
  • Contains syntax changes
  • Contains variable changes
  • Contains experimental features
  • Changes MySQL compatibility

Release note

Please refer to Release Notes Language Style Guide to write a quality release note.

None

@ti-chi-bot ti-chi-bot bot added do-not-merge/needs-linked-issue do-not-merge/needs-tests-checked release-note-none Denotes a PR that doesn't merit a release note. size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Dec 29, 2023
Copy link

tiprow bot commented Dec 29, 2023

Hi @tangenta. 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.

Copy link

codecov bot commented Dec 29, 2023

Codecov Report

Merging #49929 (8cceae2) into master (c52655c) will decrease coverage by 3.5949%.
Report is 124 commits behind head on master.
The diff coverage is 58.3333%.

Additional details and impacted files
@@               Coverage Diff                @@
##             master     #49929        +/-   ##
================================================
- Coverage   70.9302%   67.3354%   -3.5949%     
================================================
  Files          1368       2567      +1199     
  Lines        395446     843447    +448001     
================================================
+ Hits         280491     567939    +287448     
- Misses        95296     251661    +156365     
- Partials      19659      23847      +4188     
Flag Coverage Δ
integration 36.7631% <8.3333%> (?)
unit 79.3379% <58.3333%> (+8.4076%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Components Coverage Δ
dumpling 73.6130% <ø> (+19.6466%) ⬆️
parser ∅ <ø> (∅)
br 71.7765% <ø> (+18.8171%) ⬆️

@zimulala zimulala self-requested a review January 5, 2024 07:18
@ti-chi-bot ti-chi-bot bot added size/S Denotes a PR that changes 10-29 lines, ignoring generated files. and removed size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Jan 5, 2024
@tangenta tangenta changed the title [DNM] session: enable general log for sbtest1 domain: record latest schema version after syncer restarted Jan 5, 2024
@ti-chi-bot ti-chi-bot bot added do-not-merge/needs-triage-completed needs-cherry-pick-release-6.1 Should cherry pick this PR to release-6.1 branch. needs-cherry-pick-release-6.5 Should cherry pick this PR to release-6.5 branch. needs-cherry-pick-release-7.1 Should cherry pick this PR to release-7.1 branch. needs-cherry-pick-release-7.5 Should cherry pick this PR to release-7.5 branch. and removed do-not-merge/needs-linked-issue do-not-merge/needs-tests-checked do-not-merge/needs-triage-completed labels Jan 5, 2024
@tangenta
Copy link
Contributor Author

tangenta commented Jan 5, 2024

/retest

Copy link

tiprow bot commented Jan 5, 2024

@tangenta: Cannot trigger testing until a trusted user reviews the PR and leaves an /ok-to-test message.

In response to this:

/retest

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.

@tangenta
Copy link
Contributor Author

tangenta commented Jan 6, 2024

/retest

Copy link

tiprow bot commented Jan 6, 2024

@tangenta: Cannot trigger testing until a trusted user reviews the PR and leaves an /ok-to-test message.

In response to this:

/retest

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.

@@ -228,6 +236,11 @@ func (s *schemaValidator) Check(txnTS uint64, schemaVer int64, relatedPhysicalTa
logutil.BgLogger().Info("the schema validator stopped before checking")
return nil, ResultUnknown
}

if schemaVer < s.restartSchemaVer {
logutil.BgLogger().Info("the schema version is too old", zap.Int64("schemaVer", schemaVer))
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

add please check if the tidb and pd are healthy after the transaction started

@tangenta
Copy link
Contributor Author

tangenta commented Jan 9, 2024

/retest

Copy link

tiprow bot commented Jan 9, 2024

@tangenta: Cannot trigger testing until a trusted user reviews the PR and leaves an /ok-to-test message.

In response to this:

/retest

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.

@ti-chi-bot ti-chi-bot bot added approved needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Jan 9, 2024
Copy link

ti-chi-bot bot commented Jan 10, 2024

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: wjhuang2016, zimulala

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

The pull request process is described here

Needs approval from an approver in each of these files:

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

@ti-chi-bot ti-chi-bot bot added lgtm and removed needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Jan 10, 2024
Copy link

ti-chi-bot bot commented Jan 10, 2024

[LGTM Timeline notifier]

Timeline:

  • 2024-01-09 16:37:23.144914826 +0000 UTC m=+374832.729168510: ☑️ agreed by wjhuang2016.
  • 2024-01-10 02:22:08.766187972 +0000 UTC m=+409918.350441659: ☑️ agreed by zimulala.

Copy link

tiprow bot commented Jan 10, 2024

@tangenta: The following test failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name Commit Details Required Rerun command
tiprow_fast_test 8cceae2 link true /test tiprow_fast_test

Full PR test history. Your PR dashboard.

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. I understand the commands that are listed here.

@ti-chi-bot ti-chi-bot bot merged commit caab9b9 into pingcap:master Jan 10, 2024
21 of 22 checks passed
@ti-chi-bot
Copy link
Member

In response to a cherrypick label: new pull request created to branch release-7.6: #50243.

@ti-chi-bot
Copy link
Member

In response to a cherrypick label: new pull request created to branch release-6.1: #50245.

@ti-chi-bot
Copy link
Member

In response to a cherrypick label: new pull request created to branch release-6.5: #50246.

@ti-chi-bot
Copy link
Member

In response to a cherrypick label: new pull request created to branch release-7.1: #50247.

@ti-chi-bot
Copy link
Member

In response to a cherrypick label: new pull request created to branch release-7.5: #50248.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
approved lgtm needs-cherry-pick-release-6.1 Should cherry pick this PR to release-6.1 branch. needs-cherry-pick-release-6.5 Should cherry pick this PR to release-6.5 branch. needs-cherry-pick-release-7.1 Should cherry pick this PR to release-7.1 branch. needs-cherry-pick-release-7.5 Should cherry pick this PR to release-7.5 branch. needs-cherry-pick-release-7.6 release-note-none Denotes a PR that doesn't merit a release note. size/S Denotes a PR that changes 10-29 lines, ignoring generated files.
Projects
None yet
4 participants