Fix two race issues in schedule_queue #81148

wgliang · 2019-08-08T03:08:24Z

What type of PR is this?

Uncomment only one /kind <> line, hit enter to put that in a new line, and remove leading whitespaces from that line:

/kind api-change

/kind cleanup
/kind design
/kind documentation
/kind failing-test
/kind feature
/kind flake

/kind bug
What this PR does / why we need it:
Run: go test k8s.io/kubernetes/pkg/scheduler/internal/queue --race --count=50

You can get:

WARNING: DATA RACE
Write at 0x00c000386120 by goroutine 39:
  runtime.mapdelete_faststr()
      /usr/local/Cellar/go/1.12.7/libexec/src/runtime/map_faststr.go:297 +0x0
  k8s.io/kubernetes/pkg/scheduler/util.(*heapData).Pop()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/util/heap.go:113 +0x203
  container/heap.Pop()
      /usr/local/Cellar/go/1.12.7/libexec/src/container/heap/heap.go:64 +0xb0
  k8s.io/kubernetes/pkg/scheduler/util.(*Heap).Pop()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/util/heap.go:200 +0x5b
  k8s.io/kubernetes/pkg/scheduler/internal/queue.(*PriorityQueue).flushBackoffQCompleted()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/internal/queue/scheduling_queue.go:356 +0x490
  k8s.io/kubernetes/pkg/scheduler/internal/queue.(*PriorityQueue).flushBackoffQCompleted-fm()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/internal/queue/scheduling_queue.go:334 +0x41
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:152 +0x61
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:153 +0x108
  k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Until()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88 +0x5a

Previous read at 0x00c000386120 by goroutine 38:
  runtime.mapaccess2_faststr()
      /usr/local/Cellar/go/1.12.7/libexec/src/runtime/map_faststr.go:107 +0x0
  k8s.io/kubernetes/pkg/scheduler/util.(*Heap).Get()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/util/heap.go:221 +0x11d
  k8s.io/kubernetes/pkg/scheduler/internal/queue.TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/internal/queue/scheduling_queue_test.go:357 +0xa12
  testing.tRunner()
      /usr/local/Cellar/go/1.12.7/libexec/src/testing/testing.go:865 +0x163

Goroutine 39 (running) created at:
  k8s.io/kubernetes/pkg/scheduler/internal/queue.(*PriorityQueue).run()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/internal/queue/scheduling_queue.go:200 +0xd0
  k8s.io/kubernetes/pkg/scheduler/internal/queue.NewPriorityQueueWithClock()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/internal/queue/scheduling_queue.go:193 +0x9af
  k8s.io/kubernetes/pkg/scheduler/internal/queue.TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff()
      /Users/wangguoliang/Documents/mos/src/k8s.io/kubernetes/pkg/scheduler/internal/queue/scheduling_queue.go:164 +0x70
  testing.tRunner()
      /usr/local/Cellar/go/1.12.7/libexec/src/testing/testing.go:865 +0x163

Which issue(s) this PR fixes:

Fixes #

Special notes for your reviewer:

Does this PR introduce a user-facing change?:

NONE

Additional documentation e.g., KEPs (Kubernetes Enhancement Proposals), usage docs, etc.:

NONE

wgliang · 2019-08-08T03:09:01Z

/sig scheduling

draveness

The data race is indeed a problem that we need to solve. But can we have a benchmark number for this change since this one adds a mutex to the important data structure in the scheduler

wgliang · 2019-08-08T03:34:37Z

The data race is indeed a problem that we need to solve. But can we have a benchmark number for this change since this one adds a mutex to the important data structure in the scheduler

Yes, agree with your comment. I will do it.

hex108 · 2019-08-08T04:02:10Z

util.Heap is used by queue.PriorityQueue, and operations for PriorityQueue has already been protected by its own lock. It seems that the race is caused by the test case?

wgliang · 2019-08-08T04:10:43Z

