From 0159a37274aa85bdfc53e324183de5667cf48801 Mon Sep 17 00:00:00 2001
From: tiancaiamao <tiancaiamao@gmail.com>
Date: Tue, 10 Jan 2023 10:59:23 +0800
Subject: [PATCH 1/3] executor,store/copr: trace the buildCopTask and limitExec
 close duration when it's slow

---
 executor/executor.go      | 20 +++++++++++++++++++-
 store/copr/coprocessor.go | 10 +++++++++-
 2 files changed, 28 insertions(+), 2 deletions(-)

diff --git a/executor/executor.go b/executor/executor.go
index 1679ed9e57e12..2e7da1e9a2fc6 100644
--- a/executor/executor.go
+++ b/executor/executor.go
@@ -1350,6 +1350,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.
@@ -1427,13 +1430,28 @@ 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(span.Context()), opentracing.StartTime(start))
+			defer span1.Finish()
+		}
+	}
 }
 
 func (e *LimitExec) adjustRequiredRows(chk *chunk.Chunk) *chunk.Chunk {
diff --git a/store/copr/coprocessor.go b/store/copr/coprocessor.go
index 94a2f478290a8..f0c10666c0402 100644
--- a/store/copr/coprocessor.go
+++ b/store/copr/coprocessor.go
@@ -384,12 +384,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
 }

From 55e46f8715656dbb53e4a33833307b178ef4012a Mon Sep 17 00:00:00 2001
From: tiancaiamao <tiancaiamao@gmail.com>
Date: Fri, 13 Jan 2023 21:02:51 +0800
Subject: [PATCH 2/3] merge master and fix build

---
 executor/executor.go      | 3 ++-
 store/copr/coprocessor.go | 1 +
 2 files changed, 3 insertions(+), 1 deletion(-)

diff --git a/executor/executor.go b/executor/executor.go
index 71928f22ac85b..c2fcdaa2d7887 100644
--- a/executor/executor.go
+++ b/executor/executor.go
@@ -1491,10 +1491,11 @@ func (e *LimitExec) Close() error {
 		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(span.Context()), opentracing.StartTime(start))
+			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/coprocessor.go b/store/copr/coprocessor.go
index 82b604c1303d0..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"

From f97102e84e36c1b9f4bd24e80ef87ff3bab10f41 Mon Sep 17 00:00:00 2001
From: tiancaiamao <tiancaiamao@gmail.com>
Date: Tue, 17 Jan 2023 10:29:13 +0800
Subject: [PATCH 3/3] address comment

---
 store/copr/BUILD.bazel | 1 +
 1 file changed, 1 insertion(+)

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",