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

ddl: make read and write async during adding index #39249

Merged
merged 14 commits into from
Nov 23, 2022

Conversation

tangenta
Copy link
Contributor

@tangenta tangenta commented Nov 18, 2022

What problem does this PR solve?

Issue Number: ref #35983

Problem Summary:

This is a further step from #39191.

What is changed and how it works?

This PR introduces the cop-request sender pool for coprocessor-read. Each sender lives in a separate goroutine, builds a coprocessor request for a task range, holds the index columns values from coprocessor response, converts them to index KVs, and sends the index KVs to a channel in batch.

The backfill workers keep reading index KVs from the channel, and write them to lightning's local engines.

Compared with the synchronous version(before this PR), it has the following advantages:

  • One task range builds & sends exactly one coprocessor request. The network overhead is minimized.
  • The backfill workers do not have to wait for a specific cop-request sender. On the contrary, any backfill worker can write index KVs from any task ranges. The unnecessary wait time is reduced in a pipeline way.
  • It provides a way to control the concurrency of coprocessor requests and backfill workers separately. Higher resource utilization.

As a quick verification, here is the add index performance:

mysql> show create table sbtest1;
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table   | Create Table                                                                                                                                                                                                                                                                                                                                                      |
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| sbtest1 | CREATE TABLE `sbtest1` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `k` int(11) NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`) /*T![clustered_index] CLUSTERED */,
  KEY `k_1` (`k`),
  KEY `idx` (`c`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin AUTO_INCREMENT=10245403 |
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

mysql> select count(1) from sbtest1;
+----------+
| count(1) |
+----------+
| 10000000 |
+----------+
1 row in set (0.38 sec)

The commit before #39191:

mysql> alter table sbtest1 add index idx (c);
Query OK, 0 rows affected (33.39 sec)

mysql> alter table sbtest1 add index idx (c);
Query OK, 0 rows affected (33.04 sec)

After this PR:

mysql> alter table sbtest1 add index idx (c);
Query OK, 0 rows affected (24.44 sec)

mysql> alter table sbtest1 add index idx (c);
Query OK, 0 rows affected (24.11 sec)

By using this patch to record the time spent on each phase of adding index, we have the following log:

The commit before #39191:

[2022/11/19 17:44:20.055 +08:00] [INFO] [index.go:681] ["[ddl] finish add index job"] [job="ID:128, Type:add index, State:running, SchemaState:write reorganization, SchemaID:79, TableID:81, RowCount:10000000, ArgLen:3, start time: 2022-11-19 17:43:46.852 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:437479292260057090"] ["time details"="{FinishImport:10.647325, add-index-worker:33.156462, backfill txn read:{sum: 9.113188, min: 0.000642, max: 0.018580, cnt: 9630}, backfill txn write:{sum: 5.055656, min: 0.000057, max: 0.854642, cnt: 9630}, sendTasksAndWait:16.134893, waitAsyncCommit:5.000677, worker_0 handle task:15.358384, writePhysicalTableRecord:16.418132}"]
[2022/11/19 17:45:01.062 +08:00] [INFO] [index.go:681] ["[ddl] finish add index job"] [job="ID:130, Type:add index, State:running, SchemaState:write reorganization, SchemaID:79, TableID:81, RowCount:10000000, ArgLen:3, start time: 2022-11-19 17:44:28.202 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:437479303021330433"] ["time details"="{FinishImport:10.145438, add-index-worker:32.821141, backfill txn read:{sum: 9.562348, min: 0.000647, max: 0.010847, cnt: 9630}, backfill txn write:{sum: 4.799680, min: 0.000055, max: 0.758292, cnt: 9630}, sendTasksAndWait:16.475801, waitAsyncCommit:5.001322, worker_0 handle task:15.440283, writePhysicalTableRecord:16.659963}"]
{
    add-index-worker:33.156462, 
    writePhysicalTableRecord:16.418132
    sendTasksAndWait:16.134893, 
    worker_0 handle task:15.358384, 
    backfill txn read:{sum: 9.113188, min: 0.000642, max: 0.018580, cnt: 9630}, 
    backfill txn write:{sum: 5.055656, min: 0.000057, max: 0.854642, cnt: 9630}, 
    waitAsyncCommit:5.000677, 
    FinishImport:10.647325, 
}

After this PR:

[2022/11/19 17:40:57.877 +08:00] [INFO] [index.go:681] ["[ddl] finish add index job"] [job="ID:124, Type:add index, State:running, SchemaState:write reorganization, SchemaID:79, TableID:81, RowCount:10000000, ArgLen:3, start time: 2022-11-19 17:40:33.651 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:437479239267123201"] ["time details"="{FinishImport:9.907962, add-index-worker:24.171184, backfill txn read:{sum: 0.100579, min: 0.000000, max: 0.017990, cnt: 1332}, backfill txn write:{sum: 7.046383, min: 0.000333, max: 0.840017, cnt: 1332}, sendTasksAndWait:7.881558, waitAsyncCommit:5.035024, worker_0 handle task:7.878787, writePhysicalTableRecord:8.188198}"]
[2022/11/19 17:41:49.673 +08:00] [INFO] [index.go:681] ["[ddl] finish add index job"] [job="ID:126, Type:add index, State:running, SchemaState:write reorganization, SchemaID:79, TableID:81, RowCount:10000000, ArgLen:3, start time: 2022-11-19 17:41:25.75 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:437479252846444545"] ["time details"="{FinishImport:10.584037, add-index-worker:23.898931, backfill txn read:{sum: 0.030856, min: 0.000000, max: 0.013301, cnt: 1306}, backfill txn write:{sum: 6.217490, min: 0.000293, max: 0.710101, cnt: 1306}, sendTasksAndWait:7.079167, waitAsyncCommit:5.001162, worker_0 handle task:6.733710, writePhysicalTableRecord:7.246942}"]
{
    add-index-worker:24.171184, 
    writePhysicalTableRecord:8.188198
    sendTasksAndWait:7.881558, 
    worker_0 handle task:7.878787, 
    backfill txn read:{sum: 0.100579, min: 0.000000, max: 0.017990, cnt: 1332}, 
    backfill txn write:{sum: 7.046383, min: 0.000333, max: 0.840017, cnt: 1332}, 
    waitAsyncCommit:5.035024, 
    FinishImport:9.907962, 
}

backfill txn read is reduced from 9.11 seconds to 0.10 seconds, it is almost eliminated.

Check List

Tests

  • Unit test
  • Integration test
  • Manual test (add detailed scripts or steps below)
  • No code

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
Copy link
Member

ti-chi-bot commented Nov 18, 2022

[REVIEW NOTIFICATION]

This pull request has been approved by:

  • Benjamin2037
  • hawkingrei

To complete the pull request process, please ask the reviewers in the list to review by filling /cc @reviewer in the comment.
After your PR has acquired the required number of LGTMs, you can assign this pull request to the committer in the list by filling /assign @committer in the comment to help you merge this pull request.

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

Reviewer can indicate their review by submitting an approval review.
Reviewer can cancel approval by submitting a request changes review.

@ti-chi-bot ti-chi-bot added release-note-none Denotes a PR that doesn't merit a release note. size/L Denotes a PR that changes 100-499 lines, ignoring generated files. labels Nov 18, 2022
@tangenta tangenta added the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Nov 18, 2022
@ti-chi-bot ti-chi-bot removed the do-not-merge/work-in-progress Indicates that a PR should not merge because it is a work in progress. label Nov 18, 2022
@tangenta
Copy link
Contributor Author

/hold WIP

@ti-chi-bot ti-chi-bot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Nov 18, 2022
@ti-chi-bot ti-chi-bot added needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. size/XL Denotes a PR that changes 500-999 lines, ignoring generated files. and removed size/L Denotes a PR that changes 100-499 lines, ignoring generated files. labels Nov 18, 2022
@ti-chi-bot ti-chi-bot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Nov 18, 2022
@tangenta
Copy link
Contributor Author

/run-check_dev_2

@tangenta
Copy link
Contributor Author

/unhold

@ti-chi-bot ti-chi-bot removed the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Nov 19, 2022
@Benjamin2037 Benjamin2037 self-requested a review November 20, 2022 03:26
@@ -273,7 +273,7 @@ func (w *backfillWorker) handleBackfillTask(d *ddlCtx, task *reorgBackfillTask,
rc.increaseRowCount(int64(taskCtx.addedCount))
rc.mergeWarnings(taskCtx.warnings, taskCtx.warningsCount)

if num := result.scanCount - lastLogCount; num >= 30000 {
if num := result.scanCount - lastLogCount; num >= 90000 {
Copy link
Collaborator

Choose a reason for hiding this comment

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

For 90000 row print log, it will be how much of interval of time?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Normally, throughput of adding index using ingest is about 200k rows per second.

Copy link
Collaborator

Choose a reason for hiding this comment

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

how about we set 200k rows print one log?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Maybe 200k is too large for the old implementation, the average throughput is 20k rows per second.

Copy link
Member

@hawkingrei hawkingrei Nov 21, 2022

Choose a reason for hiding this comment

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

I think we can create a sliding window to static the throughput. so we can adapt the rows for machine performance.

Lucky, I have create a sliding windows at util/window at this pr

Copy link
Collaborator

@Benjamin2037 Benjamin2037 left a comment

Choose a reason for hiding this comment

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

LGTM

@ti-chi-bot ti-chi-bot added the status/LGT1 Indicates that a PR has LGTM 1. label Nov 21, 2022
Copy link
Member

@wjhuang2016 wjhuang2016 left a comment

Choose a reason for hiding this comment

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

Any tests for changing the worker size while adding the index?

ddl/backfilling.go Outdated Show resolved Hide resolved
@ti-chi-bot ti-chi-bot added status/LGT2 Indicates that a PR has LGTM 2. and removed status/LGT1 Indicates that a PR has LGTM 1. labels Nov 21, 2022
Comment on lines +442 to 445
if scheduler.copReqSenderPool != nil {
scheduler.copReqSenderPool.sendTask(task)
}
scheduler.taskCh <- task
Copy link
Contributor

Choose a reason for hiding this comment

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

Should the task be sent to two different channels?

Copy link
Contributor Author

@tangenta tangenta Nov 22, 2022

Choose a reason for hiding this comment

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

I think so. This is because I want to keep the old backfill implementation and introduce as few changes as possible:

Old backfill:

       scheduler.taskCh -> backfill worker -> read rows -> write indexes -> resultCh

New backfill in this PR:

       scheduler.taskCh -> backfill worker -> write indexes -> resultCh
                                             ^
                                             |
copReqSenderPool.taskCh -> cop-req sender -> read rows

If we only use one channel, then it will be

       scheduler.taskCh -> backfill worker -> write indexes -> resultCh
                        |                    ^
                        v                    |
                        -> cop-req sender -> read rows

The backfill worker cannot process the next task until the current task is complete. However, this is not the behavior we want in the cop-request sender pool. To gain better performance, the sender pool should be always filled with tasks.

Besides, for one channel solution, it is not easy to set the concurrency of backfill worker and cop-request sender separately.

@tangenta
Copy link
Contributor Author

Any tests for changing the worker size while adding the index?

If you mean the test for the backfill worker, you can search TestCheckWorkerNumCh in the code.

@tangenta
Copy link
Contributor Author

/merge

@ti-chi-bot
Copy link
Member

This pull request has been accepted and is ready to merge.

Commit hash: ea47941

@ti-chi-bot ti-chi-bot added the status/can-merge Indicates a PR has been approved by a committer. label Nov 23, 2022
@ti-chi-bot ti-chi-bot merged commit c9531d4 into pingcap:master Nov 23, 2022
@sre-bot
Copy link
Contributor

sre-bot commented Nov 23, 2022

TiDB MergeCI notify

🔴 Bad News! [1] CI still failing after this pr merged.
These failed integration tests don't seem to be introduced by the current PR.

CI Name Result Duration Compare with Parent commit
idc-jenkins-ci-tidb/mybatis-test 🔴 failed 1, success 0, total 1 10 min Existing failure
idc-jenkins-ci/integration-cdc-test 🟢 all 39 tests passed 21 min Existing passed
idc-jenkins-ci-tidb/integration-common-test 🟢 all 17 tests passed 15 min Existing passed
idc-jenkins-ci-tidb/common-test 🟢 all 11 tests passed 10 min Existing passed
idc-jenkins-ci-tidb/tics-test 🟢 all 1 tests passed 5 min 47 sec Existing passed
idc-jenkins-ci-tidb/integration-ddl-test 🟢 all 6 tests passed 5 min 31 sec Existing passed
idc-jenkins-ci-tidb/sqllogic-test-2 🟢 all 28 tests passed 4 min 31 sec Existing passed
idc-jenkins-ci-tidb/sqllogic-test-1 🟢 all 26 tests passed 4 min 21 sec Existing passed
idc-jenkins-ci-tidb/integration-compatibility-test 🟢 all 1 tests passed 3 min 12 sec Existing passed
idc-jenkins-ci-tidb/plugin-test 🟢 build success, plugin test success 4min Existing passed

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
release-note-none Denotes a PR that doesn't merit a release note. size/XL Denotes a PR that changes 500-999 lines, ignoring generated files. status/can-merge Indicates a PR has been approved by a committer. status/LGT2 Indicates that a PR has LGTM 2.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants