From 51abc7b9a51f66e9477db9a28d253b8ecb39b2ee Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Felix=20Geisend=C3=B6rfer?= Date: Wed, 16 Oct 2024 14:34:39 +0200 Subject: [PATCH] contrib/slog: clone record before calling Add (#2929) --- contrib/log/slog/slog.go | 1 + contrib/log/slog/slog_test.go | 45 +++++++++++++++++++++++++++++++++++ 2 files changed, 46 insertions(+) diff --git a/contrib/log/slog/slog.go b/contrib/log/slog/slog.go index 1a27186a27..5cb0fcbdc2 100644 --- a/contrib/log/slog/slog.go +++ b/contrib/log/slog/slog.go @@ -42,6 +42,7 @@ type handler struct { func (h *handler) Handle(ctx context.Context, rec slog.Record) error { span, ok := tracer.SpanFromContext(ctx) if ok { + rec = rec.Clone() rec.Add( slog.Uint64(ext.LogKeyTraceID, span.Context().TraceID()), slog.Uint64(ext.LogKeySpanID, span.Context().SpanID()), diff --git a/contrib/log/slog/slog_test.go b/contrib/log/slog/slog_test.go index 5b74691469..86254dde88 100644 --- a/contrib/log/slog/slog_test.go +++ b/contrib/log/slog/slog_test.go @@ -9,6 +9,7 @@ import ( "bytes" "context" "encoding/json" + "io" "log/slog" "strings" "testing" @@ -74,3 +75,47 @@ func TestWrapHandler(t *testing.T) { return WrapHandler(slog.NewJSONHandler(b, nil)) }) } + +// TestRecordClone is a regression test for https://github.com/DataDog/dd-trace-go/issues/2918. +func TestRecordClone(t *testing.T) { + // start a new span + span, ctx := tracer.StartSpanFromContext(context.Background(), "test") + defer span.Finish() + + r := slog.Record{} + gate := func() { + // Calling Handle below should not overwrite this value + r.Add("sentinel-key", "sentinel-value") + } + h := handlerGate{gate, WrapHandler(slog.NewJSONHandler(io.Discard, nil))} + // Up to slog.nAttrsInline (5) attributes are stored in the front array of + // the record. Make sure to add more records than that to trigger the bug. + for i := 0; i < 5*10; i++ { + r.Add("i", i) + } + h.Handle(ctx, r) + + var foundSentinel bool + r.Attrs(func(a slog.Attr) bool { + if a.Key == "sentinel-key" { + foundSentinel = true + return false + } + return true + }) + assert.True(t, foundSentinel) +} + +// handlerGate calls a gate function before calling the underlying handler. This +// allows simulating a concurrent modification of the record that happens after +// Handle is called (and the record has been copied), but before the back array +// of the Record is written to. +type handlerGate struct { + gate func() + slog.Handler +} + +func (h handlerGate) Handle(ctx context.Context, r slog.Record) { + h.gate() + h.Handler.Handle(ctx, r) +}