diff --git a/contrib/net/http/trace_test.go b/contrib/net/http/trace_test.go index f85a592861..0489f8c3ef 100644 --- a/contrib/net/http/trace_test.go +++ b/contrib/net/http/trace_test.go @@ -329,8 +329,8 @@ func TestTraceAndServe(t *testing.T) { t.Setenv("DD_TRACE_HTTP_SERVER_ERROR_STATUSES", "500") cfg := &ServeConfig{ - Service: "service", - Resource: "resource", + Service: "service", + Resource: "resource", } handler := func(w http.ResponseWriter, r *http.Request) { diff --git a/ddtrace/tracer/log_test.go b/ddtrace/tracer/log_test.go index 268e0ad015..6319bbd6cb 100644 --- a/ddtrace/tracer/log_test.go +++ b/ddtrace/tracer/log_test.go @@ -187,9 +187,11 @@ func TestLogFormat(t *testing.T) { defer stop() tp.Reset() tp.Ignore("appsec: ", telemetry.LogPrefix) - tracer.StartSpan("test", ServiceName("test-service"), ResourceName("/"), WithSpanID(12345)) + sp := tracer.StartSpan("test", ServiceName("test-service"), ResourceName("/"), WithSpanID(12345)) + sCtx, ok := sp.Context().(*spanContext) + assert.True(ok) assert.Len(tp.Logs(), 1) - assert.Regexp(logPrefixRegexp+` DEBUG: Started Span: dd.trace_id="12345" dd.span_id="12345" dd.parent_id="0", Operation: test, Resource: /, Tags: map.*, map.*`, tp.Logs()[0]) + assert.Regexp(logPrefixRegexp+` DEBUG: Started Span: dd.trace_id="`+sCtx.TraceID128()+`" dd.span_id="12345" dd.parent_id="0", Operation: test, Resource: /, Tags: map.*, map.*`, tp.Logs()[0]) } func TestLogPropagators(t *testing.T) { diff --git a/ddtrace/tracer/span.go b/ddtrace/tracer/span.go index 6b7568ec48..c9d6bace83 100644 --- a/ddtrace/tracer/span.go +++ b/ddtrace/tracer/span.go @@ -709,7 +709,7 @@ func (s *span) Format(f fmt.State, c rune) { } } var traceID string - if sharedinternal.BoolEnv("DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED", false) && s.context.traceID.HasUpper() { + if sharedinternal.BoolEnv("DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED", true) && s.context.traceID.HasUpper() { traceID = s.context.TraceID128() } else { traceID = fmt.Sprintf("%d", s.TraceID) diff --git a/ddtrace/tracer/span_test.go b/ddtrace/tracer/span_test.go index 4c9b4d1c59..355ac35920 100644 --- a/ddtrace/tracer/span_test.go +++ b/ddtrace/tracer/span_test.go @@ -712,7 +712,8 @@ func TestSpanLog(t *testing.T) { tracer, _, _, stop := startTestTracer(t) defer stop() span := tracer.StartSpan("test.request").(*span) - expect := fmt.Sprintf(`dd.trace_id="%d" dd.span_id="%d" dd.parent_id="0"`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) } t.Run("noservice_first", noServiceTest) @@ -722,7 +723,8 @@ func TestSpanLog(t *testing.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" dd.parent_id="0"`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`dd.service=tracer.test dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) @@ -731,7 +733,8 @@ func TestSpanLog(t *testing.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" dd.parent_id="0"`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`dd.service=tracer.test dd.env=testenv dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) @@ -740,7 +743,8 @@ func TestSpanLog(t *testing.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" dd.parent_id="0"`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`dd.service=tracer.test dd.version=1.2.3 dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) @@ -749,7 +753,8 @@ func TestSpanLog(t *testing.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" dd.parent_id="0"`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`dd.service=tracer.test dd.env=testenv dd.version=1.2.3 dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) @@ -761,7 +766,8 @@ func TestSpanLog(t *testing.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" dd.parent_id="0"`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`dd.service=tracer.test dd.env=testenv dd.version=1.2.3 dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) @@ -773,7 +779,8 @@ func TestSpanLog(t *testing.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" dd.parent_id="0"`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`dd.service=tracer.test dd.env=testenv dd.version=1.2.3 dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) @@ -782,7 +789,8 @@ func TestSpanLog(t *testing.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" dd.parent_id="0")`, span.TraceID, span.SpanID) + sctx := span.Context().(*spanContext) + expect := fmt.Sprintf(`%%!b(ddtrace.Span=dd.service=tracer.test dd.version=1.2.3 dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0")`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%b", span)) }) @@ -790,9 +798,10 @@ func TestSpanLog(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) + sctx := span.Context().(*spanContext) stop() // no service, env, or version after the tracer is stopped - expect := fmt.Sprintf(`dd.trace_id="%d" dd.span_id="%d" dd.parent_id="0"`, span.TraceID, span.SpanID) + expect := fmt.Sprintf(`dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) @@ -803,34 +812,32 @@ func TestSpanLog(t *testing.T) { assert := assert.New(t) tracer, _, _, stop := startTestTracer(t) span := tracer.StartSpan("test.request").(*span) + sctx := span.Context().(*spanContext) stop() // service is not included: it is cleared when we stop the tracer // env, version are included: it reads the environment variable when there is no tracer - expect := fmt.Sprintf(`dd.env=testenv dd.version=1.2.3 dd.trace_id="%d" dd.span_id="%d" dd.parent_id="0"`, span.TraceID, span.SpanID) + expect := fmt.Sprintf(`dd.env=testenv dd.version=1.2.3 dd.trace_id="%s" dd.span_id="%d" dd.parent_id="0"`, sctx.TraceID128(), span.SpanID) assert.Equal(expect, fmt.Sprintf("%v", span)) }) - t.Run("128-bit-generation-only", func(t *testing.T) { - // Generate 128 bit trace ids, but don't log them. So only the lower - // 64 bits should be logged in decimal form. - // DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED is true by default - // DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED is false by default + t.Run("128-bit-logging-default", func(t *testing.T) { + // Generate and log 128 bit trace ids by default assert := assert.New(t) tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithEnv("testenv")) defer stop() span := tracer.StartSpan("test.request").(*span) - span.TraceID = 12345678 span.SpanID = 87654321 span.Finish() - expect := `dd.service=tracer.test dd.env=testenv dd.trace_id="12345678" dd.span_id="87654321" dd.parent_id="0"` + expect := fmt.Sprintf(`dd.service=tracer.test dd.env=testenv dd.trace_id=%q dd.span_id="87654321" dd.parent_id="0"`, span.context.TraceID128()) assert.Equal(expect, fmt.Sprintf("%v", span)) + v, _ := getMeta(span, keyTraceID128) + assert.NotEmpty(v) }) t.Run("128-bit-logging-only", func(t *testing.T) { - // Logging 128-bit trace ids is enabled, but it's not present in + // Logging 128-bit trace ids is enabled, but format is not present in // the span. So only the lower 64 bits should be logged in decimal form. t.Setenv("DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED", "false") - t.Setenv("DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED", "true") assert := assert.New(t) tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithEnv("testenv")) defer stop() @@ -842,27 +849,9 @@ func TestSpanLog(t *testing.T) { assert.Equal(expect, fmt.Sprintf("%v", span)) }) - t.Run("128-bit-logging-with-generation", func(t *testing.T) { - // Logging 128-bit trace ids is enabled, and a 128-bit trace id, so - // a quoted 32 byte hex string should be printed for the dd.trace_id. - t.Setenv("DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED", "true") - t.Setenv("DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED", "true") - assert := assert.New(t) - tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithEnv("testenv")) - defer stop() - span := tracer.StartSpan("test.request").(*span) - span.SpanID = 87654321 - span.Finish() - expect := fmt.Sprintf(`dd.service=tracer.test dd.env=testenv dd.trace_id=%q dd.span_id="87654321" dd.parent_id="0"`, span.context.TraceID128()) - assert.Equal(expect, fmt.Sprintf("%v", span)) - v, _ := getMeta(span, keyTraceID128) - assert.NotEmpty(v) - }) - t.Run("128-bit-logging-with-small-upper-bits", func(t *testing.T) { // Logging 128-bit trace ids is enabled, and a 128-bit trace id, so // a quoted 32 byte hex string should be printed for the dd.trace_id. - t.Setenv("DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED", "true") t.Setenv("DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED", "false") assert := assert.New(t) tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithEnv("testenv")) @@ -878,7 +867,6 @@ func TestSpanLog(t *testing.T) { t.Run("128-bit-logging-with-empty-upper-bits", func(t *testing.T) { // Logging 128-bit trace ids is enabled, and but the upper 64 bits // are empty, so the dd.trace_id should be printed as raw digits (not hex). - t.Setenv("DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED", "true") t.Setenv("DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED", "false") assert := assert.New(t) tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithEnv("testenv")) @@ -890,6 +878,20 @@ func TestSpanLog(t *testing.T) { v, _ := getMeta(span, keyTraceID128) assert.Equal("", v) }) + t.Run("128-bit-logging-disabled", func(t *testing.T) { + // Only the lower 64 bits should be logged in decimal form. + // DD_TRACE_128_BIT_TRACEID_GENERATION_ENABLED is true by default + t.Setenv("DD_TRACE_128_BIT_TRACEID_LOGGING_ENABLED", "false") + assert := assert.New(t) + tracer, _, _, stop := startTestTracer(t, WithService("tracer.test"), WithEnv("testenv")) + defer stop() + span := tracer.StartSpan("test.request").(*span) + span.TraceID = 12345678 + span.SpanID = 87654321 + span.Finish() + expect := `dd.service=tracer.test dd.env=testenv dd.trace_id="12345678" dd.span_id="87654321" dd.parent_id="0"` + assert.Equal(expect, fmt.Sprintf("%v", span)) + }) } func TestRootSpanAccessor(t *testing.T) {