fix data race for Test_Run_Positive_VolumeMountControllerAttachEnabledRace #103353

njuptlzf · 2021-06-30T11:59:08Z

What type of PR is this?

/kind flake
/kind failing-test

What this PR does / why we need it:

fix the DATA RACE of generatedVolumeName.
fix the DATA RACE of testing.t.

Which issue(s) this PR fixes:

Fixes #102932

Special notes for your reviewer:

NONE

Does this PR introduce a user-facing change?

NONE

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

NONE

I can reproduce it by
./stress -p 300 ./reconciler.test -test.run "Test_Run_Positive_VolumeMountControllerAttachEnabledRace"

k8s-ci-robot · 2021-06-30T11:59:16Z

Hi @njuptlzf. Thanks for your PR.

I'm waiting for a kubernetes member to verify that this patch is reasonable to test. If it is, they should reply with /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

I understand the commands that are listed here.

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.

njuptlzf · 2021-06-30T12:04:35Z

pkg/kubelet/volumemanager/reconciler/reconciler_test.go

@@ -1834,7 +1835,6 @@ func Test_Run_Positive_VolumeMountControllerAttachEnabledRace(t *testing.T) {
 	fakePlugin.UnmountDeviceHook = func(mountPath string) error {
 		// Act:
 		// 3. While a volume is being unmounted, add it back to the desired state of world
-		t.Logf("UnmountDevice called")


WARNING: DATA RACE Read at 0x00c000547cc3 by goroutine 85: testing.(*common).logDepth() /root/tools/go1163/src/testing/testing.go:759 +0x164 testing.(*common).log() /root/tools/go1163/src/testing/testing.go:746 +0x8f testing.(*common).Logf() /root/tools/go1163/src/testing/testing.go:792 +0x21 k8s.io/kubernetes/pkg/kubelet/volumemanager/reconciler.Test_Run_Positive_VolumeMountControllerAttachEnabledRace.func2() /root/workspace/kubernetes/pkg/kubelet/volumemanager/reconciler/reconciler_test.go:1837 +0xea k8s.io/kubernetes/pkg/volume/testing.(*FakeVolume).UnmountDevice() /root/workspace/kubernetes/pkg/volume/testing/testing.go:1101 +0x154 k8s.io/kubernetes/pkg/volume/util/operationexecutor.(*operationGenerator).GenerateUnmountDeviceFunc.func1() /root/workspace/kubernetes/pkg/volume/util/operationexecutor/operation_generator.go:936 +0x41b k8s.io/kubernetes/pkg/volume/util/types.(*GeneratedOperations).Run() /root/workspace/kubernetes/pkg/volume/util/types/types.go:79 +0x195 k8s.io/kubernetes/pkg/volume/util/nestedpendingoperations.(*nestedPendingOperations).Run.func1() /root/workspace/kubernetes/pkg/volume/util/nestedpendingoperations/nestedpendingoperations.go:183 +0x159 Previous write at 0x00c000547cc3 by main goroutine: testing.tRunner.func1() /root/tools/go1163/src/testing/testing.go:1180 +0x52c testing.tRunner() /root/tools/go1163/src/testing/testing.go:1197 +0x22a testing.runTests() /root/tools/go1163/src/testing/testing.go:1509 +0x612 testing.(*M).Run() /root/tools/go1163/src/testing/testing.go:1417 +0x3b3 main.main() _testmain.go:73 +0x236 Goroutine 85 (running) created at: k8s.io/kubernetes/pkg/volume/util/nestedpendingoperations.(*nestedPendingOperations).Run() /root/workspace/kubernetes/pkg/volume/util/nestedpendingoperations/nestedpendingoperations.go:178 +0x572 k8s.io/kubernetes/pkg/volume/util/operationexecutor.(*operationExecutor).UnmountDevice() /root/workspace/kubernetes/pkg/volume/util/operationexecutor/operation_executor.go:905 +0x2d3 k8s.io/kubernetes/pkg/kubelet/volumemanager/reconciler.(*reconciler).unmountDetachDevices() /root/workspace/kubernetes/pkg/kubelet/volumemanager/reconciler/reconciler.go:302 +0x3e3 k8s.io/kubernetes/pkg/kubelet/volumemanager/reconciler.(*reconciler).reconcile() /root/workspace/kubernetes/pkg/kubelet/volumemanager/reconciler/reconciler.go:177 +0x54 k8s.io/kubernetes/pkg/kubelet/volumemanager/reconciler.(*reconciler).reconciliationLoopFunc.func1() /root/workspace/kubernetes/pkg/kubelet/volumemanager/reconciler/reconciler.go:151 +0x5b k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1() /root/workspace/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:155 +0x75 k8s.io/apimachinery/pkg/util/wait.BackoffUntil() /root/workspace/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:156 +0xba k8s.io/apimachinery/pkg/util/wait.JitterUntil() /root/workspace/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133 +0x114 k8s.io/apimachinery/pkg/util/wait.Until() /root/workspace/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:90 +0x8e k8s.io/kubernetes/pkg/kubelet/volumemanager/reconciler.(*reconciler).Run() /root/workspace/kubernetes/pkg/kubelet/volumemanager/reconciler/reconciler.go:146 +0x2f ==================

fix DATA RACE of tesing.t for https://github.com/golang/go/blob/d19a53338fa6272b4fe9c39d66812a79e1464cd2/src/testing/testing.go#L1237-L1238

pacoxu · 2021-06-30T12:15:31Z

/ok-to-test

njuptlzf · 2021-06-30T12:19:25Z

Befor this pr:

# ./stress -p 300 ./reconciler.test -test.run "Test_Run_Positive_VolumeMountControllerAttachEnabledRace"
2h16m30s: 1089927 runs so far, 73 failures (0.01%)

/tmp# find /tmp/go-stress-20210701T014412* -type f |xargs grep "DATA"
/tmp/go-stress-20210701T014412-033946034:WARNING: DATA RACE
/tmp/go-stress-20210701T014412-213477365:WARNING: DATA RACE
/tmp/go-stress-20210701T014412-400779095:WARNING: DATA RACE
/tmp/go-stress-20210701T014412-512170394:WARNING: DATA RACE
/tmp/go-stress-20210701T014412-809148112:WARNING: DATA RACE

After this pr:

# ./stress -p 300 ./reconciler.test -test.run "Test_Run_Positive_VolumeMountControllerAttachEnabledRace"
1h35m25s: 783657 runs so far, 35 failures (0.00%)

# find /tmp/go-stress-20210630T172003* -type f |xargs grep "DATA"
#

Other problems are all because of

E0701 02:37:20.808501   41250 reconciler.go:389] "Cannot get volumes from disk" err="open fake-dir: no such file or directory"

--- FAIL: Test_Run_Positive_VolumeMountControllerAttachEnabledRace (12.52s)
    reconciler_test.go:1837: UnmountDevice called
    reconciler_test.go:1650: Timed out waiting for volume "fake-plugin/fake-device1" to be attached.
FAIL

It should be -p 300 which causes the operating system to fail to create a folder, not DATA RACE.

njuptlzf · 2021-06-30T12:25:49Z

Does this need to enter the 1.22 milestone? @BenTheElder

matthyx · 2021-07-04T16:10:11Z

/lgtm

pacoxu · 2021-07-05T02:28:58Z

/assign @msau42 @jingxu97
Could you take a look?

matthyx · 2021-07-05T06:20:33Z

/triage accepted
/priority important-soon

ehashman · 2021-07-06T16:59:53Z

/remove-kind failing-test

249043822 · 2021-07-12T05:57:55Z

/lgtm

msau42 · 2021-07-16T03:21:54Z

pkg/kubelet/volumemanager/reconciler/reconciler_test.go

@@ -1861,5 +1861,5 @@ func Test_Run_Positive_VolumeMountControllerAttachEnabledRace(t *testing.T) {
 	dsw.DeletePodFromVolume(podName, generatedVolumeName)


Does this need to use the original name too?

I’m not an expert in volume, and it may take time to investigate.
But there is no data race here in the stress test.

Actually no need, because dsw.DeletePodFromVolume(podName, generatedVolumeName) runs before UnmountDeviceHook, use generatedVolumeNameCopy maybe still a good change

pkg/kubelet/volumemanager/reconciler/reconciler_test.go

…dRace

249043822 · 2021-07-27T00:15:54Z

/test pull-kubernetes-integration

249043822 · 2021-07-27T01:14:37Z

the fix looks good.

msau42 · 2021-07-27T03:03:46Z

/lgtm
/approve

Thank you!

k8s-ci-robot · 2021-07-27T03:03:54Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: msau42, njuptlzf

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/kubelet/volumemanager/OWNERS~~ [msau42]

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

BenTheElder · 2021-08-05T02:55:26Z

Thanks!

k8s-ci-robot requested review from davidz627 and jingxu97 June 30, 2021 12:00

njuptlzf commented Jun 30, 2021

View reviewed changes

k8s-ci-robot added ok-to-test Indicates a non-member PR verified by an org member that is safe to test. and removed needs-ok-to-test Indicates a PR that requires an org member to verify it is safe to test. labels Jun 30, 2021

ehashman added this to Triage in SIG Node CI/Test Board Jun 30, 2021

k8s-ci-robot assigned matthyx Jul 4, 2021

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Jul 4, 2021

k8s-ci-robot assigned jingxu97 and msau42 Jul 5, 2021

k8s-ci-robot added the triage/accepted Indicates an issue or PR is ready to be actively worked on. label Jul 5, 2021

k8s-ci-robot removed the kind/failing-test Categorizes issue or PR as related to a consistently or frequently failing test. label Jul 6, 2021

k8s-ci-robot assigned 249043822 Jul 12, 2021

249043822 removed their assignment Jul 12, 2021

msau42 reviewed Jul 16, 2021

View reviewed changes

njuptlzf force-pushed the fix_datarace branch from f3fb26a to 4c18131 Compare July 16, 2021 05:08

k8s-ci-robot removed the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Jul 16, 2021

njuptlzf requested review from msau42 and 249043822 July 16, 2021 05:15

njuptlzf force-pushed the fix_datarace branch from 4c18131 to fb3ae14 Compare July 16, 2021 13:50

k8s-ci-robot added size/S Denotes a PR that changes 10-29 lines, ignoring generated files. and removed size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Jul 16, 2021

SergeyKanzhelev added this to Triage in SIG Node PR Triage Jul 21, 2021

SergeyKanzhelev moved this from PRs - Needs Approver to PRs - Needs Reviewer in SIG Node CI/Test Board Jul 21, 2021

249043822 reviewed Jul 26, 2021

View reviewed changes

pkg/kubelet/volumemanager/reconciler/reconciler_test.go Outdated Show resolved Hide resolved

fix data race for Test_Run_Positive_VolumeMountControllerAttachEnable…

1555877

…dRace

njuptlzf force-pushed the fix_datarace branch from fb3ae14 to 1555877 Compare July 26, 2021 09:19

njuptlzf requested a review from 249043822 July 26, 2021 09:19

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Jul 27, 2021

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Jul 27, 2021

ehashman moved this from PRs - Needs Reviewer to PRs - Needs Approver in SIG Node CI/Test Board Aug 2, 2021

k8s-ci-robot merged commit fa1d682 into kubernetes:master Aug 5, 2021

SIG Node CI/Test Board automation moved this from PRs - Needs Approver to Done Aug 5, 2021

k8s-ci-robot added this to the v1.23 milestone Aug 5, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix data race for Test_Run_Positive_VolumeMountControllerAttachEnabledRace #103353

fix data race for Test_Run_Positive_VolumeMountControllerAttachEnabledRace #103353

njuptlzf commented Jun 30, 2021 •

edited

k8s-ci-robot commented Jun 30, 2021

njuptlzf Jun 30, 2021

pacoxu commented Jun 30, 2021

njuptlzf commented Jun 30, 2021 •

edited

njuptlzf commented Jun 30, 2021

matthyx commented Jul 4, 2021

pacoxu commented Jul 5, 2021

matthyx commented Jul 5, 2021

ehashman commented Jul 6, 2021

249043822 commented Jul 12, 2021

msau42 Jul 16, 2021

njuptlzf Jul 16, 2021

249043822 Jul 16, 2021

249043822 commented Jul 27, 2021

249043822 commented Jul 27, 2021

msau42 commented Jul 27, 2021

k8s-ci-robot commented Jul 27, 2021

BenTheElder commented Aug 5, 2021

		@@ -1861,5 +1861,5 @@ func Test_Run_Positive_VolumeMountControllerAttachEnabledRace(t *testing.T) {
		dsw.DeletePodFromVolume(podName, generatedVolumeName)

fix data race for Test_Run_Positive_VolumeMountControllerAttachEnabledRace #103353

fix data race for Test_Run_Positive_VolumeMountControllerAttachEnabledRace #103353

Conversation

njuptlzf commented Jun 30, 2021 • edited

What type of PR is this?

What this PR does / why we need it:

Which issue(s) this PR fixes:

Special notes for your reviewer:

Does this PR introduce a user-facing change?

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

k8s-ci-robot commented Jun 30, 2021

njuptlzf Jun 30, 2021

Choose a reason for hiding this comment

pacoxu commented Jun 30, 2021

njuptlzf commented Jun 30, 2021 • edited

njuptlzf commented Jun 30, 2021

matthyx commented Jul 4, 2021

pacoxu commented Jul 5, 2021

matthyx commented Jul 5, 2021

ehashman commented Jul 6, 2021

249043822 commented Jul 12, 2021

msau42 Jul 16, 2021

Choose a reason for hiding this comment

njuptlzf Jul 16, 2021

Choose a reason for hiding this comment

249043822 Jul 16, 2021

Choose a reason for hiding this comment

249043822 commented Jul 27, 2021

249043822 commented Jul 27, 2021

msau42 commented Jul 27, 2021

k8s-ci-robot commented Jul 27, 2021

BenTheElder commented Aug 5, 2021

njuptlzf commented Jun 30, 2021 •

edited

njuptlzf commented Jun 30, 2021 •

edited