Skip to content

Commit

Permalink
contrib/slog: clone record before calling Add
Browse files Browse the repository at this point in the history
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
  • Loading branch information
felixge committed Oct 15, 2024
1 parent 93311db commit 7362172
Show file tree
Hide file tree
Showing 2 changed files with 46 additions and 0 deletions.
1 change: 1 addition & 0 deletions contrib/log/slog/slog.go
Original file line number Diff line number Diff line change
Expand Up @@ -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()),
Expand Down
45 changes: 45 additions & 0 deletions contrib/log/slog/slog_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ import (
"bytes"
"context"
"encoding/json"
"io"
"log/slog"
"strings"
"testing"
Expand Down Expand Up @@ -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)
}

0 comments on commit 7362172

Please sign in to comment.