gcp-compute-persistent-disk-csi-driver icon indicating copy to clipboard operation
gcp-compute-persistent-disk-csi-driver copied to clipboard

Disk failed to relink with udevadm

Open jpds opened this issue 4 years ago • 38 comments

I've been running a database cluster with a statefulset for a number of months of GKE. Yesterday I upgraded to to regular channel version 1.16.13-gke.401 and today I found that that statefulset had its first pod with this in describe pod:

Events:
  Type     Reason       Age                   From                                                          Message
  ----     ------       ----                  ----                                                          -------
  Warning  FailedMount  29m (x19 over 97m)    kubelet, gke-cluster-f51460e-nodes-preemptible-n-593b5f7a-rej6  Unable to attach or mount volumes: unmounted volumes=[data], unattached volumes=[data stolon-secrets stolon-token-xxxxx]: timed out waiting for the condition
  Warning  FailedMount  9m15s (x45 over 98m)  kubelet, gke-cluster-f51460e-nodes-preemptible-n-593b5f7a-rej6  MountVolume.MountDevice failed for volume "pvc-2e9a43cc-3655-4d64-af9e-9b4643b629a2" : rpc error: code = Internal desc = Error when getting device path: error verifying GCE PD ("pvc-2e9a43cc-3655-4d64-af9e-9b4643b629a2") is attached: failed to find and re-link disk pvc-2e9a43cc-3655-4d64-af9e-9b4643b629a2 with udevadm after retrying for 3s: failed to trigger udevadm fix: udevadm --trigger requested to fix disk pvc-2e9a43cc-3655-4d64-af9e-9b4643b629a2 but no such disk was found
  Warning  FailedMount  4m10s (x9 over 90m)   kubelet, gke-cluster-f51460e-nodes-preemptible-n-593b5f7a-rej6  Unable to attach or mount volumes: unmounted volumes=[data], unattached volumes=[stolon-secrets stolon-token-xxxxx data]: timed out waiting for the condition

jpds avatar Sep 15 '20 19:09 jpds

Can you confirm that the PD behind the associated PV/PVC is healthy?

mattcary avatar Sep 15 '20 19:09 mattcary

It is indeed, I did kubectl delete pod db-0 and the database cluster came back after that.

jpds avatar Sep 15 '20 21:09 jpds

Weird, so pod 0 must have gotten in to a weird state? Possibly the attach failed but the kubelet couldn't figure it out, and deleting the pod forced a retry.

Maybe just one of those things, but I wonder if there is a race condition somewhere we're missing.

mattcary avatar Sep 15 '20 21:09 mattcary

By the time we get to the MountDevice error, I believe the Attach call should have succeded.

We have seem some strange udev problems in the past where udev missed an event or didn't update its device cache. We've tried to workaround it by doing a "udev trigger" when things seem strange, but there's potentially still some scenarios where that won't help.

msau42 avatar Sep 15 '20 22:09 msau42

This just failed again, there's definitely a regression between 1.16.3-gke.1 and .401.

jpds avatar Sep 16 '20 21:09 jpds

Do you mean 1.16.13-gke.1 and .401? I don't think we ever released a 1.16.3-gke.1. If so, both those versions use v0.7.0-gke.0 of the driver.

If you meant 1.15.13-gke.1, then the pdcsi driver was on v0.6.0-gke.0, and potentially https://github.com/kubernetes-sigs/gcp-compute-persistent-disk-csi-driver/pull/459 could be playing a factor.

Is this issue reliably reproducible? Are you able to ssh to the node and inspect the local path to the PD and what its udev link and scsi 83 page says?

msau42 avatar Sep 18 '20 23:09 msau42

Indeed, 1.16.13-gke.1 and .401 - sorry.

I upgraded the cluster to regular-channel/1.17.9-gke.1504 last Friday and it seems to have not had this issue so far.

jpds avatar Sep 25 '20 21:09 jpds

1.17.9-gke.1504 uses v0.7.0-gke.0 of the pd driver.

Given all the versions you used had the same driver version that includes #459, maybe it could be an OS issue. cc @mattcary

msau42 avatar Sep 25 '20 22:09 msau42

Also hit the same issue. One thing interesting is I found my CSIDriver object is misconfigured.

$ kubectl get csidriver                                                             
NAME                    ATTACHREQUIRED   PODINFOONMOUNT   MODES        AGE
pd.csi.storage.gke.io   false            false            Persistent   6d20h

The attachrequired field should set to true.

