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

planner: encode insert/delete/update executor plan ... (#19176) #19269

Merged
merged 12 commits into from
Sep 3, 2020
Merged

planner: encode insert/delete/update executor plan ... (#19176) #19269

merged 12 commits into from
Sep 3, 2020

Conversation

ti-srebot
Copy link
Contributor

cherry-pick #19176 to release-4.0

What problem does this PR solve?

Before this PR, TiDB doesn't record the insert/update/delete executor plan information in the Plan field of slow-log file.

here is some example of Plan field in slow-log file:

# Time: 2020-08-13T17:06:21.386092+08:00
...
# Plan: tidb_decode_plan('ONwwCTI3XzEJMAkwCU4vQQkwCXRpbWU6My4wMjE1NDVtcywgbG9vcHM6MQkyMTUgQnl0ZXMJTi9BCg==')
insert into t values (1,1);
# Time: 2020-08-13T17:06:21.388531+08:00
...
# Plan: tidb_decode_plan('3gLYMAkyOF80CTAJMAlOL0EJMAl0aW1lOjUzNC40NDnCtXMsIGxvb3BzOjEJMS4wODk4NDM3NSBLQgEtPAoxCTMxXzgJMAkyLjY1ODYdAUw1CWRhdGE6U2VsZWN0aW9uXzcJMQlaFDQ4MC44OS5aADAyLCBycGMgbnVtOiAxCQwFhAA0AYQAMwkqkHByb2Mga2V5czo3CTIyNCBCeXRlcwlOL0EKMgkxXzcJMV8wCTJGhQA4bHQodGVzdC50LmEsIDEwBQEAKRGKCDBzLBXcAfsBThQzCTEwXzYFT6A4CXRhYmxlOnQsIGtlZXAgb3JkZXI6ZmFsc2UsIHN0YXRzOnBzZXVkb25QAA==')
update t set b=b+1 where a < 1000000;
# Time: 2020-08-13T17:06:21.390418+08:00
...
# Plan: tidb_decode_plan('2QLYMAkyOV80CTAJMAlOL0EJMAl0aW1lOjQwNS41NznCtXMsIGxvb3BzOjEJMS4xNDQ1MzEyNSBLQgEtPAoxCTMxXzgJMAkyLjY1ODYdAUw1CWRhdGE6U2VsZWN0aW9uXzcJMQlaFDM3NC4zMi5aADAyLCBycGMgbnVtOiAxCQwFhBQzNDAuODUJKohwcm9jIGtleXM6NwkyMjIgQnl0ZXMJTi9BCjIJMV83CTFfME6FADxsdCh0ZXN0LnQuYSwgMTApEYUEMHMZ1wH2AUkUMwkxMF82BUqgOAl0YWJsZTp0LCBrZWVwIG9yZGVyOmZhbHNlLCBzdGF0czpwc2V1ZG9uUAA=')
delete from t where a<10;

test> select tidb_decode_plan('ONwwCTI3XzEJMAkwCU4vQQkwCXRpbWU6My4wMjE1NDVtcywgbG9vcHM6MQkyMTUgQnl0ZXMJTi9BCg==');
+--------------------------------------------------------------------------------------------------------------+
| tidb_decode_plan('ONwwCTI3XzEJMAkwCU4vQQkwCXRpbWU6My4wMjE1NDVtcywgbG9vcHM6MQkyMTUgQnl0ZXMJTi9BCg==')         |
+--------------------------------------------------------------------------------------------------------------+
|     id          task    estRows    operator info    actRows    execution info              memory       disk |
|     Insert_1    root    0          N/A              0          time:3.021545ms, loops:1    215 Bytes    N/A  |
+--------------------------------------------------------------------------------------------------------------+
1 row in set
Time: 0.011s
test> select tidb_decode_plan('3gLYMAkyOF80CTAJMAlOL0EJMAl0aW1lOjUzNC40NDnCtXMsIGxvb3BzOjEJMS4wODk4NDM3NSBLQgEtPAoxCTMxXzgJMAkyLjY1ODYdAUw1CWRhdGE6U2VsZWN0aW9uXzcJMQlaFDQ4MC44OS5aADAyLCBycGMgbnVtOiAxCQwFhAA0AYQAMwkqkHByb2Mga2V5czo3CTIyNCBCeXRlcwlOL0EKMgkxXzcJMV8wCTJGhQA4bHQodGVzdC50LmEsIDEwBQEAKRGKCDBzLBXcAfsBThQzCTEwXzYFT6A4CXRhYmxlOnQsIGtlZXAgb3JkZXI6ZmFsc2UsIHN0YXRzOnBzZXVkb25QAA==');
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| tidb_decode_plan('3gLYMAkyOF80CTAJMAlOL0EJMAl0aW1lOjUzNC40NDnCtXMsIGxvb3BzOjEJMS4wODk4NDM3NSBLQgEtPAoxCTMxXzgJMAkyLjY1ODYdAUw1CWRhdGE6U2VsZWN0aW9uXzcJMQlaFDQ4MC44OS5aADAyLCBycGMgbnVtOiAxCQwFhAA0AYQAMwkqkHByb2Mga2V5czo3CTIyNCBCeXRlcwlOL0EKMgkxXzcJMV8wCTJGhQ |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|     id                   task         estRows               operator info                              actRows    execution info                                                            memory           disk                                                |
|     Update_4             root         0                     N/A                                        0          time:534.449µs, loops:1                                                  1.08984375 KB    N/A                                                  |
|     └─TableReader_8      root         2.6586666666666665    data:Selection_7                           1          time:480.899µs, loops:2, rpc num: 1, rpc time:434.439µs, proc keys:7    224 Bytes        N/A                                                   |
|       └─Selection_7      cop[tikv]    2.6586666666666665    lt(test.t.a, 1000000)                      1          time:0s, loops:1                                                          N/A              N/A                                                 |
|         └─TableScan_6    cop[tikv]    8                     table:t, keep order:false, stats:pseudo    1          time:0s, loops:1                                                          N/A              N/A                                                 |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set
Time: 0.011s
test> select tidb_decode_plan('2QLYMAkyOV80CTAJMAlOL0EJMAl0aW1lOjQwNS41NznCtXMsIGxvb3BzOjEJMS4xNDQ1MzEyNSBLQgEtPAoxCTMxXzgJMAkyLjY1ODYdAUw1CWRhdGE6U2VsZWN0aW9uXzcJMQlaFDM3NC4zMi5aADAyLCBycGMgbnVtOiAxCQwFhBQzNDAuODUJKohwcm9jIGtleXM6NwkyMjIgQnl0ZXMJTi9BCjIJMV83CTFfME6FADxsdCh0ZXN0LnQuYSwgMTApEYUEMHMZ1wH2AUkUMwkxMF82BUqgOAl0YWJsZTp0LCBrZWVwIG9yZGVyOmZhbHNlLCBzdGF0czpwc2V1ZG9uUAA=');
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| tidb_decode_plan('2QLYMAkyOV80CTAJMAlOL0EJMAl0aW1lOjQwNS41NznCtXMsIGxvb3BzOjEJMS4xNDQ1MzEyNSBLQgEtPAoxCTMxXzgJMAkyLjY1ODYdAUw1CWRhdGE6U2VsZWN0aW9uXzcJMQlaFDM3NC4zMi5aADAyLCBycGMgbnVtOiAxCQwFhBQzNDAuODUJKohwcm9jIGtleXM6NwkyMjIgQnl0ZXMJTi9BCjIJMV83CTFfME6FAD |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|     id                   task         estRows               operator info                              actRows    execution info                                                            memory           disk                                                |
|     Delete_4             root         0                     N/A                                        0          time:405.579µs, loops:1                                                  1.14453125 KB    N/A                                                  |
|     └─TableReader_8      root         2.6586666666666665    data:Selection_7                           1          time:374.329µs, loops:2, rpc num: 1, rpc time:340.859µs, proc keys:7    222 Bytes        N/A                                                   |
|       └─Selection_7      cop[tikv]    2.6586666666666665    lt(test.t.a, 10)                           1          time:0s, loops:1                                                          N/A              N/A                                                 |
|         └─TableScan_6    cop[tikv]    8                     table:t, keep order:false, stats:pseudo    1          time:0s, loops:1                                                          N/A              N/A                                                 |
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

Attention

Currently, the insert/update/delete executor runtime information doesn't contain the transaction commit duration

What is changed and how it works?

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

  • planner: encode insert/delete/update plan in slow log plan field.

@crazycs520 @ti-srebot
cherry pick pingcap#19176 to release-4.0
ba98530 
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
AilinKid
AilinKid reviewed Aug 20, 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.

pls resolve the conflicts

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

tangenta
tangenta reviewed Sep 2, 2020
View reviewed changes
Copy link
Contributor

@tangenta tangenta 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
AilinKid
AilinKid approved these changes 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 status/LGT2 Indicates that a PR has LGTM 2. and removed status/LGT1 Indicates that a PR has LGTM 1. labels Sep 2, 2020
@AilinKid
Copy link
Contributor

AilinKid commented Sep 2, 2020

/run-all-tests

@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:

  • 19664
  • 19692

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

/run-all-tests

@ti-srebot
Copy link
Contributor Author

@ti-srebot merge failed.

@crazycs520
Copy link
Contributor

/run-unit-test

@crazycs520
Copy link
Contributor

/run-unit-test

@crazycs520
Copy link
Contributor

/run-all-tests

@crazycs520
Copy link
Contributor

/run-unit-test

3 similar comments
@crazycs520
Copy link
Contributor

/run-unit-test

@crazycs520
Copy link
Contributor

/run-unit-test

@crazycs520
Copy link
Contributor

/run-unit-test

@crazycs520
Copy link
Contributor

/run-all-tests

@crazycs520
Copy link
Contributor

/run-all-tests

@zz-jason zz-jason changed the title planner: encode insert/delete/update executor plan information in slow log plan field (#19176) planner: encode insert/delete/update executor plan ... (#19176) Sep 3, 2020
@zz-jason zz-jason merged commit b73ecaf into pingcap:release-4.0 Sep 3, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@zz-jason zz-jason zz-jason left review comments

@tangenta tangenta tangenta left review comments

@AilinKid AilinKid AilinKid approved these changes

@XuHuaiyu XuHuaiyu Awaiting requested review from XuHuaiyu

Assignees

@crazycs520 crazycs520

Labels
sig/sql-infra SIG: SQL Infra status/can-merge Indicates a PR has been approved by a committer. status/LGT2 Indicates that a PR has LGTM 2. type/usability type/4.0-cherry-pick
Projects
None yet
Milestone
v4.0.6
Development

Successfully merging this pull request may close these issues.

None yet
5 participants
@ti-srebot @crazycs520 @AilinKid @zz-jason @tangenta