search

sirupsen / logrus

Structured, pluggable logging for Go.
MIT License
24.76k stars 2.27k forks source link

Fix data race in hooks.test package #1362

Closed FrancoisWagner closed 1 year ago

FrancoisWagner commented 1 year ago

Prior fix:

go test -race -timeout 30s -run ^TestNewLocal$ github.com/sirupsen/logrus/hooks/test
time="2022-12-22T10:57:57+01:00" level=info msg=info
time="2022-12-22T10:57:57+01:00" level=info msg=info
time="2022-12-22T10:57:57+01:00" level=info msg=info
==================
WARNING: DATA RACE
Write at 0x00c00009f4d0 by goroutine 7:
  runtime.mapaccess2_fast32()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/runtime/map_fast32.go:53 +0x1cc
  github.com/sirupsen/logrus.LevelHooks.Add()
      /Users/wfrancoi/Downloads/logrus/hooks.go:20 +0x170
  github.com/sirupsen/logrus/hooks/test.NewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test.go:35 +0x38
  github.com/sirupsen/logrus/hooks/test.TestNewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:102 +0x3b8
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.(*T).Run.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x44

Previous read at 0x00c00009f4d0 by goroutine 8:
  github.com/sirupsen/logrus.(*Entry).fireHooks()
      /Users/wfrancoi/Downloads/logrus/entry.go:274 +0x98
  github.com/sirupsen/logrus.(*Entry).log()
      /Users/wfrancoi/Downloads/logrus/entry.go:242 +0x624
  github.com/sirupsen/logrus.(*Entry).Log()
      /Users/wfrancoi/Downloads/logrus/entry.go:304 +0x84
time="2022-12-22T10:57:57+01:00" level=info msg=info
  github.com/sirupsen/logrus.(*Logger).Log()
      /Users/wfrancoi/Downloads/logrus/logger.go:204 +0x70
  github.com/sirupsen/logrus.(*Logger).Info()
      /Users/wfrancoi/Downloads/logrus/logger.go:226 +0x64
  github.com/sirupsen/logrus/hooks/test.TestNewLocal.func1()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:97 +0x34
  github.com/sirupsen/logrus/hooks/test.TestNewLocal.func3()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:99 +0x48

Goroutine 7 (running) created at:
  testing.(*T).Run()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x560
  testing.runTests.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1839 +0x94
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.runTests()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1837 +0x6c8
  testing.(*M).Run()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1719 +0x878
  main.main()
      _testmain.go:53 +0x2fc

Goroutine 8 (running) created at:
  github.com/sirupsen/logrus/hooks/test.TestNewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:96 +0x2a0
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.(*T).Run.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x44
==================
time="2022-12-22T10:57:57+01:00" level=info msg=info
==================
WARNING: DATA RACE
Read at 0x00c0001340a0 by goroutine 13:
  github.com/sirupsen/logrus.(*Entry).fireHooks()
      /Users/wfrancoi/Downloads/logrus/entry.go:275 +0x170
  github.com/sirupsen/logrus.(*Entry).log()
      /Users/wfrancoi/Downloads/logrus/entry.go:242 +0x624
  github.com/sirupsen/logrus.(*Entry).Log()
      /Users/wfrancoi/Downloads/logrus/entry.go:304 +0x84
  github.com/sirupsen/logrus.(*Logger).Log()
      /Users/wfrancoi/Downloads/logrus/logger.go:204 +0x70
  github.com/sirupsen/logrus.(*Logger).Info()
      /Users/wfrancoi/Downloads/logrus/logger.go:226 +0x64
  github.com/sirupsen/logrus/hooks/test.TestNewLocal.func1()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:97 +0x34
  github.com/sirupsen/logrus/hooks/test.TestNewLocal.func3()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:99 +0x48

Previous write at 0x00c0001340a0 by goroutine 7:
  github.com/sirupsen/logrus.LevelHooks.Add()
      /Users/wfrancoi/Downloads/logrus/hooks.go:20 +0x17c
  github.com/sirupsen/logrus/hooks/test.NewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test.go:35 +0x38
  github.com/sirupsen/logrus/hooks/test.TestNewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:102 +0x3b8
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.(*T).Run.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x44

