tracing: set redactability on individual spans (and their children)

For redaction of statement diagnostics bundles we need the ability to
redact traces of query execution. The general ability to redact traces
was added in cockroachdb#70562 and cockroachdb#73405, but due to performance impact,
fine-grained redaction was turned off by default and redactability was
made configurable per tracer.

When tracing query execution for a redacted statement bundle, we want
fine-grained redaction for a specific span (and its children) regardless
of its tracer's redactability. This change addresses this by plumbing
through a flag to set redactability on individual spans, which is
inherited by child spans.

(I considered making this another recording mode instead of a separate
field, but redactability seems like an orthogonal concern to verbose or
structured recording mode. Plus we may want to remove this flag one day
if we enable fine-grained redaction for all traces, and that will be
easier with it as a separate field.)

Epic: CRDB-19756

Release note: None

pkg/util/tracing/BUILD.bazel

@@ -84,6 +84,7 @@ go_test(
  "//pkg/util/tracing/tracingpb",
  "@com_github_cockroachdb_errors//:errors",
  "@com_github_cockroachdb_logtags//:logtags",
+ "@com_github_cockroachdb_redact//:redact",
  "@com_github_gogo_protobuf//types",
  "@com_github_stretchr_testify//require",
  "@io_opentelemetry_go_otel//attribute",

pkg/util/tracing/crdbspan.go

@@ -1149,6 +1149,9 @@ func (s *crdbSpan) getRecordingNoChildrenLocked(
  if s.recordingType() == tracingpb.RecordingVerbose {
  rs.EnsureTagGroup(tracingpb.AnonymousTagGroupName).AddTag("_verbose", "1")
  }
+ if s.sp.i.redactable || s.tracer.Redactable() {
+ rs.EnsureTagGroup(tracingpb.AnonymousTagGroupName).AddTag("_redactable", "")
+ }
  if s.mu.recording.droppedLogs {
  rs.EnsureTagGroup(tracingpb.AnonymousTagGroupName).AddTag("_dropped_logs", "")
  }

pkg/util/tracing/span.go

@@ -229,13 +229,14 @@ func (sp *Span) String() string {
  return sp.OperationName()
 }
 
-// Redactable returns true if this Span's tracer is marked redactable
+// Redactable returns true if this span is redactable or this span's tracer is
+// redactable.
 func (sp *Span) Redactable() bool {
  if sp == nil || sp.i.isNoop() {
  return false
  }
  sp.detectUseAfterFinish()
- return sp.Tracer().Redactable()
+ return sp.i.redactable || sp.Tracer().Redactable()
 }
 
 // Finish marks the Span as completed. It is illegal to use a Span after calling
@@ -578,6 +579,7 @@ func (sp *Span) reset(
  otelSpan oteltrace.Span,
  netTr trace.Trace,
  sterile bool,
+ redactable bool,
 ) {
  if sp.i.crdb == nil {
  // We assume that spans being reset have come from the sync.Pool.
@@ -620,11 +622,12 @@ func (sp *Span) reset(
 
  c := sp.i.crdb
  sp.i = spanInner{
- tracer: sp.i.tracer,
- crdb: c,
- otelSpan: otelSpan,
- netTr: netTr,
- sterile: sterile,
+ tracer: sp.i.tracer,
+ crdb: c,
+ otelSpan: otelSpan,
+ netTr: netTr,
+ sterile: sterile,
+ redactable: redactable,
  }
 
  c.traceID = traceID
@@ -849,6 +852,11 @@ type SpanMeta struct {
  // any info about the span in order to not have a child be created on the
  // other side. Similarly, ExtractMetaFrom does not deserialize this field.
  sterile bool
+
+ // redactable is set if calls to Record and Recordf for this span (and child
+ // spans) should use fine-grained redaction regardless of whether the tracer
+ // is redactable.
+ redactable bool
 }
 
 // Empty returns whether or not the SpanMeta is a zero value.
@@ -874,6 +882,7 @@ func (sm SpanMeta) ToProto() *tracingpb.TraceInfo {
  TraceID: sm.traceID,
  ParentSpanID: sm.spanID,
  RecordingMode: sm.recordingType.ToProto(),
+ Redactable: sm.redactable,
  }
  if sm.otelCtx.HasTraceID() {
  var traceID [16]byte = sm.otelCtx.TraceID()
@@ -899,10 +908,11 @@ func SpanMetaFromProto(info tracingpb.TraceInfo) SpanMeta {
  }
 
  sm := SpanMeta{
- traceID: info.TraceID,
- spanID: info.ParentSpanID,
- otelCtx: otelCtx,
- sterile: false,
+ traceID: info.TraceID,
+ spanID: info.ParentSpanID,
+ otelCtx: otelCtx,
+ sterile: false,
+ redactable: info.Redactable,
  }
  switch info.RecordingMode {
  case tracingpb.RecordingMode_OFF:

pkg/util/tracing/span_inner.go

@@ -43,6 +43,11 @@ type spanInner struct {
  // a root span. This is useful for span corresponding to long-running
  // operations that don't want to be associated with derived operations.
  sterile bool
+
+ // redactable is set if calls to Record and Recordf for this span (and child
+ // spans) should use fine-grained redaction regardless of whether the tracer
+ // is redactable.
+ redactable bool
 }
 
 func (s *spanInner) TraceID() tracingpb.TraceID {
@@ -202,7 +207,8 @@ func (s *spanInner) Meta() SpanMeta {
  spanID == 0 &&
  !otelCtx.TraceID().IsValid() &&
  recordingType == 0 &&
- !sterile {
+ !sterile &&
+ !s.redactable {
  return SpanMeta{}
  }
  return SpanMeta{
@@ -211,6 +217,7 @@ func (s *spanInner) Meta() SpanMeta {
  otelCtx: otelCtx,
  recordingType: recordingType,
  sterile: sterile,
+ redactable: s.redactable,
  }
 }
 
@@ -284,7 +291,7 @@ func (s *spanInner) Recordf(format string, args ...interface{}) {
  return
  }
  var str redact.RedactableString
- if s.Tracer().Redactable() {
+ if s.redactable || s.Tracer().Redactable() {
  str = redact.Sprintf(format, args...)
  } else {
  // `fmt.Sprintf` when called on a logEntry will use the faster

pkg/util/tracing/span_options.go

@@ -75,6 +75,7 @@ type spanOptions struct {
  ForceRealSpan bool // see WithForceRealSpan
  SpanKind oteltrace.SpanKind // see WithSpanKind
  Sterile bool // see WithSterile
+ Redactable bool // see WithRedactable
  EventListeners []EventListener // see WithEventListeners
 
  // recordingTypeExplicit is set if the WithRecording() option was used. In
@@ -116,6 +117,14 @@ func (opts *spanOptions) recordingType() tracingpb.RecordingType {
  return recordingType
 }
 
+func (opts *spanOptions) redactable() bool {
+ redactable := opts.Redactable
+ if !opts.Parent.empty() && opts.Parent.i.redactable {
+ redactable = true
+ }
+ return redactable
+}
+
 // otelContext returns information about the OpenTelemetry parent span. If there
 // is a local parent with an otel Span, that Span is returned. If there is a
 // RemoteParent, a SpanContext is returned. If there's no OpenTelemetry parent,
@@ -442,6 +451,20 @@ func (w withSterileOption) apply(opts spanOptions) spanOptions {
  return opts
 }
 
+type withRedactableOption struct{}
+
+// WithRedactable configures the span (and its children) to use fine-grained
+// redaction for all calls to Record and Recordf, regardless of whether the
+// span's tracer is redactable.
+func WithRedactable() SpanOption {
+ return withRedactableOption{}
+}
+
+func (w withRedactableOption) apply(opts spanOptions) spanOptions {
+ opts.Redactable = true
+ return opts
+}
+
 type eventListenersOption []EventListener
 
 var _ SpanOption = eventListenersOption{}

pkg/util/tracing/test_utils.go

@@ -174,6 +174,14 @@ func CheckRecordedSpans(rec tracingpb.Recording, expected string) error {
 // t.Fatal(err)
 // }
 func CheckRecording(rec tracingpb.Recording, expected string) error {
+ return checkRecording(rec, expected, false /* redact */)
+}
+
+func CheckRedactedRecording(rec tracingpb.Recording, expected string) error {
+ return checkRecording(rec, expected, true /* redact */)
+}
+
+func checkRecording(rec tracingpb.Recording, expected string, redact bool) error {
  normalize := func(rec string) string {
  // normalize the string form of a recording for ease of comparison.
  //
@@ -231,8 +239,14 @@ func CheckRecording(rec tracingpb.Recording, expected string) error {
  sortChildrenMetadataByName(rec[i].ChildrenMetadata)
  }
 
+ var got string
+ if redact {
+ got = string(rec.Redact())
+ } else {
+ got = rec.String()
+ }
  exp := normalize(expected)
- got := normalize(rec.String())
+ got = normalize(got)
  if got != exp {
  diff := difflib.UnifiedDiff{
  A: difflib.SplitLines(exp),

pkg/util/tracing/tracer.go

@@ -979,6 +979,7 @@ func (t *Tracer) newSpan(
  otelSpan oteltrace.Span,
  netTr trace.Trace,
  sterile bool,
+ redactable bool,
 ) *Span {
  if t.testing.MaintainAllocationCounters {
  atomic.AddInt32(&t.spansCreated, 1)
@@ -987,7 +988,7 @@ func (t *Tracer) newSpan(
  h.span.reset(
  traceID, spanID, operation, goroutineID,
  startTime, logTags, eventListeners, kind,
- otelSpan, netTr, sterile)
+ otelSpan, netTr, sterile, redactable)
  return &h.span
 }
 
@@ -1190,7 +1191,7 @@ child operation: %s, tracer created at:
  s := t.newSpan(
  traceID, spanID, opName, uint64(goid.Get()),
  startTime, opts.LogTags, opts.EventListeners, opts.SpanKind,
- otelSpan, netTr, opts.Sterile)
+ otelSpan, netTr, opts.Sterile, opts.redactable())
 
  s.i.crdb.SetRecordingType(opts.recordingType())
  s.i.crdb.parentSpanID = opts.parentSpanID()

pkg/util/tracing/tracer_test.go

@@ -23,6 +23,7 @@ import (
  "github.com/cockroachdb/cockroach/pkg/util/iterutil"
  "github.com/cockroachdb/cockroach/pkg/util/tracing/tracingpb"
  "github.com/cockroachdb/logtags"
+ "github.com/cockroachdb/redact"
  "github.com/gogo/protobuf/types"
  "github.com/stretchr/testify/require"
  "go.opentelemetry.io/otel/attribute"
@@ -262,6 +263,56 @@ func TestSterileSpan(t *testing.T) {
  require.Len(t, carrier.MD, 0)
 }
 
+func TestRedactableSpan(t *testing.T) {
+ tr := NewTracerWithOpt(context.Background(), WithTracingMode(TracingModeActiveSpansRegistry))
+
+ // Check that a span that was not configured to use fine-grained redaction
+ // does not.
+ s1 := tr.StartSpan("non-redactable", WithRecording(tracingpb.RecordingVerbose))
+ require.False(t, s1.Redactable())
+ s1.Recordf("s1: %s %s", redact.Safe("safe"), redact.Unsafe("unsafe"))
+
+ // Check that a span configured to use fine-grained redaction does, and its
+ // children do, too.
+ s2 := tr.StartSpan("redactable", WithParent(s1), WithRedactable())
+ require.True(t, s2.Redactable())
+ s2.Recordf("s2: %s %s", redact.Safe("safe"), redact.Unsafe("unsafe"))
+
+ s3 := tr.StartSpan("redactable-child", WithParent(s2))
+ require.True(t, s3.Redactable())
+ s3.Recordf("s3: %s %s", redact.Safe("safe"), redact.Unsafe("unsafe"))
+
+ // Check that a sterile redactable span does not produce a redactable child.
+ s4 := tr.StartSpan("sterile-redactable-child", WithParent(s3), WithSterile())
+ require.True(t, s4.Redactable())
+ s4.Recordf("s4: %s %s", redact.Safe("safe"), redact.Unsafe("unsafe"))
+
+ s5 := tr.StartSpan("non-redactable-child", WithParent(s4))
+ require.False(t, s5.Redactable())
+ s5.Recordf("s5: %s %s", redact.Safe("safe"), redact.Unsafe("unsafe"))
+
+ s5.Finish()
+ s4.Finish()
+ s3.Finish()
+ s2.Finish()
+ require.NoError(t, CheckRedactedRecording(s1.FinishAndGetRecording(tracingpb.RecordingVerbose), `
+ === operation:non-redactable _verbose:1
+ [sterile-redactable-child]
+ [redactable-child]
+ [redactable]
+ event:‹×›
+ === operation:redactable _verbose:1 _redactable:
+ [sterile-redactable-child]
+ [redactable-child]
+ event:s2: safe ‹×›
+ === operation:redactable-child _verbose:1 _redactable:
+ [sterile-redactable-child]
+ event:s3: safe ‹×›
+ === operation:sterile-redactable-child _verbose:1 _redactable:
+ event:s4: safe ‹×›
+ `))
+}
+
 func TestTracerInjectExtractNoop(t *testing.T) {
  tr := NewTracerWithOpt(context.Background(), WithTracingMode(TracingModeOnDemand))
  tr2 := NewTracerWithOpt(context.Background(), WithTracingMode(TracingModeOnDemand))

pkg/util/tracing/tracingpb/recorded_span.go

@@ -196,5 +196,5 @@ func (m OperationMetadata) SafeFormat(s redact.SafePrinter, _ rune) {
  if m.ContainsUnfinished {
  s.Printf(", unfinished")
  }
- s.Print("}")
+ s.Printf("}")
 }

pkg/util/tracing/tracingpb/recording.go

@@ -140,6 +140,14 @@ type logRecord struct {
 // TODO(andrei): this should be unified with
 // SessionTracing.generateSessionTraceVTable().
 func (r Recording) String() string {
+ return r.format(false /* redact */)
+}
+
+func (r Recording) Redact() redact.RedactableString {
+ return redact.RedactableString(r.format(true /* redact */))
+}
+
+func (r Recording) format(redact bool) string {
  if len(r) == 0 {
  return "<empty recording>"
  }
@@ -152,7 +160,13 @@ func (r Recording) String() string {
  1000*entry.Timestamp.Sub(start).Seconds(),
  1000*entry.timeSincePrev.Seconds(),
  strings.Repeat(" ", entry.depth+1))
- fmt.Fprint(&buf, entry.Msg.StripMarkers())
+ var msg string
+ if redact {
+ msg = string(entry.Msg.Redact())
+ } else {
+ msg = entry.Msg.StripMarkers()
+ }
+ fmt.Fprint(&buf, msg)
  buf.WriteByte('\n')
  }
  }
@@ -290,7 +304,7 @@ func (r Recording) visitSpan(sp RecordedSpan, depth int) []traceLogData {
  })
  for _, c := range childrenMetadata {
  var sb redact.StringBuilder
- sb.Printf("[%s: %s]", redact.SafeString(c.Operation), c.Metadata.String())
+ sb.Printf("[%s: %v]", redact.SafeString(c.Operation), c.Metadata)
  ownLogs = append(ownLogs, conv(sb.RedactableString(), sp.StartTime, time.Time{}))
  }
 

pkg/util/tracing/tracingpb/tracing.proto

@@ -43,5 +43,6 @@ message TraceInfo {
  }
 
  OtelInfo otel = 4;
-}
 
+ bool redactable = 5;
+}