From 753f98ca6deaa4200c9c47567c8cac01f301790c Mon Sep 17 00:00:00 2001 From: Robert Liebowitz Date: Wed, 22 Jan 2025 04:15:57 -0500 Subject: [PATCH] contrib/log/slog: avoid logging 0 value trace/span IDs (#2994) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: Dario Castañé --- contrib/log/slog/slog.go | 2 +- contrib/log/slog/slog_test.go | 76 ++++++++++++++++++++++++++++------- 2 files changed, 62 insertions(+), 16 deletions(-) diff --git a/contrib/log/slog/slog.go b/contrib/log/slog/slog.go index a29866f294..ccb9800ee4 100644 --- a/contrib/log/slog/slog.go +++ b/contrib/log/slog/slog.go @@ -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) diff --git a/contrib/log/slog/slog_test.go b/contrib/log/slog/slog_test.go index 7546009b0f..36a5960db4 100644 --- a/contrib/log/slog/slog_test.go +++ b/contrib/log/slog/slog_test.go @@ -48,8 +48,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 @@ -74,25 +95,50 @@ 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) { t.Run("testLogger", func(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) }) t.Run("slogtest", func(t *testing.T) {