Race in test TestProducerGracefulShutdown
Closed this issue · 1 comments
carsonip commented
Race detector found race in TestProducerGracefulShutdown. Most likely not a real race condition but some form of leakage. The hypothesis is that consumer isn't closed properly and logs after test ends.
=== RUN TestProducerGracefulShutdown/AtMostOnceDelivery/sync
==================
WARNING: DATA RACE
Read at 0x00c0000d66c3 by goroutine 12023:
testing.(*common).logDepth()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:998 +0x4c4
testing.(*common).log()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:985 +0xa4
testing.(*common).Logf()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:1036 +0x6a
testing.(*T).Logf()
<autogenerated>:1 +0x75
go.uber.org/zap/zaptest.testingWriter.Write()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/zaptest/logger.go:130 +0x12c
go.uber.org/zap/zaptest.(*testingWriter).Write()
<autogenerated>:1 +0x7e
go.uber.org/zap/zapcore.(*ioCore).Write()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/zapcore/core.go:99 +0x199
go.uber.org/zap/zapcore.(*CheckedEntry).Write()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/zapcore/entry.go:255 +0x2ce
go.uber.org/zap.(*Logger).Debug()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/logger.go:212 +0x6d
github.com/twmb/franz-go/plugin/kzap.(*Logger).Log()
/home/runner/go/pkg/mod/github.com/twmb/franz-go/plugin/kzap@v1.1.2/kzap.go:110 +0x407
github.com/twmb/franz-go/pkg/kgo.(*wrappedLogger).Log()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/logger.go:123 +0xcf
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).readResponse()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:1224 +0x7f5
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).handleResp()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:1436 +0xf6
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).handleResps()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:1426 +0x84
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).waitResp.func1()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:1275 +0xbc
Previous write at 0x00c0000d66c3 by goroutine 11557:
testing.tRunner.func1()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:1563 +0x82d
runtime.deferreturn()
/opt/hostedtoolcache/go/1.20.5/x64/src/runtime/panic.go:476 +0x32
testing.(*T).Run.func1()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:1629 +0x47
Goroutine 12023 (running) created at:
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).waitResp()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:1275 +0x29d
github.com/twmb/franz-go/pkg/kgo.(*broker).handleReq()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:445 +0x1384
github.com/twmb/franz-go/pkg/kgo.(*broker).handleReqs()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:273 +0x107
github.com/twmb/franz-go/pkg/kgo.(*broker).do.func1()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.13.5/pkg/kgo/broker.go:247 +0xb4
Goroutine 11557 (finished) created at:
testing.(*T).Run()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:1629 +0x805
github.com/elastic/apm-queue/kafka.TestProducerGracefulShutdown()
/home/runner/work/apm-queue/apm-queue/kafka/producer_test.go:243 +0xb8
testing.tRunner()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:1576 +0x216
testing.(*T).Run.func1()
/opt/hostedtoolcache/go/1.20.5/x64/src/testing/testing.go:1629 +0x47
==================
kruskall commented
Just got another one:
=== RUN TestProducerGracefulShutdown/AtMostOnceDelivery
==================
WARNING: DATA RACE
Read at 0x00c0003c6ba3 by goroutine 12229:
testing.(*common).logDepth()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:998 +0x4c4
testing.(*common).log()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:985 +0xa4
testing.(*common).Logf()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:1036 +0x6a
testing.(*T).Logf()
<autogenerated>:1 +0x75
go.uber.org/zap/zaptest.testingWriter.Write()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/zaptest/logger.go:130 +0x12c
go.uber.org/zap/zaptest.(*testingWriter).Write()
<autogenerated>:1 +0x7e
go.uber.org/zap/zapcore.(*ioCore).Write()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/zapcore/core.go:99 +0x199
go.uber.org/zap/zapcore.(*CheckedEntry).Write()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/zapcore/entry.go:255 +0x2ce
go.uber.org/zap.(*Logger).Debug()
/home/runner/go/pkg/mod/go.uber.org/zap@v1.24.0/logger.go:212 +0x6d
github.com/twmb/franz-go/plugin/kzap.(*Logger).Log()
/home/runner/go/pkg/mod/github.com/twmb/franz-go/plugin/kzap@v1.1.2/kzap.go:110 +0x407
github.com/twmb/franz-go/pkg/kgo.(*wrappedLogger).Log()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/logger.go:123 +0xcf
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).readResponse()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:1236 +0x7f5
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).handleResp()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:1448 +0xf6
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).handleResps()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:1438 +0x84
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).waitResp.func1()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:1287 +0xbc
Previous write at 0x00c0003c6ba3 by goroutine 11763:
testing.tRunner.func1()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:1563 +0x82d
runtime.deferreturn()
/opt/hostedtoolcache/go/1.20.6/x64/src/runtime/panic.go:476 +0x32
testing.(*T).Run.func1()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:1629 +0x47
Goroutine 12229 (running) created at:
github.com/twmb/franz-go/pkg/kgo.(*brokerCxn).waitResp()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:1287 +0x29d
github.com/twmb/franz-go/pkg/kgo.(*broker).handleReq()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:457 +0x1384
github.com/twmb/franz-go/pkg/kgo.(*broker).handleReqs()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:285 +0x107
github.com/twmb/franz-go/pkg/kgo.(*broker).do.func1()
/home/runner/go/pkg/mod/github.com/twmb/franz-go@v1.14.3/pkg/kgo/broker.go:259 +0xb4
Goroutine 11763 (finished) created at:
testing.(*T).Run()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:1629 +0x805
github.com/elastic/apm-queue/kafka.TestProducerGracefulShutdown()
/home/runner/work/apm-queue/apm-queue/kafka/producer_test.go:278 +0xb8
testing.tRunner()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:1576 +0x216
testing.(*T).Run.func1()
/opt/hostedtoolcache/go/1.20.6/x64/src/testing/testing.go:1629 +0x47
==================
https://github.com/elastic/apm-queue/actions/runs/5813193056/job/15760205545?pr=264