Jiawei0227 avatar Oct 05 '20 18:10 Jiawei0227

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.

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

fejta-bot avatar Jan 03 '21 19:01 fejta-bot

Stale issues rot after 30d of inactivity. Mark the issue as fresh with /remove-lifecycle rotten. Rotten issues close after an additional 30d of inactivity.

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 rotten

fejta-bot avatar Feb 02 '21 19:02 fejta-bot

I am facing the same issue I believe. I am using server with

Server Version: version.Info{Major:"1", Minor:"18+", GitVersion:"v1.18.14-gke.1600", GitCommit:"44dfef46993969762b5df37fe3dda47621476708", GitTreeState:"clean", BuildDate:"2021-01-12T09:20:19Z", GoVersion:"go1.13.15b4", Compiler:"gc", Platform:"linux/amd64"}
Events:
  Type     Reason                  Age                 From                     Message
  ----     ------                  ----                ----                     -------
  Normal   Scheduled               2m20s               default-scheduler        Successfully assigned pre-1361943147524919296/prof-tbyg-nginx-rc-np5sz to gke-ci-cluster-default-pool-c344e6a7-3pb1
  Normal   SuccessfulAttachVolume  2m7s                attachdetach-controller  AttachVolume.Attach succeeded for volume "pvc-c3d4cc67-c3da-47a7-8eb7-3f3959b32afb"
  Warning  FailedMount             56s (x8 over 2m4s)  kubelet                  MountVolume.MountDevice failed for volume "pvc-c3d4cc67-c3da-47a7-8eb7-3f3959b32afb" : rpc error: code = Internal desc = Error when getting device path: rpc error: code = Internal desc = error verifying GCE PD ("pvc-c3d4cc67-c3da-47a7-8eb7-3f3959b32afb") is attached: failed to find and re-link disk pvc-c3d4cc67-c3da-47a7-8eb7-3f3959b32afb with udevadm after retrying for 3s: failed to trigger udevadm fix: failed to get SCSI Serial num: scsi_id failed for device "/dev/sdb" with output : exit status 1
  Warning  FailedMount             17s                 kubelet                  Unable to attach or mount volumes: unmounted volumes=[nginx-rc-volume], unattached volumes=[default-token-rzz2g nginx-rc-volume]: timed out waiting for the condition

I have enabled the CSI using this. It's using the csi driver v1.0.1-gke.0

anemade avatar Feb 17 '21 08:02 anemade

/lifecycle frozen

mattcary avatar Feb 17 '21 18:02 mattcary

Any update on this issue. This is easily reproducible and hitting us frequently

madhurnawandar avatar Aug 04 '21 05:08 madhurnawandar

@madhurnawandar can you post steps to get a repro here?

mattcary avatar Aug 05 '21 21:08 mattcary

@mattcary Hey This issue is coming as an intermittent issue and we are able to regenerate the issue, when we install 4-5 applications with PVCs in single namespace then one of the application always break with volume mount issue with below error:

Error when getting device path: rpc error: code = Internal desc = error verifying GCE PD ("pvc-8419ba38-f017-4b09-a17c-675377299ceb") is attached: failed to find and re-link disk pvc-8419ba38-f017-4b09-a17c-675377299ceb with udevadm after retrying for 3s: failed to trigger udevadm fix: failed to get SCSI Serial num: scsi_id failed for device "/dev/sdb" with output : exit status 1

We have tried upgrading gce-pd-csidriver to the latest stable and still the issuer is the same. Seems the relevant code is https://github.com/kubernetes-sigs/gcp-compute-persistent-disk-csi-driver/blob/82070d808371d6cca9d18fdd6cbacf4b559cf698/pkg/mount-manager/device-utils.go#L121

Any clues?

umeshkumhar avatar Aug 11 '21 04:08 umeshkumhar

@umeshkumhar We haven't had a chance to reproduce it. Are you able to come up with even an intermittently reproducing test case?

mattcary avatar Aug 11 '21 15:08 mattcary

@mattcary We just install helm chart for MongoDB, Redis and MySQL with PVCs in a single namespace, At random any PVC will fail and block out ginkgo test execution,

It somethings works fine, that is 1 in 20 execution.

We also tried re-creating new GKE cluster with 1.18.20-gke.901

Please suggest something, its a blocker for us.

umeshkumhar avatar Aug 25 '21 07:08 umeshkumhar

Looks like I'm having the same issue

MountVolume.MountDevice failed for volume "pvc-a851fe88-219b-442c-a52c-50848fda18af" : rpc error: code = Internal desc = Error when getting device path: error verifying GCE PD ("pvc-a851fe88-219b-442c-a52c-50848fda18af") is attached: failed to find and re-link disk pvc-a851fe88-219b-442c-a52c-50848fda18af with udevadm after retrying for 3s: failed to trigger udevadm fix: failed to get SCSI Serial num: scsi_id failed for device "/dev/sdaa" with output : exit status 1

ivanbenko avatar Sep 24 '21 06:09 ivanbenko

I'm facing this issue on pre-emptible node pool, whever a node was preempt, the pods status is changing to ContainerCreating and stuck on mount device

Warning  FailedMount  4m51s (x167 over 5h29m)  kubelet  MountVolume.MountDevice failed for volume "pvc-5628bf1d-78c7-4819-8391-6e76a841234a" : rpc error: code = Internal desc = Error when getting device path: rpc error: code = Internal desc = error verifying GCE PD ("pvc-5628bf1d-78c7-4819-8391-6e76a841234a") is attached: failed to find and re-link disk pvc-5628bf1d-78c7-4819-8391-6e76a841234a with udevadm after retrying for 3s: failed to trigger udevadm fix: udevadm --trigger requested to fix disk pvc-5628bf1d-78c7-4819-8391-6e76a841234a but no such disk was found

any update yet on this issue?

duythinht avatar Mar 09 '22 04:03 duythinht

We are actively looking into several related issues. Do you have a reliable reproduction recipie? Thx.

mattcary avatar Mar 10 '22 02:03 mattcary

i have the same problem on gke, it usually happens on preempted node with statefulset pvc template. it seems to be related to the node and i can always fix it by draining the node where the pod scheduled on.

lapcchan avatar Mar 21 '22 09:03 lapcchan

We are also hitting this with pre-emptible node pools, post pre-emption. GKE 1.22

Edit: Deleting the pods would get them stuck in terminating, deleteting with --force, removed them but on recreation they would fail the same way. Only way to fix this for us was to manually delete the instances and scale the node pool back up, to recreate the ndoes.

cristicbz avatar Apr 06 '22 12:04 cristicbz

