Pods do not get cleaned up #45688

lorenz · 2017-05-11T21:13:09Z

#28750 describes the problem for a much older Kubernetes version and is marked as fixed.

Is this a BUG REPORT or FEATURE REQUEST? (choose one): Bug Report

Kubernetes version:

Client Version: version.Info{Major:"1", Minor:"6", GitVersion:"v1.6.1", GitCommit:"b0b7a323cc5a4a2019b2e9520c21c7830b7f708e", GitTreeState:"clean", BuildDate:"2017-04-03T20:44:38Z", GoVersion:"go1.7.5", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"6", GitVersion:"v1.6.1+coreos.0", GitCommit:"9212f77ed8c169a0afa02e58dce87913c6387b3e", GitTreeState:"clean", BuildDate:"2017-04-04T00:32:53Z", GoVersion:"go1.7.5", Compiler:"gc", Platform:"linux/amd64"}

Environment:

3 Physical Linux servers
CoreOS 1353.7.0 (latest stable)
4.9.24-coreos
Set up from scratch, custom OSPF networking using CNI
Hyperkube using kubelet-wrapper

What happened:
Some terminated pods are not cleaned up (staying in Terminating state) for a long time (maybe indefinitely?) because of issues deleting secret volumes.

Log excerpt:

May 11 20:56:07 yellow kubelet-wrapper[7595]: E0511 20:56:07.540894    7595 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/secret/91eabb5e-336f-11e7-927a-d43d7e00dee7-default-token-86xhs\" (\"91eabb5e-336f-11e7-927a-d43d7e00dee7\")" failed. No retries permitted until 2017-05-11 20:58:07.540871959 +0000 UTC (durationBeforeRetry 2m0s). Error: UnmountVolume.TearDown failed for volume "kubernetes.io/secret/91eabb5e-336f-11e7-927a-d43d7e00dee7-default-token-86xhs" (volume.spec.Name: "default-token-86xhs") pod "91eabb5e-336f-11e7-927a-d43d7e00dee7" (UID: "91eabb5e-336f-11e7-927a-d43d7e00dee7") with: rename /var/lib/kubelet/pods/91eabb5e-336f-11e7-927a-d43d7e00dee7/volumes/kubernetes.io~secret/default-token-86xhs /var/lib/kubelet/pods/91eabb5e-336f-11e7-927a-d43d7e00dee7/volumes/kubernetes.io~secret/wrapped_default-token-86xhs.deleting~739204662: device or resource busy
May 11 20:56:07 yellow kubelet-wrapper[7595]: E0511 20:56:07.540858    7595 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/secret/6d50be26-3371-11e7-a5bf-74d435166e57-default-token-86xhs\" (\"6d50be26-3371-11e7-a5bf-74d435166e57\")" failed. No retries permitted until 2017-05-11 20:58:07.540839041 +0000 UTC (durationBeforeRetry 2m0s). Error: UnmountVolume.TearDown failed for volume "kubernetes.io/secret/6d50be26-3371-11e7-a5bf-74d435166e57-default-token-86xhs" (volume.spec.Name: "default-token-86xhs") pod "6d50be26-3371-11e7-a5bf-74d435166e57" (UID: "6d50be26-3371-11e7-a5bf-74d435166e57") with: rename /var/lib/kubelet/pods/6d50be26-3371-11e7-a5bf-74d435166e57/volumes/kubernetes.io~secret/default-token-86xhs /var/lib/kubelet/pods/6d50be26-3371-11e7-a5bf-74d435166e57/volumes/kubernetes.io~secret/wrapped_default-token-86xhs.deleting~556013427: device or resource busy
May 11 20:56:07 yellow kubelet-wrapper[7595]: I0511 20:56:07.540561    7595 reconciler.go:190] UnmountVolume operation started for volume "kubernetes.io/secret/91eabb5e-336f-11e7-927a-d43d7e00dee7-default-token-86xhs" (spec.Name: "default-token-86xhs") from pod "91eabb5e-336f-11e7-927a-d43d7e00dee7" (UID: "91eabb5e-336f-11e7-927a-d43d7e00dee7").
May 11 20:56:07 yellow kubelet-wrapper[7595]: I0511 20:56:07.540462    7595 reconciler.go:190] UnmountVolume operation started for volume "kubernetes.io/secret/6d50be26-3371-11e7-a5bf-74d435166e57-default-token-86xhs" (spec.Name: "default-token-86xhs") from pod "6d50be26-3371-11e7-a5bf-74d435166e57" (UID: "6d50be26-3371-11e7-a5bf-74d435166e57").

Excerpt from mount:

tmpfs on /var/lib/kubelet/pods/91eabb5e-336f-11e7-927a-d43d7e00dee7/volumes/kubernetes.io~secret/default-token-86xhs type tmpfs (rw,relatime,seclabel)

Output from fuser -vm:

                     USER        PID ACCESS COMMAND
/var/lib/kubelet/pods/91eabb5e-336f-11e7-927a-d43d7e00dee7/volumes/kubernetes.io~secret/default-token-86xhs:
                     root     kernel mount /var/lib/kubelet/pods/91eabb5e-336f-11e7-927a-d43d7e00dee7/volumes/kubernetes.io~secret/default-token-86xhs

