From a360b4ca8c180414d19eae8d7c883771534ea03b Mon Sep 17 00:00:00 2001 From: Tom Fleet Date: Mon, 6 Apr 2026 12:31:26 +0100 Subject: [PATCH 1/2] Fix attrs being silently dropped on child loggers --- log.go | 4 +-- log_test.go | 75 ++++++++++++++++++++++++++++++++++++++++++----------- 2 files changed, 62 insertions(+), 17 deletions(-) diff --git a/log.go b/log.go index c934f48..86c7ee4 100644 --- a/log.go +++ b/log.go @@ -178,6 +178,7 @@ func (l *Logger) clone() *Logger { timeFunc: l.timeFunc, timeFormat: l.timeFormat, prefix: l.prefix, + attrs: l.attrs, level: l.level, mu: l.mu, } @@ -216,8 +217,7 @@ func putBuffer(buf *bytes.Buffer) { // Approx 65kb const maxSize = 64 << 10 if buf.Cap() > maxSize { - // Make the buffer nil so GC cleans it up - buf = nil + return } bufPool.Put(buf) diff --git a/log_test.go b/log_test.go index e05938e..16b73e9 100644 --- a/log_test.go +++ b/log_test.go @@ -147,6 +147,8 @@ func TestDebug(t *testing.T) { } func TestWith(t *testing.T) { + hue.Enabled(false) // Force no color + // Constantly return the same time fixedTime := func() time.Time { fixed, err := time.Parse(time.RFC3339, "2025-04-01T13:34:03Z") @@ -157,24 +159,67 @@ func TestWith(t *testing.T) { fixedTimeString := fixedTime().Format(time.RFC3339) - buf := &bytes.Buffer{} - - logger := log.New(buf, log.TimeFunc(fixedTime)) - - logger.Info("I'm an info message") - - sub := logger.With( - slog.Bool("sub", true), - slog.String("hello", "world"), - ) + tests := []struct { + name string + fn func(logger *log.Logger) string // Exercise the logger, return output + want string + }{ + { + name: "attrs appear on sub logger", + fn: func(logger *log.Logger) string { + buf := &bytes.Buffer{} + l := log.New(buf, log.TimeFunc(fixedTime)) + l.Info("I'm an info message") + sub := l.With(slog.Bool("sub", true), slog.String("hello", "world")) + sub.Info("I'm also an info message") + + return buf.String() + }, + want: "[TIME] INFO: I'm an info message\n[TIME] INFO: I'm also an info message sub=true hello=world\n", + }, + { + name: "chained With preserves earlier attrs", + fn: func(logger *log.Logger) string { + buf := &bytes.Buffer{} + l := log.New(buf, log.TimeFunc(fixedTime)) + l.With(slog.String("a", "1")).With(slog.String("b", "2")).Info("chained") - sub.Info("I'm also an info message") + return buf.String() + }, + want: "[TIME] INFO: chained a=1 b=2\n", + }, + { + name: "Prefixed preserves attrs from With", + fn: func(logger *log.Logger) string { + buf := &bytes.Buffer{} + l := log.New(buf, log.TimeFunc(fixedTime)) + l.With(slog.String("a", "1")).Prefixed("svc").Info("prefixed") - got := buf.String() - got = strings.TrimSpace(strings.ReplaceAll(got, fixedTimeString, "[TIME]")) + "\n" + return buf.String() + }, + want: "[TIME] INFO svc: prefixed a=1\n", + }, + { + name: "parent logger not affected by child With", + fn: func(logger *log.Logger) string { + buf := &bytes.Buffer{} + l := log.New(buf, log.TimeFunc(fixedTime)) + _ = l.With(slog.String("child", "attr")) + l.Info("parent should have no attrs") + + return buf.String() + }, + want: "[TIME] INFO: parent should have no attrs\n", + }, + } - want := "[TIME] INFO: I'm an info message\n[TIME] INFO: I'm also an info message sub=true hello=world\n" - test.Diff(t, got, want) + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + got := tt.fn(nil) + got = strings.ReplaceAll(got, fixedTimeString, "[TIME]") + test.Diff(t, got, tt.want) + }) + } } func TestRace(t *testing.T) { From 070da807bb34766a8d5710812ee375d432dd338b Mon Sep 17 00:00:00 2001 From: Tom Fleet Date: Mon, 6 Apr 2026 12:37:02 +0100 Subject: [PATCH 2/2] Clean up un-needed nil --- Taskfile.yml | 2 +- log_test.go | 12 ++++++------ 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/Taskfile.yml b/Taskfile.yml index 70a0ec7..454ccb4 100644 --- a/Taskfile.yml +++ b/Taskfile.yml @@ -69,7 +69,7 @@ tasks: - .golangci.yml preconditions: - sh: command -v golangci-lint - msg: staticcheck not installed, run `brew install golangci-lint` + msg: golangci-lint not installed, run `brew install golangci-lint` - sh: command -v typos msg: requires typos-cli, run `brew install typos-cli` diff --git a/log_test.go b/log_test.go index 16b73e9..fedf34f 100644 --- a/log_test.go +++ b/log_test.go @@ -161,12 +161,12 @@ func TestWith(t *testing.T) { tests := []struct { name string - fn func(logger *log.Logger) string // Exercise the logger, return output + fn func() string // Exercise the logger, return output want string }{ { name: "attrs appear on sub logger", - fn: func(logger *log.Logger) string { + fn: func() string { buf := &bytes.Buffer{} l := log.New(buf, log.TimeFunc(fixedTime)) l.Info("I'm an info message") @@ -179,7 +179,7 @@ func TestWith(t *testing.T) { }, { name: "chained With preserves earlier attrs", - fn: func(logger *log.Logger) string { + fn: func() string { buf := &bytes.Buffer{} l := log.New(buf, log.TimeFunc(fixedTime)) l.With(slog.String("a", "1")).With(slog.String("b", "2")).Info("chained") @@ -190,7 +190,7 @@ func TestWith(t *testing.T) { }, { name: "Prefixed preserves attrs from With", - fn: func(logger *log.Logger) string { + fn: func() string { buf := &bytes.Buffer{} l := log.New(buf, log.TimeFunc(fixedTime)) l.With(slog.String("a", "1")).Prefixed("svc").Info("prefixed") @@ -201,7 +201,7 @@ func TestWith(t *testing.T) { }, { name: "parent logger not affected by child With", - fn: func(logger *log.Logger) string { + fn: func() string { buf := &bytes.Buffer{} l := log.New(buf, log.TimeFunc(fixedTime)) _ = l.With(slog.String("child", "attr")) @@ -215,7 +215,7 @@ func TestWith(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - got := tt.fn(nil) + got := tt.fn() got = strings.ReplaceAll(got, fixedTimeString, "[TIME]") test.Diff(t, got, tt.want) })