Skip to content

fix(vfsevents): remove sleep-based race in TestNonVersionedBucketMetadata - #339

Merged
funkyshu merged 1 commit into
mainfrom
fix/313-s3events-race-nonversioned
Jul 16, 2026
Merged

fix(vfsevents): remove sleep-based race in TestNonVersionedBucketMetadata#339
funkyshu merged 1 commit into
mainfrom
fix/313-s3events-race-nonversioned

Conversation

@funkyshu

Copy link
Copy Markdown
Member

Summary

Validates #313.

The originally reported TestS3WatcherTestSuite/TestStart race (mock ReceiveMessage unexpected-call panic) was already fixed in contrib/vfsevents v1.1.5 via Maybe() expectations on the poll goroutine's ReceiveMessage call. Confirmed by running go test -race -run TestS3WatcherTestSuite/TestStart -count=200 ./watchers/s3events/... on current main — 0 failures.

However, stress-testing the whole s3events suite (-race -count=200) turned up a still-live, related data race in TestNonVersionedBucketMetadata: it starts pollOnce in a goroutine and then reads the handler-populated receivedEvent after a fixed time.Sleep(50ms), instead of synchronizing on the handler actually firing. This races with the goroutine's write and is flagged reliably by -race.

Changes

  • TestNonVersionedBucketMetadata: replaced the time.Sleep wait with the same eventReceived channel + select synchronization pattern already used by the neighboring TestEnhancedMetadata test.
  • Removed a harmless duplicate s.sqsClient = mocks.NewSqsClient(s.T()) line in SetupTest.
  • Updated contrib/vfsevents/CHANGELOG.md under [Unreleased].

Test plan

  • go test -race -run TestS3WatcherTestSuite -count=200 ./contrib/vfsevents/watchers/s3events/... — passes cleanly (previously failed intermittently on TestNonVersionedBucketMetadata due to the race).
  • go build ./... && go vet ./... for contrib/vfsevents — clean.
  • golangci-lint run ./watchers/s3events/... — only a pre-existing, unrelated nolintlint finding in s3events.go (not touched by this PR).

Note

While stress-testing, I also found similar sleep-based races in contrib/vfsevents/watchers/gcsevents tests (TestEnhancedMetadata, TestOverwriteEventSuppression, TestRetryBackoffTiming). Confirmed pre-existing on main and unrelated to this PR/issue — will file a separate issue to track those.

Made with Cursor

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR fixes a race/flakiness source in the contrib/vfsevents S3 events watcher tests by removing a sleep-based wait and replacing it with explicit synchronization, so the test no longer reads shared state before the polling goroutine completes.

Changes:

  • Reworked TestNonVersionedBucketMetadata to wait for pollOnce completion via a result channel (instead of time.Sleep).
  • Removed a duplicate mocks.NewSqsClient(...) initialization in SetupTest.
  • Added a [Unreleased] changelog entry documenting the test fix in contrib/vfsevents.

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated 1 comment.

File Description
contrib/vfsevents/watchers/s3events/s3events_test.go Removes sleep-based timing and synchronizes with the pollOnce goroutine to eliminate a data race/flaky assertions.
contrib/vfsevents/CHANGELOG.md Documents the test race fix under [Unreleased].

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread contrib/vfsevents/watchers/s3events/s3events_test.go
…data

Validates #313: the originally reported TestS3WatcherTestSuite/TestStart
race (unexpected mock call panic) was already fixed in v1.1.5 via
Maybe() expectations. Stress-testing the s3events package with
-race -count=200 surfaced a related, still-live data race in
TestNonVersionedBucketMetadata: it started pollOnce in a goroutine and
read the handler-set receivedEvent after a fixed time.Sleep(50ms)
instead of synchronizing on the goroutine's completion, racing with
the goroutine's write.

Fixed by waiting on pollOnce's own completion via an error channel,
rather than only synchronizing on the handler firing. This closes a
residual race window where the goroutine's DeleteMessage mock call
could still be in flight when the subtest (and its mock assertions)
returned, and it lets the test assert pollOnce returned without error.
Also removed a duplicate mocks.NewSqsClient(s.T()) assignment in
SetupTest.

Verified: go test -race -run TestS3WatcherTestSuite -count=200 now
passes cleanly (was previously failing intermittently).
@funkyshu
funkyshu force-pushed the fix/313-s3events-race-nonversioned branch from 86e2fae to 300ebeb Compare July 16, 2026 07:19
@c2fo-cibot c2fo-cibot Bot added size/M Denotes a PR that changes 30-99 lines and removed size/S Denotes a PR that changes 10-29 lines labels Jul 16, 2026
@funkyshu
funkyshu merged commit 0c48476 into main Jul 16, 2026
34 checks passed
@funkyshu
funkyshu deleted the fix/313-s3events-race-nonversioned branch July 16, 2026 07:23
funkyshu added a commit that referenced this pull request Jul 16, 2026
Fixes #340. Same root cause as #339: TestEnhancedMetadata,
TestOverwriteEventSuppression, and TestRetryBackoffTiming each start
receiveWithRetry in a goroutine and then read test-local state
(receivedEvent/receivedEvents) after a fixed time.Sleep(50ms), racing
with the goroutine's write.

Since RetryConfig.Enabled defaults to false, receiveWithRetry makes a
single receive() call and returns, matching each test's Once() mock
expectations. Fixed by waiting on receiveWithRetry's own completion via
an error channel (rather than a sleep or a handler-only signal), and
asserting it returns without error. On the timeout path, cancel the
context immediately and give the goroutine a short bounded window to
exit before failing, so it can't keep touching the mock after the
subtest has already failed.

Extracted the wait/cancel/grace-period logic (previously duplicated
across all three tests) into a shared waitForReceive suite helper.