The reason why they're not being cleaned up is because the volume is not being unmounted before being moved to the deletion area and you can't move a directory which is a mountpoint with a rename() syscall, which is what Go does internally when you call os.Rename.

What you expected to happen:
The Pods should be cleaned up.

How to reproduce it (as minimally and precisely as possible):
Happens on all three machines, so probably CoreOS + kubelet-wrapper should work.

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

jagosan · 2017-05-12T21:54:44Z

/sig node
@kubernetes/sig-node-bugs

Great write-up, thanks for the extra detail.

k8s-ci-robot · 2017-05-12T21:54:53Z

@jagosan: Reiterating the mentions to trigger a notification:
@kubernetes/sig-node-bugs.

In response to this:

/sig node
@kubernetes/sig-node-bugs

Great write-up, thanks for the extra detail.

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. I understand the commands that are listed here.

moon03432 · 2017-05-24T07:00:24Z

@lorenz I had the same issue, but it's now resolved. Maybe you could try "grep -l container_id /proc/*/mountinfo" to check who's preventing your pod from terminating.

muffin87 · 2017-07-04T10:05:49Z

@moon03432: I have the same problem. Can you tell me how you resolved the problem?

I see containers in state Dead

docker ps -a | grep -i dead
0576840ae036        memcached@sha256:ba5e944da20c3be51cf2e9e4d9b791ef196e718cb4397f9a19040859f0fdc9c1                                           "docker-entrypoint.sh"   5 days ago          Dead                                                                  k8s_distribution-memcached.ca523114_distribution-memcached-1887283407-bzr10_playground_03dc6bd3-4f82-11e7-b0aa-1c98ec1a3b64_f2e75018
04102f1b8cd3        gcr.io/google_containers/pause-amd64@sha256:163ac025575b775d1c0f9bf0bdd0f086883171eb475b5068e7defa4ca9e76516                "/pause"                 5 days ago          Dead                                                                  k8s_POD.f932fb66_distribution-memcached-1887283407-bzr10_playground_03dc6bd3-4f82-11e7-b0aa-1c98ec1a3b64_28a76405

When it comes to deleting I also get this error message

docker rm k8s_POD.f932fb66_distribution-memcached-1887283407-bzr10_playground_03dc6bd3-4f82-11e7-b0aa-1c98ec1a3b64_28a76405
Error response from daemon: Unable to remove filesystem for 04102f1b8cd3a83dc034c6721202270cebf089931d2fb541ec6aa579a1b84309: remove /var/lib/docker/containers/04102f1b8cd3a83dc034c6721202270cebf089931d2fb541ec6aa579a1b84309/shm: device or resource busy

The strange thing for me was that the mountinfo grep listed my three hits:

