Existing PVC fails to mount. CSI driver detects disk as unformatted, tries to format with failure

CSI azure disk driver has occasional issue mounting EXT4 type filesystems on an existing PVC. The existing PVC is already formatted and mounts with no issues on a different node. This issue comes randomly and rebooting the node fixes the issue.

Logs from csi-azuredisk-node:

I0430 14:08:19.621330       1 utils.go:77] GRPC call: /csi.v1.Node/NodeStageVolume
I0430 14:08:19.621347       1 utils.go:78] GRPC request: {"publish_context":{"LUN":"1"},"staging_target_path":"/var/lib/kubelet/plugins/kubernetes.io/csi/disk.csi.azure.com/b58d47700dde483cad7e8dc9dafbfdd647ba6bce9f7fc1e6bd97eab060342458/globalmount","volume_capability":{"AccessType":{"Mount":{}},"access_mode":{"mode":7}},"volume_context":{"csi.storage.k8s.io/pv/name":"pvc-badac45c-1f58-4661-9f28-70cbeb76afcf","csi.storage.k8s.io/pvc/name":"mailpit-ci","csi.storage.k8s.io/pvc/namespace":"ci","requestedsizegib":"1","storage.kubernetes.io/csiProvisionerIdentity":"1690288341491-8081-disk.csi.azure.com","storageAccountType":"Standard_LRS"},"volume_id":"/subscriptions/2d4e0d10-2bac-408a-b571-2b5a75445710/resourceGroups/madme-prod/providers/Microsoft.Compute/disks/pvc-badac45c-1f58-4661-9f28-70cbeb76afcf"}
I0430 14:08:20.160160       1 azure_common_linux.go:185] azureDisk - found /dev/disk/azure/scsi1/lun1 by sdc under /dev/disk/azure/scsi1/
I0430 14:08:20.160199       1 nodeserver.go:116] NodeStageVolume: perf optimization is disabled for /dev/disk/azure/scsi1/lun1. perfProfile none accountType
I0430 14:08:20.160849       1 nodeserver.go:157] NodeStageVolume: formatting /dev/disk/azure/scsi1/lun1 and mounting at /var/lib/kubelet/plugins/kubernetes.io/csi/disk.csi.azure.com/b58d47700dde483cad7e8dc9dafbfdd647ba6bce9f7fc1e6bd97eab060342458/globalmount with mount options([])
I0430 14:08:20.160870       1 mount_linux.go:579] Attempting to determine if disk "/dev/disk/azure/scsi1/lun1" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun1])
I0430 14:08:20.248512       1 mount_linux.go:582] Output: ""
I0430 14:08:20.248540       1 mount_linux.go:517] Disk "/dev/disk/azure/scsi1/lun1" appears to be unformatted, attempting to format as type: "ext4" with options: [-F -m0 /dev/disk/azure/scsi1/lun1]
E0430 14:08:23.488030       1 mount_linux.go:524] format of disk "/dev/disk/azure/scsi1/lun1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/disk.csi.azure.com/b58d47700dde483cad7e8dc9dafbfdd647ba6bce9f7fc1e6bd97eab060342458/globalmount") options:("defaults") errcode:(exit status 1) output:(mke2fs 1.46.6 (1-Feb-2023)
Discarding device blocks: failed - Remote I/O error
Creating filesystem with 2097152 4k blocks and 524288 inodes
Filesystem UUID: b39a85ef-53e8-4bd7-b0a9-a0103d688981
Superblock backups stored on blocks:
    32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632

Allocating group tables: done
Writing inode tables: done
Creating journal (16384 blocks): done
Writing superblocks and filesystem accounting information: mkfs.ext4: I/O error while writing out and closing file system
)
E0430 14:08:23.488075       1 utils.go:82] GRPC error: rpc error: code = Internal desc = could not format /dev/disk/azure/scsi1/lun1(lun: 1), and mount it at /var/lib/kubelet/plugins/kubernetes.io/csi/disk.csi.azure.com/b58d47700dde483cad7e8dc9dafbfdd647ba6bce9f7fc1e6bd97eab060342458/globalmount, failed with format of disk "/dev/disk/azure/scsi1/lun1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/disk.csi.azure.com/b58d47700dde483cad7e8dc9dafbfdd647ba6bce9f7fc1e6bd97eab060342458/globalmount") options:("defaults") errcode:(exit status 1) output:(mke2fs 1.46.6 (1-Feb-2023)
Discarding device blocks: failed - Remote I/O error
Creating filesystem with 2097152 4k blocks and 524288 inodes
Filesystem UUID: b39a85ef-53e8-4bd7-b0a9-a0103d688981
Superblock backups stored on blocks:
    32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632

Allocating group tables: done
Writing inode tables: done
Creating journal (16384 blocks): done
Writing superblocks and filesystem accounting information: mkfs.ext4: I/O error while writing out and closing file system
)

