sql: revive BenchmarkTracing

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

    $ 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/bench_test.go

@@ -437,12 +437,8 @@ 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.
+// 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)
@@ -456,15 +452,11 @@ func BenchmarkTracing(b *testing.B) {
 
 		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} {
+					// Disable statement sampling to de-noise this benchmark.
+					db.Exec(b, "SET CLUSTER SETTING sql.txn_stats.sample_rate = 0.0")
+					db.Exec(b, fmt.Sprintf("SET CLUSTER SETTING sql.trace.debug_force_real_spans.enabled = %t", tracingEnabled))
+					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,

pkg/sql/exec_util.go

@@ -190,6 +190,15 @@ var traceSessionEventLogEnabled = settings.RegisterBoolSetting(
 	false,
 ).WithPublic()
 
+// debugForceRealSpans can be used to force the use of real tracing spans for
+// every statement. It's used primarily to measure the tracing overhead in
+// BenchmarkTracing.
+var debugForceRealSpans = settings.RegisterBoolSetting(
+	"sql.trace.debug_force_real_spans.enabled",
+	"set to true to force the use of real tracing spans for every statement",
+	false,
+)
+
 // ReorderJoinsLimitClusterSettingName is the name of the cluster setting for
 // the maximum number of joins to reorder.
 const ReorderJoinsLimitClusterSettingName = "sql.defaults.reorder_joins_limit"

pkg/sql/txn_state.go

@@ -157,10 +157,11 @@ func (ts *txnState) resetForNewSQLTxn(
 	// (automatic or user-directed) retries. The span is closed by finishSQLTxn().
 	opName := sqlTxnName
 	alreadyRecording := tranCtx.sessionTracing.Enabled()
+	debugForceRealSpan := debugForceRealSpans.Get(&tranCtx.settings.SV)
 
 	var txnCtx context.Context
 	var sp *tracing.Span
-	if alreadyRecording {
+	if alreadyRecording || debugForceRealSpan {
 		// 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
 }