# OCP vsphere csi bug
## 確認方法1
Creating a simple pod and pvc on the node consistently fails with:
```
Warning FailedMount 1s (x6 over 17s) kubelet MountVolume.SetUp failed for volume "pvc-f5abf781-571f-400a-8d7b-7396297f9e08" : rpc error: code = FailedPrecondition desc = volume ID: "b32d480a-76f7-4607-8313-4c72c9bfa033" does not appear staged to "/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount"
```
The mount already exists, using the /dev/mapper device:
```
sh-5.1# mount | grep csi
/dev/mapper/36000c29622f0b0506766a70d894fab33 on /var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount type ext4 (rw,relatime,seclabel)
```
From the vmware-vsphere-csi-driver-node pod logs:
```
time="2023-10-05T22:06:50Z" level=info msg="attempting to mount disk" fsType=ext4 options="[defaults]" source=/dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 target=/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount
time="2023-10-05T22:06:50Z" level=info msg="mount command" args="-t ext4 -o defaults /dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 /var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount" cmd=mount
time="2023-10-05T22:06:50Z" level=error msg="mount Failed" args="-t ext4 -o defaults /dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 /var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount" cmd=mount error="exit status 32" output="mount: /var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount: wrong fs type, bad option, bad superblock on /dev/mapper/36000c29622f0b0506766a70d894fab33, missing codepage or helper program, or other error.\n"
time="2023-10-05T22:06:50Z" level=info msg="checking if disk is formatted using lsblk" args="[-n -o FSTYPE /dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33]" disk=/dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33
time="2023-10-05T22:06:50Z" level=info msg="disk appears unformatted, attempting format" fsType=ext4 options="[defaults]" source=/dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 target=/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount
time="2023-10-05T22:06:50Z" level=info msg="disk successfully formatted" fsType=ext4 options="[defaults]" source=/dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 target=/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount
time="2023-10-05T22:06:50Z" level=info msg="mount command" args="-t ext4 -o defaults /dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 /var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount" cmd=mount
{"level":"info","time":"2023-10-05T22:06:50.72190959Z","caller":"osutils/linux_os_utils.go:165","msg":"nodeStageBlockVolume: Device mounted successfully at \"/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount\"","TraceId":"9f8724a8-f723-418d-a6ae-a39e2e89b3c1"}
{"level":"info","time":"2023-10-05T22:06:50.729223209Z","caller":"service/node.go:153","msg":"NodePublishVolume: called with args {VolumeId:b32d480a-76f7-4607-8313-4c72c9bfa033 PublishContext:map[diskUUID:6000c29622f0b0506766a70d894fab33 type:vSphere CNS Block Volume] StagingTargetPath:/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount TargetPath:/var/lib/kubelet/pods/72ff68b1-b789-4691-bed0-f9155382bc47/volumes/kubernetes.io~csi/pvc-f5abf781-571f-400a-8d7b-7396297f9e08/mount VolumeCapability:mount:<fs_type:\"ext4\" > access_mode:<mode:SINGLE_NODE_WRITER > Readonly:false Secrets:map[] VolumeContext:map[storage.kubernetes.io/csiProvisionerIdentity:1696539203537-8081-csi.vsphere.vmware.com type:vSphere CNS Block Volume] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}","TraceId":"be11ce91-ddd2-4c2c-a0cc-881e1c0b42be"}
{"level":"info","time":"2023-10-05T22:06:50.729349471Z","caller":"osutils/linux_os_utils.go:604","msg":"check path exits /dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33","TraceId":"be11ce91-ddd2-4c2c-a0cc-881e1c0b42be"}
{"level":"info","time":"2023-10-05T22:06:50.729399936Z","caller":"osutils/linux_os_utils.go:390","msg":"PublishMountVolume called with args: {VolID:b32d480a-76f7-4607-8313-4c72c9bfa033 Target:/var/lib/kubelet/pods/72ff68b1-b789-4691-bed0-f9155382bc47/volumes/kubernetes.io~csi/pvc-f5abf781-571f-400a-8d7b-7396297f9e08/mount StagingTarget:/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount DiskID:6000c29622f0b0506766a70d894fab33 VolumePath:/dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 Device:/dev/dm-0 Ro:false}","TraceId":"be11ce91-ddd2-4c2c-a0cc-881e1c0b42be"}
{"level":"info","time":"2023-10-05T22:06:50.729415411Z","caller":"osutils/linux_os_utils.go:961","msg":"FsType received from Volume Capability: \"ext4\"","TraceId":"be11ce91-ddd2-4c2c-a0cc-881e1c0b42be"}
{"level":"info","time":"2023-10-05T22:06:50.729428549Z","caller":"osutils/linux_os_utils.go:763","msg":"creating directory :\"/var/lib/kubelet/pods/72ff68b1-b789-4691-bed0-f9155382bc47/volumes/kubernetes.io~csi/pvc-f5abf781-571f-400a-8d7b-7396297f9e08/mount\"","TraceId":"be11ce91-ddd2-4c2c-a0cc-881e1c0b42be"}
{"level":"info","time":"2023-10-05T22:06:50.729499721Z","caller":"osutils/linux_os_utils.go:771","msg":"created directory","TraceId":"be11ce91-ddd2-4c2c-a0cc-881e1c0b42be"}
{"level":"error","time":"2023-10-05T22:06:50.732062255Z","caller":"osutils/linux_os_utils.go:444","msg":"volume ID: \"b32d480a-76f7-4607-8313-4c72c9bfa033\" does not appear staged to \"/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/3a3fecfcf6c6c61fb2df59da41392ae1d7e972fd0ce582a79bf8ee60b6220aad/globalmount\"","TraceId":"be11ce91-ddd2-4c2c-a0cc-881e1c0b42be","stacktrace":"sigs.k8s.io/vsphere-csi-driver/v3/pkg/csi/service/osutils.(*OsUtils).PublishMountVol\n\t/go/src/github.com/kubernetes-sigs/vsphere-csi-driver/pkg/csi/service/osutils/linux_os_utils.go:444\nsigs.k8s.io/vsphere-csi-driver/v3/pkg/csi/service.(*vsphereCSIDriver).NodePublishVolume\n\t/go/src/github.com/kubernetes-sigs/vsphere-csi-driver/pkg/csi/service/node.go:199\ngithub.com/container-storage-interface/spec/lib/go/csi._Node_NodePublishVolume_Handler\n\t/go/src/github.com/kubernetes-sigs/vsphere-csi-driver/vendor/github.com/container-storage-interface/spec/lib/go/csi/csi.pb.go:6141\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/src/github.com/kubernetes-sigs/vsphere-csi-driver/vendor/google.golang.org/grpc/server.go:1283\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/src/github.com/kubernetes-sigs/vsphere-csi-driver/vendor/google.golang.org/grpc/server.go:1620\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\t/go/src/github.com/kubernetes-sigs/vsphere-csi-driver/vendor/google.golang.org/grpc/server.go:922"}
```
The /globalmount mount command fails using /dev/disk/by-id/wwn-0x6000c29622f0b0506766a70d894fab33 because it's already mounted using /dev/mapper/36000c29622f0b0506766a70d894fab33
But then nodeStageBlockVolume still sees /globalmount is mounted and reports "Device mounted successfully".
When we get to PublishMountVolume, it looks to see if the path is mounted by device but it's looking for the wrong device (i.e. not the one that's actually mounted).
Workaround:
Remove /etc/multipath.conf and /etc/multipath/wwids, then reboot the node.
My test pod came up successfully after that.
## 確認方法2
Mounting CSI volumes then fails with:
```
Warning FailedMount 3s (x4 over 7s) kubelet MountVolume.SetUp failed for volume "pvc-77d05006-3912-4ba1-b6ae-f19c5e766d37" : rpc error: code = FailedPrecondition desc = volume ID: "ff8a685e-d1fc-4f05-bea6-46ba15133a4f" does not appear staged to "/var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/219f1da44c39eb24d8c03677ee0907cedd00e9a8924a4dd288720a89704e19f7/globalmount"
```
PublishMountVol claims that the volume is not staged because GetDevMounts did not find the device in the mount table.
```
2023-10-06T19:47:58.862Z DEBUG osutils/linux_os_utils.go:418 publishMountVol: device {FullPath:/dev/disk/by-id/wwn-0x6000c295f967d947c5528549554637c8 Name:wwn-0x6000c295f967d947c5528549554637c8 RealDev:/dev/dm-0}, device mounts [] {"TraceId": "e4cb48f6-dc34-4163-bc31-071b6db5c57d"}
```
RealDev shows as `/dev/dm-0` here, but the mount table shows `/dev/mapper/36000c295f967d947c5528549554637c8`:
```
sh-5.1# mount | grep csi
/dev/mapper/36000c295f967d947c5528549554637c8 on /var/lib/kubelet/plugins/kubernetes.io/csi/csi.vsphere.vmware.com/219f1da44c39eb24d8c03677ee0907cedd00e9a8924a4dd288720a89704e19f7/globalmount type ext4 (rw,relatime,seclabel)
sh-5.1# ls -l /dev/mapper/36000c295f967d947c5528549554637c8
lrwxrwxrwx. 1 root root 7 Oct 6 19:39 /dev/mapper/36000c295f967d947c5528549554637c8 -> ../dm-0
sh-5.1# ls -l /dev/disk/by-id/wwn-0x6000c295f967d947c5528549554637c8
lrwxrwxrwx. 1 root root 10 Oct 6 19:39 /dev/disk/by-id/wwn-0x6000c295f967d947c5528549554637c8 -> ../../dm-0
```
It points to the same underlying device (/dev/dm-0) though.