From d763473f0f5bc88c029f2abc796d15dd9aa3e24b Mon Sep 17 00:00:00 2001 From: Bas van Beek Date: Fri, 8 Sep 2023 11:56:49 +0200 Subject: [PATCH] fix race conditions in scope manager when uninitialized (#21) --- scope/scope.go | 22 +++++++++++++++++----- scope/scope_test.go | 34 ++++++++++++++++++++++++++++++++++ 2 files changed, 51 insertions(+), 5 deletions(-) diff --git a/scope/scope.go b/scope/scope.go index 3a45db4..e232f6b 100644 --- a/scope/scope.go +++ b/scope/scope.go @@ -134,7 +134,9 @@ func (s *scope) With(keyValuePairs ...interface{}) telemetry.Logger { sc.kvs = append(sc.kvs, k, keyValuePairs[i+1]) } } + lock.Lock() uninitialized[s.name] = append(uninitialized[s.name], sc) + lock.Unlock() return sc } @@ -147,7 +149,9 @@ func (s *scope) Context(ctx context.Context) telemetry.Logger { sc := s.Clone() sc.(*scope).ctx = ctx + lock.Lock() uninitialized[s.name] = append(uninitialized[s.name], sc.(*scope)) + lock.Unlock() return sc } @@ -159,7 +163,9 @@ func (s *scope) Metric(m telemetry.Metric) telemetry.Logger { sc := s.Clone() sc.(*scope).metric = m + lock.Lock() uninitialized[s.name] = append(uninitialized[s.name], sc.(*scope)) + lock.Unlock() return sc } @@ -226,7 +232,7 @@ func Register(name, description string) Scope { name = strings.ToLower(strings.Trim(name, "\r\n\t ")) sc, ok := scopes[name] if !ok { - level := int32(DefaultLevel()) + level := int32(defaultLevel()) sc = &scope{ name: name, description: description, @@ -249,11 +255,10 @@ func Register(name, description string) Scope { // Find a scoped logger by its name. func Find(name string) (Scope, bool) { - lock.Lock() - defer lock.Unlock() - name = strings.ToLower(strings.Trim(name, "\r\n\t ")) + lock.Lock() s, ok := scopes[name] + lock.Unlock() return s, ok } @@ -303,7 +308,7 @@ func PrintRegistered() { fmt.Printf("- %-*s [%-5s] %s\n", pad, "default", - DefaultLevel().String(), + defaultLevel().String(), "", ) for _, n := range names { @@ -343,6 +348,13 @@ func SetDefaultLevel(lvl telemetry.Level) { // DefaultLevel returns the logging level used for new scopes. func DefaultLevel() telemetry.Level { + lock.Lock() + defer lock.Unlock() + + return defaultLevel() +} + +func defaultLevel() telemetry.Level { if defaultLogger != nil { return defaultLogger.Level() } diff --git a/scope/scope_test.go b/scope/scope_test.go index b0f514c..f1d6a79 100644 --- a/scope/scope_test.go +++ b/scope/scope_test.go @@ -20,12 +20,46 @@ import ( "errors" "fmt" "io" + "strconv" + "sync" "testing" "github.com/tetratelabs/telemetry" "github.com/tetratelabs/telemetry/function" ) +func TestParallel(t *testing.T) { + logger := Register("root", "root scope") + ctx := context.Background() + wg := sync.WaitGroup{} + routines := 100 + wg.Add(4 * routines) + m := &mockMetric{} + for i := 0; i < routines; i++ { + scopeName := strconv.Itoa(i - i%2) + go func() { + l := logger.Context(ctx).Metric(m).With("key", "value") + l.Debug("test log line") + wg.Done() + }() + go func() { + Register(scopeName, "test scope") + wg.Done() + }() + go func() { + lvl := DefaultLevel() + logger.Debug(strconv.Itoa(int(lvl))) + wg.Done() + }() + go func() { + SetDefaultLevel(telemetry.LevelInfo) + wg.Done() + }() + } + wg.Wait() + cleanup() +} + func TestLogger(t *testing.T) { emitter := func(w io.Writer) function.Emit { return func(level telemetry.Level, msg string, err error, values function.Values) {