OS Almalinux:

[root@azure-madme-prod-k8s-master-0 ~]# uname -a
Linux azure-madme-prod-k8s-master-0 4.18.0-348.2.1.el8_5.x86_64 #1 SMP Mon Nov 15 09:17:08 EST 2021 x86_64 x86_64 x86_64 GNU/Linux

Kubernetes version: 1.28.6

CSI driver version:

  containerStatuses:
  - containerID: containerd://dce7b621afc56c3de8282913dccd4cff27561e460f332ef143ffe11fc9e9f08f
    image: mcr.microsoft.com/oss/kubernetes-csi/azuredisk-csi:v1.28.5
    imageID: mcr.microsoft.com/oss/kubernetes-csi/azuredisk-csi@sha256:62a0d981bb638e3c977e0b7cde3d5310c4149e8fb65209fcc902f8367fd164d3

CSI driver and Storageclass manifests:

[root@azure-madme-prod-k8s-master-0 ~]# kubectl get csidriver -o yaml disk.csi.azure.com
apiVersion: storage.k8s.io/v1
kind: CSIDriver
metadata:
  annotations:
    csiDriver: v1.28.5
    meta.helm.sh/release-name: azuredisk-csi-driver
    meta.helm.sh/release-namespace: kube-system
    snapshot: v6.2.2
  creationTimestamp: "2024-04-11T09:33:38Z"
  labels:
    app.kubernetes.io/managed-by: Helm
  name: disk.csi.azure.com
  resourceVersion: "397134341"
  uid: 1bee115f-1392-4387-b765-aa8a221e4a08
spec:
  attachRequired: true
  fsGroupPolicy: File
  podInfoOnMount: false
  requiresRepublish: false
  seLinuxMount: false
  storageCapacity: false
  volumeLifecycleModes:
  - Persistent
[root@azure-madme-prod-k8s-master-0 ~]#
[root@azure-madme-prod-k8s-master-0 ~]#
[root@azure-madme-prod-k8s-master-0 ~]# kubectl get sc -o yaml az-standard
allowVolumeExpansion: true
apiVersion: storage.k8s.io/v1
kind: StorageClass
metadata:
  annotations:
    kubectl.kubernetes.io/last-applied-configuration: |
      {"allowVolumeExpansion":true,"apiVersion":"storage.k8s.io/v1","kind":"StorageClass","metadata":{"annotations":{"storageclass.kubernetes.io/is-default-class":"true"},"name":"az-standard"},"parameters":{"storageAccountType":"Standard_LRS"},"provisioner":"disk.csi.azure.com","reclaimPolicy":"Delete"}
    storageclass.kubernetes.io/is-default-class: "true"
  creationTimestamp: "2022-07-07T23:42:34Z"
  name: az-standard
  resourceVersion: "397131988"
  uid: 1055c20b-d26a-4178-a280-14b205d88097
parameters:
  storageAccountType: Standard_LRS
provisioner: disk.csi.azure.com
reclaimPolicy: Delete
volumeBindingMode: Immediate

PVC manifest:

