Kubernetes 1.7.0 local storage teardown failed #48331

CallMeFoxie · 2017-06-30T09:02:55Z

/kind bug

Tearing down (for example simple updating pods in stateful set) of local-storage PVC seems to be broken:

I0630 10:46:44.480172 24010 reconciler.go:186] operationExecutor.UnmountVolume started for volume "test" (UniqueName: "kubernetes.io/local-volume/97513921-5d70-11e7-a549-180373f4ecc0-test-affinity-test-1") pod "97513921-5d70-11e7-a549-180373f4ecc0" (UID: "97513921-5d70-11e7-a549-180373f4ecc0")
I0630 10:46:44.480243 24010 local.go:271] Unmounting volume "test-affinity-test-1" at path "/www/adm/kubernetes/root/pods/97513921-5d70-11e7-a549-> 180373f4ecc0/volumes/kubernetes.iolocal-volume/test-affinity-test-1"
W0630 10:46:44.480277 24010 util.go:87] Warning: "/www/adm/kubernetes/root/pods/97513921-5d70-11e7-a549-180373f4ecc0/volumes/kubernetes.iolocal-volume/test-affinity-test-1" is not a mountpoint, deleting
E0630 10:46:44.480328 24010 nestedpendingoperations.go:262] Operation for ""kubernetes.io/local-volume/97513921-5d70-11e7-a549-180373f4ecc0-test-affinity-test-1" ("97513921-5d70-11e7-a549-180373f4ecc0")" failed. No retries permitted until 2017-06-30 10:46:48.48030593 +0200 CEST (durationBeforeRetry 4s). Error: UnmountVolume.TearDown failed for volume "test" (UniqueName: "kubernetes.io/local-volume/97513921-5d70-11e7-a549-180373f4ecc0-test-affinity-test-1") pod "97513921-5d70-11e7-a549-180373f4ecc0" (UID: "97513921-5d70-11e7-a549-180373f4ecc0") : remove /www/adm/kubernetes/root/pods/97513921-5d70-11e7-a549-180373f4ecc0/volumes/kubernetes.io~local-volume/test-affinity-test-1: device or resource busy

I've managed to track it down to
pkg/volume/local/local.go calling through some pkg/volume/util/util.go mounter.IsLikelyNotMountPoint(dir)

which literally has written in its comments:

// IsLikelyNotMountPoint determines if a directory is not a mountpoint.
// It is fast but not necessarily ALWAYS correct. If the path is in fact
// a bind mount from one part of a mount to another it will not be detected.
// mkdir /tmp/a /tmp/b; mount --bin /tmp/a /tmp/b; IsLikelyNotMountPoint("/tmp/b")
// will return true. When in fact /tmp/b is a mount point. If this situation
// if of interest to you, don't use this function...

which makes it detect it as a normal directory rather than a mount dir (as it is a normal directory... just bind mounted)

Environment:

Kubernetes version (use kubectl version): v1.7.0
Cloud provider or hardware configuration**: self hosted

Testing out a (dirty?) patch as we're speaking

The text was updated successfully, but these errors were encountered:

k8s-github-robot · 2017-06-30T09:03:20Z

@CallMeFoxie There are no sig labels on this issue. Please add a sig label by:
(1) mentioning a sig: @kubernetes/sig-<team-name>-misc
e.g., @kubernetes/sig-api-machinery-* for API Machinery
(2) specifying the label manually: /sig <label>
e.g., /sig scalability for sig/scalability

Note: method (1) will trigger a notification to the team. You can find the team list here and label list here

CallMeFoxie · 2017-06-30T09:14:11Z

/sig storage

CallMeFoxie · 2017-06-30T09:18:54Z

Whoops the dirty fix to force umount does not work as it may fail "as it was already unmounted".

Trying out a patch which reads /proc/mounts instead, it seems to be workign much better, can remove/add pods to those PV(C)s without any issue:

