From a6c3d2cb9211d86de5d43f7bb31a6cdf3c6e9379 Mon Sep 17 00:00:00 2001 From: Andrei Matei Date: Wed, 22 Sep 2021 18:30:07 -0400 Subject: [PATCH] util/tracing: optimize span tags and expand their collection This patch makes the collection of span tags generally allocation-free by storing the tags into memory pre-allocated in the span. In tandem with a previous commit which moved away from a generic (interface{}) interface for Span.SetTag(), this makes span collection very cheap. As such, this patch also re-enables the collection of tags for non-verbose (but also not no-op) spans. The collecting of tags on non-verbose spans was stopped in eba03c4243693df39c0152680c13c8d875428b27 because of these allocations, as well as the allocations performed by the variadic WithTags option for StartSpan(). I'm not re-introducing WithTags. The motivation for this change is that I want to make broader use of the open spans registry, and I want (non-verbose) spans in the registry to have their tags available for inspection. I'm also planning of introducing new tags for static info defining a span (e.g. the SQL query for spans representing query execution). Note that tags in non-verbose spans continue to not be included in Recordings (and hence not serialized-deserialized over the network). This was the case, and the patch does not change it. I've run BenchmarkTracing and it shows no change. Release note: None --- pkg/util/tracing/crdbspan.go | 31 ++++++++++++++----------------- pkg/util/tracing/span_test.go | 13 ++++++------- pkg/util/tracing/tracer.go | 12 ++++++------ 3 files changed, 26 insertions(+), 30 deletions(-) diff --git a/pkg/util/tracing/crdbspan.go b/pkg/util/tracing/crdbspan.go index 87a8c689be0..deaa06c9101 100644 --- a/pkg/util/tracing/crdbspan.go +++ b/pkg/util/tracing/crdbspan.go @@ -90,16 +90,16 @@ type crdbSpanMu struct { remoteSpans []tracingpb.RecordedSpan } + // The Span's associated baggage. + baggage map[string]string + // tags are only captured when recording. These are tags that have been // added to this Span, and will be appended to the tags in logTags when // someone needs to actually observe the total set of tags that is a part of // this Span. // TODO(radu): perhaps we want a recording to capture all the tags (even // those that were set before recording started)? - tags map[string]attribute.Value - - // The Span's associated baggage. - baggage map[string]string + tags []attribute.KeyValue } type childSpanRefs struct { @@ -274,15 +274,14 @@ func (s *crdbSpan) importRemoteSpans(remoteSpans []tracingpb.RecordedSpan) { } func (s *crdbSpan) setTagLocked(key string, value attribute.Value) { - if s.recordingType() != RecordingVerbose { - // Don't bother storing tags if we're unlikely to retrieve them. - return - } - - if s.mu.tags == nil { - s.mu.tags = make(map[string]attribute.Value) + k := attribute.Key(key) + for i := range s.mu.tags { + if s.mu.tags[i].Key == k { + s.mu.tags[i].Value = value + return + } } - s.mu.tags[key] = value + s.mu.tags = append(s.mu.tags, attribute.KeyValue{Key: k, Value: value}) } func (s *crdbSpan) record(msg redact.RedactableString) { @@ -459,11 +458,9 @@ func (s *crdbSpan) getRecordingLocked(wantTags bool) tracingpb.RecordedSpan { 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, v.Emit()) - } + for _, kv := range s.mu.tags { + // We encode the tag values as strings. + addTag(string(kv.Key), kv.Value.Emit()) } } diff --git a/pkg/util/tracing/span_test.go b/pkg/util/tracing/span_test.go index d442f5d31be..ab02661ca39 100644 --- a/pkg/util/tracing/span_test.go +++ b/pkg/util/tracing/span_test.go @@ -504,8 +504,8 @@ func (i *countingStringer) String() string { return fmt.Sprint(*i) } -// TestSpanTagsInRecordings verifies that tags are dropped if the span is -// not verbose. +// TestSpanTagsInRecordings verifies that tags added before a recording started +// are part of the recording. func TestSpanTagsInRecordings(t *testing.T) { tr := NewTracer() var counter countingStringer @@ -525,20 +525,19 @@ func TestSpanTagsInRecordings(t *testing.T) { // We didn't stringify the log tag. require.Zero(t, int(counter)) - // Verify that we didn't hold onto anything underneath. sp.SetVerbose(true) rec = sp.GetRecording() require.Len(t, rec, 1) - require.Len(t, rec[0].Tags, 4) // _unfinished:1 _verbose:1 tagfoo:tagbar foo1:1 + require.Len(t, rec[0].Tags, 5) // _unfinished:1 _verbose:1 tagfoo:tagbar foo1:1 foor2:bar2 _, ok := rec[0].Tags["foo2"] - require.False(t, ok) + require.True(t, ok) require.Equal(t, 1, int(counter)) - // Verify that subsequent tags are captured. + // Verify that subsequent tags are also captured. sp.SetTag("foo3", attribute.StringValue("bar3")) rec = sp.GetRecording() require.Len(t, rec, 1) - require.Len(t, rec[0].Tags, 5) + require.Len(t, rec[0].Tags, 6) _, ok = rec[0].Tags["foo3"] require.True(t, ok) require.Equal(t, 2, int(counter)) diff --git a/pkg/util/tracing/tracer.go b/pkg/util/tracing/tracer.go index 8e04f8e78b2..c6cf7e5ddf5 100644 --- a/pkg/util/tracing/tracer.go +++ b/pkg/util/tracing/tracer.go @@ -503,6 +503,8 @@ func (t *Tracer) startSpanGeneric( span Span crdbSpan crdbSpan octx optimizedContext + // tagsAlloc preallocates space for crdbSpan.mu.tags. + tagsAlloc [3]attribute.KeyValue }{} helper.crdbSpan = crdbSpan{ @@ -520,6 +522,10 @@ func (t *Tracer) startSpanGeneric( helper.crdbSpan.mu.operation = opName helper.crdbSpan.mu.recording.logs = newSizeLimitedBuffer(maxLogBytesPerSpan) helper.crdbSpan.mu.recording.structured = newSizeLimitedBuffer(maxStructuredBytesPerSpan) + helper.crdbSpan.mu.tags = helper.tagsAlloc[:0] + if opts.SpanKind != oteltrace.SpanKindUnspecified { + helper.crdbSpan.setTagLocked(spanKindTagKey, attribute.StringValue(opts.SpanKind.String())) + } helper.span.i = spanInner{ tracer: t, crdb: &helper.crdbSpan, @@ -555,12 +561,6 @@ func (t *Tracer) startSpanGeneric( s.i.crdb.enableRecording(opts.recordingType()) } - // Deal with opts.SpanKind. This needs to be done after we enable recording - // above because tags are dropped on the floor before recording is enabled. - if opts.SpanKind != oteltrace.SpanKindUnspecified { - helper.crdbSpan.setTagLocked(spanKindTagKey, attribute.StringValue(opts.SpanKind.String())) - } - // Copy baggage from parent. This similarly fans out over the various // spans contained in Span. //