diff --git a/ddtrace/tracer/span.go b/ddtrace/tracer/span.go index b5c0c94e70..efc3561a00 100644 --- a/ddtrace/tracer/span.go +++ b/ddtrace/tracer/span.go @@ -9,6 +9,7 @@ package tracer import ( "fmt" + "os" "reflect" "runtime" "runtime/debug" @@ -19,6 +20,8 @@ import ( "gopkg.in/DataDog/dd-trace-go.v1/ddtrace" "gopkg.in/DataDog/dd-trace-go.v1/ddtrace/ext" + "gopkg.in/DataDog/dd-trace-go.v1/ddtrace/internal" + "gopkg.in/DataDog/dd-trace-go.v1/internal/globalconfig" "github.com/tinylib/msgp/msgp" "golang.org/x/xerrors" @@ -337,6 +340,36 @@ func (s *span) String() string { return strings.Join(lines, "\n") } +// Format implements fmt.Formatter. +func (s *span) Format(f fmt.State, c rune) { + switch c { + case 's': + fmt.Fprint(f, s.String()) + case 'v': + if svc := globalconfig.ServiceName(); svc != "" { + fmt.Fprintf(f, "dd.service=%s ", svc) + } + if tr, ok := internal.GetGlobalTracer().(*tracer); ok { + if env, ok := tr.config.globalTags[ext.Environment]; ok { + fmt.Fprintf(f, "dd.env=%s ", env) + } + if tr.config.version != "" { + fmt.Fprintf(f, "dd.version=%s ", tr.config.version) + } + } else { + if env := os.Getenv("DD_ENV"); env != "" { + fmt.Fprintf(f, "dd.env=%s ", env) + } + if v := os.Getenv("DD_VERSION"); v != "" { + fmt.Fprintf(f, "dd.version=%s ", v) + } + } + fmt.Fprintf(f, "dd.trace_id=%d dd.span_id=%d", s.TraceID, s.SpanID) + default: + fmt.Fprintf(f, "%%!%c(ddtrace.Span=%v)", c, s) + } +} + const ( keySamplingPriority = "_sampling_priority_v1" keySamplingPriorityRate = "_sampling_priority_rate_v1" diff --git a/ddtrace/tracer/span_test.go b/ddtrace/tracer/span_test.go index 3630b6593f..1108f0d598 100644 --- a/ddtrace/tracer/span_test.go +++ b/ddtrace/tracer/span_test.go @@ -8,6 +8,7 @@ package tracer import ( "errors" "fmt" + "os" "strings" "testing" "time" @@ -404,6 +405,101 @@ func TestSpanSamplingPriority(t *testing.T) { } } +func TestSpanLog(t *testing.T) { + t.Run("default", func(t *testing.T) { + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test")) + defer stop() + span := tracer.StartSpan("test.request").(*span) + expect := fmt.Sprintf("dd.service=tracer.test dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) + + t.Run("env", func(t *testing.T) { + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithEnv("testenv")) + defer stop() + span := tracer.StartSpan("test.request").(*span) + expect := fmt.Sprintf("dd.service=tracer.test dd.env=testenv dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) + + t.Run("version", func(t *testing.T) { + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithServiceVersion("1.2.3")) + defer stop() + span := tracer.StartSpan("test.request").(*span) + expect := fmt.Sprintf("dd.service=tracer.test dd.version=1.2.3 dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) + + t.Run("full", func(t *testing.T) { + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithServiceVersion("1.2.3"), WithEnv("testenv")) + defer stop() + span := tracer.StartSpan("test.request").(*span) + expect := fmt.Sprintf("dd.service=tracer.test dd.env=testenv dd.version=1.2.3 dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) + + t.Run("subservice", func(t *testing.T) { + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithServiceVersion("1.2.3"), WithEnv("testenv")) + defer stop() + span := tracer.StartSpan("test.request", ServiceName("subservice name")).(*span) + expect := fmt.Sprintf("dd.service=tracer.test dd.env=testenv dd.version=1.2.3 dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) + + t.Run("env", func(t *testing.T) { + os.Setenv("DD_SERVICE", "tracer.test") + defer os.Unsetenv("DD_SERVICE") + os.Setenv("DD_VERSION", "1.2.3") + defer os.Unsetenv("DD_VERSION") + os.Setenv("DD_ENV", "testenv") + defer os.Unsetenv("DD_ENV") + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t) + defer stop() + span := tracer.StartSpan("test.request").(*span) + expect := fmt.Sprintf("dd.service=tracer.test dd.env=testenv dd.version=1.2.3 dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) + + t.Run("badformat", func(t *testing.T) { + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithServiceVersion("1.2.3")) + defer stop() + span := tracer.StartSpan("test.request").(*span) + expect := fmt.Sprintf("%%!b(ddtrace.Span=dd.service=tracer.test dd.version=1.2.3 dd.trace_id=%d dd.span_id=%d)", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%b", span)) + }) + + t.Run("notracer/options", func(t *testing.T) { + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithServiceVersion("1.2.3"), WithEnv("testenv")) + span := tracer.StartSpan("test.request").(*span) + stop() + expect := fmt.Sprintf("dd.service=tracer.test dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) + + t.Run("notracer/env", func(t *testing.T) { + os.Setenv("DD_SERVICE", "tracer.test") + defer os.Unsetenv("DD_SERVICE") + os.Setenv("DD_VERSION", "1.2.3") + defer os.Unsetenv("DD_VERSION") + os.Setenv("DD_ENV", "testenv") + defer os.Unsetenv("DD_ENV") + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t) + span := tracer.StartSpan("test.request").(*span) + stop() + expect := fmt.Sprintf("dd.service=tracer.test dd.env=testenv dd.version=1.2.3 dd.trace_id=%d dd.span_id=%d", span.TraceID, span.SpanID) + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) +} + func BenchmarkSetTagMetric(b *testing.B) { span := newBasicSpan("bench.span") keys := "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ"