From d9d4c0502c43073c2c283c3cc465c0b7f23712bf Mon Sep 17 00:00:00 2001 From: Julio Guerra Date: Thu, 27 Oct 2022 17:56:00 +0200 Subject: [PATCH] Revert "ddtrace/tracer: removed dependency between discovery flag and single span sampling" This reverts commit 7748843376acdfdd78926df17eb52a3a8f81c28e. --- ddtrace/tracer/rules_sampler.go | 2 +- ddtrace/tracer/sampler_test.go | 41 +----- ddtrace/tracer/spancontext.go | 2 +- ddtrace/tracer/time.go | 7 +- ddtrace/tracer/time_windows.go | 22 ++-- ddtrace/tracer/tracer.go | 13 +- ddtrace/tracer/tracer_test.go | 216 +------------------------------- 7 files changed, 22 insertions(+), 281 deletions(-) diff --git a/ddtrace/tracer/rules_sampler.go b/ddtrace/tracer/rules_sampler.go index 1e67d4a46c..b7ac1daeae 100644 --- a/ddtrace/tracer/rules_sampler.go +++ b/ddtrace/tracer/rules_sampler.go @@ -360,7 +360,7 @@ func (rs *singleSpanRulesSampler) apply(span *span) bool { } var sampled bool if rule.limiter != nil { - sampled, rate = rule.limiter.allowOne(nowTime()) + sampled, rate = rule.limiter.allowOne(time.Now()) if !sampled { return false } diff --git a/ddtrace/tracer/sampler_test.go b/ddtrace/tracer/sampler_test.go index 4793622121..1aacd0d2e5 100644 --- a/ddtrace/tracer/sampler_test.go +++ b/ddtrace/tracer/sampler_test.go @@ -355,6 +355,7 @@ func TestRulesSampler(t *testing.T) { makeSpan := func(op string, svc string) *span { return newSpan(op, svc, "", 0, 0, 0) } + t.Run("no-rules", func(t *testing.T) { assert := assert.New(t) rs := newRulesSampler(nil, nil) @@ -448,46 +449,6 @@ func TestRulesSampler(t *testing.T) { } }) - t.Run("matching-span-rules", func(t *testing.T) { - defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - for _, tt := range []struct { - rules string - spanSrv string - spanName string - }{ - { - rules: `[{"name": "abcd?", "sample_rate": 1.0, "max_per_second":100}]`, - spanSrv: "test-service", - spanName: "abcde", - }, - { - rules: `[{"service": "*abcd","max_per_second":100, "sample_rate": 1.0}]`, - spanSrv: "xyzabcd", - spanName: "abcde", - }, - { - rules: `[{"service": "?*", "sample_rate": 1.0, "max_per_second":100}]`, - spanSrv: "test-service", - spanName: "abcde", - }, - } { - t.Run("", func(t *testing.T) { - os.Setenv("DD_SPAN_SAMPLING_RULES", tt.rules) - _, rules, _ := samplingRulesFromEnv() - - assert := assert.New(t) - rs := newRulesSampler(nil, rules) - - span := makeFinishedSpan(tt.spanName, tt.spanSrv) - result := rs.SampleSpan(span) - assert.True(result) - assert.Contains(span.Metrics, keySpanSamplingMechanism) - assert.Contains(span.Metrics, keySingleSpanSamplingRuleRate) - assert.Contains(span.Metrics, keySingleSpanSamplingMPS) - }) - } - }) - t.Run("not-matching-span-rules-from-env", func(t *testing.T) { defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") for _, tt := range []struct { diff --git a/ddtrace/tracer/spancontext.go b/ddtrace/tracer/spancontext.go index 65627b882a..59f24c82cd 100644 --- a/ddtrace/tracer/spancontext.go +++ b/ddtrace/tracer/spancontext.go @@ -341,6 +341,6 @@ func (t *trace) finishedOne(s *span) { atomic.AddUint32(&tr.spansFinished, uint32(len(t.spans))) tr.pushTrace(&finishedTrace{ spans: t.spans, - willSend: decisionKeep == samplingDecision(atomic.LoadUint32((*uint32)(&t.samplingDecision))), + decision: samplingDecision(atomic.LoadUint32((*uint32)(&t.samplingDecision))), }) } diff --git a/ddtrace/tracer/time.go b/ddtrace/tracer/time.go index 70f44c6bda..86ac9d1253 100644 --- a/ddtrace/tracer/time.go +++ b/ddtrace/tracer/time.go @@ -10,8 +10,7 @@ package tracer import "time" -// nowTime returns the current time, as computed by Time.Now(). -var nowTime func() time.Time = func() time.Time { return time.Now() } - // now returns the current UNIX time in nanoseconds, as computed by Time.UnixNano(). -var now func() int64 = func() int64 { return time.Now().UnixNano() } +func now() int64 { + return time.Now().UnixNano() +} diff --git a/ddtrace/tracer/time_windows.go b/ddtrace/tracer/time_windows.go index f1ecd4f903..0eaa37e85d 100644 --- a/ddtrace/tracer/time_windows.go +++ b/ddtrace/tracer/time_windows.go @@ -26,23 +26,15 @@ func lowPrecisionNow() int64 { return time.Now().UnixNano() } -// We use this method of initializing now over an init function due to dependency issues. The init -// function may run after other declarations, such as that in payload_test:19, which results in a -// nil dereference panic. -var now func() int64 = func() func() int64 { - if err := windows.LoadGetSystemTimePreciseAsFileTime(); err != nil { - log.Warn("Unable to load high precison timer, defaulting to time.Now()") - return lowPrecisionNow - } else { - return highPrecisionNow - } -}() +var now func() int64 -var nowTime func() time.Time = func() func() time.Time { +// If GetSystemTimePreciseAsFileTime is not available we default to the less +// precise implementation based on time.Now() +func init() { if err := windows.LoadGetSystemTimePreciseAsFileTime(); err != nil { log.Warn("Unable to load high precison timer, defaulting to time.Now()") - return func() time.Time { return time.Unix(0, lowPrecisionNow()) } + now = lowPrecisionNow } else { - return func() time.Time { return time.Unix(0, highPrecisionNow()) } + now = highPrecisionNow } -}() +} diff --git a/ddtrace/tracer/tracer.go b/ddtrace/tracer/tracer.go index 958f9b33b0..1512d0f5c9 100644 --- a/ddtrace/tracer/tracer.go +++ b/ddtrace/tracer/tracer.go @@ -323,16 +323,13 @@ func (t *tracer) worker(tick <-chan time.Time) { // finishedTrace holds information about a trace that has finished, including its spans. type finishedTrace struct { spans []*span - willSend bool // willSend indicates whether the trace will be sent to the agent. + decision samplingDecision } // sampleFinishedTrace applies single-span sampling to the provided trace, which is considered to be finished. func (t *tracer) sampleFinishedTrace(info *finishedTrace) { - if len(info.spans) > 0 { - if p, ok := info.spans[0].context.samplingPriority(); ok && p > 0 { - // The trace is kept, no need to run single span sampling rules. - return - } + if info.decision == decisionKeep { + return } var kept []*span if t.rulesSampling.HasSpanRules() { @@ -351,9 +348,7 @@ func (t *tracer) sampleFinishedTrace(info *finishedTrace) { atomic.AddUint32(&t.droppedP0Traces, 1) } atomic.AddUint32(&t.droppedP0Spans, uint32(len(info.spans)-len(kept))) - if !info.willSend { - info.spans = kept - } + info.spans = kept } func (t *tracer) pushTrace(trace *finishedTrace) { diff --git a/ddtrace/tracer/tracer_test.go b/ddtrace/tracer/tracer_test.go index 350c07a938..3b3b002b74 100644 --- a/ddtrace/tracer/tracer_test.go +++ b/ddtrace/tracer/tracer_test.go @@ -9,7 +9,6 @@ import ( "context" "encoding/base64" "errors" - "fmt" "io" "net/http" "net/http/httptest" @@ -285,7 +284,6 @@ func TestTracerStartSpan(t *testing.T) { } func TestSamplingDecision(t *testing.T) { - t.Run("sampled", func(t *testing.T) { tracer, _, _, stop := startTestTracer(t) defer stop() @@ -359,6 +357,7 @@ func TestSamplingDecision(t *testing.T) { assert.Equal(t, uint32(2), tracer.droppedP0Spans) }() defer stop() + tracer.config.agent.DropP0s = true tracer.config.sampler = NewRateSampler(0) tracer.prioritySampling.defaultRate = 0 tracer.config.serviceName = "test_service" @@ -374,17 +373,10 @@ func TestSamplingDecision(t *testing.T) { assert.Equal(t, decisionDrop, span.context.trace.samplingDecision) }) - t.Run("client_dropped_with_single_spans:stats_enabled", func(t *testing.T) { + t.Run("client_dropped_with_single_spans", func(t *testing.T) { os.Setenv("DD_SPAN_SAMPLING_RULES", `[{"service": "test_*","name":"*_1", "sample_rate": 1.0, "max_per_second": 15.0}]`) defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - // Stats are enabled, rules are available. Trace sample rate equals 0. - // Span sample rate equals 1. The trace should be dropped. One single span is extracted. tracer, _, _, stop := startTestTracer(t) - defer func() { - // Must check these after tracer is stopped to avoid flakiness - assert.Equal(t, uint32(0), tracer.droppedP0Traces) - assert.Equal(t, uint32(1), tracer.droppedP0Spans) - }() defer stop() tracer.config.agent.DropP0s = true tracer.config.featureFlags = make(map[string]struct{}) @@ -396,6 +388,7 @@ func TestSamplingDecision(t *testing.T) { child := tracer.StartSpan("name_2", ChildOf(parent.context)).(*span) child.Finish() parent.Finish() + tracer.pushTrace(&finishedTrace{spans: []*span{parent, child}}) tracer.Stop() assert.Equal(t, float64(ext.PriorityAutoReject), parent.Metrics[keySamplingPriority]) assert.Equal(t, decisionDrop, parent.context.trace.samplingDecision) @@ -403,205 +396,6 @@ func TestSamplingDecision(t *testing.T) { assert.Equal(t, 1.0, parent.Metrics[keySingleSpanSamplingRuleRate]) assert.Equal(t, 15.0, parent.Metrics[keySingleSpanSamplingMPS]) }) - - t.Run("client_dropped_with_single_spans:stats_disabled", func(t *testing.T) { - os.Setenv("DD_SPAN_SAMPLING_RULES", `[{"service": "test_*","name":"*_1", "sample_rate": 1.0, "max_per_second": 15.0}]`) - defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - // Stats are disabled, rules are available. Trace sample rate equals 0. - // Span sample rate equals 1. The trace should be dropped. One span has single span tags set. - tracer, _, _, stop := startTestTracer(t) - defer func() { - // Must check these after tracer is stopped to avoid flakiness - assert.Equal(t, uint32(0), tracer.droppedP0Traces) - assert.Equal(t, uint32(1), tracer.droppedP0Spans) - }() - defer stop() - tracer.config.featureFlags = make(map[string]struct{}) - tracer.config.sampler = NewRateSampler(0) - tracer.prioritySampling.defaultRate = 0 - tracer.config.serviceName = "test_service" - parent := tracer.StartSpan("name_1").(*span) - child := tracer.StartSpan("name_2", ChildOf(parent.context)).(*span) - child.Finish() - parent.Finish() - tracer.Stop() - assert.Equal(t, float64(ext.PriorityAutoReject), parent.Metrics[keySamplingPriority]) - assert.Equal(t, decisionDrop, parent.context.trace.samplingDecision) - assert.Equal(t, 8.0, parent.Metrics[keySpanSamplingMechanism]) - assert.Equal(t, 1.0, parent.Metrics[keySingleSpanSamplingRuleRate]) - assert.Equal(t, 15.0, parent.Metrics[keySingleSpanSamplingMPS]) - }) - - t.Run("client_dropped_with_single_span_rules", func(t *testing.T) { - os.Setenv("DD_SPAN_SAMPLING_RULES", `[{"service": "match","name":"nothing", "sample_rate": 1.0, "max_per_second": 15.0}]`) - defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - // Rules are available, but match nothing. Trace sample rate equals 0. - // The trace should be dropped. No single spans extracted. - tracer, _, _, stop := startTestTracer(t) - defer func() { - // Must check these after tracer is stopped to avoid flakiness - assert.Equal(t, uint32(1), tracer.droppedP0Traces) - assert.Equal(t, uint32(2), tracer.droppedP0Spans) - }() - defer stop() - tracer.config.featureFlags = make(map[string]struct{}) - tracer.config.sampler = NewRateSampler(0) - tracer.prioritySampling.defaultRate = 0 - tracer.config.serviceName = "test_service" - parent := tracer.StartSpan("name_1").(*span) - child := tracer.StartSpan("name_2", ChildOf(parent.context)).(*span) - child.Finish() - parent.Finish() - tracer.Stop() - assert.Equal(t, float64(ext.PriorityAutoReject), parent.Metrics[keySamplingPriority]) - assert.Equal(t, decisionDrop, parent.context.trace.samplingDecision) - assert.NotContains(t, parent.Metrics, keySpanSamplingMechanism) - assert.NotContains(t, parent.Metrics, keySingleSpanSamplingRuleRate) - assert.NotContains(t, parent.Metrics, keySingleSpanSamplingMPS) - }) - - t.Run("client_kept_with_single_spans", func(t *testing.T) { - os.Setenv("DD_SPAN_SAMPLING_RULES", `[{"service": "test_*","name":"*", "sample_rate": 1.0}]`) - defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - // Rules are available. Trace sample rate equals 1. Span sample rate equals 1. - // The trace should be kept. No single spans extracted. - tracer, _, _, stop := startTestTracer(t) - defer stop() - tracer.config.agent.DropP0s = true - tracer.config.featureFlags = make(map[string]struct{}) - tracer.config.sampler = NewRateSampler(1) - tracer.prioritySampling.defaultRate = 1 - tracer.config.serviceName = "test_service" - parent := tracer.StartSpan("name_1").(*span) - child := tracer.StartSpan("name_2", ChildOf(parent.context)).(*span) - child.Finish() - parent.Finish() - tracer.Stop() - // single span sampling should only run on dropped traces - assert.Equal(t, float64(ext.PriorityAutoKeep), parent.Metrics[keySamplingPriority]) - assert.Equal(t, decisionKeep, parent.context.trace.samplingDecision) - assert.NotContains(t, parent.Metrics, keySpanSamplingMechanism) - assert.NotContains(t, parent.Metrics, keySingleSpanSamplingRuleRate) - assert.NotContains(t, parent.Metrics, keySingleSpanSamplingMPS) - }) - - t.Run("single_spans_with_max_per_second:rate_1.0", func(t *testing.T) { - os.Setenv("DD_SPAN_SAMPLING_RULES", - `[{"service": "test_*","name":"name_*", "sample_rate": 1.0,"max_per_second":50}]`) - defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - os.Setenv("DD_TRACE_SAMPLE_RATE", "0.8") - defer os.Unsetenv("DD_TRACE_SAMPLE_RATE") - tracer, _, _, stop := startTestTracer(t) - // Don't allow the rate limiter to reset while the test is running. - current := time.Now() - nowTime = func() time.Time { return current } - defer func() { - nowTime = func() time.Time { return time.Now() } - }() - defer stop() - tracer.config.featureFlags = make(map[string]struct{}) - tracer.config.serviceName = "test_service" - var spans []*span - for i := 0; i < 100; i++ { - s := tracer.StartSpan(fmt.Sprintf("name_%d", i)).(*span) - for j := 0; j < 9; j++ { - child := tracer.newChildSpan(fmt.Sprintf("name_%d_%d", i, j), s) - child.Finish() - spans = append(spans, child) - } - s.Finish() - spans = append(spans, s) - } - tracer.Stop() - - var singleSpans, keptSpans int - for _, s := range spans { - if _, ok := s.Metrics[keySpanSamplingMechanism]; ok { - singleSpans++ - assert.Equal(t, 1.0, s.Metrics[keySingleSpanSamplingRuleRate]) - assert.Equal(t, 50.0, s.Metrics[keySingleSpanSamplingMPS]) - } - if s.Metrics[keySamplingPriority] == ext.PriorityUserKeep { - keptSpans++ - } - } - assert.Equal(t, 50, singleSpans) - assert.InDelta(t, 0.8, float64(keptSpans)/float64(len(spans)), 0.19) - }) - - t.Run("single_spans_without_max_per_second:rate_1.0", func(t *testing.T) { - os.Setenv("DD_SPAN_SAMPLING_RULES", `[{"service": "test_*","name":"name_*", "sample_rate": 1.0}]`) - defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - os.Setenv("DD_TRACE_SAMPLE_RATE", "0.8") - defer os.Unsetenv("DD_TRACE_SAMPLE_RATE") - tracer, _, _, stop := startTestTracer(t) - defer stop() - tracer.config.featureFlags = make(map[string]struct{}) - tracer.config.serviceName = "test_service" - spans := []*span{} - for i := 0; i < 100; i++ { - s := tracer.StartSpan("name_1").(*span) - for i := 0; i < 9; i++ { - child := tracer.StartSpan("name_2", ChildOf(s.context)) - child.Finish() - spans = append(spans, child.(*span)) - } - spans = append(spans, s) - s.Finish() - } - tracer.Stop() - - singleSpans, keptSpans := 0, 0 - for _, s := range spans { - if _, ok := s.Metrics[keySpanSamplingMechanism]; ok { - singleSpans++ - continue - } - if s.Metrics[keySamplingPriority] == ext.PriorityUserKeep { - keptSpans++ - } - } - assert.Equal(t, 1000, keptSpans+singleSpans) - assert.InDelta(t, 0.8, float64(keptSpans)/float64(1000), 0.15) - }) - - t.Run("single_spans_without_max_per_second:rate_0.5", func(t *testing.T) { - os.Setenv("DD_SPAN_SAMPLING_RULES", `[{"service": "test_*","name":"name_2", "sample_rate": 0.5}]`) - defer os.Unsetenv("DD_SPAN_SAMPLING_RULES") - os.Setenv("DD_TRACE_SAMPLE_RATE", "0.8") - defer os.Unsetenv("DD_TRACE_SAMPLE_RATE") - tracer, _, _, stop := startTestTracer(t) - defer stop() - tracer.config.featureFlags = make(map[string]struct{}) - tracer.config.serviceName = "test_service" - spans := []*span{} - for i := 0; i < 100; i++ { - s := tracer.StartSpan("name_1").(*span) - for i := 0; i < 9; i++ { - child := tracer.StartSpan("name_2", ChildOf(s.context)) - child.Finish() - spans = append(spans, child.(*span)) - } - spans = append(spans, s) - s.Finish() - } - tracer.Stop() - singleSpans, keptTotal, keptChildren := 0, 0, 0 - for _, s := range spans { - if _, ok := s.Metrics[keySpanSamplingMechanism]; ok { - singleSpans++ - continue - } - if s.Metrics[keySamplingPriority] == ext.PriorityUserKeep { - keptTotal++ - if s.context.trace.root.SpanID != s.SpanID { - keptChildren++ - } - } - } - assert.InDelta(t, 0.5, float64(singleSpans)/(float64(900-keptChildren)), 0.15) - assert.InDelta(t, 0.8, float64(keptTotal)/1000, 0.15) - }) } func TestTracerRuntimeMetrics(t *testing.T) { @@ -1431,11 +1225,11 @@ func TestPushPayload(t *testing.T) { s.Meta["key"] = strings.Repeat("X", payloadSizeLimit/2+10) // half payload size reached - tracer.pushTrace(&finishedTrace{[]*span{s}, true}) + tracer.pushTrace(&finishedTrace{[]*span{s}, decisionKeep}) tracer.awaitPayload(t, 1) // payload size exceeded - tracer.pushTrace(&finishedTrace{[]*span{s}, true}) + tracer.pushTrace(&finishedTrace{[]*span{s}, decisionKeep}) flush(2) }