diff --git a/executor/executor.go b/executor/executor.go index 81afc5620daca..c2fcdaa2d7887 100644 --- a/executor/executor.go +++ b/executor/executor.go @@ -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. @@ -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 { diff --git a/store/copr/BUILD.bazel b/store/copr/BUILD.bazel index 9ea8467d01dfa..a7cdd81453fd7 100644 --- a/store/copr/BUILD.bazel +++ b/store/copr/BUILD.bazel @@ -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", diff --git a/store/copr/coprocessor.go b/store/copr/coprocessor.go index 08f0f055a31e3..f446912ef33af 100644 --- a/store/copr/coprocessor.go +++ b/store/copr/coprocessor.go @@ -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" @@ -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 }