From a4bd02e35ce0f0236ae055984a65d38494a8e247 Mon Sep 17 00:00:00 2001 From: Song Gao Date: Fri, 12 Nov 2021 12:35:06 +0800 Subject: [PATCH] planner: add optimizer trace framework for logicalOptimize (#29559) --- executor/executor.go | 2 + planner/core/logical_plan_test.go | 55 +++++++++++++ planner/core/optimizer.go | 51 +++++++++++- planner/core/plan.go | 13 +++ planner/core/rule_aggregation_elimination.go | 10 ++- planner/core/rule_aggregation_push_down.go | 2 +- planner/core/rule_build_key_info.go | 6 +- planner/core/rule_column_pruning.go | 2 +- planner/core/rule_decorrelate.go | 18 ++--- planner/core/rule_eliminate_projection.go | 2 +- .../core/rule_generate_column_substitute.go | 2 +- planner/core/rule_join_elimination.go | 5 +- planner/core/rule_join_reorder.go | 2 +- planner/core/rule_max_min_eliminate.go | 2 +- planner/core/rule_partition_processor.go | 5 +- planner/core/rule_predicate_push_down.go | 2 +- planner/core/rule_result_reorder.go | 2 +- planner/core/rule_topn_push_down.go | 2 +- sessionctx/stmtctx/stmtctx.go | 6 ++ util/tracing/opt_trace.go | 81 +++++++++++++++++++ 20 files changed, 239 insertions(+), 31 deletions(-) create mode 100644 util/tracing/opt_trace.go diff --git a/executor/executor.go b/executor/executor.go index 572f30649a6ad..7383941acd046 100644 --- a/executor/executor.go +++ b/executor/executor.go @@ -1682,6 +1682,8 @@ func ResetContextOfStmt(ctx sessionctx.Context, s ast.StmtNode) (err error) { sc.CTEStorageMap = map[int]*CTEStorages{} sc.IsStaleness = false sc.LockTableIDs = make(map[int64]struct{}) + sc.EnableOptimizeTrace = false + sc.LogicalOptimizeTrace = nil sc.InitMemTracker(memory.LabelForSQLText, vars.MemQuotaQuery) sc.InitDiskTracker(memory.LabelForSQLText, -1) diff --git a/planner/core/logical_plan_test.go b/planner/core/logical_plan_test.go index a0bb8a8070726..c800f5c577a4f 100644 --- a/planner/core/logical_plan_test.go +++ b/planner/core/logical_plan_test.go @@ -2071,3 +2071,58 @@ func (s *testPlanSuite) TestWindowLogicalPlanAmbiguous(c *C) { } } } + +func (s *testPlanSuite) TestLogicalOptimizeWithTraceEnabled(c *C) { + sql := "select * from t where a in (1,2)" + defer testleak.AfterTest(c)() + tt := []struct { + flags []uint64 + steps int + }{ + { + flags: []uint64{ + flagEliminateAgg, + flagPushDownAgg}, + steps: 2, + }, + { + flags: []uint64{ + flagEliminateAgg, + flagPushDownAgg, + flagPrunColumns, + flagBuildKeyInfo, + }, + steps: 4, + }, + { + flags: []uint64{}, + steps: 0, + }, + } + + for i, tc := range tt { + comment := Commentf("case:%v sql:%s", i, sql) + stmt, err := s.ParseOneStmt(sql, "", "") + c.Assert(err, IsNil, comment) + err = Preprocess(s.ctx, stmt, WithPreprocessorReturn(&PreprocessorReturn{InfoSchema: s.is})) + c.Assert(err, IsNil, comment) + sctx := MockContext() + sctx.GetSessionVars().StmtCtx.EnableOptimizeTrace = true + builder, _ := NewPlanBuilder().Init(sctx, s.is, &hint.BlockHintProcessor{}) + domain.GetDomain(sctx).MockInfoCacheAndLoadInfoSchema(s.is) + ctx := context.TODO() + p, err := builder.Build(ctx, stmt) + c.Assert(err, IsNil) + flag := uint64(0) + for _, f := range tc.flags { + flag = flag | f + } + p, err = logicalOptimize(ctx, flag, p.(LogicalPlan)) + c.Assert(err, IsNil) + _, ok := p.(*LogicalProjection) + c.Assert(ok, IsTrue) + otrace := sctx.GetSessionVars().StmtCtx.LogicalOptimizeTrace + c.Assert(otrace, NotNil) + c.Assert(len(otrace.Steps), Equals, tc.steps) + } +} diff --git a/planner/core/optimizer.go b/planner/core/optimizer.go index 7cc352c9b8447..55127627b7477 100644 --- a/planner/core/optimizer.go +++ b/planner/core/optimizer.go @@ -35,6 +35,7 @@ import ( "github.com/pingcap/tidb/types" utilhint "github.com/pingcap/tidb/util/hint" "github.com/pingcap/tidb/util/set" + "github.com/pingcap/tidb/util/tracing" "go.uber.org/atomic" ) @@ -83,9 +84,44 @@ var optRuleList = []logicalOptRule{ &columnPruner{}, // column pruning again at last, note it will mess up the results of buildKeySolver } +type logicalOptimizeOp struct { + // tracer is goring to track optimize steps during rule optimizing + tracer *tracing.LogicalOptimizeTracer +} + +func defaultLogicalOptimizeOption() *logicalOptimizeOp { + return &logicalOptimizeOp{} +} + +func (op *logicalOptimizeOp) withEnableOptimizeTracer(tracer *tracing.LogicalOptimizeTracer) *logicalOptimizeOp { + op.tracer = tracer + return op +} + +func (op *logicalOptimizeOp) appendBeforeRuleOptimize(name string, before LogicalPlan) { + if op.tracer == nil { + return + } + op.tracer.AppendRuleTracerBeforeRuleOptimize(name, before.buildLogicalPlanTrace()) +} + +func (op *logicalOptimizeOp) appendStepToCurrent(id int, tp, reason, action string) { + if op.tracer == nil { + return + } + op.tracer.AppendRuleTracerStepToCurrent(id, tp, reason, action) +} + +func (op *logicalOptimizeOp) trackAfterRuleOptimize(after LogicalPlan) { + if op.tracer == nil { + return + } + op.tracer.TrackLogicalPlanAfterRuleOptimize(after.buildLogicalPlanTrace()) +} + // logicalOptRule means a logical optimizing rule, which contains decorrelate, ppd, column pruning, etc. type logicalOptRule interface { - optimize(context.Context, LogicalPlan) (LogicalPlan, error) + optimize(context.Context, LogicalPlan, *logicalOptimizeOp) (LogicalPlan, error) name() string } @@ -335,6 +371,15 @@ func enableParallelApply(sctx sessionctx.Context, plan PhysicalPlan) PhysicalPla } func logicalOptimize(ctx context.Context, flag uint64, logic LogicalPlan) (LogicalPlan, error) { + opt := defaultLogicalOptimizeOption() + stmtCtx := logic.SCtx().GetSessionVars().StmtCtx + if stmtCtx.EnableOptimizeTrace { + tracer := &tracing.LogicalOptimizeTracer{Steps: make([]*tracing.LogicalRuleOptimizeTracer, 0)} + opt = opt.withEnableOptimizeTracer(tracer) + defer func() { + stmtCtx.LogicalOptimizeTrace = tracer + }() + } var err error for i, rule := range optRuleList { // The order of flags is same as the order of optRule in the list. @@ -343,10 +388,12 @@ func logicalOptimize(ctx context.Context, flag uint64, logic LogicalPlan) (Logic if flag&(1<