From 4990d733d33d12fe46ad79d58f39f6b8294823ae Mon Sep 17 00:00:00 2001
From: irfan sharif <irfanmahmoudsharif@gmail.com>
Date: Mon, 11 Jan 2021 12:12:36 -0500
Subject: [PATCH] tracing,sql: introduce BenchmarkTracing
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

  make bench PKG=./pkg/sql/tests \
    TESTFLAGS='-benchtime=5000x -count=20' \
    BENCHES='BenchmarkTracing'

Old is without always-on tracing, new is with.

  name                                old time/op    new time/op    delta
  Tracing/tracing=x/Insert/rows=1-16     248µs ± 3%     245µs ± 3%  -1.10%  (p=0.035 n=20+20)
  Tracing/tracing=x/Update/rows=1-16     334µs ± 2%     334µs ± 3%    ~     (p=0.931 n=20+20)
  Tracing/tracing=x/Delete/rows=1-16     242µs ± 3%     236µs ± 3%  -2.13%  (p=0.000 n=20+20)
  Tracing/tracing=x/Scan/rows=1-16       171µs ± 4%     174µs ± 4%    ~     (p=0.141 n=19+20)

  name                                old alloc/op   new alloc/op   delta
  Tracing/tracing=x/Insert/rows=1-16    38.7kB ± 1%    38.8kB ± 1%  +0.25%  (p=0.009 n=17+20)
  Tracing/tracing=x/Update/rows=1-16    53.5kB ± 1%    53.5kB ± 1%    ~     (p=0.693 n=20+20)
  Tracing/tracing=x/Delete/rows=1-16    42.3kB ± 1%    42.2kB ± 0%    ~     (p=0.833 n=19+17)
  Tracing/tracing=x/Scan/rows=1-16      23.6kB ± 2%    23.7kB ± 2%    ~     (p=0.765 n=19+20)

  name                                old allocs/op  new allocs/op  delta
  Tracing/tracing=x/Insert/rows=1-16       314 ± 0%       314 ± 0%  +0.14%  (p=0.004 n=20+13)
  Tracing/tracing=x/Update/rows=1-16       532 ± 0%       532 ± 0%  +0.12%  (p=0.002 n=16+19)
  Tracing/tracing=x/Delete/rows=1-16       324 ± 0%       323 ± 0%    ~     (p=0.249 n=19+20)
  Tracing/tracing=x/Scan/rows=1-16         257 ± 0%       257 ± 1%  -0.14%  (p=0.011 n=15+20)

Release note: None
---
 pkg/sql/tests/kv_test.go   | 59 ++++++++++++++++++++++++++++++++++++++
 pkg/util/tracing/tracer.go |  2 +-
 2 files changed, 60 insertions(+), 1 deletion(-)

diff --git a/pkg/sql/tests/kv_test.go b/pkg/sql/tests/kv_test.go
index 3e81894fa3f1..be0eabfaa4f0 100644
--- a/pkg/sql/tests/kv_test.go
+++ b/pkg/sql/tests/kv_test.go
@@ -24,6 +24,7 @@ import (
 	"github.com/cockroachdb/cockroach/pkg/base"
 	kv2 "github.com/cockroachdb/cockroach/pkg/kv"
 	"github.com/cockroachdb/cockroach/pkg/testutils/serverutils"
+	"github.com/cockroachdb/cockroach/pkg/util/log"
 	"github.com/cockroachdb/errors"
 )
 
@@ -148,12 +149,26 @@ type kvSQL struct {
 }
 
 func newKVSQL(b *testing.B) kvInterface {
+	return newKVSQLWithTracing(b, false)
+}
+
+func newKVSQLWithTracing(b *testing.B, enabled bool) kvInterface {
 	s, db, _ := serverutils.StartServer(b, base.TestServerArgs{UseDatabase: "bench"})
 
 	if _, err := db.Exec(`CREATE DATABASE IF NOT EXISTS bench`); err != nil {
 		b.Fatal(err)
 	}
 
+	var tracingMode string
+	if enabled {
+		tracingMode = "background"
+	} else {
+		tracingMode = "legacy"
+	}
+	if _, err := db.Exec(fmt.Sprintf("SET CLUSTER SETTING trace.mode = %s", tracingMode)); err != nil {
+		b.Fatal(err)
+	}
+
 	kv := &kvSQL{}
 	kv.db = db
 	kv.doneFn = func() {
@@ -297,3 +312,47 @@ func BenchmarkKV(b *testing.B) {
 		})
 	}
 }
+
+// BenchmarkTracing measures the overhead of always-on tracing. It also reports
+// the memory utilization.
+func BenchmarkTracing(b *testing.B) {
+	defer log.Scope(b).Close(b)
+
+	for i, opFn := range []func(kvInterface, int, int) error{
+		kvInterface.Insert,
+		kvInterface.Update,
+		kvInterface.Delete,
+		kvInterface.Scan,
+	} {
+		opName := runtime.FuncForPC(reflect.ValueOf(opFn).Pointer()).Name()
+		opName = strings.TrimPrefix(opName, "github.com/cockroachdb/cockroach/pkg/sql/tests_test.kvInterface.")
+		for _, tracingEnabled := range []bool{true, false} {
+			var trace = "f"
+			if tracingEnabled {
+				trace = "t"
+			}
+
+			for _, rows := range []int{1, 10, 100, 1000, 10000} {
+				b.Run(fmt.Sprintf("tracing=%s/%s/rows=%d", trace, opName, rows), func(b *testing.B) {
+
+					b.ReportAllocs()
+
+					kv := newKVSQLWithTracing(b, tracingEnabled)
+					defer kv.done()
+
+					if err := kv.prep(rows, i != 0 /* Insert */ && i != 2 /* Delete */); err != nil {
+						b.Fatal(err)
+					}
+
+					b.ResetTimer()
+					for i := 0; i < b.N; i++ {
+						if err := opFn(kv, rows, i); err != nil {
+							b.Fatal(err)
+						}
+					}
+					b.StopTimer()
+				})
+			}
+		}
+	}
+}
diff --git a/pkg/util/tracing/tracer.go b/pkg/util/tracing/tracer.go
index 9737c2638fb5..6782151126ce 100644
--- a/pkg/util/tracing/tracer.go
+++ b/pkg/util/tracing/tracer.go
@@ -263,7 +263,7 @@ func (t *Tracer) AlwaysTrace() bool {
 
 // startSpanGeneric is the implementation of StartSpanCtx and StartSpan. In
 // the latter case, ctx == noCtx and the returned Context is the supplied one;
-// otherwise the returned Context reflects the returned Span.
+// otherwise the returned Context embeds the returned Span.
 func (t *Tracer) startSpanGeneric(
 	ctx context.Context, opName string, opts spanOptions,
 ) (context.Context, *Span) {