Goroutine 13 (running) created at:
  github.com/sirupsen/logrus/hooks/test.TestNewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:96 +0x2a0
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.(*T).Run.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x44

Goroutine 7 (running) created at:
  testing.(*T).Run()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x560
  testing.runTests.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1839 +0x94
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.runTests()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1837 +0x6c8
  testing.(*M).Run()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1719 +0x878
  main.main()
      _testmain.go:53 +0x2fc
==================
==================
WARNING: DATA RACE
Read at 0x00c00009b0c0 by goroutine 13:
  github.com/sirupsen/logrus.LevelHooks.Fire()
      /Users/wfrancoi/Downloads/logrus/hooks.go:27 +0x9c
  github.com/sirupsen/logrus.(*Entry).fireHooks()
      /Users/wfrancoi/Downloads/logrus/entry.go:280 +0x238
  github.com/sirupsen/logrus.(*Entry).log()
      /Users/wfrancoi/Downloads/logrus/entry.go:242 +0x624
  github.com/sirupsen/logrus.(*Entry).Log()
      /Users/wfrancoi/Downloads/logrus/entry.go:304 +0x84
  github.com/sirupsen/logrus.(*Logger).Log()
      /Users/wfrancoi/Downloads/logrus/logger.go:204 +0x70
  github.com/sirupsen/logrus.(*Logger).Info()
      /Users/wfrancoi/Downloads/logrus/logger.go:226 +0x64
  github.com/sirupsen/logrus/hooks/test.TestNewLocal.func1()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:97 +0x34
  github.com/sirupsen/logrus/hooks/test.TestNewLocal.func3()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:99 +0x48

Previous write at 0x00c00009b0c0 by goroutine 7:
  github.com/sirupsen/logrus.LevelHooks.Add()
      /Users/wfrancoi/Downloads/logrus/hooks.go:20 +0x110
  github.com/sirupsen/logrus/hooks/test.NewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test.go:35 +0x38
time="2022-12-22T10:57:57+01:00" level=info msg=info
  github.com/sirupsen/logrus/hooks/test.TestNewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:102 +0x3b8
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.(*T).Run.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x44

Goroutine 13 (running) created at:
  github.com/sirupsen/logrus/hooks/test.TestNewLocal()
      /Users/wfrancoi/Downloads/logrus/hooks/test/test_test.go:96 +0x2a0
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.(*T).Run.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x44

Goroutine 7 (running) created at:
  testing.(*T).Run()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1486 +0x560
  testing.runTests.func1()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1839 +0x94
  testing.tRunner()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1439 +0x18c
  testing.runTests()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1837 +0x6c8
  testing.(*M).Run()
      /opt/homebrew/Cellar/go/1.18.4/libexec/src/testing/testing.go:1719 +0x878
  main.main()
      _testmain.go:53 +0x2fc
==================
time="2022-12-22T10:57:57+01:00" level=info msg=info
time="2022-12-22T10:57:57+01:00" level=info msg=info
time="2022-12-22T10:57:57+01:00" level=info msg=info
time="2022-12-22T10:57:57+01:00" level=info msg=info
--- FAIL: TestNewLocal (0.00s)
    testing.go:1312: race detected during execution of test
FAIL
FAIL    github.com/sirupsen/logrus/hooks/test   0.274s
FAIL

After fix:

go test -race -timeout 30s -run ^TestNewLocal$ github.com/sirupsen/logrus/hooks/test
ok      github.com/sirupsen/logrus/hooks/test   0.240s
FrancoisWagner commented 1 year ago

@sirupsen @dgsb could you have a look at this PR?

FrancoisWagner commented 1 year ago

Thanks @sirupsen! Any chance we could have a new patch release with this fix? Thanks!

sirupsen commented 1 year ago

v1.8.2 now has this