util.Heap is used by queue.PriorityQueue, and operations for PriorityQueue has already been protected by its own lock. It seems that the race is caused by the test case?

From the test results, the two issues are separate.

hex108 · 2019-08-08T05:01:13Z

We do not need add lock for heap since the user PriorityQueue has lock for it. :)

wgliang · 2019-08-08T06:39:49Z

We do not need add lock for heap since the user PriorityQueue has lock for it. :)

I have been tested and found it caused by the test code. Thank you for your reminder.

wgliang · 2019-08-08T06:42:56Z

@draveness I have modified the code so it seems that I don't need to continue testing the performance data. Thanks.

draveness · 2019-08-08T07:04:13Z

@draveness I have modified the code so it seems that I don't need to continue testing the performance data. Thanks.

Verified locally, this indeed solves the data race problem in the schedule queue tests. But I'm quite interested in the cause of the data race, the two tests use two different priority queue, it's not supposed to cause the problem, could you explain a little bit to me?

wgliang · 2019-08-08T08:02:42Z

@draveness I have modified the code so it seems that I don't need to continue testing the performance data. Thanks.

Verified locally, this indeed solves the data race problem in the schedule queue tests. But I'm quite interested in the cause of the data race, the two tests use two different priority queue, it's not supposed to cause the problem, could you explain a little bit to me?