grep docker /proc/*/mountinfo | grep 04102f1b8cd3a83dc034c6721202270cebf089931d2fb541ec6aa579a1b84309
/proc/24991/mountinfo:1107 1092 0:61 / /var/lib/docker/containers/04102f1b8cd3a83dc034c6721202270cebf089931d2fb541ec6aa579a1b84309/shm rw,nosuid,nodev,noexec,relatime - tmpfs shm rw,seclabel,size=65536k
/proc/25007/mountinfo:1107 1092 0:61 / /var/lib/docker/containers/04102f1b8cd3a83dc034c6721202270cebf089931d2fb541ec6aa579a1b84309/shm rw,nosuid,nodev,noexec,relatime - tmpfs shm rw,seclabel,size=65536k
/proc/25314/mountinfo:1562 1342 0:61 / /root-disk/var/lib/docker/containers/04102f1b8cd3a83dc034c6721202270cebf089931d2fb541ec6aa579a1b84309/shm rw,nosuid,nodev,noexec,relatime - tmpfs shm rw,seclabel,size=65536k

When I look at the pids i see:

ps auwx | grep 24991 | grep -v grep
root     24991  0.0  0.0  77144 20572 ?        Ssl  Jun29   0:00 /usr/bin/ruby /usr/bin/fluentd -c /fluentd/etc/fluent.conf -p /fluentd/plugins
ps auwx | grep 25007 | grep -v grep
root     25007  0.9  0.0 191708 79384 ?        Sl   Jun29  61:12 /usr/bin/ruby /usr/bin/fluentd -c /fluentd/etc/fluent.conf -p /fluentd/plugins
ps auwx | grep 25314 | grep -v grep
root     25314  0.1  0.0 1946604 35112 ?       Ssl  Jun29   9:03 /bin/node_exporter

lorenz · 2017-07-08T19:41:40Z

Just wanted to say that this is still an issue on 1.7.0. This is also not caused by a process hanging on to the mountpoint, I can unmount the path/volume myself and kubelet will clean up the pod. Could we have kubelet attempt unmounting if it sees that a volume can't be removed because it's busy? I could prepare a PR for that.

euank · 2017-07-11T00:55:18Z

What Container Linux version are you reproducing this on, @lorenz?

We included a kubelet-wrapper change in 1353.8.0 which fixes an issue with the same symptoms.

lorenz · 2017-07-11T15:26:57Z

@euank After some tests I think you're right. I tried to reproduce on the two machines on 1409.5.0 and it cleans up pods properly. The only machine where it doesn't is the one still on 1298.7.0 (soon going to get updated). So I think we can (at least for my problem, not sure about the other ones) close this as fixed in CoreOS 1353.8.0.

moon03432 · 2017-07-19T11:27:07Z

@muffin87 I just killed my node_exporter. I think this could release some dead containers but not all of them.

muffin87 · 2017-07-20T06:10:32Z

@moon03432: Thanks for the answer! Yeah right killing node_exporter and flutend will free up the busy resources.

I can reproduce this when I create a Pod and mount /var/lib into the container.
I think this could be a combined problem with CentOS 7.3 and the old kernel and devicemapper docker storage driver.

matthewceroni · 2017-09-07T17:23:48Z

@euank

Do you happen to have a Issue # within the CoreOS project that describes the fix?

euank · 2017-09-07T21:02:36Z

@matthewceroni yeah, it's coreos/bugs#1831 (comment) / coreos/coreos-overlay#2508

jingxu97 · 2017-10-19T21:49:11Z

ref #51835

- Mark kubelet datadir volume as a recursive mount in kubelet-wrapper kubernetes/kubernetes#45688 https://github.com/coreos/coreos-overlay/pull/2508/files

rambo45 · 2018-02-01T06:03:50Z

I am still getting this error with kubelet 1.9.2

Nothing shows up with lsof or fuser on /var/lib/kubelet/pods/..

Apparently, stopping the docker service released the lock and i was able to remove those directories manually

lorenz · 2018-02-01T13:19:46Z

@rambo45 Are you running Docker 17.xx? These still don't seem to be stable with Kubernetes.

rambo45 · 2018-02-05T05:10:33Z

@lorenz I am running Docker 17.03, it seem to work for the most part until you start deleting and recreating containers rapidly which seem to hit a race condition with the volume cleanups. I think its still manageable once there is enough documentation around these scenarios.

lorenz · 2018-02-05T05:30:25Z

@rambo45 Seeing exactly the same. Luckily CoreOS still ships 1.12 if you enable it, so I'm currently running that option everywhere. I have a lot of container churn, so staying on 17.09 (what CoreOS ships by default) was not an option, within 24h I accumulated a few hundred pods stuck in terminating. Still awaiting a proper cri-containerd so that I can get rid of Docker for good.

k8s-ci-robot added the sig/node Categorizes an issue or PR as relevant to SIG Node. label May 12, 2017

lorenz closed this as completed Jul 11, 2017

puneetkatyal mentioned this issue Oct 21, 2017

Fix pods not getting cleaned up vmware-archive/ansible-coreos-kubelet#8

Merged

Paxa mentioned this issue Jul 17, 2018

Pods stuck on terminating #51835

Closed

tvs mentioned this issue Jul 24, 2018

CFCR should ship with a Kubernetes-validated version of Docker cloudfoundry-incubator/kubo-deployment#332

Closed

tmiddlet2666 mentioned this issue May 29, 2019

Document Pod Deletion Issue when using K8s < 1.13.0 oracle/coherence-operator#151

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Pods do not get cleaned up #45688

Pods do not get cleaned up #45688

lorenz commented May 11, 2017 •

edited

Loading

jagosan commented May 12, 2017

k8s-ci-robot commented May 12, 2017

moon03432 commented May 24, 2017 •

edited

Loading

muffin87 commented Jul 4, 2017

lorenz commented Jul 8, 2017 •

edited

Loading

euank commented Jul 11, 2017

lorenz commented Jul 11, 2017

moon03432 commented Jul 19, 2017

muffin87 commented Jul 20, 2017

matthewceroni commented Sep 7, 2017

euank commented Sep 7, 2017

jingxu97 commented Oct 19, 2017

rambo45 commented Feb 1, 2018

lorenz commented Feb 1, 2018

rambo45 commented Feb 5, 2018

lorenz commented Feb 5, 2018

Pods do not get cleaned up #45688

Pods do not get cleaned up #45688

Comments

lorenz commented May 11, 2017 • edited Loading

jagosan commented May 12, 2017

k8s-ci-robot commented May 12, 2017

moon03432 commented May 24, 2017 • edited Loading

muffin87 commented Jul 4, 2017

lorenz commented Jul 8, 2017 • edited Loading

euank commented Jul 11, 2017

lorenz commented Jul 11, 2017

moon03432 commented Jul 19, 2017

muffin87 commented Jul 20, 2017

matthewceroni commented Sep 7, 2017

euank commented Sep 7, 2017

jingxu97 commented Oct 19, 2017

rambo45 commented Feb 1, 2018

lorenz commented Feb 1, 2018

rambo45 commented Feb 5, 2018

lorenz commented Feb 5, 2018

lorenz commented May 11, 2017 •

edited

Loading

moon03432 commented May 24, 2017 •

edited

Loading

lorenz commented Jul 8, 2017 •

edited

Loading