diff --git a/pkg/util/mount/mount_linux.go b/pkg/util/mount/mount_linux.go
index 1685ecb..4c007ba 100644
--- a/pkg/util/mount/mount_linux.go
+++ b/pkg/util/mount/mount_linux.go
@@ -180,6 +180,22 @@ func IsNotMountPoint(file string) (bool, error) {
 	if err != nil {
 		return true, err
 	}
+	mountsfd, err := os.Open("/proc/mounts")
+	if err != nil {
+		return true, err
+	}
+
+	scanner := bufio.NewScanner(mountsfd)
+	for scanner.Scan() {
+		line := scanner.Text()
+		parts := strings.Split(line, " ")
+		if len(parts) >= 2 {
+			if strings.Compare(parts[1], file) == 0 {
+				return false, nil
+			}
+		}
+	}
+
 	// If the directory has a different device as parent, then it is a mountpoint.
 	if stat.Sys().(*syscall.Stat_t).Dev != rootStat.Sys().(*syscall.Stat_t).Dev {
 		return false, nil

ianchakeres · 2017-06-30T14:07:27Z

I experienced this issue while writing some e2e tests - #47999

These tests can be used to reproduce the issue on GCE.

The run-one-command pod tests succeed (e.g. "when one pod requests one prebound PVC), while the pods that are created and deleted independently end up encountering this bug.

For example,
Context("when two pods request one prebound PVC one after other"
Context("when two pods request one prebound PVC at the same time"

@msau42 @jeffvance

CallMeFoxie · 2017-06-30T14:23:36Z

I am unsure if this fix fixes the GCE issues as well as I've never used GCE (or AWS for that matter) but it seems to fix it for self hosted kubernetes.

Can make it into PR if it's a reasonable fix? Only unsure about the err at opening /proc/mounts - not sure how it behaves on GCE/AWS/within docker.

ianchakeres · 2017-06-30T14:32:46Z

@CallMeFoxie - Let's reuse listProcMounts(procMountsPath) to get all the info from /proc/mounts.

Yes. Let's get a PR, and I'll test it on GCE.

You want to submit the PR or should I?

ianchakeres · 2017-06-30T15:22:14Z

Here's the code I'm testing.

	mountPoints, mountPointsErr := listProcMounts(procMountsPath)
        if mountPointsErr == nil {
                for _, mp := range mountPoints {
                        if mp.Path == file {
                                return false, nil
                        }
                }
        }

msau42 · 2017-06-30T20:22:46Z

If I understand correctly, the issue is if the underlying directory is a just a dir and not a mount point, and you bind mount that, then IsLikelyNotMountPoint() will detect it as a directory instead of a mount.

If that's the case, I'm curious why Ian's tests are only running into this problem in the case of two pods accessing the same volume.

msau42 · 2017-06-30T20:29:37Z

For the fix, I would prefer that a new method is used instead of IsLikelyNotMountPoint(). It is being used by other plugins and having to iterate through all the mounts on a node could impact performance. Also it is only the local storage plugin where the underyling directory may not be a mount point.

ianchakeres · 2017-06-30T20:33:26Z

@msau42 The tests are failing even if I run one pod after the other. I'll create a test that just uses one pod with create and destroy (instead of one-command pod) to see if I can repro the error.

msau42 · 2017-06-30T20:45:49Z

Ok, sounds like this is just a generic issue then with non-mount point local volumes then, which fits in with the root cause.

msau42 · 2017-06-30T22:20:10Z

Btw, I noticed in the common Unmount method, that if it thinks it is not a mount point, then it's going to go and delete all the contents of the directory. This is definitely not the behavior we want because the directory cleanup should only happen when the PV gets released and not during unmount.

So we should definitely get a fix into the next 1.7 patch.

cc @saad-ali

msau42 · 2017-06-30T22:37:43Z

Actually nevermind, the unmount calls os.Remove, not os.RemoveAll, so it's not as bad. Sorry for the scare.

ianchakeres · 2017-07-02T02:22:03Z

/assign @ianchakeres

…ssue Automatic merge from submit-queue Add local volume bug to known issues **What this PR does / why we need it**: Update known issues with local volume issue kubernetes#48331

Automatic merge from submit-queue Local storage teardown fix **What this PR does / why we need it**: Local storage uses bindmounts and the method IsLikelyNotMountPoint does not detect these as mountpoints. Therefore, local PVs are not properly unmounted when they are deleted. **Which issue this PR fixes**: fixes #48331 **Special notes for your reviewer**: You can use these e2e tests to reproduce the issue and validate the fix works appropriately #47999 The existing method IsLikelyNotMountPoint purposely does not check mountpoints reliability (https://github.com/kubernetes/kubernetes/blob/4c5b22d4c6b630ff1d76b1d15d74c6597c0aa037/pkg/util/mount/mount_linux.go#L161), since the number of mountpoints can be large. https://github.com/kubernetes/kubernetes/blob/4c5b22d4c6b630ff1d76b1d15d74c6597c0aa037/pkg/util/mount/mount.go#L46 This implementation changes the behavior for local storage to detect mountpoints reliably, and avoids changing the behavior for any other callers to a UnmountPath. **Release note**: ``` Fixes bind-mount teardown failure with non-mount point Local volumes (issue #48331). ```

arunmk · 2017-07-12T18:41:52Z

Is there a way to know the release for which this fix is scheduled?

Thanks

Automatic merge from submit-queue (batch tested with PRs 50670, 50332) e2e test for local storage mount point **What this PR does / why we need it**: We discovered that kubernetes can treat local directories and actual mountpoints differently. For example, #48331. The current local storage e2e tests use directories. This PR introduces a test that creates a tmpfs and mounts it, and runs one of the local storage e2e tests. **Which issue this PR fixes**: fixes #49126 **Special notes for your reviewer**: I cherrypicked PR #50177, since local storage e2e tests are broken in master on 2017-08-08 due to "no such host" error. This PR replaces NodeExec with SSH commands. You can run the tests using the following commands: ``` $ NUM_NODES=1 KUBE_FEATURE_GATES="PersistentLocalVolumes=true" go run hack/e2e.go -- -v --up $ go run hack/e2e.go -- -v --test --test_args="--ginkgo.focus=\[Feature:LocalPersistentVolumes\]" ``` Here are the summary of results from my test run: ``` Ran 9 of 651 Specs in 387.905 seconds SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 642 Skipped PASS Ginkgo ran 1 suite in 6m29.369318483s Test Suite Passed 2017/08/08 11:54:01 util.go:133: Step './hack/ginkgo-e2e.sh --ginkgo.focus=\[Feature:LocalPersistentVolumes\]' finished in 6m32.077462612s ``` **Release note**: `NONE`

Automatic merge from submit-queue Local storage teardown fix **What this PR does / why we need it**: Local storage uses bindmounts and the method IsLikelyNotMountPoint does not detect these as mountpoints. Therefore, local PVs are not properly unmounted when they are deleted. **Which issue this PR fixes**: fixes #48331 **Special notes for your reviewer**: You can use these e2e tests to reproduce the issue and validate the fix works appropriately kubernetes/kubernetes#47999 The existing method IsLikelyNotMountPoint purposely does not check mountpoints reliability (https://github.com/kubernetes/kubernetes/blob/4c5b22d4c6b630ff1d76b1d15d74c6597c0aa037/pkg/util/mount/mount_linux.go#L161), since the number of mountpoints can be large. https://github.com/kubernetes/kubernetes/blob/4c5b22d4c6b630ff1d76b1d15d74c6597c0aa037/pkg/util/mount/mount.go#L46 This implementation changes the behavior for local storage to detect mountpoints reliably, and avoids changing the behavior for any other callers to a UnmountPath. **Release note**: ``` Fixes bind-mount teardown failure with non-mount point Local volumes (issue kubernetes/kubernetes#48331). ```

k8s-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Jun 30, 2017

k8s-github-robot added the needs-sig Indicates an issue or PR lacks a `sig/foo` label and requires one. label Jun 30, 2017

k8s-ci-robot added the sig/storage Categorizes an issue or PR as relevant to SIG Storage. label Jun 30, 2017

k8s-github-robot removed the needs-sig Indicates an issue or PR lacks a `sig/foo` label and requires one. label Jun 30, 2017

saad-ali added this to the v1.7 milestone Jun 30, 2017

msau42 mentioned this issue Jun 30, 2017

Add local volume bug to known issues #48369

Merged

k8s-ci-robot assigned ianchakeres Jul 2, 2017

ianchakeres mentioned this issue Jul 2, 2017

Local storage teardown fix #48402

Merged

k8s-github-robot closed this as completed in #48402 Jul 12, 2017

msau42 mentioned this issue Jul 13, 2017

Automated cherry pick of #48402 #48524 upstream release 1.7 #48809

Merged

ianchakeres mentioned this issue Aug 8, 2017

e2e test for local storage mount point #50332

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Kubernetes 1.7.0 local storage teardown failed #48331

Kubernetes 1.7.0 local storage teardown failed #48331

CallMeFoxie commented Jun 30, 2017

k8s-github-robot commented Jun 30, 2017

CallMeFoxie commented Jun 30, 2017

CallMeFoxie commented Jun 30, 2017 •

edited

Loading

ianchakeres commented Jun 30, 2017

CallMeFoxie commented Jun 30, 2017

ianchakeres commented Jun 30, 2017

ianchakeres commented Jun 30, 2017 •

edited

Loading

msau42 commented Jun 30, 2017

msau42 commented Jun 30, 2017

ianchakeres commented Jun 30, 2017

msau42 commented Jun 30, 2017 •

edited

Loading

msau42 commented Jun 30, 2017

msau42 commented Jun 30, 2017

ianchakeres commented Jul 2, 2017

arunmk commented Jul 12, 2017

Kubernetes 1.7.0 local storage teardown failed #48331

Kubernetes 1.7.0 local storage teardown failed #48331

Comments

CallMeFoxie commented Jun 30, 2017

k8s-github-robot commented Jun 30, 2017

CallMeFoxie commented Jun 30, 2017

CallMeFoxie commented Jun 30, 2017 • edited Loading

ianchakeres commented Jun 30, 2017

CallMeFoxie commented Jun 30, 2017

ianchakeres commented Jun 30, 2017

ianchakeres commented Jun 30, 2017 • edited Loading

msau42 commented Jun 30, 2017

msau42 commented Jun 30, 2017

ianchakeres commented Jun 30, 2017

msau42 commented Jun 30, 2017 • edited Loading

msau42 commented Jun 30, 2017

msau42 commented Jun 30, 2017

ianchakeres commented Jul 2, 2017

arunmk commented Jul 12, 2017

CallMeFoxie commented Jun 30, 2017 •

edited

Loading

ianchakeres commented Jun 30, 2017 •

edited

Loading

msau42 commented Jun 30, 2017 •

edited

Loading