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

executor: improve the runtime stats of index lookup reader (#21982) #22136

Merged
merged 5 commits into from
Jan 26, 2021

Conversation

ti-srebot
Copy link
Contributor

cherry-pick #21982 to release-4.0


What problem does this PR solve?

close #21981

The IndexRangeScan runtime stats of IndexLookUp executor is not accurate.

What is changed and how it works?

  1. Refine the runtime stats of IndexLookUp.
index_task: {total_time: 1.1s, fetch_handle: 254.2ms, build: 52µs, wait: 841.6ms}, table_task: {total_time: 6.21s, num: 28, concurrency: 5}  

index_task: indicate the time cost of the index-worker to fetch handles.

  • total: indicate the total time cost of index_task.
  • fetch_handle: indicate the cost time of fetch index data and extract handle.
  • build: indicate the cost time of the building task.
  • wait: indicate the wait time before sending the task to the table-worker.

table_task: indicate the time cost of the table-worker to fetch rows.

  • total: indicate the total time cost of all table-workers.
  • num: indicate the task num.
  • concurrency: indicate the concurrency of the table-workers.
  1. Fix the IndexRangeScan runtime stats.

Example:

> explain analyze select sum(a*b) from stress_test.t_index_lookup use index (idx0) where a < 1000000;
+------------------------------+-----------+---------+-----------+-------------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+---------+------+
| id                           | estRows   | actRows | task      | access object                       | execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         | operator info                                                                        | memory  | disk |
+------------------------------+-----------+---------+-----------+-------------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+---------+------+
| HashAgg_13                   | 1.00      | 1       | root      |                                     | time:1.28s, loops:2, partial_worker:{wall_time:1.277913747s, concurrency:5, task_num:1, tot_wait:6.389244265s, tot_exec:37.62µs, tot_time:6.389290205s, max:1.277887377s, p95:1.277887377s}, final_worker:{wall_time:1.277966117s, concurrency:5, task_num:1, tot_wait:6.389549975s, tot_exec:38.83µs, tot_time:6.389594825s, max:1.277954257s, p95:1.277954257s}                                                                                                                                      | funcs:sum(Column#8)->Column#6                                                        | N/A     | N/A  |
| └─IndexLookUp_14             | 1.00      | 36      | root      |                                     | time:1.28s, loops:2, index_task: {total_time: 1.1s, fetch_handle: 254.2ms, build: 52µs, wait: 841.6ms}, table_task: {total_time: 6.21s, num: 28, concurrency: 5}                                                                                                                                                                                                                                                                                                                                                  |                                                                                      | 6.61 MB | N/A  |
|   ├─IndexRangeScan_11(Build) | 500000.00 | 500000  | cop[tikv] | table:t_index_lookup, index:idx0(a) | time:234.4ms, loops:491, cop_task: {num: 1, max: 234.2ms, proc_keys: 500000, tot_proc: 230ms, rpc_num: 1, rpc_time: 234.2ms, copr_cache: disabled}, tikv_task:{time:223ms, loops:493}, total_keys: 500001, processed_keys: 500000, rocksdb: {delete_skipped_count: 50590, key_skipped_count: 550590, block_cache_hit_count: 380, block_read_count: 0, block_read: 0 Bytes}                                                                                                                             | range:[-inf,1000000), keep order:false                                               | N/A     | N/A  |
|   └─HashAgg_7(Probe)         | 1.00      | 36      | cop[tikv] |                                     | time:4.84s, loops:56, cop_task: {num: 36, max: 237.8ms, min: 9.01ms, avg: 141.5ms, p95: 233.6ms, max_proc_keys: 20480, p95_proc_keys: 20480, tot_proc: 4.74s, tot_wait: 6ms, rpc_num: 36, rpc_time: 5.09s, copr_cache: disabled}, tikv_task:{proc max:222ms, min:7ms, p80:209ms, p95:216ms, iters:516, tasks:36}, total_keys: 501993, processed_keys: 500000, rocksdb: {delete_skipped_count: 2478, key_skipped_count: 10965, block_cache_hit_count: 953740, block_read_count: 0, block_read: 0 Bytes} | funcs:sum(mul(stress_test.t_index_lookup.a, stress_test.t_index_lookup.b))->Column#8 | N/A     | N/A  |
|     └─TableRowIDScan_12      | 500000.00 | 500000  | cop[tikv] | table:t_index_lookup                | tikv_task:{proc max:218ms, min:7ms, p80:208ms, p95:213ms, iters:516, tasks:36}                                                                                                                                                                                                                                                                                                                                                                                                                         | keep order:false                                                                     | N/A     | N/A  |
+------------------------------+-----------+---------+-----------+-------------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------+---------+------+

Related changes

  • Need to cherry-pick to the release branch

Check List

Tests

  • Unit test
  • Manual test

Side effects

  • Performance regression
    • Consumes more CPU
    • Consumes more MEM

Release note

  • Fix issue of runtime stats of index lookup reader doesn't accurate.

Signed-off-by: ti-srebot <ti-srebot@pingcap.com>
@ti-srebot
Copy link
Contributor Author

/run-all-tests

@ti-srebot
Copy link
Contributor Author

@crazycs520 you're already a collaborator in bot's repo.

@jebter jebter modified the milestones: 4.0.0, v4.0.11 Jan 7, 2021
@@ -622,10 +622,15 @@ func (e *IndexLookUpExecutor) initRuntimeStats() {
if e.runtimeStats != nil {
if e.stats == nil {
e.stats = &IndexLookUpRunTimeStats{
<<<<<<< HEAD
Copy link
Contributor

Choose a reason for hiding this comment

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

@qw4990 qw4990 added the type/bugfix This PR fixes a bug. label Jan 25, 2021
@crazycs520
Copy link
Contributor

/run-all-tests

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.

LGTM

@ti-srebot ti-srebot added the status/LGT1 Indicates that a PR has LGTM 1. label Jan 26, 2021
Copy link
Contributor

@AilinKid AilinKid 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-srebot ti-srebot added status/LGT2 Indicates that a PR has LGTM 2. and removed status/LGT1 Indicates that a PR has LGTM 1. labels Jan 26, 2021
@ti-srebot ti-srebot added status/LGT3 The PR has already had 3 LGTM. and removed status/LGT2 Indicates that a PR has LGTM 2. labels Jan 26, 2021
@qw4990
Copy link
Contributor

qw4990 commented Jan 26, 2021

/merge

@ti-srebot ti-srebot added the status/can-merge Indicates a PR has been approved by a committer. label Jan 26, 2021
@ti-srebot
Copy link
Contributor Author

Your auto merge job has been accepted, waiting for:

  • 21874
  • 20981
  • 21464
  • 21483
  • 21525
  • 21590
  • 21604
  • 21614
  • 21673
  • 21697
  • 21810
  • 22527
  • 22148
  • 22106
  • 21945

@qw4990 qw4990 merged commit 4ad6aff into pingcap:release-4.0 Jan 26, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
sig/execution SIG execution status/can-merge Indicates a PR has been approved by a committer. status/LGT3 The PR has already had 3 LGTM. type/bugfix This PR fixes a bug. type/usability type/4.0-cherry-pick
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants