NetApp / trident

Storage orchestrator for containers
Apache License 2.0
762 stars 222 forks source link

Change a log level from error to warning in CheckMountOptions() #781

Closed ysakashita closed 1 year ago

ysakashita commented 2 years ago

Describe the bug

I would like to change a log level from error to warning in CheckMountOptions(). I found the error messege in trident log(v22.10.0).

time="2022-11-07T03:21:02Z" level=error msg="checking mount options failed; mismatch in mount option: bind, this might cause mount failure" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI source=/dev/dm-4 target=/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d

This error is shown in the result of CheckMountOptions(). When CheckMountOptions() fails, it only outputs the error message but does not stop processing.

If you don't want to stop the process with only a check, I would like it to be a warning level, not an error. Please let me know about the use case of error and the correct process that should be followed, if you don't change the log level.

Another point, I think a procMount (info source: /proc/self/mountinfo) in CheckMountOptions() doesn't include the bind option. So if the method tries to check the bind option, it will always fail.

Here are the logs before and after this error.

2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="GRPC call: /csi.v1.Node/NodePublishVolume" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="GRPC request: volume_id:\"pvc-831fab01-891d-463c-a51a-6d08aa468474\" publish_context:<key:\"LUKSEncryption\" value:\"false\" > publish_context:<key:\"filesystemType\" value:\"raw\" > publish_context:<key:\"iscsiIgroup\" value:\"demo-stateful-w-default-9eb74500-ttwn6-c65e27a9-3f5a-49b9-aac8-d515c882c36a\" > publish_context:<key:\"iscsiInterface\" value:\"\" > publish_context:<key:\"iscsiLunNumber\" value:\"9\" > publish_context:<key:\"iscsiLunSerial\" value:\"\" > publish_context:<key:\"iscsiTargetIqn\" value:\"iqn.1992-08.com.netapp:sn.b9a2cb12b64811e8894e00a098ea6221:vs.5\" > publish_context:<key:\"iscsiTargetPortalCount\" value:\"2\" > publish_context:<key:\"mountOptions\" value:\"\" > publish_context:<key:\"p1\" value:\"10.30.108.248\" > publish_context:<key:\"p2\" value:\"10.30.108.249\" > publish_context:<key:\"protocol\" value:\"block\" > publish_context:<key:\"sharedTarget\" value:\"true\" > publish_context:<key:\"useCHAP\" value:\"false\" > staging_target_path:\"/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/staging/pvc-831fab01-891d-463c-a51a-6d08aa468474\" target_path:\"/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d\" volume_capability:<block:<> access_mode:<mode:SINGLE_NODE_WRITER > > volume_context:<key:\"backendUUID\" value:\"cb9a5979-58e3-4145-84aa-1d8e4df6c4b2\" > volume_context:<key:\"internalName\" value:\"stateful_demo_k8s_pre_stg_caas_corp_zlab_co_jp_pvc_831fab01_891d_463c_a51a_6d08aa468474\" > volume_context:<key:\"name\" value:\"pvc-831fab01-891d-463c-a51a-6d08aa468474\" > volume_context:<key:\"protocol\" value:\"block\" > volume_context:<key:\"storage.kubernetes.io/csiProvisionerIdentity\" value:\"1667694587219-8081-csi.trident.netapp.io\" > " requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Attempting to acquire shared lock (NodePublishVolume-pvc-831fab01-891d-463c-a51a-6d08aa468474)." lock=csi_node_server requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Acquired shared lock (NodePublishVolume-pvc-831fab01-891d-463c-a51a-6d08aa468474)." lock=csi_node_server requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg=">>>> NodePublishVolume" Method=NodePublishVolume Type=CSI_Node requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg=">>>> osutils_linux.GetTargetFilePath" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="<<<< osutils_linux.GetTargetFilePath" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Publish Info found" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg=">>>> mount_linux.MountDevice" device=/dev/dm-4 mountpoint=/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d options=bind requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg=">>>> mount_linux.IsMounted" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI source=/dev/dm-4 target=/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Mountpoint found: {10790 2548 0:6 /dm-4 /host/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d [rw nosuid noexec relatime] devtmpfs udev [rw size=4056840k nr_inodes=1014210 mode=755]}" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Device found: dm-4" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=error msg="checking mount options failed; mismatch in mount option: bind, this might cause mount failure" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI source=/dev/dm-4 target=/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Mount information found." requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI source=/dev/dm-4 target=/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="<<<< mount_linux.IsMounted" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI source=/dev/dm-4 target=/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-831fab01-891d-463c-a51a-6d08aa468474/e2410367-77ba-40d5-9242-7def5ceee42d
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Already mounted: true, mountpoint exists: true" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="<<<< mount_linux.MountDevice" requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="<<<< NodePublishVolume" Method=NodePublishVolume Type=CSI_Node requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="Released shared lock (NodePublishVolume-pvc-831fab01-891d-463c-a51a-6d08aa468474)." lock=csi_node_server requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI
2022-11-07T12:21:02+09:00 {app="node.csi.trident.netapp.io", filename="/var/log/pods/trident_trident-csi-l47n9_6ecc661f-e6c3-46bb-b6f9-9bf9be5aba27/trident-main/0.log", job="trident/node.csi.trident.netapp.io", node_name="demo-stateful-w-default-9eb74500-ttwn6", pod="trident-csi-l47n9"}                                   time="2022-11-07T03:21:02Z" level=debug msg="GRPC response: " requestID=c8d856be-1fff-4926-8770-7a5bbeb4ed0c requestSource=CSI

Environment Provide accurate information about the environment to help us reproduce the issue.

To Reproduce None

Expected behavior The error messege in CheckoutMountOptions() will be warning level.

ysakashita commented 1 year ago

@gnarl Thank you for fixing it!