[root@azure-madme-prod-k8s-master-0 ~]# kubectl get pvc -n ci -o yaml mailpit-ci
apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  annotations:
    kubectl.kubernetes.io/last-applied-configuration: |
      {"apiVersion":"v1","kind":"PersistentVolumeClaim","metadata":{"annotations":{},"labels":{"app.kubernetes.io/instance":"mailpit-ci","app.kubernetes.io/managed-by":"Helm","app.kubernetes.io/name":"mailpit","argocd.argoproj.io/instance":"mailpit-ci","helm.sh/chart":"mailpit-0.5.0"},"name":"mailpit-ci","namespace":"ci"},"spec":{"accessModes":["ReadWriteOnce"],"resources":{"requests":{"storage":"1Gi"}},"storageClassName":"az-standard"}}
    pv.kubernetes.io/bind-completed: "yes"
    pv.kubernetes.io/bound-by-controller: "yes"
    volume.beta.kubernetes.io/storage-provisioner: disk.csi.azure.com
    volume.kubernetes.io/storage-provisioner: disk.csi.azure.com
  creationTimestamp: "2023-08-02T09:39:02Z"
  finalizers:
  - kubernetes.io/pvc-protection
  labels:
    app.kubernetes.io/instance: mailpit-ci
    app.kubernetes.io/managed-by: Helm
    app.kubernetes.io/name: mailpit
    argocd.argoproj.io/instance: mailpit-ci
    helm.sh/chart: mailpit-0.5.0
  name: mailpit-ci
  namespace: ci
  resourceVersion: "213609911"
  uid: badac45c-1f58-4661-9f28-70cbeb76afcf
spec:
  accessModes:
  - ReadWriteOnce
  resources:
    requests:
      storage: 1Gi
  storageClassName: az-standard
  volumeMode: Filesystem
  volumeName: pvc-badac45c-1f58-4661-9f28-70cbeb76afcf
status:
  accessModes:
  - ReadWriteOnce
  capacity:
    storage: 1Gi
  phase: Bound

Anyone ever seen this kind of issue? Seems very strange and very random. Seems like the CSI driver cant detect the ext4 filesystem present and tries to format it.

that disk could be partially broken, pls take a snapshot and then use fsck -y /dev/sdx to fix the original disk.

I dont think its a broken disk. On a node reboot that same PVC mounts fine, also when the pod is evicted to a different node, the PVC is mounted fine. It more looks like a parsing error to me (or unexpected output from blkid) as seen in:

I0430 14:08:20.160870       1 mount_linux.go:579] Attempting to determine if disk "/dev/disk/azure/scsi1/lun1" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun1])
I0430 14:08:20.248512       1 mount_linux.go:582] Output: ""

Ill try to tackle down some more details as after reboot the PVCs are mounted fine. Also I would note, that we did not have this issue on 1.27, this issue seems to be present on 1.28 only.

Hello, this issue keeps coming for us. I have zero idea what could be wrong. The issue comes on already existing PVCs that had no issues in the past.

This part is confirmed, BLKID returns an empty string:

I0517 06:56:08.200257       1 mount_linux.go:579] Attempting to determine if disk "/dev/disk/azure/scsi1/lun5" is formatted using blkid with args: ([-p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun5])
I0517 06:56:08.289216       1 mount_linux.go:582] Output: ""

blkid is returning an error code 2. Adding some debug output:

[root@azure-madme-prod-k8s-node-2 ~]# LIBBLKID_DEBUG=all blkid -p -s TYPE -s PTTYPE -o export /dev/disk/azure/scsi1/lun5
1422445: libblkid:     INIT: library debug mask: 0xffff
1422445: libblkid:     INIT: library version: 2.32.1 [16-Jul-2018]
Available "LIBBLKID_DEBUG=<name>[,...]|<mask>" debug masks:
   all      [0xffff] : info about all subsystems
   cache    [0x0004] : blkid tags cache
   config   [0x0008] : config file utils
   dev      [0x0010] : device utils
   devname  [0x0020] : /proc/partitions evaluation
   devno    [0x0040] : conversions to device name
   evaluate [0x0080] : tags resolving
   help     [0x0001] : this help
   lowprobe [0x0100] : superblock/raids/partitions probing
   buffer   [0x2000] : low-probing buffers
   probe    [0x0200] : devices verification
   read     [0x0400] : cache parsing
   save     [0x0800] : cache writing
   tag      [0x1000] : tags utils
