Skip to content

Race in shutting down event broadcasters (manifests as test flake) #1171

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
DirectXMan12 opened this issue Sep 21, 2020 · 7 comments
Closed
Labels
kind/bug Categorizes issue or PR as related to a bug. kind/flake Categorizes issue or PR as related to a flaky test. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. priority/critical-urgent Highest priority. Must be actively worked on as someone's top priority right now.

Comments

@DirectXMan12
Copy link
Contributor

Full description of the issue is at kubernetes/kubernetes#94906.

The TL;DR is that it's unherently unsafe (racey) to stop an event broadcaster due to the way it does non-blocking event emission. We might have to fork that code entirely to fix it in a timely manner.

Symptoms look like

relevant race detector output/stack traces
==================
WARNING: DATA RACE
Write at 0x00c0001762b0 by goroutine 171:
  runtime.closechan()
      /usr/local/go/src/runtime/chan.go:334 +0x0
  k8s.io/client-go/tools/record.(*eventBroadcasterImpl).Shutdown()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/pkg/watch/mux.go:199 +0x68
  sigs.k8s.io/controller-runtime/pkg/internal/recorder.(*Provider).Stop.func1()
      /home/prow/go/src/sigs.k8s.io/controller-runtime/pkg/internal/recorder/recorder.go:73 +0xa0
Previous read at 0x00c0001762b0 by goroutine 168:
  runtime.chansend()
      /usr/local/go/src/runtime/chan.go:142 +0x0
  k8s.io/client-go/tools/record.(*recorderImpl).generateEvent.func1()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/pkg/watch/mux.go:189 +0x11b
Goroutine 171 (running) created at:
  sigs.k8s.io/controller-runtime/pkg/internal/recorder.(*Provider).Stop()
      /home/prow/go/src/sigs.k8s.io/controller-runtime/pkg/internal/recorder/recorder.go:66 +0x8c
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).engageStopProcedure()
      /home/prow/go/src/sigs.k8s.io/controller-runtime/pkg/manager/internal.go:563 +0x38d
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).Start.func1()
      /home/prow/go/src/sigs.k8s.io/controller-runtime/pkg/manager/internal.go:468 +0x49
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).Start()
      /home/prow/go/src/sigs.k8s.io/controller-runtime/pkg/manager/internal.go:518 +0x339
  sigs.k8s.io/controller-runtime/pkg/manager.glob..func3.3.8.3.6()
      /home/prow/go/src/sigs.k8s.io/controller-runtime/pkg/manager/manager_test.go:273 +0x22b
Goroutine 168 (finished) created at:
  k8s.io/client-go/tools/record.(*recorderImpl).generateEvent()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/record/event.go:341 +0x42a
  k8s.io/client-go/tools/record.(*recorderImpl).Event()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/record/event.go:349 +0xcf
  k8s.io/client-go/tools/record.(*recorderImpl).Eventf()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/record/event.go:353 +0xd7
  sigs.k8s.io/controller-runtime/pkg/internal/recorder.(*lazyRecorder).Eventf()
      /home/prow/go/src/sigs.k8s.io/controller-runtime/pkg/internal/recorder/recorder.go:151 +0xf3
  k8s.io/client-go/tools/leaderelection/resourcelock.(*LeaseLock).RecordEvent()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/leaderelection/resourcelock/leaselock.go:85 +0x30b
  k8s.io/client-go/tools/leaderelection/resourcelock.(*MultiLock).RecordEvent()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/leaderelection/resourcelock/multilock.go:88 +0xa5
  k8s.io/client-go/tools/leaderelection.(*LeaderElector).acquire.func1()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/leaderelection/leaderelection.go:251 +0x213
  k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:155 +0x6f
  k8s.io/apimachinery/pkg/util/wait.BackoffUntil()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:156 +0xb3
  k8s.io/apimachinery/pkg/util/wait.JitterUntil()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:133 +0x10d
  k8s.io/client-go/tools/leaderelection.(*LeaderElector).acquire()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/leaderelection/leaderelection.go:244 +0x2b2
  k8s.io/client-go/tools/leaderelection.(*LeaderElector).Run()
      /home/prow/go/pkg/mod/k8s.io/[email protected]/tools/leaderelection/leaderelection.go:203 +0xee
==================
@DirectXMan12
Copy link
Contributor Author

/kind bug
/kind flake
/priority critical-urgent

@k8s-ci-robot k8s-ci-robot added kind/bug Categorizes issue or PR as related to a bug. kind/flake Categorizes issue or PR as related to a flaky test. priority/critical-urgent Highest priority. Must be actively worked on as someone's top priority right now. labels Sep 21, 2020
@fejta-bot
Copy link

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle stale

@k8s-ci-robot k8s-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Dec 20, 2020
@fejta-bot
Copy link

Stale issues rot after 30d of inactivity.
Mark the issue as fresh with /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle rotten

@k8s-ci-robot k8s-ci-robot added lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. and removed lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. labels Jan 20, 2021
@camilamacedo86
Copy link
Member

@vincepri since it is priority bug, could we not add it to a milestone 0.9 or 0.10?

@vincepri
Copy link
Member

vincepri commented Feb 3, 2021

I was waiting for the bug to be cherry picked, but yeah we can add it

@fejta-bot
Copy link

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-contributor-experience at kubernetes/community.
/close

@k8s-ci-robot
Copy link
Contributor

@fejta-bot: Closing this issue.

In response to this:

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-contributor-experience at kubernetes/community.
/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Categorizes issue or PR as related to a bug. kind/flake Categorizes issue or PR as related to a flaky test. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. priority/critical-urgent Highest priority. Must be actively worked on as someone's top priority right now.
Projects
None yet
Development

No branches or pull requests

5 participants