From b9d451406decb5cab037cc3a473547e0eb940370 Mon Sep 17 00:00:00 2001 From: georlav Date: Mon, 4 Mar 2019 20:38:10 +0200 Subject: [PATCH 1/2] fix ReportCaller race condition --- entry.go | 2 ++ logrus_test.go | 17 +++++++++++++++++ 2 files changed, 19 insertions(+) diff --git a/entry.go b/entry.go index fd377286c..4ca6081d3 100644 --- a/entry.go +++ b/entry.go @@ -206,7 +206,9 @@ func (entry Entry) log(level Level, msg string) { entry.Level = level entry.Message = msg if entry.Logger.ReportCaller { + entry.Logger.mu.Lock() entry.Caller = getCaller() + entry.Logger.mu.Unlock() } entry.fireHooks() diff --git a/logrus_test.go b/logrus_test.go index dfa053bbd..72b6ea254 100644 --- a/logrus_test.go +++ b/logrus_test.go @@ -743,3 +743,20 @@ func TestReportCallerOnTextFormatter(t *testing.T) { l.Formatter.(*TextFormatter).DisableColors = true l.WithFields(Fields{"func": "func", "file": "file"}).Info("test") } + +func TestSetReportCallerRace(t *testing.T) { + l := New() + l.Out = ioutil.Discard + l.SetReportCaller(true) + + var wg sync.WaitGroup + wg.Add(100) + + for i := 0; i < 100; i++ { + go func() { + l.Error("Some Error") + wg.Done() + }() + } + wg.Wait() +} From cf1b9fd15e80ce9ce658546d333f031de2d08331 Mon Sep 17 00:00:00 2001 From: David Bariod Date: Wed, 6 Mar 2019 14:08:02 +0100 Subject: [PATCH 2/2] fix sync.Once usage instead of adding a mutex lock --- entry.go | 17 +++++++++-------- 1 file changed, 9 insertions(+), 8 deletions(-) diff --git a/entry.go b/entry.go index 4ca6081d3..191621487 100644 --- a/entry.go +++ b/entry.go @@ -156,20 +156,23 @@ func getPackageName(f string) string { // getCaller retrieves the name of the first non-logrus calling function func getCaller() *runtime.Frame { - // Restrict the lookback frames to avoid runaway lookups - pcs := make([]uintptr, maximumCallerDepth) - depth := runtime.Callers(minimumCallerDepth, pcs) - frames := runtime.CallersFrames(pcs[:depth]) // cache this package's fully-qualified name callerInitOnce.Do(func() { - logrusPackage = getPackageName(runtime.FuncForPC(pcs[0]).Name()) + pcs := make([]uintptr, 2) + _ = runtime.Callers(0, pcs) + logrusPackage = getPackageName(runtime.FuncForPC(pcs[1]).Name()) // now that we have the cache, we can skip a minimum count of known-logrus functions - // XXX this is dubious, the number of frames may vary store an entry in a logger interface + // XXX this is dubious, the number of frames may vary minimumCallerDepth = knownLogrusFrames }) + // Restrict the lookback frames to avoid runaway lookups + pcs := make([]uintptr, maximumCallerDepth) + depth := runtime.Callers(minimumCallerDepth, pcs) + frames := runtime.CallersFrames(pcs[:depth]) + for f, again := frames.Next(); again; f, again = frames.Next() { pkg := getPackageName(f.Function) @@ -206,9 +209,7 @@ func (entry Entry) log(level Level, msg string) { entry.Level = level entry.Message = msg if entry.Logger.ReportCaller { - entry.Logger.mu.Lock() entry.Caller = getCaller() - entry.Logger.mu.Unlock() } entry.fireHooks()