When Pods scheduled on a particular worker node it always fails. How to debug it?

6/24/2020

I have a 3 node kubernetes cluster installed using kubeadm. However, when pods are scheduled on a particular kubernetes worker, it fails to do mounting and sometimes goes to pending state altogether. Can someone please suggest as to how to debug this.

Update -: Error log of worker.

Jun 24 19:14:19 kub-minion-1 kubelet[3268]: E0624 19:14:19.481535    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:21 kub-minion-1 kubelet[3268]: E0624 19:14:21.489485    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:22 kub-minion-1 kubelet[3268]: E0624 19:14:22.446385    3268 pod_workers.go:191] Error syncing pod 871b0139-85b7-46c0-8616-24eb87e2d38d ("calico-kube-controllers-76d4774d89-88djk_kube-system(871b0139-85b7-46c0-8616-24eb87e2d38d)"), skipping: failed to "StartContainer" for "calico-kube-controllers" with ImagePullBackOff: "Back-off pulling image \"calico/kube-controllers:v3.14.1\""
Jun 24 19:14:23 kub-minion-1 kubelet[3268]: E0624 19:14:23.483911    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:25 kub-minion-1 kubelet[3268]: E0624 19:14:25.494279    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:27 kub-minion-1 kubelet[3268]: E0624 19:14:27.519243    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:29 kub-minion-1 kubelet[3268]: E0624 19:14:29.505746    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:31 kub-minion-1 kubelet[3268]: E0624 19:14:31.555006    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.470044    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.609573    3268 configmap.go:200] Couldn't get configMap default/izac-cp-kafka-connect-jmx-configmap: object "default"/"izac-cp-kafka-connect-jmx-configmap" not registered
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.609639    3268 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/configmap/82f16d16-2363-4167-a7a8-6af0ce96ba95-jmx-config podName:82f16d16-2363-4167-a7a8-6af0ce96ba95 nodeName:}" failed. No retries permitted until 2020-06-24 19:16:35.609618005 +0530 IST m=+571503.228144805 (durationBeforeRetry 2m2s). Error: "MountVolume.SetUp failed for volume \"jmx-config\" (UniqueName: \"kubernetes.io/configmap/82f16d16-2363-4167-a7a8-6af0ce96ba95-jmx-config\") pod \"izac-cp-kafka-connect-8c6d86c4d-r5r4s\" (UID: \"82f16d16-2363-4167-a7a8-6af0ce96ba95\") : object \"default\"/\"izac-cp-kafka-connect-jmx-configmap\" not registered"
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.609853    3268 secret.go:195] Couldn't get secret default/nginx-ingress-backend-token-d6drl: object "default"/"nginx-ingress-backend-token-d6drl" not registered
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.609892    3268 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/ac02ceb4-726d-4209-a97b-d3f4249d646a-nginx-ingress-backend-token-d6drl podName:ac02ceb4-726d-4209-a97b-d3f4249d646a nodeName:}" failed. No retries permitted until 2020-06-24 19:16:35.609874166 +0530 IST m=+571503.228400966 (durationBeforeRetry 2m2s). Error: "MountVolume.SetUp failed for volume \"nginx-ingress-backend-token-d6drl\" (UniqueName: \"kubernetes.io/secret/ac02ceb4-726d-4209-a97b-d3f4249d646a-nginx-ingress-backend-token-d6drl\") pod \"nginx-ingress-default-backend-7c868597f4-f8rtt\" (UID: \"ac02ceb4-726d-4209-a97b-d3f4249d646a\") : object \"default\"/\"nginx-ingress-backend-token-d6drl\" not registered"
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.610039    3268 configmap.go:200] Couldn't get configMap default/izac-cp-schema-registry-jmx-configmap: object "default"/"izac-cp-schema-registry-jmx-configmap" not registered
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.610072    3268 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/configmap/7bf54920-7557-4149-90da-3e8f261fc18c-jmx-config podName:7bf54920-7557-4149-90da-3e8f261fc18c nodeName:}" failed. No retries permitted until 2020-06-24 19:16:35.610056758 +0530 IST m=+571503.228583538 (durationBeforeRetry 2m2s). Error: "MountVolume.SetUp failed for volume \"jmx-config\" (UniqueName: \"kubernetes.io/configmap/7bf54920-7557-4149-90da-3e8f261fc18c-jmx-config\") pod \"izac-cp-schema-registry-6cbf6d694b-6lwl6\" (UID: \"7bf54920-7557-4149-90da-3e8f261fc18c\") : object \"default\"/\"izac-cp-schema-registry-jmx-configmap\" not registered"
Jun 24 19:14:33 kub-minion-1 kubelet[3268]: E0624 19:14:33.610198    3268 secret.go:195] Couldn't get secret default/izac-jobserver-token-qdfps: object "default"/"izac-jobserver-token-qdfps" not registered
Jun 24 19:14:36 kub-minion-1 kubelet[3268]: E0624 19:14:36.155302    3268 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/a6125528-30b9-4da5-9449-ff32f17a43f7-izac-kafkaadmin-token-d5vjn podName:a6125528-30b9-4da5-9449-ff32f17a43f7 nodeName:}" failed. No retries permitted until 2020-06-24 19:16:38.155279619 +0530 IST m=+571505.773806419 (durationBeforeRetry 2m2s). Error: "MountVolume.SetUp failed for volume \"izac-kafkaadmin-token-d5vjn\" (UniqueName: \"kubernetes.io/secret/a6125528-30b9-4da5-9449-ff32f17a43f7-izac-kafkaadmin-token-d5vjn\") pod \"izac-kafkaadmin-7db7645d4-n2nrk\" (UID: \"a6125528-30b9-4da5-9449-ff32f17a43f7\") : object \"default\"/\"izac-kafkaadmin-token-d5vjn\" not registered"
Jun 24 19:14:36 kub-minion-1 kubelet[3268]: E0624 19:14:36.155353    3268 secret.go:195] Couldn't get secret default/izac-eventview-token-hx56g: object "default"/"izac-eventview-token-hx56g" not registered
Jun 24 19:14:36 kub-minion-1 kubelet[3268]: E0624 19:14:36.155386    3268 nestedpendingoperations.go:301] Operation for "{volumeName:kubernetes.io/secret/f7aa6503-0424-406e-9f27-517c3046f38a-izac-eventview-token-hx56g podName:f7aa6503-0424-406e-9f27-517c3046f38a nodeName:}" failed. No retries permitted until 2020-06-24 19:16:38.155370912 +0530 IST m=+571505.773897711 (durationBeforeRetry 2m2s). Error: "MountVolume.SetUp failed for volume \"izac-eventview-token-hx56g\" (UniqueName: \"kubernetes.io/secret/f7aa6503-0424-406e-9f27-517c3046f38a-izac-eventview-token-hx56g\") pod \"izac-eventview-bbc689b4-8wzfd\" (UID: \"f7aa6503-0424-406e-9f27-517c3046f38a\") : object \"default\"/\"izac-eventview-token-hx56g\" not registered"
Jun 24 19:14:37 kub-minion-1 kubelet[3268]: E0624 19:14:37.569743    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:39 kub-minion-1 kubelet[3268]: E0624 19:14:39.549682    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:41 kub-minion-1 kubelet[3268]: E0624 19:14:41.461248    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:43 kub-minion-1 kubelet[3268]: E0624 19:14:43.562688    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:45 kub-minion-1 kubelet[3268]: E0624 19:14:45.469403    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:47 kub-minion-1 kubelet[3268]: E0624 19:14:47.469884    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:48 kub-minion-1 kubelet[3268]: E0624 19:14:48.469826    3268 pod_workers.go:191] Error syncing pod 871b0139-85b7-46c0-8616-24eb87e2d38d ("calico-kube-controllers-76d4774d89-88djk_kube-system(871b0139-85b7-46c0-8616-24eb87e2d38d)"), skipping: failed to "StartContainer" for "calico-kube-controllers" with ImagePullBackOff: "Back-off pulling image \"calico/kube-controllers:v3.14.1\""
Jun 24 19:14:49 kub-minion-1 kubelet[3268]: E0624 19:14:49.466371    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:51 kub-minion-1 kubelet[3268]: E0624 19:14:51.559734    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:53 kub-minion-1 kubelet[3268]: E0624 19:14:53.584893    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:55 kub-minion-1 kubelet[3268]: E0624 19:14:55.445726    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:57 kub-minion-1 kubelet[3268]: E0624 19:14:57.609778    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:14:59 kub-minion-1 kubelet[3268]: E0624 19:14:59.498661    3268 kubelet_volumes.go:154] orphaned pod "093642bc-5ef9-4c41-b9f4-032a6866b400" found, but volume paths are still present on disk : There were a total of 38 errors similar to this. Turn up verbosity to see them.
Jun 24 19:15:00 kub-minion-1 kubelet[3268]: E0624 19:15:00.445806    3268 pod_workers.go:191] Error syncing pod 871b0139-85b7-46c0-8616-24eb87e2d38d ("calico-kube-controllers-76d4774d89-88djk_kube-system(871b0139-85b7-46c0-8616-24eb87e2d38d)"), skipping: failed to "StartContainer" for "calico-kube-controllers" with ImagePullBackOff: "Back-off pulling image \"calico/kube-controllers:v3.14.1\""

