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

*: add trace support for subquery #11182

Merged
merged 14 commits into from
Jul 24, 2019
Merged

Conversation

tiancaiamao
Copy link
Contributor

What problem does this PR solve?

Building a query plan may execute the subquery, but I've no idea what's happening.
For example, I don't why executor.Compile takes so long.

mysql> trace format='row'  select 1, (select sleep(1));
+---------------------------------------+-----------------+--------------+
| operation                             | startTS         | duration     |
+---------------------------------------+-----------------+--------------+
| session.getTxnFuture                  | 20:56:25.071109 | 7.453µs      |
|   ├─session.Execute                   | 20:56:25.071102 | 1.001027416s |
|   ├─session.ParseSQL                  | 20:56:25.071230 | 97.145µs     |
|   ├─executor.Compile                  | 20:56:25.071386 | 1.000643885s |
|   ├─session.runStmt                   | 20:56:26.072058 | 43.809µs     |
|   ├─session.CommitTxn                 | 20:56:26.072090 | 3.509µs      |
|   ├─*executor.ProjectionExec.Next     | 20:56:26.072138 | 5.418µs      |
|   ├─*executor.TableDualExec.Next      | 20:56:26.072139 | 349ns        |
|   ├─*executor.ProjectionExec.Next     | 20:56:26.072148 | 7.049µs      |
|   └─*executor.TableDualExec.Next      | 20:56:26.072150 | 341ns        |
+---------------------------------------+-----------------+--------------+
10 rows in set (1.00 sec)

In this commit, the trace support for subquery is added.
After this change, I know that executor.Compile is slow because it enters the EvalSubQuery function from the following output:

mysql> trace format='row'  select 1, (select sleep(1));
+---------------------------------------+-----------------+--------------+
| operation                             | startTS         | duration     |
+---------------------------------------+-----------------+--------------+
| session.getTxnFuture                  | 20:55:32.007173 | 7.54µs       |
|   ├─session.Execute                   | 20:55:32.007166 | 1.003288171s |
|   ├─session.ParseSQL                  | 20:55:32.007295 | 93.867µs     |
|   ├─executor.Compile                  | 20:55:32.007458 | 1.002949077s |
|   ├─executor.EvalSubQuery             | 20:55:32.007761 | 1.002603472s |
|   ├─*executor.MaxOneRowExec.Next      | 20:55:32.007804 | 1.002550013s |
|   ├─*executor.ProjectionExec.Next     | 20:55:32.007811 | 1.002498283s |
|   ├─*executor.TableDualExec.Next      | 20:55:32.007819 | 2.991µs      |
|   ├─*executor.ProjectionExec.Next     | 20:55:33.010342 | 8.316µs      |
|   ├─*executor.TableDualExec.Next      | 20:55:33.010345 | 518ns        |
|   ├─*executor.MaxOneRowExec.Next      | 20:55:33.010360 | 511ns        |
|   ├─session.runStmt                   | 20:55:33.010418 | 19.784µs     |
|   ├─session.CommitTxn                 | 20:55:33.010431 | 2.551µs      |
|   ├─*executor.ProjectionExec.Next     | 20:55:33.010460 | 6.054µs      |
|   ├─*executor.TableDualExec.Next      | 20:55:33.010461 | 319ns        |
|   ├─*executor.ProjectionExec.Next     | 20:55:33.010470 | 4.241µs      |
|   └─*executor.TableDualExec.Next      | 20:55:33.010471 | 287ns        |
+---------------------------------------+-----------------+--------------+
17 rows in set (1.00 sec)

The result should display in a tree format view, I'll investigate the bug in the next PR.

What is changed and how it works?

Add context.Context to many functions parameter until adding this code is possible in plannercore.EvalSubquery:

if span := opentracing.SpanFromContext(ctx); span != nil && span.Tracer() != nil {
  span1 := span.Tracer().StartSpan("executor.EvalSubQuery", opentracing.ChildOf(span.Context()))
  defer span1.Finish()
}

Check List

Tests

  • No code

Code changes

  • Has exported function/method change

Related changes

  • Need to cherry-pick to the release branch

@tiancaiamao tiancaiamao added type/enhancement The issue or PR belongs to an enhancement. needs-cherry-pick-3.0 labels Jul 10, 2019
@tiancaiamao
Copy link
Contributor Author

PTAL @zz-jason @jackysp

@codecov
Copy link

codecov bot commented Jul 10, 2019

Codecov Report

Merging #11182 into master will not change coverage.
The diff coverage is n/a.

@@             Coverage Diff             @@
##             master     #11182   +/-   ##
===========================================
  Coverage   82.1068%   82.1068%           
===========================================
  Files           425        425           
  Lines         94360      94360           
===========================================
  Hits          77476      77476           
  Misses        11488      11488           
  Partials       5396       5396

@tiancaiamao
Copy link
Contributor Author

/run-all-tests

@tiancaiamao
Copy link
Contributor Author

PTAL @zz-jason @jackysp

planner/core/expression_rewriter.go Show resolved Hide resolved
planner/core/expression_rewriter.go Outdated Show resolved Hide resolved
planner/core/expression_rewriter.go Outdated Show resolved Hide resolved
planner/core/expression_rewriter.go Outdated Show resolved Hide resolved
planner/core/logical_plan_builder.go Outdated Show resolved Hide resolved
planner/core/logical_plan_builder.go Outdated Show resolved Hide resolved
planner/core/planbuilder.go Outdated Show resolved Hide resolved
planner/core/planbuilder.go Show resolved Hide resolved
planner/core/planbuilder.go Outdated Show resolved Hide resolved
planner/core/planbuilder.go Outdated Show resolved Hide resolved
Copy link
Member

@jackysp jackysp left a comment

Choose a reason for hiding this comment

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

LGTM

zz-jason
zz-jason previously approved these changes Jul 23, 2019
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

@zz-jason zz-jason added the status/LGT2 Indicates that a PR has LGTM 2. label Jul 23, 2019
@zz-jason
Copy link
Member

/run-all-tests

@zz-jason
Copy link
Member

@tiancaiamao CI failed.

@tiancaiamao
Copy link
Contributor Author

/run-all-tests

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

@zz-jason zz-jason added status/can-merge Indicates a PR has been approved by a committer. and removed status/LGT2 Indicates that a PR has LGTM 2. labels Jul 24, 2019
@sre-bot
Copy link
Contributor

sre-bot commented Jul 24, 2019

/run-all-tests

@sre-bot
Copy link
Contributor

sre-bot commented Jul 24, 2019

@tiancaiamao merge failed.

@tiancaiamao
Copy link
Contributor Author

/rebuild

@zz-jason zz-jason added status/all tests passed status/can-merge Indicates a PR has been approved by a committer. and removed status/can-merge Indicates a PR has been approved by a committer. labels Jul 24, 2019
@sre-bot
Copy link
Contributor

sre-bot commented Jul 24, 2019

/run-all-tests

@sre-bot
Copy link
Contributor

sre-bot commented Jul 24, 2019

success

@sre-bot sre-bot merged commit abbca53 into pingcap:master Jul 24, 2019
@sre-bot
Copy link
Contributor

sre-bot commented Jul 24, 2019

cherry pick to release-3.0 failed

@tiancaiamao tiancaiamao deleted the trace-subquery branch July 24, 2019 11:06
tiancaiamao added a commit to tiancaiamao/tidb that referenced this pull request Jul 26, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status/can-merge Indicates a PR has been approved by a committer. type/enhancement The issue or PR belongs to an enhancement.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants