Skip to content

Commit

Permalink
executor,store/copr: trace the buildCopTask and limitExec close durat…
Browse files Browse the repository at this point in the history
…ion when it's slow (#40579)

ref #40441
  • Loading branch information
tiancaiamao authored Jan 17, 2023
1 parent b9fb22d commit 4620df6
Show file tree
Hide file tree
Showing 3 changed files with 31 additions and 2 deletions.
21 changes: 20 additions & 1 deletion executor/executor.go
Original file line number Diff line number Diff line change
Expand Up @@ -1393,6 +1393,9 @@ type LimitExec struct {

// columnIdxsUsedByChild keep column indexes of child executor used for inline projection
columnIdxsUsedByChild []int

// Log the close time when opentracing is enabled.
span opentracing.Span
}

// Next implements the Executor Next interface.
Expand Down Expand Up @@ -1470,13 +1473,29 @@ func (e *LimitExec) Open(ctx context.Context) error {
e.childResult = tryNewCacheChunk(e.children[0])
e.cursor = 0
e.meetFirstBatch = e.begin == 0
if span := opentracing.SpanFromContext(ctx); span != nil && span.Tracer() != nil {
e.span = span
}
return nil
}

// Close implements the Executor Close interface.
func (e *LimitExec) Close() error {
start := time.Now()

e.childResult = nil
return e.baseExecutor.Close()
err := e.baseExecutor.Close()

elapsed := time.Since(start)
if elapsed > time.Millisecond {
logutil.BgLogger().Info("limit executor close takes a long time",
zap.Duration("elapsed", elapsed))
if e.span != nil {
span1 := e.span.Tracer().StartSpan("limitExec.Close", opentracing.ChildOf(e.span.Context()), opentracing.StartTime(start))
defer span1.Finish()
}
}
return err
}

func (e *LimitExec) adjustRequiredRows(chk *chunk.Chunk) *chunk.Chunk {
Expand Down
1 change: 1 addition & 0 deletions store/copr/BUILD.bazel
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ go_library(
"//util/trxevents",
"@com_github_dgraph_io_ristretto//:ristretto",
"@com_github_gogo_protobuf//proto",
"@com_github_opentracing_opentracing_go//:opentracing-go",
"@com_github_pingcap_errors//:errors",
"@com_github_pingcap_failpoint//:failpoint",
"@com_github_pingcap_kvproto//pkg/coprocessor",
Expand Down
11 changes: 10 additions & 1 deletion store/copr/coprocessor.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import (
"unsafe"

"github.com/gogo/protobuf/proto"
"github.com/opentracing/opentracing-go"
"github.com/pingcap/errors"
"github.com/pingcap/failpoint"
"github.com/pingcap/kvproto/pkg/coprocessor"
Expand Down Expand Up @@ -384,12 +385,20 @@ func buildCopTasks(bo *Backoffer, cache *RegionCache, ranges *KeyRanges, req *kv
builder.reverse()
}
tasks := builder.build()
if elapsed := time.Since(start); elapsed > time.Millisecond*500 {
elapsed := time.Since(start)
if elapsed > time.Millisecond*500 {
logutil.BgLogger().Warn("buildCopTasks takes too much time",
zap.Duration("elapsed", elapsed),
zap.Int("range len", rangesLen),
zap.Int("task len", len(tasks)))
}
if elapsed > time.Millisecond {
ctx := bo.GetCtx()
if span := opentracing.SpanFromContext(ctx); span != nil && span.Tracer() != nil {
span1 := span.Tracer().StartSpan("copr.buildCopTasks", opentracing.ChildOf(span.Context()), opentracing.StartTime(start))
defer span1.Finish()
}
}
metrics.TxnRegionsNumHistogramWithCoprocessor.Observe(float64(builder.regionNum()))
return tasks, nil
}
Expand Down

0 comments on commit 4620df6

Please sign in to comment.