1422445: libblkid: LOWPROBE: allocate a new probe
1422445: libblkid: LOWPROBE: zeroize wiper
1422445: libblkid: LOWPROBE: ready for low-probing, offset=0, size=34359738368
1422445: libblkid: LOWPROBE: whole-disk: YES, regfile: NO
1422445: libblkid: LOWPROBE: start probe
1422445: libblkid: LOWPROBE: zeroize wiper
1422445: libblkid: LOWPROBE: chain safeprobe superblocks ENABLED
1422445: libblkid: LOWPROBE: --> starting probing loop [SUBLKS idx=-1]
1422445: libblkid: LOWPROBE: [0] linux_raid_member:
1422445: libblkid: LOWPROBE:    call probefunc()
1422445: libblkid: LOWPROBE:    read: off=34359672832 len=64
1422445: libblkid: LOWPROBE:    read failed: Input/output error
1422445: libblkid: LOWPROBE: <-- leaving probing loop (failed=-5) [SUBLKS idx=0]
1422445: libblkid: LOWPROBE: freeing values list
1422445: libblkid: LOWPROBE: end probe
1422445: libblkid: LOWPROBE: zeroize wiper
1422445: libblkid: LOWPROBE: free probe

I was able to fix the issue by unmounting the disk in azure console and deleting the volumeattachment in kube. After this, the very same PVC is mounted again on the node with no issues. Anyone has any idea what could be causing this issue? Seems to me like an azure issue, although this issue started coming once we upgraded kube to 1.28 including the azuredisk driver.

Thanks

The Kubernetes project currently lacks enough contributors to adequately respond to all issues.

This bot triages un-triaged issues according to the following rules:

After 90d of inactivity, lifecycle/stale is applied
After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

Mark this issue as fresh with /remove-lifecycle stale
Close this issue with /close
Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues.

This bot triages un-triaged issues according to the following rules:

After 90d of inactivity, lifecycle/stale is applied
After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

Mark this issue as fresh with /remove-lifecycle rotten
Close this issue with /close
Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle rotten

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues according to the following rules:

After 90d of inactivity, lifecycle/stale is applied
After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

Reopen this issue with /reopen
Mark this issue as fresh with /remove-lifecycle rotten
Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/close not-planned

@k8s-triage-robot: Closing this issue, marking it as "Not Planned".

In response to [this](https://github.com/kubernetes-sigs/azuredisk-csi-driver/issues/2310#issuecomment-2410615817): >The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs. > >This bot triages issues according to the following rules: >- After 90d of inactivity, `lifecycle/stale` is applied >- After 30d of inactivity since `lifecycle/stale` was applied, `lifecycle/rotten` is applied >- After 30d of inactivity since `lifecycle/rotten` was applied, the issue is closed > >You can: >- Reopen this issue with `/reopen` >- Mark this issue as fresh with `/remove-lifecycle rotten` >- Offer to help out with [Issue Triage][1] > >Please send feedback to sig-contributor-experience at [kubernetes/community](https://github.com/kubernetes/community). > >/close not-planned > >[1]: https://www.kubernetes.dev/docs/guide/issue-triage/ Instructions for interacting with me using PR comments are available [here](https://git.k8s.io/community/contributors/guide/pull-requests.md). If you have questions or suggestions related to my behavior, please file an issue against the [kubernetes-sigs/prow](https://github.com/kubernetes-sigs/prow/issues/new?title=Prow%20issue:) repository.

kubernetes-sigs / azuredisk-csi-driver

Existing PVC fails to mount. CSI driver detects disk as unformatted, tries to format with failure #2310