Skip to content

Commit b4ce0d9

Browse files
committed
Reduce unnecessary string evaluation
1 parent 117a924 commit b4ce0d9

File tree

4 files changed

+40
-24
lines changed

4 files changed

+40
-24
lines changed

sql/analyzer/indexed_joins.go

Lines changed: 17 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -216,16 +216,22 @@ func replanJoin(ctx *sql.Context, n *plan.JoinNode, a *Analyzer, scope *plan.Sco
216216
// Once we've enumerated all expression groups, we can apply hints. This must be done after expression
217217
// groups have been identified, so that the applied hints use the correct metadata.
218218
for _, h := range hints {
219-
m.Tracer.Log("Applying hint: %s", h.Typ.String())
219+
m.Tracer.Log("Applying hint: %s", h.Typ)
220220
m.ApplyHint(h)
221221
}
222222

223-
m.Tracer.Log("Starting cost-based optimization for groups %s", m)
223+
if m.Tracer.TraceEnabled {
224+
m.Tracer.Log("Starting cost-based optimization for groups %s", m)
225+
}
226+
224227
err = m.OptimizeRoot()
225228
if err != nil {
226229
return nil, err
227230
}
228-
m.Tracer.Log("Completed cost-based optimization:\n%s", m.CostDebugString())
231+
232+
if m.Tracer.TraceEnabled {
233+
m.Tracer.Log("Completed cost-based optimization:\n%s", m.CostDebugString())
234+
}
229235

230236
if a.Verbose && a.Debug {
231237
a.Log("%s", m.String())
@@ -234,7 +240,9 @@ func replanJoin(ctx *sql.Context, n *plan.JoinNode, a *Analyzer, scope *plan.Sco
234240
scope.JoinTrees = append(scope.JoinTrees, m.String())
235241
}
236242

237-
m.Tracer.Log("Best root plan:\n%s", m.BestPlanDebugString())
243+
if m.Tracer.TraceEnabled {
244+
m.Tracer.Log("Best root plan:\n%s", m.BestPlanDebugString())
245+
}
238246

239247
return m.BestRootPlan(ctx)
240248
}
@@ -261,7 +269,7 @@ func addLookupJoins(ctx *sql.Context, m *memo.Memo) error {
261269
defer m.Tracer.PopDebugContext()
262270

263271
return memo.DfsRel(m.Root(), func(e memo.RelExpr) error {
264-
m.Tracer.PushDebugContext(fmt.Sprintf("%+v", e))
272+
m.Tracer.PushDebugContextFmt("%+v", e)
265273
defer m.Tracer.PopDebugContext()
266274

267275
var right *memo.ExprGroup
@@ -665,7 +673,7 @@ func addRightSemiJoins(ctx *sql.Context, m *memo.Memo) error {
665673
defer m.Tracer.PopDebugContext()
666674

667675
return memo.DfsRel(m.Root(), func(e memo.RelExpr) error {
668-
m.Tracer.PushDebugContext(fmt.Sprintf("%+v", e))
676+
m.Tracer.PushDebugContextFmt("%+v", e)
669677
defer m.Tracer.PopDebugContext()
670678

671679
semi, ok := e.(*memo.SemiJoin)
@@ -831,7 +839,7 @@ func addHashJoins(m *memo.Memo) error {
831839
defer m.Tracer.PopDebugContext()
832840

833841
return memo.DfsRel(m.Root(), func(e memo.RelExpr) error {
834-
m.Tracer.PushDebugContext(fmt.Sprintf("%+v", e))
842+
m.Tracer.PushDebugContextFmt("%+v", e)
835843
defer m.Tracer.PopDebugContext()
836844

837845
switch e.(type) {
@@ -971,7 +979,7 @@ func addRangeHeapJoin(m *memo.Memo) error {
971979
defer m.Tracer.PopDebugContext()
972980

973981
return memo.DfsRel(m.Root(), func(e memo.RelExpr) error {
974-
m.Tracer.PushDebugContext(fmt.Sprintf("%+v", e))
982+
m.Tracer.PushDebugContextFmt("%+v", e)
975983
defer m.Tracer.PopDebugContext()
976984

977985
switch e.(type) {
@@ -1082,7 +1090,7 @@ func addMergeJoins(ctx *sql.Context, m *memo.Memo) error {
10821090
defer m.Tracer.PopDebugContext()
10831091

10841092
return memo.DfsRel(m.Root(), func(e memo.RelExpr) error {
1085-
m.Tracer.PushDebugContext(fmt.Sprintf("%+v", e))
1093+
m.Tracer.PushDebugContextFmt("%+v", e)
10861094
defer m.Tracer.PopDebugContext()
10871095

10881096
var join *memo.JoinBase

sql/memo/join_order_builder.go

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -529,10 +529,10 @@ func (j *joinOrderBuilder) buildJoinOp(n *plan.JoinNode) *ExprGroup {
529529
}
530530

531531
if !isInner {
532-
j.m.Tracer.Log("Building non-inner edge for join type: %s", typ.String())
532+
j.m.Tracer.Log("Building non-inner edge for join type: %s", typ)
533533
j.buildNonInnerEdge(op, filters...)
534534
} else {
535-
j.m.Tracer.Log("Building inner edge for join type: %s", typ.String())
535+
j.m.Tracer.Log("Building inner edge for join type: %s", typ)
536536
j.buildInnerEdge(op, filters...)
537537
}
538538
return group
@@ -700,7 +700,7 @@ func setPrinter(all, s1, s2 vertexSet) {
700700

701701
// addPlans finds operators that let us join (s1 op s2) and (s2 op s1).
702702
func (j *joinOrderBuilder) addPlans(s1, s2 vertexSet) {
703-
j.m.Tracer.PushDebugContext(fmt.Sprintf("addPlans/%s<->%s", s1, s2))
703+
j.m.Tracer.PushDebugContextFmt("addPlans/%s<->%s", s1, s2)
704704
defer j.m.Tracer.PopDebugContext()
705705

706706
// all inner filters could be applied
@@ -736,14 +736,14 @@ func (j *joinOrderBuilder) addPlans(s1, s2 vertexSet) {
736736
for i, ok := j.nonInnerEdges.Next(0); ok; i, ok = j.nonInnerEdges.Next(i + 1) {
737737
e := &j.edges[i]
738738
if e.applicable(s1, s2) {
739-
j.m.Tracer.Log("Found applicable non-inner edge %d, adding join: %s", i, e.op.joinType.String())
739+
j.m.Tracer.Log("Found applicable non-inner edge %d, adding join: %s", i, e.op.joinType)
740740
j.addJoin(e.op.joinType, s1, s2, e.filters, innerJoinFilters, e.joinIsRedundant(s1, s2))
741741
return
742742
}
743743
if e.applicable(s2, s1) {
744744
// This is necessary because we only iterate s1 up to subset / 2
745745
// in DPSube()
746-
j.m.Tracer.Log("Found applicable non-inner edge %d (swapped), adding join: %s", i, e.op.joinType.String())
746+
j.m.Tracer.Log("Found applicable non-inner edge %d (swapped), adding join: %s", i, e.op.joinType)
747747
j.addJoin(e.op.joinType, s2, s1, e.filters, innerJoinFilters, e.joinIsRedundant(s2, s1))
748748
return
749749
}

sql/memo/memo.go

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -77,7 +77,7 @@ func (m *Memo) HandleErr(err error) {
7777
}
7878

7979
func (m *Memo) EnableTrace(enable bool) {
80-
m.Tracer.traceEnabled = enable
80+
m.Tracer.TraceEnabled = enable
8181
}
8282

8383
func (m *Memo) Root() *ExprGroup {
@@ -435,7 +435,7 @@ func (m *Memo) optimizeMemoGroup(grp *ExprGroup) error {
435435
return nil
436436
}
437437

438-
m.Tracer.PushDebugContext(fmt.Sprintf("optimizeMemoGroup/%d", grp.Id))
438+
m.Tracer.PushDebugContextFmt("optimizeMemoGroup/%d", grp.Id)
439439
defer m.Tracer.PopDebugContext()
440440

441441
n := grp.First
@@ -503,21 +503,21 @@ func (m *Memo) updateBest(grp *ExprGroup, n RelExpr, cost float64) {
503503
grp.Best = n
504504
grp.Cost = cost
505505
grp.HintOk = true
506-
m.Tracer.Log("Set best plan for group %d to hinted plan %s with cost %.2f", grp.Id, n.String(), cost)
506+
m.Tracer.Log("Set best plan for group %d to hinted plan %s with cost %.2f", grp.Id, n, cost)
507507
return
508508
}
509509
if grp.updateBest(n, cost) {
510-
m.Tracer.Log("Updated best plan for group %d to hinted plan %s with cost %.2f", grp.Id, n.String(), cost)
510+
m.Tracer.Log("Updated best plan for group %d to hinted plan %s with cost %.2f", grp.Id, n, cost)
511511
}
512512
} else if grp.Best == nil || !grp.HintOk {
513513
if grp.updateBest(n, cost) {
514-
m.Tracer.Log("Updated best plan for group %d to plan %s with cost %.2f (no hints satisfied)", grp.Id, n.String(), cost)
514+
m.Tracer.Log("Updated best plan for group %d to plan %s with cost %.2f (no hints satisfied)", grp.Id, n, cost)
515515
}
516516
}
517517
return
518518
}
519519
if grp.updateBest(n, cost) {
520-
m.Tracer.Log("Updated best plan for group %d to plan %s with cost %.2f", grp.Id, n.String(), cost)
520+
m.Tracer.Log("Updated best plan for group %d to plan %s with cost %.2f", grp.Id, n, cost)
521521
}
522522
}
523523

sql/memo/trace_logger.go

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -24,29 +24,37 @@ import (
2424
type TraceLogger struct {
2525
// A stack of debugger context. See PushDebugContext, PopDebugContext
2626
contextStack []string
27-
traceEnabled bool
27+
TraceEnabled bool
2828
}
2929

3030
var log = logrus.New()
3131

3232
// PushDebugContext pushes the given context string onto the context stack, to use when logging debug messages.
3333
func (a *TraceLogger) PushDebugContext(msg string) {
34-
if a != nil && a.traceEnabled {
34+
if a != nil && a.TraceEnabled {
3535
a.contextStack = append(a.contextStack, msg)
3636
}
3737
}
3838

39+
// PushDebugContextFmt pushes a formatted context string onto the context stack, to use when logging debug messages.
40+
// Useful to avoid the cost of formatting when tracing is disabled.
41+
func (a *TraceLogger) PushDebugContextFmt(fmtStr string, args ...any) {
42+
if a != nil && a.TraceEnabled {
43+
a.contextStack = append(a.contextStack, fmt.Sprintf(fmtStr, args...))
44+
}
45+
}
46+
3947
// PopDebugContext pops a context message off the context stack.
4048
func (a *TraceLogger) PopDebugContext() {
41-
if a != nil && len(a.contextStack) > 0 {
49+
if a != nil && a.TraceEnabled && len(a.contextStack) > 0 {
4250
a.contextStack = a.contextStack[:len(a.contextStack)-1]
4351
}
4452
}
4553

4654
// Log prints an INFO message to stdout with the given message and args
4755
// if the analyzer is in debug mode.
4856
func (a *TraceLogger) Log(msg string, args ...interface{}) {
49-
if a != nil && a.traceEnabled {
57+
if a != nil && a.TraceEnabled {
5058
if len(a.contextStack) > 0 {
5159
ctx := strings.Join(a.contextStack, "/")
5260
fmt.Printf("%s: "+msg+"\n", append([]interface{}{ctx}, args...)...)

0 commit comments

Comments
 (0)