Re: [kubernetes/kubernetes] EBS volume remains attached (#52906)
k8s-ci-robot
@yurig93: Reiterating the mentions to trigger a notification:
@kubernetes/sig-aws-bugs, @kubernetes/sig-storage-bugs
In response to this:
@kubernetes/sig-aws-bugs
@kubernetes/sig-storage-bugs
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.
—
You are receiving this because you are on a team that was mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.
Hemant Kumar
Can you post kubelet logs from node where volume was attached? There may be something there and we want to verify if volume was unmounted correctly after Deployment was deleted.
yurig93
This is the log right after deleting the NFS deployment:
Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.398960 1684 kubelet.go:1824] SyncLoop (DELETE, "api"): "dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala(19993cdd-9f9e-11e7-9180-0a169b5127b8)" Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.399393 1684 kuberuntime_container.go:545] Killing container "docker://8d770d238a5c5e63768c330aee6bab778b4ef2f4a0e69774de5ed784d99cf676" with 0 second grace period Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.421253 1684 kubelet.go:1818] SyncLoop (REMOVE, "api"): "dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala(19993cdd-9f9e-11e7-9180-0a169b5127b8)" Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.429334 1684 kubelet_pods.go:917] Killing unwanted pod "dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c" Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.429378 1684 kuberuntime_container.go:545] Killing container "docker://8d770d238a5c5e63768c330aee6bab778b4ef2f4a0e69774de5ed784d99cf676" with 0 second grace period Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.753823 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/54a14dda-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "54a14dda-9f8f-11e7-9180-0a169b5127b8" (UID: "54a14dda-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: W0922 15:50:31.763947 1684 container_manager_linux.go:741] CPUAccounting not enabled for pid: 1349 Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: W0922 15:50:31.763966 1684 container_manager_linux.go:744] MemoryAccounting not enabled for pid: 1349 Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.763971 1684 container_manager_linux.go:397] [ContainerManager]: Discovered runtime cgroups name: /system.slice/docker.service Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: W0922 15:50:31.764028 1684 container_manager_linux.go:741] CPUAccounting not enabled for pid: 1684 Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: W0922 15:50:31.764032 1684 container_manager_linux.go:744] MemoryAccounting not enabled for pid: 1684 Sep 22 15:50:31 ip-172-20-74-3 kubelet[1684]: I0922 15:50:31.857019 1684 qos_container_manager_linux.go:285] [ContainerManager]: Updated QoS cgroup configuration Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: I0922 15:50:33.041071 1 kube_boot.go:120] Not in role master; won't scan for volumes Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: I0922 15:50:33.041110 1 kube_boot.go:157] ensuring that kubelet systemd service is running Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: I0922 15:50:33.044487 1 kube_boot.go:160] 'systemctl status kubelet' output: Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: ● kubelet.service - Kubernetes Kubelet Server Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: Loaded: loaded (/lib/systemd/system/kubelet.service; static) Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: Active: active (running) since Fri 2017-09-22 12:10:31 UTC; 3h 40min ago Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: Docs: https://github.com/kubernetes/kubernetes Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: Main PID: 1684 Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: CGroup: /system.slice/kubelet.service Sep 22 15:50:33 ip-172-20-74-3 docker[1631]: I0922 15:50:33.044515 1 kube_boot.go:162] kubelet systemd service already running Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: W0922 15:50:33.464044 1684 kuberuntime_container.go:446] No ref for container {"docker" "8d770d238a5c5e63768c330aee6bab778b4ef2f4a0e69774de5ed784d99cf676"} Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: I0922 15:50:33.557335 1684 reconciler.go:201] UnmountVolume operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-gp2-3-lala-my-second-env") from pod "19993cdd-9f9e-11e7-9180-0a169b5127b8" (UID: "19993cdd-9f9e-11e7-9180-0a169b5127b8"). Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: I0922 15:50:33.557417 1684 reconciler.go:201] UnmountVolume operation started for volume "kubernetes.io/secret/19993cdd-9f9e-11e7-9180-0a169b5127b8-default-token-b7r73" (spec.Name: "default-token-b7r73") from pod "19993cdd-9f9e-11e7-9180-0a169b5127b8" (UID: "19993cdd-9f9e-11e7-9180-0a169b5127b8"). Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: I0922 15:50:33.576223 1684 operation_generator.go:672] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/19993cdd-9f9e-11e7-9180-0a169b5127b8-default-token-b7r73" (OuterVolumeSpecName: "default-token-b7r73") pod "19993cdd-9f9e-11e7-9180-0a169b5127b8" (UID: "19993cdd-9f9e-11e7-9180-0a169b5127b8"). InnerVolumeSpecName "default-token-b7r73". PluginName "kubernetes.io/secret", VolumeGidValue "" Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: I0922 15:50:33.576223 1684 operation_generator.go:672] UnmountVolume.TearDown succeeded for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (OuterVolumeSpecName: "pvc-gp2-3-lala-my-second-env") pod "19993cdd-9f9e-11e7-9180-0a169b5127b8" (UID: "19993cdd-9f9e-11e7-9180-0a169b5127b8"). InnerVolumeSpecName "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa". PluginName "kubernetes.io/aws-ebs", VolumeGidValue "" Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: E0922 15:50:33.649070 1684 remote_runtime.go:109] StopPodSandbox "10daa3ffa603da2884b45433f4333612587452daa1f16a5ebd59c84b48c3ef72" from runtime service failed: rpc error: code = 2 desc = NetworkPlugin kubenet failed to teardown pod "dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala" network: Error removing container from network: failed to Statfs "/proc/8095/ns/net": no such file or directory Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: E0922 15:50:33.649124 1684 kuberuntime_manager.go:784] Failed to stop sandbox {"docker" "10daa3ffa603da2884b45433f4333612587452daa1f16a5ebd59c84b48c3ef72"} Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: E0922 15:50:33.649174 1684 kubelet.go:1455] error killing pod: failed to "KillPodSandbox" for "19993cdd-9f9e-11e7-9180-0a169b5127b8" with KillPodSandboxError: "rpc error: code = 2 desc = NetworkPlugin kubenet failed to teardown pod \"dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala\" network: Error removing container from network: failed to Statfs \"/proc/8095/ns/net\": no such file or directory" Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: E0922 15:50:33.649201 1684 pod_workers.go:182] Error syncing pod 19993cdd-9f9e-11e7-9180-0a169b5127b8 ("dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala(19993cdd-9f9e-11e7-9180-0a169b5127b8)"), skipping: error killing pod: failed to "KillPodSandbox" for "19993cdd-9f9e-11e7-9180-0a169b5127b8" with KillPodSandboxError: "rpc error: code = 2 desc = NetworkPlugin kubenet failed to teardown pod \"dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala\" network: Error removing container from network: failed to Statfs \"/proc/8095/ns/net\": no such file or directory" Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: I0922 15:50:33.649439 1684 qos_container_manager_linux.go:285] [ContainerManager]: Updated QoS cgroup configuration Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: I0922 15:50:33.657776 1684 reconciler.go:353] UnmountDevice operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: I0922 15:50:33.657814 1684 reconciler.go:363] Detached volume "kubernetes.io/secret/19993cdd-9f9e-11e7-9180-0a169b5127b8-default-token-b7r73" (spec.Name: "default-token-b7r73") devicePath: "" Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: E0922 15:50:33.672214 1684 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40\"" failed. No retries permitted until 2017-09-22 15:50:34.172181426 +0000 UTC (durationBeforeRetry 500ms). Error: UnmountDevice failed for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") because the device is in use when it was no longer expected to be in use Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: W0922 15:50:33.689336 1684 docker_sandbox.go:263] NetworkPlugin kubenet failed on the status hook for pod "dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala": Cannot find the network namespace, skipping pod network status for container {"docker" "10daa3ffa603da2884b45433f4333612587452daa1f16a5ebd59c84b48c3ef72"} Sep 22 15:50:33 ip-172-20-74-3 kubelet[1684]: W0922 15:50:33.692924 1684 pod_container_deletor.go:77] Container "10daa3ffa603da2884b45433f4333612587452daa1f16a5ebd59c84b48c3ef72" not found in pod's containers Sep 22 15:50:34 ip-172-20-74-3 kubelet[1684]: I0922 15:50:34.259467 1684 reconciler.go:353] UnmountDevice operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") Sep 22 15:50:34 ip-172-20-74-3 kubelet[1684]: W0922 15:50:34.261528 1684 mount.go:131] could not determine device for path: "/var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40" Sep 22 15:50:34 ip-172-20-74-3 kubelet[1684]: W0922 15:50:34.261553 1684 util.go:76] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40 Sep 22 15:50:34 ip-172-20-74-3 kubelet[1684]: E0922 15:50:34.261602 1684 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40\"" failed. No retries permitted until 2017-09-22 15:50:35.261576055 +0000 UTC (durationBeforeRetry 1s). Error: UnmountDevice failed for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") because the device is in use when it was no longer expected to be in use Sep 22 15:50:34 ip-172-20-74-3 ntpd[1292]: Deleting interface #30 veth0e95ebe7, fe80::289e:91ff:fe2f:536a#123, interface stats: received=0, sent=0, dropped=0, active_time=6726 secs Sep 22 15:50:34 ip-172-20-74-3 ntpd[1292]: peers refreshed Sep 22 15:50:35 ip-172-20-74-3 kubelet[1684]: W0922 15:50:35.017744 1684 docker_sandbox.go:263] NetworkPlugin kubenet failed on the status hook for pod "dpl-nfs-ssh-3-lala-my-second-env-1630197342-0rv4c_ns-lala": Cannot find the network namespace, skipping pod network status for container {"docker" "10daa3ffa603da2884b45433f4333612587452daa1f16a5ebd59c84b48c3ef72"} Sep 22 15:50:35 ip-172-20-74-3 dockerd[1349]: time="2017-09-22T15:50:35.028533642Z" level=error msg="Handler for POST /v1.24/containers/10daa3ffa603da2884b45433f4333612587452daa1f16a5ebd59c84b48c3ef72/stop returned error: Container 10daa3ffa603da2884b45433f4333612587452daa1f16a5ebd59c84b48c3ef72 is already stopped" Sep 22 15:50:35 ip-172-20-74-3 kubelet[1684]: I0922 15:50:35.262579 1684 reconciler.go:353] UnmountDevice operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") Sep 22 15:50:35 ip-172-20-74-3 kubelet[1684]: W0922 15:50:35.264654 1684 mount.go:131] could not determine device for path: "/var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40" Sep 22 15:50:35 ip-172-20-74-3 kubelet[1684]: W0922 15:50:35.264675 1684 util.go:76] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40 Sep 22 15:50:35 ip-172-20-74-3 kubelet[1684]: E0922 15:50:35.264727 1684 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40\"" failed. No retries permitted until 2017-09-22 15:50:37.26469833 +0000 UTC (durationBeforeRetry 2s). Error: UnmountDevice failed for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") because the device is in use when it was no longer expected to be in use Sep 22 15:50:37 ip-172-20-74-3 kubelet[1684]: I0922 15:50:37.268305 1684 reconciler.go:353] UnmountDevice operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") Sep 22 15:50:37 ip-172-20-74-3 kubelet[1684]: W0922 15:50:37.270457 1684 mount.go:131] could not determine device for path: "/var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40" Sep 22 15:50:37 ip-172-20-74-3 kubelet[1684]: W0922 15:50:37.270485 1684 util.go:76] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40 Sep 22 15:50:37 ip-172-20-74-3 kubelet[1684]: E0922 15:50:37.270548 1684 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40\"" failed. No retries permitted until 2017-09-22 15:50:41.270521064 +0000 UTC (durationBeforeRetry 4s). Error: UnmountDevice failed for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") because the device is in use when it was no longer expected to be in use Sep 22 15:50:40 ip-172-20-74-3 kubelet[1684]: I0922 15:50:40.780746 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/5425951f-9f8f-11e7-9180-0a169b5127b8-default-token-snxdf" (spec.Name: "default-token-snxdf") pod "5425951f-9f8f-11e7-9180-0a169b5127b8" (UID: "5425951f-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:50:41 ip-172-20-74-3 kubelet[1684]: I0922 15:50:41.280824 1684 reconciler.go:353] UnmountDevice operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") Sep 22 15:50:41 ip-172-20-74-3 systemd[1]: Starting Run docker-healthcheck once... Sep 22 15:50:41 ip-172-20-74-3 kubelet[1684]: W0922 15:50:41.283519 1684 mount.go:131] could not determine device for path: "/var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40" Sep 22 15:50:41 ip-172-20-74-3 kubelet[1684]: W0922 15:50:41.283543 1684 util.go:76] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40 Sep 22 15:50:41 ip-172-20-74-3 kubelet[1684]: E0922 15:50:41.283583 1684 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40\"" failed. No retries permitted until 2017-09-22 15:50:49.283562968 +0000 UTC (durationBeforeRetry 8s). Error: UnmountDevice failed for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") because the device is in use when it was no longer expected to be in use Sep 22 15:50:41 ip-172-20-74-3 docker-healthcheck[9841]: docker healthy Sep 22 15:50:41 ip-172-20-74-3 systemd[1]: Started Run docker-healthcheck once. cceeded for volume "kubernetes.io/secret/542c37fe-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "542c37fe-9f8f-11e7-9180-0a169b5127b8" (UID: "542c37fe-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:50:48 ip-172-20-74-3 kubelet[1684]: I0922 15:50:48.805850 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/540ee71c-9f8f-11e7-9180-0a169b5127b8-kube-dns-autoscaler-token-mb07k" (spec.Name: "kube-dns-autoscaler-token-mb07k") pod "540ee71c-9f8f-11e7-9180-0a169b5127b8" (UID: "540ee71c-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:50:49 ip-172-20-74-3 kubelet[1684]: I0922 15:50:49.305715 1684 reconciler.go:353] UnmountDevice operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") Sep 22 15:50:49 ip-172-20-74-3 kubelet[1684]: W0922 15:50:49.307811 1684 mount.go:131] could not determine device for path: "/var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40" Sep 22 15:50:49 ip-172-20-74-3 kubelet[1684]: W0922 15:50:49.307872 1684 util.go:76] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40 Sep 22 15:50:49 ip-172-20-74-3 kubelet[1684]: E0922 15:50:49.307928 1684 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40\"" failed. No retries permitted until 2017-09-22 15:51:05.307900779 +0000 UTC (durationBeforeRetry 16s). Error: UnmountDevice failed for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") because the device is in use when it was no longer expected to be in use Sep 22 15:50:51 ip-172-20-74-3 kubelet[1684]: I0922 15:50:51.814563 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/54a8eb66-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "54a8eb66-9f8f-11e7-9180-0a169b5127b8" (UID: "54a8eb66-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:50:56 ip-172-20-74-3 kubelet[1684]: I0922 15:50:56.831240 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/546bd5ae-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "546bd5ae-9f8f-11e7-9180-0a169b5127b8" (UID: "546bd5ae-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:50:56 ip-172-20-74-3 systemd[1]: Starting Run docker-healthcheck once... Sep 22 15:50:56 ip-172-20-74-3 docker-healthcheck[9940]: docker healthy Sep 22 15:50:56 ip-172-20-74-3 systemd[1]: Started Run docker-healthcheck once. Sep 22 15:51:05 ip-172-20-74-3 kubelet[1684]: I0922 15:51:05.358018 1684 reconciler.go:353] UnmountDevice operation started for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") Sep 22 15:51:05 ip-172-20-74-3 kubelet[1684]: W0922 15:51:05.360289 1684 mount.go:131] could not determine device for path: "/var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40" Sep 22 15:51:05 ip-172-20-74-3 kubelet[1684]: W0922 15:51:05.360314 1684 util.go:76] Warning: Unmount skipped because path does not exist: /var/lib/kubelet/plugins/kubernetes.io/aws-ebs/mounts/aws/eu-west-1b/vol-0231dc67e42591d40 Sep 22 15:51:05 ip-172-20-74-3 kubelet[1684]: E0922 15:51:05.360380 1684 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40\"" failed. No retries permitted until 2017-09-22 15:51:37.360351365 +0000 UTC (durationBeforeRetry 32s). Error: UnmountDevice failed for volume "kubernetes.io/aws-ebs/aws://eu-west-1b/vol-0231dc67e42591d40" (spec.Name: "pvc-5d8b778f-9f9d-11e7-8d0a-020e29f6e7aa") because the device is in use when it was no longer expected to be in use Sep 22 15:51:05 ip-172-20-74-3 kubelet[1684]: I0922 15:51:05.760746 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/5444eecb-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "5444eecb-9f8f-11e7-9180-0a169b5127b8" (UID: "5444eecb-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:51:05 ip-172-20-74-3 kubelet[1684]: I0922 15:51:05.761787 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/5412d914-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "5412d914-9f8f-11e7-9180-0a169b5127b8" (UID: "5412d914-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:51:07 ip-172-20-74-3 systemd[1]: Starting Run docker-healthcheck once... Sep 22 15:51:07 ip-172-20-74-3 docker-healthcheck[10070]: docker healthy Sep 22 15:51:07 ip-172-20-74-3 systemd[1]: Started Run docker-healthcheck once. Sep 22 15:51:08 ip-172-20-74-3 kubelet[1684]: I0922 15:51:08.769332 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/54b0791d-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "54b0791d-9f8f-11e7-9180-0a169b5127b8" (UID: "54b0791d-9f8f-11e7-9180-0a169b5127b8"). Sep 22 15:51:12 ip-172-20-74-3 kubelet[1684]: I0922 15:51:12.780574 1684 operation_generator.go:597] MountVolume.SetUp succeeded for volume "kubernetes.io/secret/546438d4-9f8f-11e7-9180-0a169b5127b8-default-token-plth9" (spec.Name: "default-token-plth9") pod "546438d4-9f8f-11e7-9180-0a169b5127b8" (UID: "546438d4-9f8f-11e7-9180-0a169b5127b8").
Jing Xu
seem like volume manager able to unmount the bind mount path, but failed to unmount the global device mount path because the device is in use. @yurig93 Could you please check whether the device is still in used by some mount paths?
Hemant Kumar
If the device is still mounted (as reported in log above), can you check which process is using it? In general I have seen similar problem like this when a mount point leaks in another namespace because of another container using that volume (may be not directly but because this other container mounted /var/lib/docker/ or some other common location).
You can do cat /proc/*/mounts to find out process that could be holding the global device mount point.
yurig93
The device is no longer mounted :(
fejta-bot
Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.
Prevent issues from auto-closing with an /lifecycle frozen comment.
If this issue is safe to close now please do so with /close.
Send feedback to sig-testing, kubernetes/test-infra and/or @fejta.
/lifecycle stale
yurig93
/lifecycle frozen
yurig93
/remove-lifecycle stale
Jing Xu
@yurig93 Do you still have issue with this?
yurig93
@jingxu97 yes, moreover dynamically provisiond ebs volumes sometimes fail to attach...
`Events:
Type Reason Age From Message
Normal Scheduled 41m default-scheduler Successfully assigned dpl-nfs-ssh-90-cohgi01-gil-1691421208-fxcjc to ip-172-20-45-129.eu-west-1.compute.internal
Normal SuccessfulMountVolume 41m kubelet, ip-172-20-45-129.eu-west-1.compute.internal MountVolume.SetUp succeeded for volume "default-token-tb4mb"
Warning FailedMount 9m attachdetach AttachVolume.Attach failed for volume "pvc-95d74bd1-0448-11e8-be8c-027a6ab039aa" : timed out waiting for the condition
Warning FailedMount 19s (x18 over 39m) kubelet, ip-172-20-45-129.eu-west-1.compute.internal Unable to mount volumes for pod "dpl-nfs-ssh-90-cohgi01-gil-1691421208-fxcjc_ns-cohgi01(9c23e475-0448-11e8-9625-0afbf281ec9a)": timeout expired waiting for volumes to attach/mount for pod "ns-cohgi01"/"dpl-nfs-ssh-90-cohgi01-gil-1691421208-fxcjc". list of unattached/unmounted volumes=[vol-pvc-pvc-gp2-90-cohgi01-gil]
Warning FailedSync 19s (x18 over 39m) kubelet, ip-172-20-45-129.eu-west-1.compute.internal Error syncing pod`
Will Tran
I'm having a similar issue with the concourse chart, worker pods are privileged and run docker. I'm running k8s 1.7.11, and I run no other pods on the node other than concourse-worker and kube proxy. Here's the log output when I stop the pod:
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.780195 1271 reconciler.go:186] operationExecutor.UnmountVolume started for volume "concourse-work-dir" (UniqueName: "kubernetes.io/aws-ebs/aws://us-west-2b/vol-0da204d1146373310") pod "27f69bca-07c7-11e8-a296-02a725473222" (UID: "27f69bca-07c7-11e8-a296-02a725473222")
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.780237 1271 reconciler.go:186] operationExecutor.UnmountVolume started for volume "concourse-worker-token-j930k" (UniqueName: "kubernetes.io/secret/27f69bca-07c7-11e8-a296-02a725473222-concourse-worker-token-j930k") pod "27f69bca-07c7-11e8-a296-02a725473222" (UID: "27f69bca-07c7-11e8-a296-02a725473222")
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.812474 1271 operation_generator.go:527] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/27f69bca-07c7-11e8-a296-02a725473222-concourse-worker-token-j930k" (OuterVolumeSpecName: "concourse-worker-token-j930k") pod "27f69bca-07c7-11e8-a296-02a725473222" (UID: "27f69bca-07c7-11e8-a296-02a725473222"). InnerVolumeSpecName "concourse-worker-token-j930k". PluginName "kubernetes.io/secret", VolumeGidValue ""
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.812036 1271 operation_generator.go:527] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/27f69bca-07c7-11e8-a296-02a725473222-concourse-keys" (OuterVolumeSpecName: "concourse-keys") pod "27f69bca-07c7-11e8-a296-02a725473222" (UID: "27f69bca-07c7-11e8-a296-02a725473222"). InnerVolumeSpecName "concourse-keys". PluginName "kubernetes.io/secret", VolumeGidValue ""
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.815953 1271 operation_generator.go:527] UnmountVolume.TearDown succeeded for volume "kubernetes.io/aws-ebs/aws://us-west-2b/vol-0da204d1146373310" (OuterVolumeSpecName: "concourse-work-dir") pod "27f69bca-07c7-11e8-a296-02a725473222" (UID: "27f69bca-07c7-11e8-a296-02a725473222"). InnerVolumeSpecName "pvc-27e652d8-07c7-11e8-a296-02a725473222". PluginName "kubernetes.io/aws-ebs", VolumeGidValue ""
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.880542 1271 reconciler.go:290] Volume detached for volume "concourse-worker-token-j930k" (UniqueName: "kubernetes.io/secret/27f69bca-07c7-11e8-a296-02a725473222-concourse-worker-token-j930k") on node "ip-172-18-25-66.us-west-2.compute.internal" DevicePath ""
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.880621 1271 reconciler.go:290] Volume detached for volume "concourse-keys" (UniqueName: "kubernetes.io/secret/27f69bca-07c7-11e8-a296-02a725473222-concourse-keys") on node "ip-172-18-25-66.us-west-2.compute.internal" DevicePath ""
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: I0204 06:07:05.880861 1271 reconciler.go:283] operationExecutor.UnmountDevice started for volume "pvc-27e652d8-07c7-11e8-a296-02a725473222" (UniqueName: "kubernetes.io/aws-ebs/aws://us-west-2b/vol-0da204d1146373310") on node "ip-172-18-25-66.us-west-2.compute.internal"
Feb 4 06:07:05 ip-172-18-25-66 kubelet[1271]: E0204 06:07:05.900199 1271 nestedpendingoperations.go:262] Operation for "\"kubernetes.io/aws-ebs/aws://us-west-2b/vol-0da204d1146373310\"" failed. No retries permitted until 2018-02-04 06:07:06.400164295 +0000 UTC (durationBeforeRetry 500ms). Error: UnmountDevice failed for volume "pvc-27e652d8-07c7-11e8-a296-02a725473222" (UniqueName: "kubernetes.io/aws-ebs/aws://us-west-2b/vol-0da204d1146373310") on node "ip-172-18-25-66.us-west-2.compute.internal" : the device is in use when it was no longer expected to be in use
Robert Diebels
@yurig93 Seems like you're also encountering this issue.
You might want to check if the EBS volumes are being created, attached and whether or not Kubernetes is creating the associated PV's and PVC's.
If it's doing all of the above you probably have the same issue.
Which would be cause by Kubernetes trying to detach and attach the EBS volume to a node it's already attached to.
Hang Xie
I have the similar problem as described here, there are cases that EBS was not deleted after PV was deleted, controller log says:
Aug 16 21:02:05 ****** dockerd[11532]: E0816 21:02:05.600048 1 aws.go:2273] Error deleting EBS volume "vol-03cbb34b8a99fb1f9" since volume is currently attached to "i-03a8d8eebe8acad1b"
Aug 16 21:02:05 ****** docker[16625]: E0816 21:02:05.600048 1 aws.go:2273] Error deleting EBS volume "vol-03cbb34b8a99fb1f9" since volume is currently attached to "i-03a8d8eebe8acad1b"
Aug 16 21:02:05 ****** dockerd[11532]: E0816 21:02:05.608810 1 goroutinemap.go:150] Operation for "delete-pvc-4e0af4f2-a190-11e8-87db-0a970b4b9c8c[517ef1dd-a190-11e8-87db-0a970b4b9c8c]" failed. No retries permitted until 2018-08-16 21:02:06.108772539 +0000 UTC m=+13412.885777451 (durationBeforeRetry 500ms). Error: "Error deleting EBS volume \"vol-03cbb34b8a99fb1f9\" since volume is currently attached to \"i-03a8d8eebe8acad1b\""
Aug 16 21:02:05 ****** dockerd[11532]: I0816 21:02:05.609050 1 event.go:218] Event(v1.ObjectReference{Kind:"PersistentVolume", Namespace:"", Name:"pvc-4e0af4f2-a190-11e8-87db-0a970b4b9c8c", UID:"517ef1dd-a190-11e8-87db-0a970b4b9c8c", APIVersion:"v1", ResourceVersion:"51520", FieldPath:""}): type: 'Warning' reason: 'VolumeFailedDelete' Error deleting EBS volume "vol-03cbb34b8a99fb1f9" since volume is currently attached to "i-03a8d8eebe8acad1b"
Aug 16 21:02:05 ****** docker[16625]: E0816 21:02:05.608810 1 goroutinemap.go:150] Operation for "delete-pvc-4e0af4f2-a190-11e8-87db-0a970b4b9c8c[517ef1dd-a190-11e8-87db-0a970b4b9c8c]" failed. No retries permitted until 2018-08-16 21:02:06.108772539 +0000 UTC m=+13412.885777451 (durationBeforeRetry 500ms). Error: "Error deleting EBS volume \"vol-03cbb34b8a99fb1f9\" since volume is currently attached to \"i-03a8d8eebe8acad1b\""
Aug 16 21:02:05 ****** docker[16625]: I0816 21:02:05.609050 1 event.go:218] Event(v1.ObjectReference{Kind:"PersistentVolume", Namespace:"", Name:"pvc-4e0af4f2-a190-11e8-87db-0a970b4b9c8c", UID:"517ef1dd-a190-11e8-87db-0a970b4b9c8c", APIVersion:"v1", ResourceVersion:"51520", FieldPath:""}): type: 'Warning' reason: 'VolumeFailedDelete' Error deleting EBS volume "vol-03cbb34b8a99fb1f9" since volume is currently attached to "i-03a8d8eebe8acad1b"
I had deleted RC/POD/PVC and verified they were all gone per kubectl before deleting PV, I assume controller should do a bit more retry as the EBS volume was not attached to any EC2 eventually.
I have 14 PVs and there would be 1 EBS volume left out for every 4~5 tests, so the error rate is about 1.5%.
Trond Hindenes
I noticed the same, and discovered that nodes were missing the ec2:DetachVolume permission. It seems to me that there's missing verification logic since the kubelet logs UnmountDevice succeeded for volume while that operation at doesn't necessarily completely succeed.
—
You are receiving this because you are on a team that was mentioned.
Reply to this email directly, view it on GitHub, or unsubscribe.