1
0
mirror of https://github.com/open-telemetry/opentelemetry-go.git synced 2024-12-14 10:13:10 +02:00
opentelemetry-go/sdk/trace/span_processor_test.go

262 lines
7.1 KiB
Go
Raw Normal View History

// Copyright The OpenTelemetry Authors
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package trace_test
import (
"context"
"testing"
"go.opentelemetry.io/otel/attribute"
Add RO/RW span interfaces (#1360) * Store span data directly in the span - Nesting only some of a span's data in a `data` field (with the rest of the data living direclty in the `span` struct) is confusing. - export.SpanData is meant to be an immutable *snapshot* of a span, not the "authoritative" state of the span. - Refactor attributesMap.toSpanData into toKeyValue and make it return a []label.KeyValue which is clearer than modifying a struct passed to the function. - Read droppedCount from the attributesMap as a separate operation instead of setting it from within attributesMap.toSpanData. - Set a span's end time in the span itself rather than in the SpanData to allow reading the span's end time after a span has ended. - Set a span's end time as soon as possible within span.End so that we don't influence the span's end time with operations such as fetching span processors and generating span data. - Remove error handling for uninitialized spans. This check seems to be necessary only because we used to have an *export.SpanData field which could be nil. Now that we no longer have this field I think we can safely remove the check. The error isn't used anywhere else so remove it, too. * Store parent as trace.SpanContext The spec requires that the parent field of a Span be a Span, a SpanContext or null. Rather than extracting the parent's span ID from the trace.SpanContext which we get from the tracer, store the trace.SpanContext as is and explicitly extract the parent's span ID where necessary. * Add ReadOnlySpan interface Use this interface instead of export.SpanData in places where reading information from a span is necessary. Use export.SpanData only when exporting spans. * Add ReadWriteSpan interface Use this interface instead of export.SpanData in places where it is necessary to read information from a span and write to it at the same time. * Rename export.SpanData to SpanSnapshot SpanSnapshot represents the nature of this type as well as its intended use more accurately. Clarify the purpose of SpanSnapshot in the docs and emphasize what should and should not be done with it. * Rephrase attributesMap doc comment "refreshes" is wrong for plural ("updates"). * Refactor span.End() - Improve accuracy of span duration. Record span end time ASAP. We want to measure a user operation as accurately as possible, which means we want to mark the end time of a span as soon as possible after span.End() is called. Any operations we do inside span.End() before storing the end time affect the total duration of the span, and although these operations are rather fast at the moment they still seem to affect the duration of the span by "artificially" adding time between the start and end timestamps. This is relevant only in cases where the end time isn't explicitly specified. - Remove redundant idempotence check. Now that IsRecording() is based on the value of span.endTime, IsRecording() will always return false after span.End() had been called because span.endTime won't be zero. This means we no longer need span.endOnce. - Improve TestEndSpanTwice so that it also ensures subsequent calls to span.End() don't modify the span's end time. * Update changelog Co-authored-by: Tyler Yahn <codingalias@gmail.com> Co-authored-by: Tyler Yahn <MrAlias@users.noreply.github.com>
2020-12-11 07:15:44 +02:00
sdktrace "go.opentelemetry.io/otel/sdk/trace"
"go.opentelemetry.io/otel/trace"
)
type testSpanProcessor struct {
name string
Add RO/RW span interfaces (#1360) * Store span data directly in the span - Nesting only some of a span's data in a `data` field (with the rest of the data living direclty in the `span` struct) is confusing. - export.SpanData is meant to be an immutable *snapshot* of a span, not the "authoritative" state of the span. - Refactor attributesMap.toSpanData into toKeyValue and make it return a []label.KeyValue which is clearer than modifying a struct passed to the function. - Read droppedCount from the attributesMap as a separate operation instead of setting it from within attributesMap.toSpanData. - Set a span's end time in the span itself rather than in the SpanData to allow reading the span's end time after a span has ended. - Set a span's end time as soon as possible within span.End so that we don't influence the span's end time with operations such as fetching span processors and generating span data. - Remove error handling for uninitialized spans. This check seems to be necessary only because we used to have an *export.SpanData field which could be nil. Now that we no longer have this field I think we can safely remove the check. The error isn't used anywhere else so remove it, too. * Store parent as trace.SpanContext The spec requires that the parent field of a Span be a Span, a SpanContext or null. Rather than extracting the parent's span ID from the trace.SpanContext which we get from the tracer, store the trace.SpanContext as is and explicitly extract the parent's span ID where necessary. * Add ReadOnlySpan interface Use this interface instead of export.SpanData in places where reading information from a span is necessary. Use export.SpanData only when exporting spans. * Add ReadWriteSpan interface Use this interface instead of export.SpanData in places where it is necessary to read information from a span and write to it at the same time. * Rename export.SpanData to SpanSnapshot SpanSnapshot represents the nature of this type as well as its intended use more accurately. Clarify the purpose of SpanSnapshot in the docs and emphasize what should and should not be done with it. * Rephrase attributesMap doc comment "refreshes" is wrong for plural ("updates"). * Refactor span.End() - Improve accuracy of span duration. Record span end time ASAP. We want to measure a user operation as accurately as possible, which means we want to mark the end time of a span as soon as possible after span.End() is called. Any operations we do inside span.End() before storing the end time affect the total duration of the span, and although these operations are rather fast at the moment they still seem to affect the duration of the span by "artificially" adding time between the start and end timestamps. This is relevant only in cases where the end time isn't explicitly specified. - Remove redundant idempotence check. Now that IsRecording() is based on the value of span.endTime, IsRecording() will always return false after span.End() had been called because span.endTime won't be zero. This means we no longer need span.endOnce. - Improve TestEndSpanTwice so that it also ensures subsequent calls to span.End() don't modify the span's end time. * Update changelog Co-authored-by: Tyler Yahn <codingalias@gmail.com> Co-authored-by: Tyler Yahn <MrAlias@users.noreply.github.com>
2020-12-11 07:15:44 +02:00
spansStarted []sdktrace.ReadWriteSpan
spansEnded []sdktrace.ReadOnlySpan
shutdownCount int
}
Add RO/RW span interfaces (#1360) * Store span data directly in the span - Nesting only some of a span's data in a `data` field (with the rest of the data living direclty in the `span` struct) is confusing. - export.SpanData is meant to be an immutable *snapshot* of a span, not the "authoritative" state of the span. - Refactor attributesMap.toSpanData into toKeyValue and make it return a []label.KeyValue which is clearer than modifying a struct passed to the function. - Read droppedCount from the attributesMap as a separate operation instead of setting it from within attributesMap.toSpanData. - Set a span's end time in the span itself rather than in the SpanData to allow reading the span's end time after a span has ended. - Set a span's end time as soon as possible within span.End so that we don't influence the span's end time with operations such as fetching span processors and generating span data. - Remove error handling for uninitialized spans. This check seems to be necessary only because we used to have an *export.SpanData field which could be nil. Now that we no longer have this field I think we can safely remove the check. The error isn't used anywhere else so remove it, too. * Store parent as trace.SpanContext The spec requires that the parent field of a Span be a Span, a SpanContext or null. Rather than extracting the parent's span ID from the trace.SpanContext which we get from the tracer, store the trace.SpanContext as is and explicitly extract the parent's span ID where necessary. * Add ReadOnlySpan interface Use this interface instead of export.SpanData in places where reading information from a span is necessary. Use export.SpanData only when exporting spans. * Add ReadWriteSpan interface Use this interface instead of export.SpanData in places where it is necessary to read information from a span and write to it at the same time. * Rename export.SpanData to SpanSnapshot SpanSnapshot represents the nature of this type as well as its intended use more accurately. Clarify the purpose of SpanSnapshot in the docs and emphasize what should and should not be done with it. * Rephrase attributesMap doc comment "refreshes" is wrong for plural ("updates"). * Refactor span.End() - Improve accuracy of span duration. Record span end time ASAP. We want to measure a user operation as accurately as possible, which means we want to mark the end time of a span as soon as possible after span.End() is called. Any operations we do inside span.End() before storing the end time affect the total duration of the span, and although these operations are rather fast at the moment they still seem to affect the duration of the span by "artificially" adding time between the start and end timestamps. This is relevant only in cases where the end time isn't explicitly specified. - Remove redundant idempotence check. Now that IsRecording() is based on the value of span.endTime, IsRecording() will always return false after span.End() had been called because span.endTime won't be zero. This means we no longer need span.endOnce. - Improve TestEndSpanTwice so that it also ensures subsequent calls to span.End() don't modify the span's end time. * Update changelog Co-authored-by: Tyler Yahn <codingalias@gmail.com> Co-authored-by: Tyler Yahn <MrAlias@users.noreply.github.com>
2020-12-11 07:15:44 +02:00
func (t *testSpanProcessor) OnStart(parent context.Context, s sdktrace.ReadWriteSpan) {
psc := trace.RemoteSpanContextFromContext(parent)
kv := []attribute.KeyValue{
{
Key: "SpanProcessorName",
Value: attribute.StringValue(t.name),
},
// Store parent trace ID and span ID as attributes to be read later in
// tests so that we "do something" with the parent argument. Real
// SpanProcessor implementations will likely use the parent argument in
// a more meaningful way.
{
Key: "ParentTraceID",
Value: attribute.StringValue(psc.TraceID.String()),
},
{
Key: "ParentSpanID",
Value: attribute.StringValue(psc.SpanID.String()),
},
}
Add RO/RW span interfaces (#1360) * Store span data directly in the span - Nesting only some of a span's data in a `data` field (with the rest of the data living direclty in the `span` struct) is confusing. - export.SpanData is meant to be an immutable *snapshot* of a span, not the "authoritative" state of the span. - Refactor attributesMap.toSpanData into toKeyValue and make it return a []label.KeyValue which is clearer than modifying a struct passed to the function. - Read droppedCount from the attributesMap as a separate operation instead of setting it from within attributesMap.toSpanData. - Set a span's end time in the span itself rather than in the SpanData to allow reading the span's end time after a span has ended. - Set a span's end time as soon as possible within span.End so that we don't influence the span's end time with operations such as fetching span processors and generating span data. - Remove error handling for uninitialized spans. This check seems to be necessary only because we used to have an *export.SpanData field which could be nil. Now that we no longer have this field I think we can safely remove the check. The error isn't used anywhere else so remove it, too. * Store parent as trace.SpanContext The spec requires that the parent field of a Span be a Span, a SpanContext or null. Rather than extracting the parent's span ID from the trace.SpanContext which we get from the tracer, store the trace.SpanContext as is and explicitly extract the parent's span ID where necessary. * Add ReadOnlySpan interface Use this interface instead of export.SpanData in places where reading information from a span is necessary. Use export.SpanData only when exporting spans. * Add ReadWriteSpan interface Use this interface instead of export.SpanData in places where it is necessary to read information from a span and write to it at the same time. * Rename export.SpanData to SpanSnapshot SpanSnapshot represents the nature of this type as well as its intended use more accurately. Clarify the purpose of SpanSnapshot in the docs and emphasize what should and should not be done with it. * Rephrase attributesMap doc comment "refreshes" is wrong for plural ("updates"). * Refactor span.End() - Improve accuracy of span duration. Record span end time ASAP. We want to measure a user operation as accurately as possible, which means we want to mark the end time of a span as soon as possible after span.End() is called. Any operations we do inside span.End() before storing the end time affect the total duration of the span, and although these operations are rather fast at the moment they still seem to affect the duration of the span by "artificially" adding time between the start and end timestamps. This is relevant only in cases where the end time isn't explicitly specified. - Remove redundant idempotence check. Now that IsRecording() is based on the value of span.endTime, IsRecording() will always return false after span.End() had been called because span.endTime won't be zero. This means we no longer need span.endOnce. - Improve TestEndSpanTwice so that it also ensures subsequent calls to span.End() don't modify the span's end time. * Update changelog Co-authored-by: Tyler Yahn <codingalias@gmail.com> Co-authored-by: Tyler Yahn <MrAlias@users.noreply.github.com>
2020-12-11 07:15:44 +02:00
s.AddEvent("OnStart", trace.WithAttributes(kv...))
t.spansStarted = append(t.spansStarted, s)
}
Add RO/RW span interfaces (#1360) * Store span data directly in the span - Nesting only some of a span's data in a `data` field (with the rest of the data living direclty in the `span` struct) is confusing. - export.SpanData is meant to be an immutable *snapshot* of a span, not the "authoritative" state of the span. - Refactor attributesMap.toSpanData into toKeyValue and make it return a []label.KeyValue which is clearer than modifying a struct passed to the function. - Read droppedCount from the attributesMap as a separate operation instead of setting it from within attributesMap.toSpanData. - Set a span's end time in the span itself rather than in the SpanData to allow reading the span's end time after a span has ended. - Set a span's end time as soon as possible within span.End so that we don't influence the span's end time with operations such as fetching span processors and generating span data. - Remove error handling for uninitialized spans. This check seems to be necessary only because we used to have an *export.SpanData field which could be nil. Now that we no longer have this field I think we can safely remove the check. The error isn't used anywhere else so remove it, too. * Store parent as trace.SpanContext The spec requires that the parent field of a Span be a Span, a SpanContext or null. Rather than extracting the parent's span ID from the trace.SpanContext which we get from the tracer, store the trace.SpanContext as is and explicitly extract the parent's span ID where necessary. * Add ReadOnlySpan interface Use this interface instead of export.SpanData in places where reading information from a span is necessary. Use export.SpanData only when exporting spans. * Add ReadWriteSpan interface Use this interface instead of export.SpanData in places where it is necessary to read information from a span and write to it at the same time. * Rename export.SpanData to SpanSnapshot SpanSnapshot represents the nature of this type as well as its intended use more accurately. Clarify the purpose of SpanSnapshot in the docs and emphasize what should and should not be done with it. * Rephrase attributesMap doc comment "refreshes" is wrong for plural ("updates"). * Refactor span.End() - Improve accuracy of span duration. Record span end time ASAP. We want to measure a user operation as accurately as possible, which means we want to mark the end time of a span as soon as possible after span.End() is called. Any operations we do inside span.End() before storing the end time affect the total duration of the span, and although these operations are rather fast at the moment they still seem to affect the duration of the span by "artificially" adding time between the start and end timestamps. This is relevant only in cases where the end time isn't explicitly specified. - Remove redundant idempotence check. Now that IsRecording() is based on the value of span.endTime, IsRecording() will always return false after span.End() had been called because span.endTime won't be zero. This means we no longer need span.endOnce. - Improve TestEndSpanTwice so that it also ensures subsequent calls to span.End() don't modify the span's end time. * Update changelog Co-authored-by: Tyler Yahn <codingalias@gmail.com> Co-authored-by: Tyler Yahn <MrAlias@users.noreply.github.com>
2020-12-11 07:15:44 +02:00
func (t *testSpanProcessor) OnEnd(s sdktrace.ReadOnlySpan) {
t.spansEnded = append(t.spansEnded, s)
}
func (t *testSpanProcessor) Shutdown(_ context.Context) error {
t.shutdownCount++
return nil
}
func (t *testSpanProcessor) ForceFlush() {
}
func TestRegisterSpanProcessor(t *testing.T) {
name := "Register span processor before span starts"
tp := basicTracerProvider(t)
spNames := []string{"sp1", "sp2", "sp3"}
sps := NewNamedTestSpanProcessors(spNames)
for _, sp := range sps {
tp.RegisterSpanProcessor(sp)
}
tid, _ := trace.TraceIDFromHex("01020304050607080102040810203040")
sid, _ := trace.SpanIDFromHex("0102040810203040")
parent := trace.SpanContext{
TraceID: tid,
SpanID: sid,
}
ctx := trace.ContextWithRemoteSpanContext(context.Background(), parent)
tr := tp.Tracer("SpanProcessor")
_, span := tr.Start(ctx, "OnStart")
span.End()
wantCount := 1
for _, sp := range sps {
gotCount := len(sp.spansStarted)
if gotCount != wantCount {
t.Errorf("%s: started count: got %d, want %d\n", name, gotCount, wantCount)
}
gotCount = len(sp.spansEnded)
if gotCount != wantCount {
t.Errorf("%s: ended count: got %d, want %d\n", name, gotCount, wantCount)
}
c := 0
tidOK := false
sidOK := false
Add RO/RW span interfaces (#1360) * Store span data directly in the span - Nesting only some of a span's data in a `data` field (with the rest of the data living direclty in the `span` struct) is confusing. - export.SpanData is meant to be an immutable *snapshot* of a span, not the "authoritative" state of the span. - Refactor attributesMap.toSpanData into toKeyValue and make it return a []label.KeyValue which is clearer than modifying a struct passed to the function. - Read droppedCount from the attributesMap as a separate operation instead of setting it from within attributesMap.toSpanData. - Set a span's end time in the span itself rather than in the SpanData to allow reading the span's end time after a span has ended. - Set a span's end time as soon as possible within span.End so that we don't influence the span's end time with operations such as fetching span processors and generating span data. - Remove error handling for uninitialized spans. This check seems to be necessary only because we used to have an *export.SpanData field which could be nil. Now that we no longer have this field I think we can safely remove the check. The error isn't used anywhere else so remove it, too. * Store parent as trace.SpanContext The spec requires that the parent field of a Span be a Span, a SpanContext or null. Rather than extracting the parent's span ID from the trace.SpanContext which we get from the tracer, store the trace.SpanContext as is and explicitly extract the parent's span ID where necessary. * Add ReadOnlySpan interface Use this interface instead of export.SpanData in places where reading information from a span is necessary. Use export.SpanData only when exporting spans. * Add ReadWriteSpan interface Use this interface instead of export.SpanData in places where it is necessary to read information from a span and write to it at the same time. * Rename export.SpanData to SpanSnapshot SpanSnapshot represents the nature of this type as well as its intended use more accurately. Clarify the purpose of SpanSnapshot in the docs and emphasize what should and should not be done with it. * Rephrase attributesMap doc comment "refreshes" is wrong for plural ("updates"). * Refactor span.End() - Improve accuracy of span duration. Record span end time ASAP. We want to measure a user operation as accurately as possible, which means we want to mark the end time of a span as soon as possible after span.End() is called. Any operations we do inside span.End() before storing the end time affect the total duration of the span, and although these operations are rather fast at the moment they still seem to affect the duration of the span by "artificially" adding time between the start and end timestamps. This is relevant only in cases where the end time isn't explicitly specified. - Remove redundant idempotence check. Now that IsRecording() is based on the value of span.endTime, IsRecording() will always return false after span.End() had been called because span.endTime won't be zero. This means we no longer need span.endOnce. - Improve TestEndSpanTwice so that it also ensures subsequent calls to span.End() don't modify the span's end time. * Update changelog Co-authored-by: Tyler Yahn <codingalias@gmail.com> Co-authored-by: Tyler Yahn <MrAlias@users.noreply.github.com>
2020-12-11 07:15:44 +02:00
for _, e := range sp.spansStarted[0].Events() {
for _, kv := range e.Attributes {
switch kv.Key {
case "SpanProcessorName":
gotValue := kv.Value.AsString()
if gotValue != spNames[c] {
t.Errorf("%s: attributes: got %s, want %s\n", name, gotValue, spNames[c])
}
c++
case "ParentTraceID":
gotValue := kv.Value.AsString()
if gotValue != parent.TraceID.String() {
t.Errorf("%s: attributes: got %s, want %s\n", name, gotValue, parent.TraceID)
}
tidOK = true
case "ParentSpanID":
gotValue := kv.Value.AsString()
if gotValue != parent.SpanID.String() {
t.Errorf("%s: attributes: got %s, want %s\n", name, gotValue, parent.SpanID)
}
sidOK = true
default:
continue
}
}
}
if c != len(spNames) {
t.Errorf("%s: expected attributes(SpanProcessorName): got %d, want %d\n", name, c, len(spNames))
}
if !tidOK {
t.Errorf("%s: expected attributes(ParentTraceID)\n", name)
}
if !sidOK {
t.Errorf("%s: expected attributes(ParentSpanID)\n", name)
}
}
}
func TestUnregisterSpanProcessor(t *testing.T) {
name := "Start span after unregistering span processor"
tp := basicTracerProvider(t)
spNames := []string{"sp1", "sp2", "sp3"}
sps := NewNamedTestSpanProcessors(spNames)
for _, sp := range sps {
tp.RegisterSpanProcessor(sp)
}
tr := tp.Tracer("SpanProcessor")
_, span := tr.Start(context.Background(), "OnStart")
span.End()
for _, sp := range sps {
tp.UnregisterSpanProcessor(sp)
}
// start another span after unregistering span processor.
_, span = tr.Start(context.Background(), "Start span after unregister")
span.End()
for _, sp := range sps {
wantCount := 1
gotCount := len(sp.spansStarted)
if gotCount != wantCount {
t.Errorf("%s: started count: got %d, want %d\n", name, gotCount, wantCount)
}
gotCount = len(sp.spansEnded)
if gotCount != wantCount {
t.Errorf("%s: ended count: got %d, want %d\n", name, gotCount, wantCount)
}
}
}
func TestUnregisterSpanProcessorWhileSpanIsActive(t *testing.T) {
name := "Unregister span processor while span is active"
tp := basicTracerProvider(t)
sp := NewTestSpanProcessor("sp")
tp.RegisterSpanProcessor(sp)
tr := tp.Tracer("SpanProcessor")
_, span := tr.Start(context.Background(), "OnStart")
tp.UnregisterSpanProcessor(sp)
span.End()
wantCount := 1
gotCount := len(sp.spansStarted)
if gotCount != wantCount {
t.Errorf("%s: started count: got %d, want %d\n", name, gotCount, wantCount)
}
wantCount = 0
gotCount = len(sp.spansEnded)
if gotCount != wantCount {
t.Errorf("%s: ended count: got %d, want %d\n", name, gotCount, wantCount)
}
}
func TestSpanProcessorShutdown(t *testing.T) {
name := "Increment shutdown counter of a span processor"
tp := basicTracerProvider(t)
sp := NewTestSpanProcessor("sp")
if sp == nil {
t.Fatalf("Error creating new instance of TestSpanProcessor\n")
}
tp.RegisterSpanProcessor(sp)
wantCount := 1
err := sp.Shutdown(context.Background())
if err != nil {
t.Error("Error shutting the testSpanProcessor down\n")
}
gotCount := sp.shutdownCount
if wantCount != gotCount {
t.Errorf("%s: wrong counter: got %d, want %d\n", name, gotCount, wantCount)
}
}
func TestMultipleUnregisterSpanProcessorCalls(t *testing.T) {
name := "Increment shutdown counter after first UnregisterSpanProcessor call"
tp := basicTracerProvider(t)
sp := NewTestSpanProcessor("sp")
if sp == nil {
t.Fatalf("Error creating new instance of TestSpanProcessor\n")
}
wantCount := 1
tp.RegisterSpanProcessor(sp)
tp.UnregisterSpanProcessor(sp)
gotCount := sp.shutdownCount
if wantCount != gotCount {
t.Errorf("%s: wrong counter: got %d, want %d\n", name, gotCount, wantCount)
}
// Multiple UnregisterSpanProcessor should not trigger multiple Shutdown calls.
tp.UnregisterSpanProcessor(sp)
gotCount = sp.shutdownCount
if wantCount != gotCount {
t.Errorf("%s: wrong counter: got %d, want %d\n", name, gotCount, wantCount)
}
}
func NewTestSpanProcessor(name string) *testSpanProcessor {
return &testSpanProcessor{name: name}
}
func NewNamedTestSpanProcessors(names []string) []*testSpanProcessor {
tsp := []*testSpanProcessor{}
for _, n := range names {
tsp = append(tsp, NewTestSpanProcessor(n))
}
return tsp
}