From 82c17a891f1ea6f5a9f330bf7979554619b70624 Mon Sep 17 00:00:00 2001 From: Dmytro Rashko Date: Tue, 1 Sep 2026 22:43:42 +0200 Subject: [PATCH] Fix data race on Connection logger field NewConnection spawns the receive and processNotifications goroutines in its constructor, so a caller can only reach SetLogger after those goroutines are already running. SetLogger wrote the logger field with no synchronization while they read it through loggerOrDefault, so any call to SetLogger raced the connection's own logging. Under `go test -race` this aborts every test that connects an ACP subprocess. Store the logger in an atomic.Pointer instead. A single lock-free atomic load covers the hot loggerOrDefault read path with no mutex contention, and no lock-reentrancy risk against the connection's other mutexes; the pointer is replaced wholesale, so an atomic is sufficient. Add a regression test that feeds the connection unparseable input (which makes receive log) while calling SetLogger concurrently. It fails under -race without this change and passes with it. Verified: go test -race ./... and go build ./example/... pass. Fixes #57 Signed-off-by: Dmytro Rashko --- connection.go | 11 +++++--- connection_logger_test.go | 57 +++++++++++++++++++++++++++++++++++++++ 2 files changed, 64 insertions(+), 4 deletions(-) create mode 100644 connection_logger_test.go diff --git a/connection.go b/connection.go index e33beb0..4ab2a9b 100644 --- a/connection.go +++ b/connection.go @@ -77,7 +77,10 @@ type Connection struct { inboundCtx context.Context inboundCancel context.CancelCauseFunc - logger *slog.Logger + // logger is atomic because SetLogger may be called after NewConnection has + // already spawned the receive/processNotifications goroutines that read it + // via loggerOrDefault. + logger atomic.Pointer[slog.Logger] notifyMu sync.Mutex // notifyCond coordinates response-scoped waits for sequential notification processing. @@ -122,11 +125,11 @@ func NewConnection(handler MethodHandler, peerInput io.Writer, peerOutput io.Rea // SetLogger installs a logger used for internal connection diagnostics. // If unset, logs are written via the default logger. -func (c *Connection) SetLogger(l *slog.Logger) { c.logger = l } +func (c *Connection) SetLogger(l *slog.Logger) { c.logger.Store(l) } func (c *Connection) loggerOrDefault() *slog.Logger { - if c.logger != nil { - return c.logger + if l := c.logger.Load(); l != nil { + return l } return slog.Default() } diff --git a/connection_logger_test.go b/connection_logger_test.go new file mode 100644 index 0000000..0965136 --- /dev/null +++ b/connection_logger_test.go @@ -0,0 +1,57 @@ +package acp + +import ( + "context" + "encoding/json" + "io" + "log/slog" + "sync" + "testing" +) + +// TestConnectionSetLogger_ConcurrentWithReceive guards the logger field against +// a data race: NewConnection spawns receive/processNotifications before the +// caller has any chance to install a logger, so a later SetLogger writes the +// field while those goroutines read it through loggerOrDefault. +// +// Unparseable input makes receive log, which is the read side of the race. +// Run under -race; without synchronization on the field this fails. +func TestConnectionSetLogger_ConcurrentWithReceive(t *testing.T) { + inR, inW := io.Pipe() + outR, outW := io.Pipe() + t.Cleanup(func() { + _ = inW.Close() + _ = outW.Close() + _ = inR.Close() + _ = outR.Close() + }) + + // Drain peer output so the connection never blocks on a write. + go func() { _, _ = io.Copy(io.Discard, outR) }() + + c := NewConnection(func(ctx context.Context, method string, params json.RawMessage) (any, *RequestError) { + return nil, nil + }, outW, inR) + + discard := slog.New(slog.NewTextHandler(io.Discard, nil)) + // Install before any input arrives so the parse errors below stay off stderr. + c.SetLogger(discard) + + const iterations = 100 + + var wg sync.WaitGroup + wg.Add(1) + go func() { + defer wg.Done() + for i := 0; i < iterations; i++ { + if _, err := inW.Write([]byte("not json\n")); err != nil { + return + } + } + }() + + for i := 0; i < iterations; i++ { + c.SetLogger(discard) + } + wg.Wait() +}