sql: revive BenchmarkTracing

Fixes cockroachdb#62081. It had rotted after we removed the trace.mode setting. It
now makes use of a testing knob if enabled, installs real spans all sql
statements. We'll defer the actual investigation into the cause of the
slow-down in future PRs (prototyped in cockroachdb#62227).

    $ make bench PKG=./pkg/bench  TESTFLAGS='-benchtime=10000x -count 20' \
        BENCHES='BenchmarkTracing' BENCHTIMEOUT=50m > benchmark-tracing.txt
    $ cat benchmark-tracing.txt | grep -v tracing=t | sed 's/tracing=f\///' > old.txt
    $ cat benchmark-tracing.txt | grep -v tracing=f | sed 's/tracing=t\///' > new.txt
    $ benchstat old.txt new.txt

    name                                   old time/op    new time/op    delta
    Tracing/Cockroach/Scan1-24                382µs ± 2%     412µs ± 8%   +7.68%  (p=0.000 n=10+10)
    Tracing/Cockroach/Insert-24               579µs ± 2%     609µs ± 6%   +5.10%  (p=0.000 n=10+10)
    Tracing/MultinodeCockroach/Scan1-24       799µs ± 2%     885µs ± 1%  +10.76%  (p=0.000 n=10+9)
    Tracing/MultinodeCockroach/Insert-24     1.09ms ± 1%    1.14ms ± 2%   +5.04%  (p=0.000 n=9+10)

    name                                   old alloc/op   new alloc/op   delta
    Tracing/Cockroach/Scan1-24               25.3kB ± 5%    32.0kB ± 4%  +26.55%  (p=0.000 n=10+10)
    Tracing/Cockroach/Insert-24              38.0kB ± 6%    42.2kB ± 5%  +11.02%  (p=0.000 n=10+10)
    Tracing/MultinodeCockroach/Scan1-24      77.7kB ± 8%    97.1kB ±12%  +25.05%  (p=0.000 n=10+10)
    Tracing/MultinodeCockroach/Insert-24      107kB ± 8%     115kB ± 7%   +7.66%  (p=0.023 n=10+10)

    name                                   old allocs/op  new allocs/op  delta
    Tracing/Cockroach/Scan1-24                  256 ± 1%       280 ± 1%   +9.10%  (p=0.000 n=9+9)
    Tracing/Cockroach/Insert-24                 301 ± 2%       321 ± 1%   +6.64%  (p=0.000 n=10+10)
    Tracing/MultinodeCockroach/Scan1-24         787 ± 2%       921 ± 2%  +17.04%  (p=0.000 n=9+9)
    Tracing/MultinodeCockroach/Insert-24        748 ± 1%       805 ± 2%   +7.61%  (p=0.000 n=9+9)

Release note: None

pkg/bench/BUILD.bazel

@@ -34,6 +34,7 @@ go_test(
         "//pkg/security",
         "//pkg/security/securitytest",
         "//pkg/server",
+        "//pkg/sql",
         "//pkg/testutils/serverutils",
         "//pkg/testutils/skip",
         "//pkg/testutils/sqlutils",

pkg/bench/bench_test.go

@@ -22,8 +22,12 @@ import (
 	"sync/atomic"
 	"testing"
 
+	"github.com/cockroachdb/cockroach/pkg/base"
+	"github.com/cockroachdb/cockroach/pkg/sql"
+	"github.com/cockroachdb/cockroach/pkg/testutils/serverutils"
 	"github.com/cockroachdb/cockroach/pkg/testutils/skip"
 	"github.com/cockroachdb/cockroach/pkg/testutils/sqlutils"
+	"github.com/cockroachdb/cockroach/pkg/testutils/testcluster"
 	"github.com/cockroachdb/cockroach/pkg/util/log"
 	"github.com/cockroachdb/cockroach/pkg/util/randutil"
 	_ "github.com/go-sql-driver/mysql"
@@ -437,34 +441,65 @@ func BenchmarkSampling(b *testing.B) {
 	}
 }
 
-// BenchmarkTracing measures the overhead of always-on tracing. It also reports
-// the memory utilization.
-//
-// TODO(irfansharif): This benchmark is only useful while we transition between
-// the legacy trace.mode, and the "always-on" mode introduced in 21.1. We can
-// remove it in 21.2.
+func benchmarkCockroachWithRealSpans(b *testing.B, realSpans bool, f BenchmarkFn) {
+	s, db, _ := serverutils.StartServer(
+		b, base.TestServerArgs{
+			UseDatabase: "bench",
+			Knobs: base.TestingKnobs{
+				SQLExecutor: &sql.ExecutorTestingKnobs{
+					ForceRealTracingSpans: realSpans,
+				},
+			},
+		})
+	defer s.Stopper().Stop(context.Background())
+
+	if _, err := db.Exec(`CREATE DATABASE bench`); err != nil {
+		b.Fatal(err)
+	}
+
+	f(b, sqlutils.MakeSQLRunner(db))
+}
+
+func benchmarkMultinodeCockroachWithRealSpans(b *testing.B, realSpans bool, f BenchmarkFn) {
+	tc := testcluster.StartTestCluster(b, 3,
+		base.TestClusterArgs{
+			ReplicationMode: base.ReplicationAuto,
+			ServerArgs: base.TestServerArgs{
+				UseDatabase: "bench",
+				Knobs: base.TestingKnobs{
+					SQLExecutor: &sql.ExecutorTestingKnobs{
+						ForceRealTracingSpans: realSpans,
+					},
+				},
+			},
+		})
+	if _, err := tc.Conns[0].Exec(`CREATE DATABASE bench`); err != nil {
+		b.Fatal(err)
+	}
+	defer tc.Stopper().Stop(context.Background())
+
+	f(b, sqlutils.MakeRoundRobinSQLRunner(tc.Conns[0], tc.Conns[1], tc.Conns[2]))
+}
+
+// BenchmarkTracing measures the overhead of tracing. It also reports the memory
+// utilization.
 func BenchmarkTracing(b *testing.B) {
 	skip.UnderShort(b)
 	defer log.Scope(b).Close(b)
 
-	for _, dbFn := range []func(*testing.B, BenchmarkFn){
-		benchmarkCockroach,
-		benchmarkMultinodeCockroach,
+	for _, dbFn := range []func(*testing.B, bool, BenchmarkFn){
+		benchmarkCockroachWithRealSpans,
+		benchmarkMultinodeCockroachWithRealSpans,
 	} {
 		dbName := runtime.FuncForPC(reflect.ValueOf(dbFn).Pointer()).Name()
 		dbName = strings.TrimPrefix(dbName, "github.com/cockroachdb/cockroach/pkg/bench.benchmark")
-
+		dbName = strings.TrimSuffix(dbName, "WithRealSpans")
 		b.Run(dbName, func(b *testing.B) {
-			dbFn(b, func(b *testing.B, db *sqlutils.SQLRunner) {
-				for _, tracingEnabled := range []bool{true, false} {
-					var tracingMode string
-					if tracingEnabled {
-						tracingMode = "background"
-					} else {
-						tracingMode = "legacy"
-					}
-					db.Exec(b, fmt.Sprintf("SET CLUSTER SETTING trace.mode = %s", tracingMode))
-					b.Run(fmt.Sprintf("tracing=%s", tracingMode[:1]), func(b *testing.B) {
+			for _, tracingEnabled := range []bool{false, true} {
+				dbFn(b, tracingEnabled, func(b *testing.B, db *sqlutils.SQLRunner) {
+					// Disable statement sampling to de-noise this benchmark.
+					db.Exec(b, "SET CLUSTER SETTING sql.txn_stats.sample_rate = 0.0")
+					b.Run(fmt.Sprintf("tracing=%s", fmt.Sprintf("%t", tracingEnabled)[:1]), func(b *testing.B) {
 						for _, runFn := range []func(*testing.B, *sqlutils.SQLRunner, int){
 							runBenchmarkScan1,
 							runBenchmarkInsert,
@@ -478,8 +513,8 @@ func BenchmarkTracing(b *testing.B) {
 							})
 						}
 					})
-				}
-			})
+				})
+			}
 		})
 	}
 }

pkg/sql/conn_executor.go

@@ -576,8 +576,9 @@ func (s *Server) newConnExecutor(
 		sessionData: sd,
 		dataMutator: sdMutator,
 		state: txnState{
-			mon:     txnMon,
-			connCtx: ctx,
+			mon:                          txnMon,
+			connCtx:                      ctx,
+			testingForceRealTracingSpans: s.cfg.TestingKnobs.ForceRealTracingSpans,
 		},
 		transitionCtx: transitionCtx{
 			db:           s.cfg.DB,

pkg/sql/exec_util.go

@@ -961,6 +961,10 @@ type ExecutorTestingKnobs struct {
 	// exact control of the redaction flags (and have each test set it as
 	// necessary).
 	DeterministicExplain bool
+
+	// ForceRealTracingSpans, if set, forces the use of real (i.e. not no-op)
+	// tracing spans for every statement.
+	ForceRealTracingSpans bool
 }
 
 // PGWireTestingKnobs contains knobs for the pgwire module.

pkg/sql/txn_state.go

@@ -106,6 +106,10 @@ type txnState struct {
 	// txnAbortCount is incremented whenever the state transitions to
 	// stateAborted.
 	txnAbortCount *metric.Counter
+
+	// testingForceRealTracingSpans is a test-only knob that forces the use of
+	// real (i.e. not no-op) tracing spans for every statement.
+	testingForceRealTracingSpans bool
 }
 
 // txnType represents the type of a SQL transaction.
@@ -160,7 +164,7 @@ func (ts *txnState) resetForNewSQLTxn(
 
 	var txnCtx context.Context
 	var sp *tracing.Span
-	if alreadyRecording {
+	if alreadyRecording || ts.testingForceRealTracingSpans {
 		// WithForceRealSpan is used to support the use of session tracing,
 		// which will start recording on this span.
 		txnCtx, sp = createRootOrChildSpan(connCtx, opName, tranCtx.tracer, tracing.WithForceRealSpan())

pkg/util/tracing/span.go

@@ -255,8 +255,7 @@ func (sm *SpanMeta) String() string {
 }
 
 // Structured is an opaque protobuf that can be attached to a trace via
-// `Span.RecordStructured`. This is the only kind of data a Span carries when
-// `trace.mode = background`.
+// `Span.RecordStructured`.
 type Structured interface {
 	protoutil.Message
 }