In fact, you can see the reason from the description of the problem(#81148 (comment)): the two tests that are causing the problem are not directly responsible for the race, but they have a relationship with the logic in the main code.

hex108

Nit

hex108 · 2019-08-08T08:34:18Z

pkg/scheduler/internal/queue/scheduling_queue_test.go

@@ -351,13 +351,15 @@ func TestPriorityQueue_AddUnschedulableIfNotPresent_Backoff(t *testing.T) {
 		q.AddUnschedulableIfNotPresent(unschedulablePod, oldCycle)
 	}

+	q.lock.RLock()


It would be better to write a function(similar to L109) to wrap the lock and getting pod from podBackoffQ.

In fact, I prefer to keep the test simple and verify the data like L358.

liu-cong · 2019-08-08T18:08:27Z

pkg/scheduler/internal/queue/scheduling_queue_test.go

@@ -1055,8 +1057,11 @@ func TestHighPriorityFlushUnschedulableQLeftover(t *testing.T) {

 	addOrUpdateUnschedulablePod(q, &highPod)
 	addOrUpdateUnschedulablePod(q, &midPod)
+
+	q.lock.Lock()
 	q.unschedulableQ.podInfoMap[util.GetPodFullName(&highPod)].Timestamp = time.Now().Add(-1 * unschedulableQTimeInterval)


addOrUpdateUnschedulablePod already does locking. Instead of applying locking here, I suggest to modify addOrUpdateUnschedulablePod to accept a PodInfo input instead of Pod, therefore you can first create a PodInfo and avoid updating the podInfoMap again (in L1062-1063).

E.g.,
change

func addOrUpdateUnschedulablePod(p *PriorityQueue, pod *v1.Pod) { p.lock.Lock() defer p.lock.Unlock() p.unschedulableQ.addOrUpdate(p.newPodInfo(pod)) }

to

func addOrUpdateUnschedulablePod(p *PriorityQueue, podInfo *framework.PodInfo) { p.lock.Lock() defer p.lock.Unlock() p.unschedulableQ.addOrUpdate(podInfo) }

wgliang · 2019-08-12T10:16:21Z

/assign @Huang-Wei @bsalamat
PTAL Thanks

wgliang · 2019-08-12T10:16:53Z

/test pull-kubernetes-kubemark-e2e-gce-big

Huang-Wei

/lgtm
/approve

Thanks, @wgliang !

k8s-ci-robot · 2019-08-14T18:41:53Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: Huang-Wei, wgliang

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~pkg/scheduler/OWNERS~~ [Huang-Wei]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

k8s-ci-robot added sig/scheduling Categorizes an issue or PR as relevant to SIG Scheduling. and removed needs-sig Indicates an issue or PR lacks a `sig/foo` label and requires one. labels Aug 8, 2019

k8s-ci-robot requested review from k82cn and resouer August 8, 2019 03:10

draveness reviewed Aug 8, 2019

View reviewed changes

wgliang closed this Aug 8, 2019

wgliang force-pushed the bugfix/scheduler-heap-race branch from 35dde4a to a51d574 Compare August 8, 2019 06:36

k8s-ci-robot added size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. approved Indicates a PR has been approved by an approver from all required OWNERS files. and removed size/S Denotes a PR that changes 10-29 lines, ignoring generated files. labels Aug 8, 2019

wgliang reopened this Aug 8, 2019

k8s-ci-robot removed the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Aug 8, 2019

hex108 reviewed Aug 8, 2019

View reviewed changes

liu-cong reviewed Aug 8, 2019

View reviewed changes

Fix two race issues in scheduling_queue_test

ca61b79

wgliang force-pushed the bugfix/scheduler-heap-race branch from 79819ca to ca61b79 Compare August 8, 2019 23:50

k8s-ci-robot added size/M Denotes a PR that changes 30-99 lines, ignoring generated files. and removed size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Aug 8, 2019

k8s-ci-robot assigned bsalamat and Huang-Wei Aug 12, 2019

Huang-Wei reviewed Aug 14, 2019

View reviewed changes

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Aug 14, 2019

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Aug 14, 2019

k8s-ci-robot merged commit 8c6c94b into kubernetes:master Aug 14, 2019

k8s-ci-robot added this to the v1.16 milestone Aug 14, 2019

liu-cong mentioned this pull request Aug 21, 2019

REQUEST: New membership for liu-cong kubernetes/org#1127

Closed

6 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix two race issues in schedule_queue #81148

Fix two race issues in schedule_queue #81148

wgliang commented Aug 8, 2019 •

edited

wgliang commented Aug 8, 2019

draveness left a comment

wgliang commented Aug 8, 2019

hex108 commented Aug 8, 2019

wgliang commented Aug 8, 2019

hex108 commented Aug 8, 2019

wgliang commented Aug 8, 2019 •

edited

wgliang commented Aug 8, 2019

draveness commented Aug 8, 2019 •

edited

wgliang commented Aug 8, 2019

hex108 left a comment

hex108 Aug 8, 2019

wgliang Aug 8, 2019

liu-cong Aug 8, 2019

wgliang Aug 8, 2019

wgliang commented Aug 12, 2019

wgliang commented Aug 12, 2019

Huang-Wei left a comment

k8s-ci-robot commented Aug 14, 2019

Fix two race issues in schedule_queue #81148

Fix two race issues in schedule_queue #81148

Conversation

wgliang commented Aug 8, 2019 • edited

wgliang commented Aug 8, 2019

draveness left a comment

Choose a reason for hiding this comment

wgliang commented Aug 8, 2019

hex108 commented Aug 8, 2019

wgliang commented Aug 8, 2019

hex108 commented Aug 8, 2019

wgliang commented Aug 8, 2019 • edited

wgliang commented Aug 8, 2019

draveness commented Aug 8, 2019 • edited

wgliang commented Aug 8, 2019

hex108 left a comment

Choose a reason for hiding this comment

hex108 Aug 8, 2019

Choose a reason for hiding this comment

wgliang Aug 8, 2019

Choose a reason for hiding this comment

liu-cong Aug 8, 2019

Choose a reason for hiding this comment

wgliang Aug 8, 2019

Choose a reason for hiding this comment

wgliang commented Aug 12, 2019

wgliang commented Aug 12, 2019

Huang-Wei left a comment

Choose a reason for hiding this comment

k8s-ci-robot commented Aug 14, 2019

wgliang commented Aug 8, 2019 •

edited

wgliang commented Aug 8, 2019 •

edited

draveness commented Aug 8, 2019 •

edited