Verified: go test -race -run TestGCSWatcherTestSuite -count=200 now
passes cleanly (was previously failing on all three tests).
funkyshu added a commit that referenced this pull request Jul 16, 2026
Fixes #340. Same root cause as #339: TestEnhancedMetadata,
TestOverwriteEventSuppression, and TestRetryBackoffTiming each start
receiveWithRetry in a goroutine and then read test-local state
(receivedEvent/receivedEvents) after a fixed time.Sleep(50ms), racing
with the goroutine's write.

Since RetryConfig.Enabled defaults to false, receiveWithRetry makes a
single receive() call and returns, matching each test's Once() mock
expectations. Fixed by waiting on receiveWithRetry's own completion via
an error channel (rather than a sleep or a handler-only signal), and
asserting it returns without error. On the timeout path, cancel the
context immediately and give the goroutine a short bounded window to
exit before failing, so it can't keep touching the mock after the
subtest has already failed.

Extracted the wait/cancel/grace-period logic (previously duplicated
across all three tests) into a shared waitForReceive suite helper.
Uses time.NewTimer + defer Stop() instead of time.After so the timers
are released promptly instead of lingering until they fire, per review
feedback. Also fixed the changelog entry to consistently qualify all
three subtest names with TestGCSWatcherTestSuite/.

Verified: go test -race -run TestGCSWatcherTestSuite -count=200 now
passes cleanly (was previously failing on all three tests).
funkyshu added a commit that referenced this pull request Jul 16, 2026
TestEnhancedMetadata only synchronized on the event handler firing
(via an eventReceived channel), not on pollOnce's own completion. On
CI (ubuntu, go1.26), the subtest could finish and its mock-expectation
teardown could run before the background pollOnce goroutine made its
DeleteMessage call, producing:

  FAIL: DeleteMessage(string,string)
  FAIL: 1 out of 2 expectation(s) were met.

This is exactly the residual race risk flagged (but not fixed at the
time, since it wasn't the primary target) during review of #339's fix
for TestNonVersionedBucketMetadata.

Fixed by switching TestEnhancedMetadata to the same completion-based
synchronization (wait for pollOnce to fully return via an error
channel) already used by TestNonVersionedBucketMetadata, extracting
the shared wait/cancel/grace-period logic into a waitForPoll suite
helper (mirroring the equivalent gcsevents helper added earlier in
this PR). Uses time.NewTimer + defer Stop() to proactively avoid the
un-stopped time.After timer issue raised in review of this PR.

Verified:
- go test -race -run TestS3WatcherTestSuite -count=300 ./watchers/s3events/...
- go test -run TestS3WatcherTestSuite -count=1000 ./watchers/s3events/... (no -race, to
  stress test scheduling/timing rather than just data races)
both pass cleanly with 0 failures.

(cherry picked from commit b451efd)
funkyshu added a commit that referenced this pull request Jul 16, 2026
…341)

* fix(vfsevents): remove sleep-based races in gcsevents watcher tests

Fixes #340. Same root cause as #339: TestEnhancedMetadata,
TestOverwriteEventSuppression, and TestRetryBackoffTiming each start
receiveWithRetry in a goroutine and then read test-local state
(receivedEvent/receivedEvents) after a fixed time.Sleep(50ms), racing
with the goroutine's write.

Since RetryConfig.Enabled defaults to false, receiveWithRetry makes a
single receive() call and returns, matching each test's Once() mock
expectations. Fixed by waiting on receiveWithRetry's own completion via
an error channel (rather than a sleep or a handler-only signal), and
asserting it returns without error. On the timeout path, cancel the
context immediately and give the goroutine a short bounded window to
exit before failing, so it can't keep touching the mock after the
subtest has already failed.

Extracted the wait/cancel/grace-period logic (previously duplicated
across all three tests) into a shared waitForReceive suite helper.
Uses time.NewTimer + defer Stop() instead of time.After so the timers
are released promptly instead of lingering until they fire, per review
feedback. Also fixed the changelog entry to consistently qualify all
three subtest names with TestGCSWatcherTestSuite/.

Verified: go test -race -run TestGCSWatcherTestSuite -count=200 now
passes cleanly (was previously failing on all three tests).

* fix(vfsevents): fix CI-observed flake in TestEnhancedMetadata (s3events)

TestEnhancedMetadata only synchronized on the event handler firing
(via an eventReceived channel), not on pollOnce's own completion. On
CI (ubuntu, go1.26), the subtest could finish and its mock-expectation
teardown could run before the background pollOnce goroutine made its
DeleteMessage call, producing:

  FAIL: DeleteMessage(string,string)
  FAIL: 1 out of 2 expectation(s) were met.

This is exactly the residual race risk flagged (but not fixed at the
time, since it wasn't the primary target) during review of #339's fix
for TestNonVersionedBucketMetadata.

Fixed by switching TestEnhancedMetadata to the same completion-based
synchronization (wait for pollOnce to fully return via an error
channel) already used by TestNonVersionedBucketMetadata, extracting
the shared wait/cancel/grace-period logic into a waitForPoll suite
helper (mirroring the equivalent gcsevents helper added earlier in
this PR). Uses time.NewTimer + defer Stop() to proactively avoid the
un-stopped time.After timer issue raised in review of this PR.

Verified:
- go test -race -run TestS3WatcherTestSuite -count=300 ./watchers/s3events/...
- go test -run TestS3WatcherTestSuite -count=1000 ./watchers/s3events/... (no -race, to
  stress test scheduling/timing rather than just data races)
both pass cleanly with 0 failures.

(cherry picked from commit b451efd)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/M Denotes a PR that changes 30-99 lines

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants