From 7362172c2f799684dec654d595cf44ff1e224b46 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Felix=20Geisend=C3=B6rfer?= <felix@datadoghq.com>
Date: Tue, 15 Oct 2024 13:13:25 +0200
Subject: [PATCH] contrib/slog: clone record before calling Add

Fix a bug that could manifest itself when a slog Record is modified
concurrently (A) with our handler.Handle implementation (B). If A
completes before B, then it might overwrite an attribute added by A.

Add test case demonstrating the issue.

Fixes #2918
---
 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)
+}