mindersec / minder

Software Supply Chain Security Platform
https://minder-docs.stacklok.dev/
Apache License 2.0
290 stars 41 forks source link

Data Race in `eventer_test.go/TestEventer` #2506

Closed Vyom-Yadav closed 3 months ago

Vyom-Yadav commented 8 months ago

Describe the issue

From https://github.com/stacklok/minder/actions/runs/8162121805/job/22312401262

Though this run was for #2475, there is no logic added to the eventer in that PR that should cause a data race.

=== RUN   TestEventer
=== PAUSE TestEventer
=== CONT  TestEventer
=== RUN   TestEventer/single_topic
=== PAUSE TestEventer/single_topic
=== RUN   TestEventer/two_subscribers
=== PAUSE TestEventer/two_subscribers
=== RUN   TestEventer/two_subscribers_to_topic
=== PAUSE TestEventer/two_subscribers_to_topic
=== RUN   TestEventer/handler_fails,_message_goes_to_DLQ
=== PAUSE TestEventer/handler_fails,_message_goes_to_DLQ
=== CONT  TestEventer/single_topic
=== CONT  TestEventer/handler_fails,_message_goes_to_DLQ
=== CONT  TestEventer/two_subscribers_to_topic
=== NAME  TestEventer/single_topic
    eventer_test.go:192: published event on "a"
    eventer_test.go:199: Expected 0 events
=== CONT  TestEventer/two_subscribers
==================
WARNING: DATA RACE
Write at 0x00c00019a250 by goroutine 10:
  runtime.closechan()
      /opt/hostedtoolcache/go/1.21.7/x64/src/runtime/chan.go:357 +0x0
  github.com/stacklok/minder/internal/events_test.TestEventer.func2.2()
      /home/runner/work/minder/minder/internal/events/eventer_test.go:164 +0x33
  runtime.deferreturn()
      /opt/hostedtoolcache/go/1.21.7/x64/src/runtime/panic.go:477 +0x30
  testing.tRunner()
      /opt/hostedtoolcache/go/1.21.7/x64/src/testing/testing.go:1595 +0x261
  testing.(*T).Run.func1()
      /opt/hostedtoolcache/go/1.21.7/x64/src/testing/testing.go:1648 +0x44

Previous read at 0x00c00019a250 by goroutine 52:
  runtime.chansend()
      /opt/hostedtoolcache/go/1.21.7/x64/src/runtime/chan.go:160 +0x0
  github.com/stacklok/minder/internal/events_test.fakeHandler.func1()
      /home/runner/work/minder/minder/internal/events/eventer_test.go:64 +0x545
  github.com/stacklok/minder/internal/events.(*Eventer).Register.func1()
      /home/runner/work/minder/minder/internal/events/eventer.go:439 +0x93
  github.com/ThreeDotsLabs/watermill/message.(*Router).AddNoPublisherHandler.func1()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router.go:334 +0x34
  github.com/ThreeDotsLabs/watermill/message/router/middleware.CorrelationID.func1()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router/middleware/correlation.go:34 +0x49
  github.com/ThreeDotsLabs/watermill/message/router/middleware.Retry.Middleware-fm.Retry.Middleware.func1()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router/middleware/retry.go:41 +0x78
  github.com/ThreeDotsLabs/watermill/message/router/middleware.poisonQueue.Middleware-fm.poisonQueue.Middleware.func1()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router/middleware/poison.go:99 +0x13a
  github.com/stacklok/minder/internal/events.Setup.recordMetrics.func3.1()
      /home/runner/work/minder/minder/internal/events/eventer.go:266 +0x146
  github.com/ThreeDotsLabs/watermill/components/metrics.HandlerPrometheusMetricsMiddleware.Middleware-fm.HandlerPrometheusMetricsMiddleware.Middleware.func1()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/components/metrics/handler.go:58 +0x245
  github.com/ThreeDotsLabs/watermill/message.(*handler).handleMessage()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router.go:775 +0x28e
  github.com/ThreeDotsLabs/watermill/message.(*handler).run.func2()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router.go:620 +0x4f

Goroutine 10 (running) created at:
  testing.(*T).Run()
      /opt/hostedtoolcache/go/1.21.7/x64/src/testing/testing.go:1648 +0x845
  github.com/stacklok/minder/internal/events_test.TestEventer()
      /home/runner/work/minder/minder/internal/events/eventer_test.go:161 +0x16e4
  testing.tRunner()
      /opt/hostedtoolcache/go/1.21.7/x64/src/testing/testing.go:1595 +0x261
  testing.(*T).Run.func1()
      /opt/hostedtoolcache/go/1.21.7/x64/src/testing/testing.go:1648 +0x44

Goroutine 52 (finished) created at:
  github.com/ThreeDotsLabs/watermill/message.(*handler).run()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router.go:620 +0x42a
  github.com/ThreeDotsLabs/watermill/message.(*Router).RunHandlers.func1()
      /home/runner/go/pkg/mod/github.com/!three!dots!labs/watermill@v1.3.5/message/router.go:438 +0xd7
==================
=== NAME  TestEventer/single_topic
    testing.go:1465: race detected during execution of test
=== NAME  TestEventer/handler_fails,_message_goes_to_DLQ
    eventer_test.go:192: published event on "test_dlq"
    eventer_test.go:199: Expected 1 events
    eventer_test.go:201: awaiting event 0
=== NAME  TestEventer/two_subscribers_to_topic
    eventer_test.go:192: published event on "a"
    eventer_test.go:192: published event on "b"
    eventer_test.go:199: Expected 3 events
    eventer_test.go:201: awaiting event 0
    eventer_test.go:201: awaiting event 1
    eventer_test.go:201: awaiting event 2
=== NAME  TestEventer/two_subscribers
    eventer_test.go:192: published event on "a"
    eventer_test.go:192: published event on "b"
    eventer_test.go:192: published event on "a"
    eventer_test.go:199: Expected 3 events
    eventer_test.go:201: awaiting event 0
    eventer_test.go:201: awaiting event 1
    eventer_test.go:201: awaiting event 2
    testing.go:1465: race detected during execution of test
=== NAME  TestEventer/two_subscribers_to_topic
    testing.go:1465: race detected during execution of test
=== NAME  TestEventer/handler_fails,_message_goes_to_DLQ
    testing.go:1465: race detected during execution of test
--- FAIL: TestEventer (0.00s)
    --- FAIL: TestEventer/single_topic (0.01s)
    --- FAIL: TestEventer/two_subscribers (0.01s)
    --- FAIL: TestEventer/two_subscribers_to_topic (0.01s)
    --- FAIL: TestEventer/handler_fails,_message_goes_to_DLQ (0.11s)
FAIL

To Reproduce

No response

What version are you using?

No response

blkt commented 3 months ago

Ran the following command on both main and Vyom's branch, I could not reproduce the issue.

$ go test --race --count 250 ./internal/events/
ok      github.com/stacklok/minder/internal/events  28.815s

Closing the issue as not reproducible.