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,distsql,util: distinguish walltime from sum of walltime in execution info #57507

Merged
merged 18 commits into from
Nov 28, 2024

Conversation

yibin87
Copy link
Contributor

@yibin87 yibin87 commented Nov 19, 2024

What problem does this PR solve?

Issue Number: close #56746

Problem Summary:

What changed and how does it work?

Thanks to Keao's PR , all executors must be created by either NewBaseExecutorV2 or BuildNewBaseExecutorV2. Thus, we can identify the "parallel time" case by checking if any existing executors have the same ID. Then use a different name, like "total_parallel_time" to display it.
Some special cases:

  1. IndexLookUp & IndexMergeReader 's index plan doesn't mapping to an Executor, just mapping to several distsql calls. So need to handle them case by case.
  2. PointGet's Init function not only initializes some fields but also re-constructs its BaseExecutor, which is not reasonable, split it to two functions now.

ParallelApply & IndexLookUp Query

+--------------------------------------------+---------+---------+-----------+------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------+-----------+------+
| id                                         | estRows | actRows | task      | access object          | execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         | operator info                                                                  | memory    | disk |
+--------------------------------------------+---------+---------+-----------+------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------+-----------+------+
| Projection_11                              | 10.00   | 2       | root      |                        | time:2.77ms, loops:3, RU:2.480302, Concurrency:OFF                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     | Column#13                                                                      | 2.14 KB   | N/A  |
| └─Apply_13                                 | 10.00   | 2       | root      |                        | time:2.76ms, loops:3, Concurrency:5, cache:ON, cacheHitRatio:0.000%                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    | CARTESIAN left outer join                                                      | 778 Bytes | N/A  |
|   ├─TableReader_15(Build)                  | 10.00   | 2       | root      |                        | time:656.7µs, loops:2, cop_task: {num: 1, max: 557.5µs, proc_keys: 2, tot_proc: 64.4µs, tot_wait: 60.7µs, copr_cache_hit_ratio: 0.00, build_task_duration: 6.45µs, max_distsql_concurrency: 1}, rpc_info:{Cop:{num_rpc:1, total_time:537.1µs}}                                                                                                                                                                                                                                                                                                                                                                                                                                         | data:TableRangeScan_14                                                         | 286 Bytes | N/A  |
|   │ └─TableRangeScan_14                    | 10.00   | 2       | cop[tikv] | table:alias            | tikv_task:{time:0s, loops:1}, scan_detail: {total_process_keys: 2, total_process_keys_size: 100, total_keys: 3, get_snapshot_time: 40µs, rocksdb: {key_skipped_count: 2, block: {}}}, time_detail: {total_process_time: 64.4µs, total_wait_time: 60.7µs, tikv_wall_time: 244.6µs}                                                                                                                                                                                                                                                                                                                                                                                                      | range:[1,1], keep order:false, stats:pseudo                                    | N/A       | N/A  |
|   └─MaxOneRow_16(Probe)                    | 10.00   | 2       | root      |                        | total_time:3.93ms, loops:4                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                             |                                                                                | N/A       | N/A  |
|     └─StreamAgg_21                         | 10.00   | 2       | root      |                        | total_time:3.91ms, loops:4                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                             | funcs:sum(Column#17)->Column#13                                                | 1.45 KB   | N/A  |
|       └─Projection_48                      | 100.00  | 2       | root      |                        | total_time:3.87ms, loops:4, Concurrency:OFF                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            | cast(test.t1.c4, decimal(10,0) BINARY)->Column#17                              | 760 Bytes | N/A  |
|         └─Projection_47                    | 100.00  | 2       | root      |                        | total_time:3.81ms, loops:4, Concurrency:OFF                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            | test.t1.c3, test.t1.c4                                                         | 1.48 KB   | N/A  |
|           └─IndexLookUp_46                 | 100.00  | 2       | root      |                        | total_time:3.79ms, loops:4, index_task: {total_time: 1.68ms, fetch_handle: 1.67ms, build: 2.14µs, wait: 7.05µs}, table_task: {total_time: 1.83ms, num: 2, concurrency: 5}, next: {wait_index: 1.84ms, wait_table_lookup_build: 271.8µs, wait_table_lookup_resp: 1.55ms}                                                                                                                                                                                                                                                                                                                                                                                                                |                                                                                | 18.5 KB   | N/A  |
|             ├─IndexRangeScan_44(Build)     | 100.00  | 2       | cop[tikv] | table:t1, index:c3(c3) | total_time:1.64ms, loops:6, cop_task: {num: 2, max: 750.8µs, min: 727µs, avg: 738.9µs, p95: 750.8µs, max_proc_keys: 1, p95_proc_keys: 1, tot_proc: 118µs, tot_wait: 188.2µs, copr_cache_hit_ratio: 0.00, build_task_duration: 25.3µs, max_distsql_concurrency: 1}, rpc_info:{Cop:{num_rpc:2, total_time:1.45ms}}, tikv_task:{proc max:0s, min:0s, avg: 0s, p80:0s, p95:0s, iters:2, tasks:2}, scan_detail: {total_process_keys: 2, total_process_keys_size: 114, total_keys: 4, get_snapshot_time: 120.4µs, rocksdb: {key_skipped_count: 2, block: {}}}, time_detail: {total_process_time: 118µs, total_wait_time: 188.2µs, tikv_wall_time: 743.4µs}                                   | range: decided by [eq(test.t1.c3, test.t1.c3)], keep order:false, stats:pseudo | N/A       | N/A  |
|             └─TableRowIDScan_45(Probe)     | 100.00  | 2       | cop[tikv] | table:t1               | total_time:1.51ms, loops:4, cop_task: {num: 2, max: 665µs, min: 649.1µs, avg: 657µs, p95: 665µs, max_proc_keys: 1, p95_proc_keys: 1, tot_proc: 119.2µs, tot_wait: 170µs, copr_cache_hit_ratio: 0.00, build_task_duration: 149.7µs, max_distsql_concurrency: 1, max_extra_concurrency: 1}, rpc_info:{Cop:{num_rpc:2, total_time:1.28ms}}, tikv_task:{proc max:0s, min:0s, avg: 0s, p80:0s, p95:0s, iters:2, tasks:2}, scan_detail: {total_process_keys: 2, total_process_keys_size: 100, total_keys: 4, get_snapshot_time: 114.6µs, rocksdb: {key_skipped_count: 2, block: {}}}, time_detail: {total_process_time: 119.2µs, total_wait_time: 170µs, tikv_wall_time: 629.1µs}            | keep order:false, stats:pseudo                                                 | N/A       | N/A  |
+--------------------------------------------+---------+---------+-----------+------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------+-----------+------+

IndexMergeReader Query

+-------------------------------+----------+---------+-----------+------------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------+---------+------+
| id                            | estRows  | actRows | task      | access object          | execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   | operator info                                                       | memory  | disk |
+-------------------------------+----------+---------+-----------+------------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------+---------+------+
| IndexMerge_8                  | 18959.99 | 18959   | root      |                        | time:111.1ms, loops:20, RU:303.684901, index_task:{fetch_handle:13.903218ms, merge:4.080369ms}, table_task:{num:2, concurrency:5, fetch_row:199.93441ms, wait_time:20.396937ms}                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  | type: union                                                         | 1.14 MB | N/A  |
| ├─IndexRangeScan_5(Build)     | 9997.45  | 9978    | cop[tikv] | table:t, index:idx1(b) | time:6.38ms, loops:12, cop_task: {num: 1, max: 6.19ms, proc_keys: 9978, tot_proc: 5.19ms, tot_wait: 65.3µs, copr_cache_hit_ratio: 0.00, build_task_duration: 23.5µs, max_distsql_concurrency: 1}, rpc_info:{Cop:{num_rpc:1, total_time:6.15ms}}, tikv_task:{time:4ms, loops:14}, scan_detail: {total_process_keys: 9978, total_process_keys_size: 458988, total_keys: 9979, get_snapshot_time: 45.1µs, rocksdb: {key_skipped_count: 9978, block: {cache_hit_count: 2}}}, time_detail: {total_process_time: 5.19ms, total_suspend_time: 16.5µs, total_wait_time: 65.3µs, total_kv_read_wall_time: 4ms, tikv_wall_time: 5.49ms}                                                                                                                                                                                                                                    | range:[-inf,100000), keep order:false, stats:partial[id:allEvicted] | N/A     | N/A  |
| ├─IndexRangeScan_6(Build)     | 9958.09  | 9947    | cop[tikv] | table:t, index:idx2(c) | time:6.4ms, loops:12, cop_task: {num: 1, max: 6.23ms, proc_keys: 9947, tot_proc: 5.48ms, tot_wait: 37.5µs, copr_cache_hit_ratio: 0.00, build_task_duration: 23.5µs, max_distsql_concurrency: 1}, rpc_info:{Cop:{num_rpc:1, total_time:6.21ms}}, tikv_task:{time:5ms, loops:14}, scan_detail: {total_process_keys: 9947, total_process_keys_size: 457562, total_keys: 9948, get_snapshot_time: 25.6µs, rocksdb: {key_skipped_count: 9947, block: {cache_hit_count: 2}}}, time_detail: {total_process_time: 5.48ms, total_suspend_time: 18.8µs, total_wait_time: 37.5µs, total_kv_read_wall_time: 5ms, tikv_wall_time: 5.69ms}                                                                                                                                                                                                                                     | range:[-inf,100000), keep order:false, stats:partial[id:allEvicted] | N/A     | N/A  |
| └─TableRowIDScan_7(Probe)     | 18959.99 | 18959   | cop[tikv] | table:t                | total_time:188.9ms, loops:21, cop_task: {num: 200, max: 19.7ms, min: 8.96ms, avg: 13.7ms, p95: 18.4ms, max_proc_keys: 122, p95_proc_keys: 112, tot_proc: 530.4ms, tot_wait: 648.3ms, copr_cache_hit_ratio: 0.00, build_task_duration: 1.68ms, max_distsql_concurrency: 15}, rpc_info:{Cop:{num_rpc:200, total_time:2.73s}}, tikv_task:{proc max:16ms, min:4ms, avg: 9.73ms, p80:10ms, p95:15ms, iters:494, tasks:200}, scan_detail: {total_process_keys: 18959, total_process_keys_size: 877859, total_keys: 26786, get_snapshot_time: 6.43ms, rocksdb: {delete_skipped_count: 1434, key_skipped_count: 11028, block: {cache_hit_count: 11416, read_count: 273, read_byte: 4.24 MB, read_time: 63.8ms}}}, time_detail: {total_process_time: 530.4ms, total_suspend_time: 1.42s, total_wait_time: 648.3ms, total_kv_read_wall_time: 1.95s, tikv_wall_time: 2.65s} | keep order:false, stats:partial[id:allEvicted]                      | N/A     | N/A  |
+-------------------------------+----------+---------+-----------+------------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------+---------+------+

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

Signed-off-by: yibin <huyibin@pingcap.cn>
@ti-chi-bot ti-chi-bot bot added release-note-none Denotes a PR that doesn't merit a release note. sig/planner SIG: Planner size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Nov 19, 2024
Copy link

tiprow bot commented Nov 19, 2024

Hi @yibin87. 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-sigs/prow repository.

yibin added 4 commits November 20, 2024 09:57
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
@yibin87
Copy link
Contributor Author

yibin87 commented Nov 21, 2024

/test pull-mysql-client-test

Copy link

tiprow bot commented Nov 21, 2024

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

In response to this:

/test pull-mysql-client-test

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-sigs/prow repository.

Copy link

codecov bot commented Nov 21, 2024

Codecov Report

Attention: Patch coverage is 92.30769% with 4 lines in your changes missing coverage. Please review.

Project coverage is 73.2120%. Comparing base (cfa52d0) to head (7fc755e).
Report is 82 commits behind head on master.

Additional details and impacted files
@@               Coverage Diff                @@
##             master     #57507        +/-   ##
================================================
+ Coverage   72.8264%   73.2120%   +0.3856%     
================================================
  Files          1672       1677         +5     
  Lines        462832     478603     +15771     
================================================
+ Hits         337064     350395     +13331     
- Misses       104959     107121      +2162     
- Partials      20809      21087       +278     
Flag Coverage Δ
integration 43.3578% <90.3846%> (?)
unit 72.2236% <92.3076%> (+0.0154%) ⬆️

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

Components Coverage Δ
dumpling 52.7673% <ø> (ø)
parser ∅ <ø> (∅)
br 43.2824% <ø> (-1.8176%) ⬇️

@yibin87
Copy link
Contributor Author

yibin87 commented Nov 21, 2024

/test check-dev2

Copy link

tiprow bot commented Nov 21, 2024

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

In response to this:

/test check-dev2

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-sigs/prow repository.

Signed-off-by: yibin <huyibin@pingcap.cn>
@ti-chi-bot ti-chi-bot bot added size/L Denotes a PR that changes 100-499 lines, ignoring generated files. and removed size/M Denotes a PR that changes 30-99 lines, ignoring generated files. labels Nov 21, 2024
yibin added 3 commits November 21, 2024 17:52
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
@yibin87
Copy link
Contributor Author

yibin87 commented Nov 22, 2024

/cc @windtalker @guo-shaoge

@yibin87 yibin87 changed the title util: distinguish walltime from sum of walltime in execution info executor,distsql,util: distinguish walltime from sum of walltime in execution info Nov 22, 2024
yibin added 6 commits November 26, 2024 10:39
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
@yibin87
Copy link
Contributor Author

yibin87 commented Nov 27, 2024

/test check-dev2

@yibin87
Copy link
Contributor Author

yibin87 commented Nov 27, 2024

/test unit-test

Copy link

tiprow bot commented Nov 27, 2024

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

In response to this:

/test check-dev2

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-sigs/prow repository.

Copy link

tiprow bot commented Nov 27, 2024

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

In response to this:

/test unit-test

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-sigs/prow repository.

yibin added 2 commits November 27, 2024 12:38
Signed-off-by: yibin <huyibin@pingcap.cn>
Signed-off-by: yibin <huyibin@pingcap.cn>
@yibin87
Copy link
Contributor Author

yibin87 commented Nov 27, 2024

/test pull-integration-e2e-test

Copy link

tiprow bot commented Nov 27, 2024

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

In response to this:

/test pull-integration-e2e-test

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-sigs/prow repository.

@yibin87
Copy link
Contributor Author

yibin87 commented Nov 27, 2024

/test pull-integration-e2e-test

Copy link

tiprow bot commented Nov 27, 2024

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

In response to this:

/test pull-integration-e2e-test

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-sigs/prow repository.

Copy link
Contributor

@windtalker windtalker 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 bot added approved needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Nov 27, 2024
@yibin87
Copy link
Contributor Author

yibin87 commented Nov 27, 2024

/cc @XuHuaiyu

@ti-chi-bot ti-chi-bot bot requested a review from XuHuaiyu November 27, 2024 05:16
Signed-off-by: yibin <huyibin@pingcap.cn>
Copy link

ti-chi-bot bot commented Nov 28, 2024

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: windtalker, XuHuaiyu

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 Nov 28, 2024
Copy link

ti-chi-bot bot commented Nov 28, 2024

[LGTM Timeline notifier]

Timeline:

  • 2024-11-27 05:15:46.140367487 +0000 UTC m=+613533.760022002: ☑️ agreed by windtalker.
  • 2024-11-28 07:36:17.147702992 +0000 UTC m=+708364.767357508: ☑️ agreed by XuHuaiyu.

Copy link

tiprow bot commented Nov 28, 2024

@yibin87: 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
fast_test_tiprow 7fc755e link true /test fast_test_tiprow

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

@ti-chi-bot ti-chi-bot bot merged commit 37a1f42 into pingcap:master Nov 28, 2024
23 of 24 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
approved lgtm release-note-none Denotes a PR that doesn't merit a release note. sig/planner SIG: Planner size/L Denotes a PR that changes 100-499 lines, ignoring generated files.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Systematically distinguish accumulated parallel time from walltime
3 participants