Skip to content

Commit

Permalink
tracing: add startSpanFast for optimized path when disabled
Browse files Browse the repository at this point in the history
This change attempts to reduce the impact of `StartSpanCtx` when
called with tracing disabled.

A new fast path is introduced via the `spanSpanFast` method which
avoids the more complex logic within `startSpanGeneric`.

Additionally, the regexp-based verbose tracing is modified to use an
atomic pointer instead of a mutex, and the `SpanOption` iterator is
modified to avoid extra copies.

Stats for the disabled tracing benchmark:

Before:
```
BenchmarkStartSpan/start_span:_1         	  100000	        29.30 ns/op	       0 B/op	       0 allocs/op
```

After:
```
BenchmarkStartSpan/start_span:_1         	  100000	        18.89 ns/op	       0 B/op	       0 allocs/op
```

Part of: cockroachdb#133307

Release note: None
  • Loading branch information
dhartunian committed Dec 6, 2024
1 parent b66cbef commit b685ba5
Show file tree
Hide file tree
Showing 2 changed files with 71 additions and 32 deletions.
62 changes: 43 additions & 19 deletions pkg/util/tracing/tracer.go
Original file line number Diff line number Diff line change
Expand Up @@ -313,12 +313,7 @@ type Tracer struct {
// explicitly requested.
_activeSpansRegistryEnabled int32 // accessed atomically

forceVerboseMu struct {
syncutil.RWMutex
// opNameRegexp is matched against during span initialization. If the span
// operation name matches, then the span is forced to a VERBOSE recording mode.
opNameRegexp *regexp.Regexp
}
opNameRegexp atomic.Pointer[regexp.Regexp]

// activeSpans is a map that references all non-Finish'ed local root spans,
// i.e. those for which no WithParent(<non-nil>) option was supplied.
Expand Down Expand Up @@ -774,17 +769,15 @@ func WithUseAfterFinishOpt(panicOnUseAfterFinish, debugUseAfterFinish bool) Trac
}

func (t *Tracer) setVerboseOpNameRegexp(s string) error {
t.forceVerboseMu.Lock()
defer t.forceVerboseMu.Unlock()
if s == "" {
t.forceVerboseMu.opNameRegexp = nil
t.opNameRegexp.Store(nil)
return nil
}
compiled, err := regexp.Compile(s)
if err != nil {
return err
}
t.forceVerboseMu.opNameRegexp = compiled
t.opNameRegexp.Store(compiled)
return nil
}

Expand Down Expand Up @@ -1078,14 +1071,14 @@ func (t *Tracer) StartSpanCtx(
// NB: apply takes and returns a value to avoid forcing
// `opts` on the heap here.
var opts spanOptions
for _, o := range os {
if o == nil {
for i := range os {
if os[i] == nil {
continue
}
opts = o.apply(opts)
opts = os[i].apply(opts)
}

return t.startSpanGeneric(ctx, operationName, opts)
return t.startSpanFast(ctx, operationName, opts)
}

// AlwaysTrace returns true if operations should be traced regardless of the
Expand All @@ -1099,12 +1092,43 @@ func (t *Tracer) AlwaysTrace() bool {
}

func (t *Tracer) forceOpNameVerbose(opName string) bool {
t.forceVerboseMu.RLock()
defer t.forceVerboseMu.RUnlock()
if t.forceVerboseMu.opNameRegexp == nil {
return false
if r := t.opNameRegexp.Load(); r != nil {
return r.MatchString(opName)
}
return false
}

func (t *Tracer) startSpanFast(
ctx context.Context, opName string, opts spanOptions,
) (context.Context, *Span) {
if opts.RefType != childOfRef && opts.RefType != followsFromRef {
panic(errors.AssertionFailedf("unexpected RefType %v", opts.RefType))
}

// This is a fast path for the common case where there's no parent
// span. This contains duplicated logic from
// `(*spanOptions).recordingType()`. Specifically, we are aiming to
// avoid creating local copies of `opts.Parent` and
// `opts.RemoteParent` hence conditional logic is being inlined and
// checked locally.
if opts.Parent.Span == nil && opts.RemoteParent.Empty() {
var recordingType tracingpb.RecordingType

if opts.recordingTypeExplicit {
recordingType = opts.recordingTypeOpt
}

if recordingType < opts.minRecordingTypeOpt {
recordingType = opts.minRecordingTypeOpt
}

shouldBeNoopSpan := !(t.AlwaysTrace() || opts.ForceRealSpan || recordingType != tracingpb.RecordingOff)
forceVerbose := t.forceOpNameVerbose(opName)
if shouldBeNoopSpan && !forceVerbose && !opts.Sterile {
return maybeWrapCtx(ctx, t.noopSpan)
}
}
return t.forceVerboseMu.opNameRegexp.MatchString(opName)
return t.startSpanGeneric(ctx, opName, opts)
}

// startSpanGeneric is the implementation of StartSpanCtx and StartSpan. In
Expand Down
41 changes: 28 additions & 13 deletions pkg/util/tracing/tracer_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -1070,22 +1070,37 @@ func TestTracerStackHistory(t *testing.T) {
}

func BenchmarkStartSpan(b *testing.B) {
tr := NewTracerWithOpt(context.Background(), WithTracingMode(TracingModeActiveSpansRegistry))
require.True(b, tr.AlwaysTrace())
for i := 0; i < b.N; i++ {
tr.StartSpan("opName")
for _, mode := range []TracingMode{TracingModeOnDemand, TracingModeActiveSpansRegistry} {
b.Run(fmt.Sprintf("start span: %d", mode), func(b *testing.B) {
tr := NewTracerWithOpt(context.Background(), WithTracingMode(mode))
if mode == TracingModeActiveSpansRegistry {
require.True(b, tr.AlwaysTrace())
}
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
tr.StartSpan("opName")
}
})
b.ReportAllocs()
})
}
b.ReportAllocs()
}

func BenchmarkStartSpan_OpNameRegexp(b *testing.B) {
tr := NewTracerWithOpt(context.Background(), WithTracingMode(TracingModeActiveSpansRegistry))
require.True(b, tr.AlwaysTrace())
// Set some arbitrary regex. In our benchmark, we'll always match, but only the
// final clause in the regex.
require.NoError(b, tr.setVerboseOpNameRegexp("op1|op2|op3|^op[a-zA-Z]+"))
for i := 0; i < b.N; i++ {
tr.StartSpan("opAB")
for _, mode := range []TracingMode{TracingModeOnDemand, TracingModeActiveSpansRegistry} {
b.Run(fmt.Sprintf("start span with regexp: %d", mode), func(b *testing.B) {
tr := NewTracerWithOpt(context.Background(), WithTracingMode(mode))
require.NoError(b, tr.setVerboseOpNameRegexp("op1|op2|op3|^op[a-zA-Z]+"))

if mode == TracingModeActiveSpansRegistry {
require.True(b, tr.AlwaysTrace())
}
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
tr.StartSpan("opAB")
}
})
b.ReportAllocs()
})
}
b.ReportAllocs()
}

0 comments on commit b685ba5

Please sign in to comment.