Race Condition in controllerManager.waitForRunnable

[AliMohammadiSoumee]

I got a race condition error when I was trying to run my tests with -race flag.

The problem is with controllerManager.waitForRunnable. Based on this document, Add and Wait methods of WaitGroup should be called in the same goroutine.

controllerManager calls the WaitGroup.Add method In the controllerManager.StartRunnable method, and calls the WaitGroup.Wait method in the controllerManager.waitForRunnableToEnd method, While waitForRunnableToEnd and StartRunnable are running in different goroutines.

This log may help you, It's for v0.8.3:

WARNING: DATA RACE
Write at 0x00c00038e6a8 by goroutine 86:
  internal/race.Write()
      /usr/local/go/src/internal/race/race.go:41 +0x125
  sync.(*WaitGroup).Wait()
      /usr/local/go/src/sync/waitgroup.go:128 +0x126
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).waitForRunnableToEnd.func2()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:567 +0x44

Previous read at 0x00c00038e6a8 by goroutine 166:
  internal/race.Read()
      /usr/local/go/src/internal/race/race.go:37 +0x206
  sync.(*WaitGroup).Add()
      /usr/local/go/src/sync/waitgroup.go:71 +0x219
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).startRunnable()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:678 +0x4e
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).serveMetrics()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:384 +0x31b

Goroutine 86 (running) created at:
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).waitForRunnableToEnd()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:566 +0xcb
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).engageStopProcedure()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:548 +0x376
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).Start.func1()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:449 +0x46
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).Start()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:499 +0x575

Goroutine 166 (running) created at:
  sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).Start()
      /home/ali/Developer/Go/pkg/mod/sigs.k8s.io/controller-runtime@v0.8.3/pkg/manager/internal.go:473 +0x61b

[jpfourny]

Yeah - the usage of WaitGroup is sketchy. It's true that Wait and Add are not safe to be called concurrently. This is a ticking time-bomb.

[jpfourny]

What I don't understand is why -race is detecting the problem consistently in 0.8.3, but not back in 0.6.5. The usage patterns of WaitGroup did not change drastically.

[MadhavJivrajani]

/assign

[brakthehack]

FWIW, this is still present in v0.9.5.

[k8s-triage-robot]

The Kubernetes project currently lacks enough contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

• After 90d of inactivity, lifecycle/stale is applied
• After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
• After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

• Mark this issue or PR as fresh with /remove-lifecycle stale
• Mark this issue or PR as rotten with /lifecycle rotten
• Close this issue or PR with /close
• Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

[clementnuss]

/remove-lifecycle stale

not to get this issue closed: the race condition is still present with v0.10.3

[clementnuss]

is this issue still valid with controller-runtime v0.11.0 ?
I tried to reproduce the bug but it never happened again so far (though it did not happen deterministically)

[FillZpp]

I think it has been solved in #1695 .

[clementnuss]

@AliMohammadiSoumee @brakthehack can you guys try to reproduce your race condition with controller-runtime prior v0.11 and then with v0.11 ?

I cannot reproduce it with v0.11 personally, but it had only happened a few times
If not i think this issue could be closed

[AliMohammadiSoumee]

I have reproduced it with controller-runtime v0.11.0, and apparently, the issue is solved.

[FillZpp]

/close

[k8s-ci-robot]

@FillZpp: Closing this issue.

In response to this:

/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.