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.

Sign up for GitHub

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

Jump to bottom

*: record more rpc runtime information in cop runt ... (#18916) #19264

Merged
merged 13 commits into from
Sep 3, 2020
Merged

*: record more rpc runtime information in cop runt ... (#18916) #19264

merged 13 commits into from
Sep 3, 2020

Conversation

ti-srebot
Copy link
Contributor

@ti-srebot ti-srebot commented Aug 18, 2020 •
edited by crazycs520
Loading

cherry-pick #18916 #19277 to release-4.0

What problem does this PR solve?

Record more RPC runtime information in cop runtime stats, such as:

  • send rpc request count and type
  • backoff information

Here is some example:

Normally

+------------------------+----------+---------+-----------+---------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+--------------+------+
| id                     | estRows  | actRows | task      | access object | execution info                                                                                                                                                                                                                     | operator info                   | memory       | disk |
+------------------------+----------+---------+-----------+---------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+--------------+------+
| StreamAgg_20           | 1.00     | 1       | root      |               | time:177.902235ms, loops:2                                                                                                                                                                                                         | funcs:count(Column#9)->Column#4 | 9.484375 KB  | N/A  |
| └─TableReader_21       | 1.00     | 1024    | root      |               | time:177.870315ms, loops:2, cop_task: {num: 1024, max: 21.191093ms, min: 217.89µs, avg: 1.831162ms, p95: 6.302146ms, max_proc_keys: 83, p95_proc_keys: 72, tot_proc: 100ms, tot_wait: 41ms, rpc_num: 1024, rpc_time: 1.870528822s} | data:StreamAgg_8                | 2.3359375 KB | N/A  |
|   └─StreamAgg_8        | 1.00     | 1024    | cop[tikv] |               | proc max:1ms, min:0s, p80:0s, p95:1ms, iters:1024, tasks:1024                                                                                                                                                                      | funcs:count(1)->Column#9        | N/A          | N/A  |
|     └─TableFullScan_18 | 10000.00 | 60236   | cop[tikv] | table:t1      | proc max:1ms, min:0s, p80:0s, p95:1ms, iters:1024, tasks:1024                                                                                                                                                                      | keep order:false, stats:pseudo  | N/A          | N/A  |
+------------------------+----------+---------+-----------+---------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+--------------+------+

When 1 tikv-server is offline

+------------------------+-----------+---------+-----------+---------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+----------------+------+
| id                     | estRows   | actRows | task      | access object | execution info                                                                                                                                                                                                                                                                            | operator info                   | memory         | disk |
+------------------------+-----------+---------+-----------+---------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+----------------+------+
| StreamAgg_20           | 1.00      | 1       | root      |               | time:9.004457817s, loops:2                                                                                                                                                                                                                                                                | funcs:count(Column#9)->Column#4 | 9.484375 KB    | N/A  |
| └─TableReader_21       | 1.00      | 1024    | root      |               | time:9.004429257s, loops:2, cop_task: {num: 1024, max: 2.99937716s, min: 436.349µs, avg: 27.14526ms, p95: 1.246608ms, max_proc_keys: 613, p95_proc_keys: 551, tot_proc: 321ms, tot_wait: 146ms, rpc_num: 1043, rpc_time: 27.791302111s}, backoff{regionMiss: 11.168s, tikvRPC: 1m49.042s} | data:StreamAgg_8                | 1.435546875 KB | N/A  |
|   └─StreamAgg_8        | 1.00      | 1024    | cop[tikv] |               | proc max:1ms, min:0s, p80:1ms, p95:1ms, iters:1024, tasks:1024                                                                                                                                                                                                                            | funcs:count(1)->Column#9        | N/A            | N/A  |
|     └─TableFullScan_18 | 453621.00 | 524910  | cop[tikv] | table:t1      | proc max:1ms, min:0s, p80:1ms, p95:1ms, iters:1024, tasks:1024                                                                                                                                                                                                                            | keep order:false, stats:pseudo  | N/A            | N/A  |
+------------------------+-----------+---------+-----------+---------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------+----------------+------+

What is changed and how it works?

Related changes

  • Need to cherry-pick to the release branch

Check List

Tests

  • Unit test

Side effects

  • Performance regression
    • Consumes more CPU
    • Consumes more MEM
  • Breaking backward compatibility

Release note

  • Record more RPC runtime information in cop runtime stats

@crazycs520 @ti-srebot
cherry pick pingcap#18916 to release-4.0
e4bc758 
Signed-off-by: ti-srebot <ti-srebot@pingcap.com>
@ti-srebot
Copy link
Contributor Author

/run-all-tests

@ti-srebot ti-srebot mentioned this pull request Aug 18, 2020
Merged
@ti-srebot ti-srebot added this to the v4.0.6 milestone Aug 18, 2020
zz-jason
zz-jason reviewed Sep 1, 2020
View reviewed changes
Copy link
Member

@zz-jason zz-jason left a comment

Choose a reason for hiding this comment

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

@crazycs520 please resolve conflicts and fix CI.

@crazycs520
Copy link
Contributor

/run-all-tests

1 similar comment
@crazycs520
Copy link
Contributor

/run-all-tests

AilinKid
AilinKid reviewed Sep 2, 2020
View reviewed changes
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 the status/LGT1 Indicates that a PR has LGTM 1. label Sep 2, 2020
zz-jason
zz-jason previously approved these changes Sep 2, 2020
View reviewed changes
Copy link
Member

@zz-jason zz-jason 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 Sep 2, 2020
@zz-jason
Copy link
Member

zz-jason commented Sep 2, 2020

/merge

@zz-jason
Copy link
Member

zz-jason commented Sep 2, 2020

/run-common-test
/run-unit-test

@crazycs520
Copy link
Contributor

/run-common-test
/run-sqllogic-test-1
/sqllogic-test-2

@zz-jason
Copy link
Member

zz-jason commented Sep 2, 2020

/merge

@ti-srebot
Copy link
Contributor Author

Your auto merge job has been accepted, waiting for:

  • 17924
  • 18115
  • 18164
  • 18327

@ti-srebot
Copy link
Contributor Author

/run-all-tests

@ti-srebot
Copy link
Contributor Author

@ti-srebot merge failed.

@crazycs520
Copy link
Contributor

/run-all-tests

2 similar comments
@crazycs520
Copy link
Contributor

/run-all-tests

@zz-jason
Copy link
Member

zz-jason commented Sep 3, 2020

/run-all-tests

@crazycs520
Copy link
Contributor

/run-all-tests

@crazycs520
Copy link
Contributor

/run-all-tests

@crazycs520
Copy link
Contributor

/run-common-test tidb-test=release-4.0

@crazycs520
Copy link
Contributor

/run-all-tests

@crazycs520
Copy link
Contributor

/build

@crazycs520
Copy link
Contributor

/run-all-tests

@crazycs520
Copy link
Contributor

/run-sqllogic-test-1

@zz-jason zz-jason changed the title *: record more rpc runtime information in cop runtime stats (#18916) *: record more rpc runtime information in cop runt ... (#18916) Sep 3, 2020
@zz-jason zz-jason merged commit f5b1d1f into pingcap:release-4.0 Sep 3, 2020
crazycs520 added a commit to crazycs520/tidb that referenced this pull request Oct 9, 2020
@crazycs520
Revert "*: record more rpc runtime information in cop runt ... (pingc…
2362acb 
…ap#18916) (pingcap#19264)"

This reverts commit f5b1d1f.
@crazycs520 crazycs520 mentioned this pull request Oct 9, 2020
Closed
@crazycs520 crazycs520 modified the milestones: v4.0.6, v4.0.8 Oct 22, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@AilinKid AilinKid AilinKid left review comments

@zz-jason zz-jason zz-jason approved these changes

@qw4990 qw4990 Awaiting requested review from qw4990

@wjhuang2016 wjhuang2016 Awaiting requested review from wjhuang2016

@XuHuaiyu XuHuaiyu Awaiting requested review from XuHuaiyu

Assignees

@crazycs520 crazycs520

Labels
component/executor sig/execution SIG execution status/can-merge Indicates a PR has been approved by a committer. status/LGT2 Indicates that a PR has LGTM 2. type/enhancement The issue or PR belongs to an enhancement. type/4.0-cherry-pick
Projects
None yet
Milestone
v4.0.8
Development

Successfully merging this pull request may close these issues.
5 participants
@ti-srebot @crazycs520 @zz-jason @AilinKid @AndreMouche