We have seen some cases where the disk is attached to the host machine, but a deadlock is happening in the guest OS that is preventing the device from appearing in sysfs (which then explains the error messages above, where the device can't be found).

However we have not been able to reproduce this in order to figure out the root cause. So any further clues you can give would be helpful.

The first thing is to identify if this is the same problem: does the PD fail to appear in /dev/disk/by-id? Is the device missing from lsscsi or /sys/class/scsi_disk? (it's hard to positively identify a missing disk, all I've been able to do is count the number of scsi devices and see if it matches what is supposed to be attached to the VM, eg from gcloud compute instances describe).

If so, look in dmesg for something like "virtio_scsi: SCSI device 0 0 176 0 not found". Look for stuck kworker threads (ie, kworker threads in state "D" in ps). If there's such a stuck thread, look in /proc//stack for something like "INFO: task kworker/6:9:2470111 blocked for more than 327 seconds" and long stack traces including __scsi_add_disk or __scsi_remove_disk.

If so, it's a similar problem, and we'd appreciate more information on how this is happening, including your machine shape, number of attached devices, number of pods on the node, etc.

mattcary avatar Apr 06 '22 15:04 mattcary

Have same issue on pre-emptible node pool GKE 1.22.8-gke.200.

insider89 avatar Apr 29 '22 17:04 insider89

Also same issue:

  • Spot instance after re-creating
  • v1.22.6-gke.1000

MountVolume.MountDevice failed for volume "pvc-d8094b0e-24a5-48df-bb3c-fed39429a81b" : rpc error: code = Internal desc = Error when getting device path: rpc error: code = Internal desc = error verifying GCE PD ("pvc-d8094b0e-24a5-48df-bb3c-fed39429a81b") is attached: failed to find and re-link disk pvc-d8094b0e-24a5-48df-bb3c-fed39429a81b with udevadm after retrying for 3s: failed to trigger udevadm fix: udevadm --trigger requested to fix disk pvc-d8094b0e-24a5-48df-bb3c-fed39429a81b but no such disk was found

Disk in cloud exists and not attached to node, have annotations:

{"kubernetes.io/created-for/pv/name":"pvc-d8094b0e-24a5-48df-bb3c-fed39429a81b","kubernetes.io/created-for/pvc/name":"data-platform-postgresql-0","kubernetes.io/created-for/pvc/namespace":"marketplace-dev2","storage.gke.io/created-by":"pd.csi.storage.gke.io"}

mrVrAlex avatar Apr 29 '22 17:04 mrVrAlex

@shandyDev if the disk is not attached to the node, it's a different issue. What is the node status---is the volume listed as attached to the node there?

mattcary avatar Apr 29 '22 20:04 mattcary

@mattcary Yes, real GCE disk not attached to node (see in cloud console). All others in k8s show looks fine except one thing: volume.kubernetes.io/selected-node show already not exists node But PVC has phase: "Bound" and annotations:

   pv.kubernetes.io/bind-completed: "yes"
    pv.kubernetes.io/bound-by-controller: "yes"
    volume.beta.kubernetes.io/storage-provisioner: pd.csi.storage.gke.io
    volume.kubernetes.io/selected-node: gke-boodmo-staging-stage-342e146f-276z

Node describe (where stateful set) show attachable-volumes-gce-pd = 0

PV also has status "Bound"

apiVersion: v1
kind: PersistentVolume
metadata:
  annotations:
    pv.kubernetes.io/provisioned-by: pd.csi.storage.gke.io
  creationTimestamp: "2022-02-28T00:43:12Z"
  finalizers:
  - kubernetes.io/pv-protection
  - external-attacher/pd-csi-storage-gke-io
  name: pvc-6bf3f31b-564c-4c7d-a4b7-c678c82a4345
  resourceVersion: "208138805"
  uid: 0ddb217f-b1d7-4030-98d7-64eb885af5a0
spec:
  accessModes:
  - ReadWriteOnce
  capacity:
    storage: 8Gi
  claimRef:
    apiVersion: v1
    kind: PersistentVolumeClaim
    name: data-platform-rabbitmq-0
    namespace: marketplace-stage
    resourceVersion: "208138759"
    uid: 6bf3f31b-564c-4c7d-a4b7-c678c82a4345
  csi:
    driver: pd.csi.storage.gke.io
    fsType: ext4
    volumeAttributes:
      storage.kubernetes.io/csiProvisionerIdentity: 1645081245874-8081-pd.csi.storage.gke.io
    volumeHandle: projects/infrastructure-211207/zones/asia-south1-a/disks/pvc-6bf3f31b-564c-4c7d-a4b7-c678c82a4345
  nodeAffinity:
    required:
      nodeSelectorTerms:
      - matchExpressions:
        - key: topology.gke.io/zone
          operator: In
          values:
          - asia-south1-a
  persistentVolumeReclaimPolicy: Delete
  storageClassName: standard-rwo
  volumeMode: Filesystem
status:
  phase: Bound

mrVrAlex avatar Apr 30 '22 15:04 mrVrAlex

I'm facing the same behavior starting from v1.22 using preemptible nodes. PVCs are bound, but no pod can start due to

MountVolume.MountDevice failed for volume "pvc-bcaacf4b-426b-48a9-9b98-82e9e3c9ad69" : rpc error: code = Internal desc = Error when getting device path: rpc error: code = Internal desc = error verifying GCE PD ("gke-dev-env-e02550df-d-pvc-bcaacf4b-426b-48a9-9b98-82e9e3c9ad69") is attached: failed to find and re-link disk gke-dev-env-e02550df-d-pvc-bcaacf4b-426b-48a9-9b98-82e9e3c9ad69 with udevadm after retrying for 3s: failed to trigger udevadm fix: udevadm --trigger requested to fix disk gke-dev-env-e02550df-d-pvc-bcaacf4b-426b-48a9-9b98-82e9e3c9ad69 but no such disk was found

All PVs have label pv.kubernetes.io/migrated-to: pd.csi.storage.gke.io, but storageClass is the old one standard with provisioner kubernetes.io/gce-pd

The solution is to scale down and up again the cluster.

Feature Compute Engine persistent disk CSI Driver is enabled and has the following versions: gce-pd-driver = gke.gcr.io/gcp-compute-persistent-disk-csi-driver:v1.4.0-gke.0 csi-driver-registrar = gke.gcr.io/csi-node-driver-registrar:v2.5.0-gke.0

kopaygorodsky avatar May 03 '22 15:05 kopaygorodsky

Just had the same issue today on GKE, also with preemptible nodes and Kubernetes v1.22. Like @shandyDev, when I look at the PVC, there's a volume.kubernetes.io/selected-node annotation that is still pointing to the deleted node. The disk itself is not attached to any node.

pdfrod avatar May 03 '22 19:05 pdfrod