test: migrate timer-based tests to testing/synctest

ddtrace/tracer/span_test.go

@@ -21,6 +21,7 @@ import (
 	"github.com/DataDog/dd-trace-go/v2/internal/log"
 	"github.com/DataDog/dd-trace-go/v2/internal/samplernames"
 	"github.com/DataDog/dd-trace-go/v2/internal/statsdtest"
+	"github.com/DataDog/dd-trace-go/v2/internal/synctest"
 	"github.com/DataDog/dd-trace-go/v2/internal/telemetry"
 	"github.com/DataDog/dd-trace-go/v2/internal/telemetry/telemetrytest"
 	"github.com/DataDog/dd-trace-go/v2/internal/traceprof"
@@ -148,64 +149,68 @@ func TestSpanOperationName(t *testing.T) {
 }
 
 func TestSpanFinish(t *testing.T) {
-	if strings.HasPrefix(runtime.GOOS, "windows") {
-		t.Skip("Windows' sleep is not precise enough for this test.")
-	}
-
-	assert := assert.New(t)
-	wait := time.Millisecond * 2
-	tracer, err := newTracer(withTransport(newDefaultTransport()))
-	defer tracer.Stop()
-	assert.NoError(err)
-	span := tracer.newRootSpan("pylons.request", "pylons", "/")
+	synctest.Test(t, func(t *testing.T) {
+		assert := assert.New(t)
+		wait := time.Millisecond * 2
+		// Use dummyTransport + nop HTTP client to avoid network I/O inside the synctest bubble.
+		// withNopInfoHTTPClient intercepts the /info agent-discovery request without DNS/TCP.
+		tracer, err := newTracer(withTransport(newDummyTransport()), withNoopStats(), withNopInfoHTTPClient())
+		defer tracer.Stop()
+		assert.NoError(err)
+		span := tracer.newRootSpan("pylons.request", "pylons", "/")
 
-	// the finish should set finished and the duration
-	time.Sleep(wait)
-	span.Finish()
-	assert.Greater(span.duration, int64(wait))
-	assert.True(span.finished)
+		// the finish should set finished and the duration
+		time.Sleep(wait) // instant: fake clock advances 2ms
+		span.Finish()
+		assert.GreaterOrEqual(span.duration, int64(wait)) // fake clock is exact, so duration == wait
+		assert.True(span.finished)
+	})
 }
 
 func TestSpanFinishTwice(t *testing.T) {
-	assert := assert.New(t)
-	wait := time.Millisecond * 2
+	synctest.Test(t, func(t *testing.T) {
+		assert := assert.New(t)
+		wait := time.Millisecond * 2
 
-	tracer, _, _, stop, err := startTestTracer(t)
-	assert.Nil(err)
-	defer stop()
+		// withNopInfoHTTPClient intercepts the /info agent-discovery request without DNS/TCP.
+		// withNoopStats prevents the statsd client from doing DNS resolution inside the bubble.
+		tracer, _, _, stop, err := startTestTracer(t, withNopInfoHTTPClient(), withNoopStats())
+		assert.Nil(err)
+		defer stop()
 
-	assert.Equal(tracer.traceWriter.(*agentTraceWriter).payload.stats().itemCount, 0)
+		assert.Equal(tracer.traceWriter.(*agentTraceWriter).payload.stats().itemCount, 0)
 
-	// the finish must be idempotent
-	span := tracer.newRootSpan("pylons.request", "pylons", "/")
-	time.Sleep(wait)
-	span.Finish()
-	tracer.awaitPayload(t, 1)
-
-	// check that the span does not have any span links serialized
-	// spans don't have span links by default and they are serialized in the meta map
-	// as part of the Finish call
-	_, spanLinksStr := getMeta(span, "_dd.span_links")
-	assert.Zero(spanLinksStr)
-
-	// manipulate the span
-	span.AddLink(SpanLink{
-		TraceID: span.traceID,
-		SpanID:  span.spanID,
-		Attributes: map[string]string{
-			"manual.keep": "true",
-		},
-	})
+		// the finish must be idempotent
+		span := tracer.newRootSpan("pylons.request", "pylons", "/")
+		time.Sleep(wait) // instant: fake clock advances 2ms
+		span.Finish()
+		tracer.awaitPayload(t, 1)
+
+		// check that the span does not have any span links serialized
+		// spans don't have span links by default and they are serialized in the meta map
+		// as part of the Finish call
+		_, spanLinksStr := getMeta(span, "_dd.span_links")
+		assert.Zero(spanLinksStr)
+
+		// manipulate the span
+		span.AddLink(SpanLink{
+			TraceID: span.traceID,
+			SpanID:  span.spanID,
+			Attributes: map[string]string{
+				"manual.keep": "true",
+			},
+		})
 
-	previousDuration := span.duration
-	time.Sleep(wait)
-	span.Finish()
+		previousDuration := span.duration
+		time.Sleep(wait) // instant: fake clock advances 2ms
+		span.Finish()
 
-	assert.Equal(previousDuration, span.duration)
-	_, spanLinksStr = getMeta(span, "_dd.span_links")
-	assert.Zero(spanLinksStr)
+		assert.Equal(previousDuration, span.duration)
+		_, spanLinksStr = getMeta(span, "_dd.span_links")
+		assert.Zero(spanLinksStr)
 
-	tracer.awaitPayload(t, 1) // this checks that no other span was seen by the tracerWriter
+		tracer.awaitPayload(t, 1) // this checks that no other span was seen by the tracerWriter
+	})
 }
 
 func TestSpanFinishNilOption(t *testing.T) {
@@ -1090,34 +1095,38 @@ func TestUniqueTagKeys(t *testing.T) {
 
 // Prior to a bug fix, this failed when running `go test -race`
 func TestSpanModifyWhileFlushing(t *testing.T) {
-	tracer, _, _, stop, err := startTestTracer(t)
-	assert.Nil(t, err)
-	defer stop()
+	synctest.Test(t, func(t *testing.T) {
+		// withNopInfoHTTPClient intercepts the /info agent-discovery request without DNS/TCP.
+		// withNoopStats prevents the statsd client from doing DNS resolution inside the bubble.
+		tracer, _, _, stop, err := startTestTracer(t, withNopInfoHTTPClient(), withNoopStats())
+		assert.Nil(t, err)
+		defer stop()
 
-	done := make(chan struct{})
-	go func() {
-		span := tracer.newRootSpan("pylons.request", "pylons", "/")
-		span.Finish()
-		// It doesn't make much sense to update the span after it's been finished,
-		// but an error in a user's code could lead to this.
-		span.SetOperationName("race_test")
-		span.SetTag("race_test", "true")
-		span.SetTag("race_test2", 133.7)
-		span.SetTag("race_test3", 133.7)
-		span.SetTag(ext.Error, errors.New("t"))
-		span.SetUser("race_test_user_1")
-		done <- struct{}{}
-	}()
-
-	for {
-		select {
-		case <-done:
-			return
-		default:
-			tracer.traceWriter.flush()
-			time.Sleep(10 * time.Millisecond)
+		done := make(chan struct{})
+		go func() {
+			span := tracer.newRootSpan("pylons.request", "pylons", "/")
+			span.Finish()
+			// It doesn't make much sense to update the span after it's been finished,
+			// but an error in a user's code could lead to this.
+			span.SetOperationName("race_test")
+			span.SetTag("race_test", "true")
+			span.SetTag("race_test2", 133.7)
+			span.SetTag("race_test3", 133.7)
+			span.SetTag(ext.Error, errors.New("t"))
+			span.SetUser("race_test_user_1")
+			done <- struct{}{}
+		}()
+
+		for {
+			select {
+			case <-done:
+				return
+			default:
+				tracer.traceWriter.flush()
+				time.Sleep(10 * time.Millisecond) // instant: fake clock advances 10ms
+			}
 		}
-	}
+	})
 }
 
 func TestSpanSamplingPriority(t *testing.T) {
@@ -1427,28 +1436,33 @@ func TestRootSpanAccessor(t *testing.T) {
 }
 
 func TestSpanStartAndFinishLogs(t *testing.T) {
-	tp := new(log.RecordLogger)
-	tracer, _, _, stop, err := startTestTracer(t, WithLogger(tp), WithDebugMode(true))
-	assert.Nil(t, err)
-	defer stop()
+	synctest.Test(t, func(t *testing.T) {
+		tp := new(log.RecordLogger)
+		// withNopInfoHTTPClient intercepts the /info agent-discovery request without DNS/TCP.
+		// withNoopStats prevents the statsd client from doing DNS resolution inside the bubble.
+		tracer, _, _, stop, err := startTestTracer(t, WithLogger(tp), WithDebugMode(true), withNopInfoHTTPClient(), withNoopStats())
+		assert.Nil(t, err)
+		defer stop()
 
-	span := tracer.StartSpan("op")
-	time.Sleep(time.Millisecond * 2)
-	span.Finish()
-	started, finished := false, false
-	for _, l := range tp.Logs() {
-		if !started {
-			started = strings.Contains(l, "DEBUG: Started Span")
-		}
-		if !finished {
-			finished = strings.Contains(l, "DEBUG: Finished Span")
-		}
-		if started && finished {
-			break
+		span := tracer.StartSpan("op")
+		time.Sleep(time.Millisecond * 2) // instant: fake clock advances 2ms
+		span.Finish()
+		synctest.Wait() // wait for tracer goroutines to process the span
+		started, finished := false, false
+		for _, l := range tp.Logs() {
+			if !started {
+				started = strings.Contains(l, "DEBUG: Started Span")
+			}
+			if !finished {
+				finished = strings.Contains(l, "DEBUG: Finished Span")
+			}
+			if started && finished {
+				break
+			}
 		}
-	}
-	require.True(t, started)
-	require.True(t, finished)
+		require.True(t, started)
+		require.True(t, finished)
+	})
 }
 
 func TestSetUserPropagatedUserID(t *testing.T) {

ddtrace/tracer/stats_test.go

@@ -13,6 +13,8 @@ import (
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 
+	"github.com/DataDog/dd-trace-go/v2/internal/synctest"
+
 	"github.com/DataDog/datadog-agent/pkg/obfuscate"
 	"github.com/DataDog/datadog-go/v5/statsd"
 
@@ -33,7 +35,7 @@ func TestAlignTs(t *testing.T) {
 
 func newTestConfigWithTransportAndEnv(t *testing.T, transport transport, env string) *config {
 	assert := assert.New(t)
-	cfg, err := newTestConfig(func(c *config) {
+	cfg, err := newTestConfig(withNopInfoHTTPClient(), func(c *config) {
 		c.transport = transport
 		c.internalConfig.SetEnv(env, internalconfig.OriginCode)
 	})
@@ -43,7 +45,7 @@ func newTestConfigWithTransportAndEnv(t *testing.T, transport transport, env str
 
 func newTestConfigWithTransport(t *testing.T, transport transport) *config {
 	assert := assert.New(t)
-	cfg, err := newTestConfig(func(c *config) {
+	cfg, err := newTestConfig(withNopInfoHTTPClient(), func(c *config) {
 		c.transport = transport
 	})
 	assert.NoError(err)
@@ -86,20 +88,23 @@ func TestConcentrator(t *testing.T) {
 	})
 	t.Run("flusher", func(t *testing.T) {
 		t.Run("old", func(t *testing.T) {
-			transport := newDummyTransport()
-			c := newConcentrator(newTestConfigWithTransportAndEnv(t, transport, "someEnv"), 500_000, &statsd.NoOpClientDirect{})
-			assert.Len(t, transport.Stats(), 0)
-			ss1, ok := c.newTracerStatSpan(&s1, nil)
-			assert.True(t, ok)
-			c.Start()
-			c.In <- ss1
-			time.Sleep(2 * time.Millisecond * timeMultiplicator)
-			c.Stop()
-			actualStats := transport.Stats()
-			assert.Len(t, actualStats, 1)
-			assert.Len(t, actualStats[0].Stats, 1)
-			assert.Len(t, actualStats[0].Stats[0].Stats, 1)
-			assert.Equal(t, "http.request", actualStats[0].Stats[0].Stats[0].Name)
+			synctest.Test(t, func(t *testing.T) {
+				transport := newDummyTransport()
+				c := newConcentrator(newTestConfigWithTransportAndEnv(t, transport, "someEnv"), 500_000, &statsd.NoOpClientDirect{})
+				assert.Len(t, transport.Stats(), 0)
+				ss1, ok := c.newTracerStatSpan(&s1, nil)
+				assert.True(t, ok)
+				c.Start()
+				c.In <- ss1
+				time.Sleep(2 * time.Millisecond) // instant: fake clock advances 2ms past flush interval
+				synctest.Wait()                  // wait for concentrator goroutine to flush
+				c.Stop()
+				actualStats := transport.Stats()
+				assert.Len(t, actualStats, 1)
+				assert.Len(t, actualStats[0].Stats, 1)
+				assert.Len(t, actualStats[0].Stats[0].Stats, 1)
+				assert.Equal(t, "http.request", actualStats[0].Stats[0].Stats[0].Name)
+			})
 		})
 
 		t.Run("recent+stats", func(t *testing.T) {

ddtrace/tracer/time_windows_test.go

@@ -7,10 +7,21 @@ package tracer
 
 import (
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/assert"
 )
 
+func init() {
+	// Override now and nowTime to use time.Now() in tests. Production code
+	// calls GetSystemTimePreciseAsFileTime() directly for higher precision, but
+	// that syscall bypasses testing/synctest's fake clock. time.Now() is
+	// intercepted by synctest, so this makes the fake clock work correctly on
+	// Windows without changing production behavior.
+	now = func() int64 { return time.Now().UnixNano() }
+	nowTime = func() time.Time { return time.Now() }
+}
+
 func BenchmarkNormalTimeNow(b *testing.B) {
 	for n := 0; n < b.N; n++ {
 		lowPrecisionNow()