Skip to content

Commit

Permalink
tracing: elide tags from recording if not verbose
Browse files Browse the repository at this point in the history
This avoids some of the obviously problematic expensive stringifications
observed in #59379.

Release justification: low-risk performance optimization that unblocks sql stats.
Release note: None
  • Loading branch information
tbg committed Feb 25, 2021
1 parent 3d61fbf commit 95fc831
Show file tree
Hide file tree
Showing 3 changed files with 60 additions and 16 deletions.
39 changes: 23 additions & 16 deletions pkg/util/tracing/crdbspan.go
Original file line number Diff line number Diff line change
Expand Up @@ -278,20 +278,24 @@ func (s *crdbSpan) getRecordingLocked() tracingpb.RecordedSpan {
rs.Finished = true
}

wantTags := s.recordingType() == RecordingVerbose

addTag := func(k, v string) {
if rs.Tags == nil {
rs.Tags = make(map[string]string)
}
rs.Tags[k] = v
}

// When nobody is configured to see our spans, skip some allocations
// related to Span UX improvements.
if s.mu.duration == -1 {
addTag("_unfinished", "1")
}
if s.mu.recording.recordingType.load() == RecordingVerbose {
addTag("_verbose", "1")
if wantTags {
// When nobody is configured to see our spans, skip some allocations
// related to Span UX improvements.
if s.mu.duration == -1 {
addTag("_unfinished", "1")
}
if s.mu.recording.recordingType.load() == RecordingVerbose {
addTag("_verbose", "1")
}
}

if s.mu.stats != nil {
Expand Down Expand Up @@ -322,17 +326,20 @@ func (s *crdbSpan) getRecordingLocked() tracingpb.RecordedSpan {
rs.Baggage[k] = v
}
}
if s.logTags != nil {
setLogTags(s.logTags.Get(), func(remappedKey string, tag *logtags.Tag) {
addTag(remappedKey, tag.ValueStr())
})
}
if len(s.mu.tags) > 0 {
for k, v := range s.mu.tags {
// We encode the tag values as strings.
addTag(k, fmt.Sprint(v))
if wantTags {
if s.logTags != nil {
setLogTags(s.logTags.Get(), func(remappedKey string, tag *logtags.Tag) {
addTag(remappedKey, tag.ValueStr())
})
}
if len(s.mu.tags) > 0 {
for k, v := range s.mu.tags {
// We encode the tag values as strings.
addTag(k, fmt.Sprint(v))
}
}
}

rs.Logs = make([]tracingpb.LogRecord, len(s.mu.recording.recordedLogs))
for i, r := range s.mu.recording.recordedLogs {
rs.Logs[i].Time = r.Timestamp
Expand Down
4 changes: 4 additions & 0 deletions pkg/util/tracing/span.go
Original file line number Diff line number Diff line change
Expand Up @@ -90,6 +90,10 @@ func (sp *Span) Finish() {
// GetRecording retrieves the current recording, if the Span has recording
// enabled. This can be called while spans that are part of the recording are
// still open; it can run concurrently with operations on those spans.
//
// As a performance optimization, GetRecording does not return tags when the
// underlying Span is not verbose. Returning tags requires expensive
// stringification.
func (sp *Span) GetRecording() Recording {
// It's always valid to get the recording, even for a finished span.
return sp.i.GetRecording()
Expand Down
33 changes: 33 additions & 0 deletions pkg/util/tracing/span_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,9 @@ import (
"time"

"github.com/cockroachdb/errors"
"github.com/cockroachdb/logtags"
"github.com/gogo/protobuf/types"
"github.com/opentracing/opentracing-go"
"github.com/stretchr/testify/require"
"golang.org/x/net/trace"
"google.golang.org/grpc/metadata"
Expand Down Expand Up @@ -331,3 +333,34 @@ func TestSpan_UseAfterFinish(t *testing.T) {
})
}
}

type countingStringer int32

func (i *countingStringer) String() string {
*i++ // not for concurrent use
return fmt.Sprint(*i)
}

func TestSpan_GetRecordingTags(t *testing.T) {
// Verify that tags are omitted from GetRecording if the span is
// not verbose when the recording is pulled. See GetRecording for
// details.
tr := NewTracer()
var counter countingStringer
logTags := logtags.SingleTagBuffer("tagfoo", "tagbar")
sp := tr.StartSpan("root",
WithForceRealSpan(),
WithTags(opentracing.Tag{
Key: "foo1",
Value: &counter,
}),
WithLogTags(logTags),
)
defer sp.Finish()

require.False(t, sp.IsVerbose())
sp.SetTag("foo2", &counter)
rec := sp.GetRecording()
require.Empty(t, rec[0].Tags)
require.Zero(t, counter)
}

0 comments on commit 95fc831

Please sign in to comment.