Skip to content

Commit

Permalink
contrib/log/slog: avoid logging 0 value trace/span IDs
Browse files Browse the repository at this point in the history
If the tracer is started but explicitly deactivated, there will be a
span on the context, but the span ID and trace ID will be set to 0.
Adding this information to log outputs seems like unintentional noise
(although it's certainly possible there's a use case I'm not aware of),
so I figured disabling it would be preferred.

The change to explicitly add `tracer.WithTraceEnabled(true)` was so that
the test would be resilient to folks who might have `DD_TRACE_ENABLED`
set explicitly, which is true on my machine.
  • Loading branch information
rliebz committed Nov 26, 2024
1 parent e9a64d3 commit 5d00d07
Show file tree
Hide file tree
Showing 2 changed files with 62 additions and 16 deletions.
2 changes: 1 addition & 1 deletion contrib/log/slog/slog.go
Original file line number Diff line number Diff line change
Expand Up @@ -61,7 +61,7 @@ func (h *handler) Handle(ctx context.Context, rec slog.Record) error {
// In case the user has created group loggers, we ignore those and
// set them at the root level.
span, ok := tracer.SpanFromContext(ctx)
if ok {
if ok && span.Context().TraceID() != 0 {
traceID := strconv.FormatUint(span.Context().TraceID(), 10)
spanID := strconv.FormatUint(span.Context().SpanID(), 10)

Expand Down
76 changes: 61 additions & 15 deletions contrib/log/slog/slog_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -47,8 +47,29 @@ func assertLogEntry(t *testing.T, rawEntry, wantMsg, wantLevel string, span trac
}
}

func assertLogEntryNoTrace(t *testing.T, rawEntry, wantMsg, wantLevel string) {
t.Helper()

t.Log(rawEntry)

var entry map[string]interface{}
err := json.Unmarshal([]byte(rawEntry), &entry)
require.NoError(t, err)
require.NotEmpty(t, entry)

assert.Equal(t, wantMsg, entry["msg"])
assert.Equal(t, wantLevel, entry["level"])
assert.NotEmpty(t, entry["time"])

assert.NotContains(t, entry, ext.LogKeyTraceID)
assert.NotContains(t, entry, ext.LogKeySpanID)
}

func testLogger(t *testing.T, createLogger func(b io.Writer) *slog.Logger, assertExtra func(t *testing.T, entry map[string]interface{})) {
tracer.Start(tracer.WithLogger(internallog.DiscardLogger{}))
tracer.Start(
tracer.WithTraceEnabled(true),
tracer.WithLogger(internallog.DiscardLogger{}),
)
defer tracer.Stop()

// create the application logger
Expand All @@ -73,24 +94,49 @@ func testLogger(t *testing.T, createLogger func(b io.Writer) *slog.Logger, asser
assertLogEntry(t, logs[1], "this is an error log with tracing information", "ERROR", span, assertExtra)
}

func TestNewJSONHandler(t *testing.T) {
testLogger(
t,
func(w io.Writer) *slog.Logger {
return slog.New(NewJSONHandler(w, nil))
},
nil,
func testLoggerNoTrace(t *testing.T, createLogger func(b io.Writer) *slog.Logger) {
tracer.Start(
tracer.WithTraceEnabled(false),
tracer.WithLogger(internallog.DiscardLogger{}),
)
defer tracer.Stop()

// create the application logger
var b bytes.Buffer
logger := createLogger(&b)

// start a new span
span, ctx := tracer.StartSpanFromContext(context.Background(), "test")
defer span.Finish()

// log a message using the context containing span information
logger.Log(ctx, slog.LevelInfo, "this is an info log with tracing information")
logger.Log(ctx, slog.LevelError, "this is an error log with tracing information")

logs := strings.Split(
strings.TrimRight(b.String(), "\n"),
"\n",
)
// assert log entries contain trace information
require.Len(t, logs, 2)
assertLogEntryNoTrace(t, logs[0], "this is an info log with tracing information", "INFO")
assertLogEntryNoTrace(t, logs[1], "this is an error log with tracing information", "ERROR")
}

func TestNewJSONHandler(t *testing.T) {
createLogger := func(w io.Writer) *slog.Logger {
return slog.New(NewJSONHandler(w, nil))
}
testLogger(t, createLogger, nil)
testLoggerNoTrace(t, createLogger)
}

func TestWrapHandler(t *testing.T) {
testLogger(
t,
func(w io.Writer) *slog.Logger {
return slog.New(WrapHandler(slog.NewJSONHandler(w, nil)))
},
nil,
)
createLogger := func(w io.Writer) *slog.Logger {
return slog.New(WrapHandler(slog.NewJSONHandler(w, nil)))
}
testLogger(t, createLogger, nil)
testLoggerNoTrace(t, createLogger)
}

func TestHandlerWithAttrs(t *testing.T) {
Expand Down

0 comments on commit 5d00d07

Please sign in to comment.