fix(log): WithContext() changed the ctx field of the parent log.Filter (#3069)

* fix(log): `WithContext()` changed the ctx field of the parent log.Filter

* test(log): add concurrence test for `WithContext()`

* fix(log): concurrence problem of `Filter`

---------

Co-authored-by: 包子 <baozhecheng@foxmail.com>

log/filter.go

@@ -1,7 +1,5 @@
 package log
 
-import "context"
-
 // FilterOption is filter option.
 type FilterOption func(*Filter)
 
@@ -41,7 +39,6 @@ func FilterFunc(f func(level Level, keyvals ...interface{}) bool) FilterOption {
 
 // Filter is a logger filter.
 type Filter struct {
-	ctx    context.Context
 	logger Logger
 	level  Level
 	key    map[interface{}]struct{}
@@ -70,9 +67,6 @@ func (f *Filter) Log(level Level, keyvals ...interface{}) error {
 	// prefixkv contains the slice of arguments defined as prefixes during the log initialization
 	var prefixkv []interface{}
 	l, ok := f.logger.(*logger)
-	if ok {
-		l.ctx = f.ctx
-	}
 	if ok && len(l.prefix) > 0 {
 		prefixkv = make([]interface{}, 0, len(l.prefix))
 		prefixkv = append(prefixkv, l.prefix...)

log/filter_test.go

@@ -5,7 +5,9 @@ import (
 	"context"
 	"io"
 	"strings"
+	"sync"
 	"testing"
+	"time"
 )
 
 func TestFilterAll(_ *testing.T) {
@@ -172,3 +174,52 @@ func TestFilterWithContext(t *testing.T) {
 		t.Error("don't read ctx value")
 	}
 }
+
+type traceIDKey struct{}
+
+func setTraceID(ctx context.Context, tid string) context.Context {
+	return context.WithValue(ctx, traceIDKey{}, tid)
+}
+
+func traceIDValuer() Valuer {
+	return func(ctx context.Context) any {
+		if ctx == nil {
+			return ""
+		}
+		if tid := ctx.Value(traceIDKey{}); tid != nil {
+			return tid
+		}
+		return ""
+	}
+}
+
+func TestFilterWithContextConcurrent(t *testing.T) {
+	var buf bytes.Buffer
+	pctx := context.Background()
+	l := NewFilter(
+		With(NewStdLogger(&buf), "trace-id", traceIDValuer()),
+		FilterLevel(LevelInfo),
+	)
+
+	var wg sync.WaitGroup
+	wg.Add(1)
+	go func() {
+		defer wg.Done()
+		time.Sleep(time.Second)
+		NewHelper(l).Info("done1")
+	}()
+
+	wg.Add(1)
+	go func() {
+		defer wg.Done()
+		tid := "world"
+		ctx := setTraceID(pctx, tid)
+		NewHelper((WithContext(ctx, l))).Info("done2")
+	}()
+
+	wg.Wait()
+	expected := "INFO trace-id=world msg=done2\nINFO trace-id= msg=done1\n"
+	if got := buf.String(); got != expected {
+		t.Errorf("got: %#v", got)
+	}
+}

log/log.go

@@ -50,28 +50,16 @@ func With(l Logger, kv ...interface{}) Logger {
 // WithContext returns a shallow copy of l with its context changed
 // to ctx. The provided ctx must be non-nil.
 func WithContext(ctx context.Context, l Logger) Logger {
-	c, ok := l.(*logger)
-	if ok {
-		return &logger{
-			logger:    c.logger,
-			prefix:    c.prefix,
-			hasValuer: c.hasValuer,
-			ctx:       ctx,
-		}
+	switch v := l.(type) {
+	default:
+		return &logger{logger: l, ctx: ctx}
+	case *logger:
+		lv := *v
+		lv.ctx = ctx
+		return &lv
+	case *Filter:
+		fv := *v
+		fv.logger = WithContext(ctx, fv.logger)
+		return &fv
 	}
-
-	f, ok := l.(*Filter)
-	if ok {
-		f.ctx = ctx
-		return &Filter{
-			ctx:    ctx,
-			logger: f.logger,
-			level:  f.level,
-			key:    f.key,
-			value:  f.value,
-			filter: f.filter,
-		}
-	}
-
-	return &logger{logger: l, ctx: ctx}
 }

log/log_test.go

@@ -1,7 +1,6 @@
 package log
 
 import (
-	"context"
 	"testing"
 )
 
@@ -11,7 +10,3 @@ func TestInfo(_ *testing.T) {
 	logger = With(logger, "caller", DefaultCaller)
 	_ = logger.Log(LevelInfo, "key1", "value1")
 }
-
-func TestWithContext(_ *testing.T) {
-	WithContext(context.Background(), nil)
-}