Delay occurs in the elimination of luns attached to pods
Details: ?
Where this issue occurs:
• Cluster OCP NOPROD of Cuyo
• With Driver CSI Unity 1.6
• PVC Name csivol-05e3f78392
• wwn: 0x60060160acd04e00ebc46d61578d24f2
• SO: Red Hat Enterprise Linux CoreOS release 4.7
• UNITY SV:5.0.1.0.5.011
• CSI Driver Version: 1.6.0
Problem that occurs:
• The problem occurs when a POD with a Unity iSCSI PV terminates
• And immediately a new POD is raised using the same PV, this takes about 5 minutes to lift, indicating problems with attaching the PV (this because the PV from unity still says it belongs to another Pod)
time="2021-10-19T14:01:59Z" level=info runid=370 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838"
time="2021-10-19T14:02:58Z" level=error arrayid=ckm00195201796 runid=368 msg="failed to flush multipath device: signal: killed" func="github.com/dell/csi-unity/service.(customLogger).Error()" file="/go/src/csi-unity/service/service.go:714"
time="2021-10-19T14:02:59Z" level=info runid=371 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838"
time="2021-10-19T14:02:59Z" level=info runid=372 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838"
time="2021-10-19T14:02:59Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 found: /dev/sdm"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="get devices by wwn 360060160acd04e00ebc46d61578d24f2" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="devices for WWN 360060160acd04e00ebc46d61578d24f2: [sdg sdk sdl sdm]" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath - trying to find multipath DM name" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath device not found: dm not found" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdg/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdk/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdl/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:03:00Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:03:00Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdm/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706"
time="2021-10-19T14:03:01Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 not found"
time="2021-10-19T14:03:02Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 not found"
time="2021-10-19T14:03:02Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 not found"
log pod when we want to recreate the pod with the same pvc and this is taken:
Normal Scheduled Successfully assigned movistar-3scale/simple-volume-pod-example-04 to ocpnp-7tcvg-worker-0-mtx7v
Warning FailedMount 3m11s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = Internal desc = runid=182 error publish volume to target path: mount failed: exit status 32
mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/csivol-05e3f78392/globalmount /var/lib/kubelet/pods/5e8918ab-c55b-431b-ba9f-b1e7a232e6fa/volumes/kubernetes.io~csi/csivol-05e3f78392/mount
output: mount: /var/lib/kubelet/pods/5e8918ab-c55b-431b-ba9f-b1e7a232e6fa/volumes/kubernetes.io~csi/csivol-05e3f78392/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/csivol-05e3f78392/globalmount does not exist.
Warning FailedMount 3m10s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=184 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 3m9s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=188 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 3m7s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=192 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 3m2s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=197 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 2m54s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=201 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 2m37s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=206 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 2m5s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=214 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount (x2 over 2m8s) kubelet, ocpnp-7tcvg-worker-0-mtx7v Unable to attach or mount volumes: unmounted volumes=[example-04], unattached volumes=[example-04 default-token-f2f56]: timed out waiting for the condition
Warning FailedMount (x2 over 60s) kubelet, ocpnp-7tcvg-worker-0-mtx7v (combined from similar events): MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=231 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
How can the Team help you today?
Delay occurs in the elimination of luns attached to pods
Details: ? Where this issue occurs: • Cluster OCP NOPROD of Cuyo • With Driver CSI Unity 1.6 • PVC Name csivol-05e3f78392 • wwn: 0x60060160acd04e00ebc46d61578d24f2 • SO: Red Hat Enterprise Linux CoreOS release 4.7 • UNITY SV:5.0.1.0.5.011 • CSI Driver Version: 1.6.0
Problem that occurs: • The problem occurs when a POD with a Unity iSCSI PV terminates
• And immediately a new POD is raised using the same PV, this takes about 5 minutes to lift, indicating problems with attaching the PV (this because the PV from unity still says it belongs to another Pod)
Node driver log during deleted POD:
time="2021-10-19T14:00:47Z" level=info runid=361 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838" time="2021-10-19T14:00:58Z" level=info msg="unmount command" cmd=umount path="/var/lib/kubelet/pods/4cddd421-88f0-415f-a8a4-f7aa8e86a066/volumes/kubernetes.io~csi/csivol-05e3f78392/mount" time="2021-10-19T14:00:58Z" level=info runid=365 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838" time="2021-10-19T14:00:59Z" level=info msg="unmount command" cmd=umount path=/var/lib/kubelet/plugins/kubernetes.io/csi/pv/csivol-05e3f78392/globalmount time="2021-10-19T14:00:59Z" level=info msg="Check for disk path /dev/disk/by-id/dm-uuid-mpath-360060160acd04e00ebc46d61578d24f2 found: /dev/dm-1" time="2021-10-19T14:00:59Z" level=info arrayid=ckm00195201796 runid=368 msg="resolve wwn for DM: dm-1" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:00:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath - get block device included in DM" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:00:59Z" level=info arrayid=ckm00195201796 runid=368 msg="get devices by wwn 360060160acd04e00ebc46d61578d24f2" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:00:59Z" level=info arrayid=ckm00195201796 runid=368 msg="devices for WWN 360060160acd04e00ebc46d61578d24f2: [sdg sdk sdl sdm]" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:00:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath - trying to find multipath DM name" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:00:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath - start flush dm: /dev/dm-1" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:00:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath command: chroot args: /noderoot multipath -f /dev/dm-1" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:01:27Z" level=info runid=369 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838"
Log node driver elapsed LUN elimination.
time="2021-10-19T14:01:59Z" level=info runid=370 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838" time="2021-10-19T14:02:58Z" level=error arrayid=ckm00195201796 runid=368 msg="failed to flush multipath device: signal: killed" func="github.com/dell/csi-unity/service.(customLogger).Error()" file="/go/src/csi-unity/service/service.go:714" time="2021-10-19T14:02:59Z" level=info runid=371 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838" time="2021-10-19T14:02:59Z" level=info runid=372 msg="Executing NodeGetCapabilities with args: {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}" func="github.com/dell/csi-unity/service.(service).NodeGetCapabilities()" file="/go/src/csi-unity/service/node.go:838" time="2021-10-19T14:02:59Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 found: /dev/sdm" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="get devices by wwn 360060160acd04e00ebc46d61578d24f2" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="devices for WWN 360060160acd04e00ebc46d61578d24f2: [sdg sdk sdl sdm]" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath - trying to find multipath DM name" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="multipath device not found: dm not found" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdg/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdk/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:02:59Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdl/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:03:00Z" level=info arrayid=ckm00195201796 runid=368 msg="device state is: running" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:03:00Z" level=info arrayid=ckm00195201796 runid=368 msg="writing '1' to /sys/class/block/sdm/device/delete" func="github.com/dell/csi-unity/service.(customLogger).Info()" file="/go/src/csi-unity/service/service.go:706" time="2021-10-19T14:03:01Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 not found" time="2021-10-19T14:03:02Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 not found" time="2021-10-19T14:03:02Z" level=info msg="Check for disk path /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2 not found"
log pod when we want to recreate the pod with the same pvc and this is taken:
Normal Scheduled Successfully assigned movistar-3scale/simple-volume-pod-example-04 to ocpnp-7tcvg-worker-0-mtx7v
Warning FailedMount 3m11s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = Internal desc = runid=182 error publish volume to target path: mount failed: exit status 32
mounting arguments: -o bind /var/lib/kubelet/plugins/kubernetes.io/csi/pv/csivol-05e3f78392/globalmount /var/lib/kubelet/pods/5e8918ab-c55b-431b-ba9f-b1e7a232e6fa/volumes/kubernetes.io~csi/csivol-05e3f78392/mount
output: mount: /var/lib/kubelet/pods/5e8918ab-c55b-431b-ba9f-b1e7a232e6fa/volumes/kubernetes.io~csi/csivol-05e3f78392/mount: special device /var/lib/kubelet/plugins/kubernetes.io/csi/pv/csivol-05e3f78392/globalmount does not exist.
Warning FailedMount 3m10s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=184 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 3m9s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=188 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 3m7s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=192 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 3m2s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=197 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 2m54s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=201 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 2m37s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=206 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount 2m5s kubelet, ocpnp-7tcvg-worker-0-mtx7v MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=214 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory
Warning FailedMount (x2 over 2m8s) kubelet, ocpnp-7tcvg-worker-0-mtx7v Unable to attach or mount volumes: unmounted volumes=[example-04], unattached volumes=[example-04 default-token-f2f56]: timed out waiting for the condition
Warning FailedMount (x2 over 60s) kubelet, ocpnp-7tcvg-worker-0-mtx7v (combined from similar events): MountVolume.SetUp failed for volume "csivol-05e3f78392" : rpc error: code = NotFound desc = runid=231 Disk path not found. Error: readlink /dev/disk/by-id/wwn-0x60060160acd04e00ebc46d61578d24f2: no such file or directory