Update 2-: Kubectl describe pod <pod name> gives -:

 Normal   Scheduled    25m                  default-scheduler      Successfully assigned default/izac-eventview-78775467d6-6bvxq to kub-minion-1
  Warning  FailedMount  2m1s (x16 over 24m)  kubelet, kub-minion-1  MountVolume.SetUp failed for volume "izac-eventview-token-hrzcc" : mount failed: exit status 1
Mounting command: systemd-run
Mounting arguments: --description=Kubernetes transient mount for /var/lib/kubelet/pods/6fd35008-2adf-4a35-a88a-28c2991d40ac/volumes/kubernetes.io~secret/izac-eventview-token-hrzcc --scope -- mount -t tmpfs tmpfs /var/lib/kubelet/pods/6fd35008-2adf-4a35-a88a-28c2991d40ac/volumes/kubernetes.io~secret/izac-eventview-token-hrzcc
Output: Failed to start transient scope unit: Connection timed out
-- Anish Sarangi
kubernetes

1 Answer

7/3/2020

The issue was that StorageOS pod was taking up certain OS specific service which was preventing mounting. I had to shutdown Kubelet Service forecibly, and delete StorageOS operator. Then had to restart the entire cluster after deleting pods in minion.

-- Anish Sarangi
Source: StackOverflow