sirupsen / logrus

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

Data race in hooks.test package #1395

Closed kiashok closed 1 year ago

kiashok commented 1 year ago

Hi,

I was extending a certain function in windows platform matcher code in containerd which might be exposing a data race in hooks.test package:

Link to logs: https://github.com/containerd/containerd/actions/runs/5602781682/job/15178272751?pr=8778

DATA RACE:

WARNING: DATA RACE Read at 0x00c0003d5703 by goroutine 358: testing.(*common).logDepth()

=== FAIL: . TestTransferEcho (0.07s) C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:992 +0xc4 testing.(common).log() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:985 +0x84 testing.(common).Log() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1026 +0x5b testing.(T).Log() :1 +0x55 github.com/containerd/containerd/log/logtest.(testHook).Fire() D:/a/containerd/containerd/src/github.com/containerd/containerd/log/logtest/log_hook.go:47 +0x1f0 github.com/sirupsen/logrus.LevelHooks.Fire() D:/a/containerd/containerd/pkg/mod/github.com/sirupsen/logrus@v1.9.3/hooks.go:28 +0xbd github.com/sirupsen/logrus.(Entry).fireHooks() D:/a/containerd/containerd/pkg/mod/github.com/sirupsen/logrus@v1.9.3/entry.go:280 +0x316 github.com/sirupsen/logrus.(Entry).log() D:/a/containerd/containerd/pkg/mod/github.com/sirupsen/logrus@v1.9.3/entry.go:242 +0x859 github.com/sirupsen/logrus.(Entry).Log() D:/a/containerd/containerd/pkg/mod/github.com/sirupsen/logrus@v1.9.3/entry.go:304 +0x8b github.com/sirupsen/logrus.(Entry).Logf() D:/a/containerd/containerd/pkg/mod/github.com/sirupsen/logrus@v1.9.3/entry.go:349 +0xc4 github.com/sirupsen/logrus.(Entry).Errorf() D:/a/containerd/containerd/pkg/mod/github.com/sirupsen/logrus@v1.9.3/entry.go:378 +0x64 github.com/containerd/containerd/pkg/transfer/archive.(ImageExportStream).MarshalAny.func1() D:/a/containerd/containerd/src/github.com/containerd/containerd/pkg/transfer/archive/exporter.go:122 +0x187

Previous write at 0x00c0003d5703 by goroutine 315: testing.tRunner.func1() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1563 +0x82d runtime.deferreturn() C:/hostedtoolcache/windows/go/1.20.6/x64/src/runtime/panic.go:476 +0x32 testing.(*T).Run.func1() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1629 +0x47

Goroutine 358 (running) created at: github.com/containerd/containerd/pkg/transfer/archive.(ImageExportStream).MarshalAny() D:/a/containerd/containerd/src/github.com/containerd/containerd/pkg/transfer/archive/exporter.go:120 +0x21a github.com/containerd/containerd/pkg/transfer/proxy.(proxyTransferrer).marshalAny() D:/a/containerd/containerd/src/github.com/containerd/containerd/pkg/transfer/proxy/transfer.go:115 +0x105 github.com/containerd/containerd/pkg/transfer/proxy.(proxyTransferrer).Transfer() D:/a/containerd/containerd/src/github.com/containerd/containerd/pkg/transfer/proxy/transfer.go:94 +0x3f8 github.com/containerd/containerd.(Client).Transfer() D:/a/containerd/containerd/src/github.com/containerd/containerd/transfer.go:41 +0x32b github.com/containerd/containerd/integration/client.newImportExportEcho.func1() D:/a/containerd/containerd/src/github.com/containerd/containerd/integration/client/transfer_test.go:48 +0x517 testing.tRunner() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1576 +0x216 testing.(*T).Run.func1() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1629 +0x47

Goroutine 315 (finished) created at: testing.(T).Run() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1629 +0x805 testing.runTests.func1() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:2036 +0x8d testing.tRunner() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1576 +0x216 testing.runTests() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:2034 +0x87c testing.(M).Run() C:/hostedtoolcache/windows/go/1.20.6/x64/src/testing/testing.go:1906 +0xb44 github.com/containerd/containerd/integration/client.TestMain() D:/a/containerd/containerd/src/github.com/containerd/containerd/integration/client/client_test.go:164 +0x12c4 main.main() _testmain.go:195 +0x324 The code pointed to indicates a possible race which outputting logs. While running these tests locally on windows, I see that these tests are skipped altogether. I've investigated the transfer service code and doesn't look like it could be generating the race either.

I see that there were a few data races were fixed in the past few months. Could this be race in hooks.test?

Github issue on containerd: https://github.com/containerd/containerd/issues/8853

kiashok commented 1 year ago

@sirupsen any thoughts?

github-actions[bot] commented 1 year ago

This issue is stale because it has been open for 30 days with no activity.

github-actions[bot] commented 1 year ago

This issue was closed because it has been inactive for 14 days since being marked as stale.