Hide Forgot
Description of problem: Log level of liveness probe container of Cinder CSI driver is not changed when ClusterCSIDriver.Spec.LogLevel is changed. Version-Release number of selected component (if applicable): 4.9.0-0.nightly-2021-11-30-041848 How reproducible: Always Steps to Reproduce: 1. oc edit clustercsidriver ebs.csi.aws.com - change "logLevel: Normal" to "Trace" 2. Wait for the operator to re-deploy everything. 3. Check log level of liveness probe containers oc -n openshift-cluster-csi-drivers get deployment aws-ebs-csi-driver-controller -o yaml Actual results: Log level is not specified in csi-livenessprobe container: - args: - --csi-address=/csi/csi.sock - --probe-timeout=3s - --health-port=10301 image: quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:27bf62619a6463e7f7c175800c0507e0e7427b45db1b33429962709aad35aee7 imagePullPolicy: IfNotPresent name: csi-liveness-probe Expected results: - args: - --v=6 Note that it's probably the same with *all* CSI drivers we ship in OCP.
Liveness probe container should now react to operator's log level changes. I verified the fix using the following steps, posting it for reference and later verification by QE. ======= 1) Get logs from liveness probe container: $ oc -n openshift-cluster-csi-drivers logs aws-ebs-csi-driver-controller-f486cf7ff-s8p76 csi-liveness-probe I1206 11:51:01.840062 1 main.go:149] calling CSI driver to discover driver name I1206 11:51:01.842260 1 main.go:155] CSI driver name: "ebs.csi.aws.com" I1206 11:51:01.842358 1 main.go:183] ServeMux listening at "0.0.0.0:10301" 2) Change log level in cluster csi driver object: (change "logLevel: Normal" to "logLevel: Trace") $ oc edit clustercsidriver ebs.csi.aws.com 3) Verify pods are recreated: oc -n openshift-cluster-csi-drivers get pod | grep controller aws-ebs-csi-driver-controller-f486cf7ff-jnlbv 11/11 Running 0 8s aws-ebs-csi-driver-controller-f486cf7ff-xq59m 0/11 ContainerCreating 0 3s $ oc -n openshift-cluster-csi-drivers get pod | grep controller aws-ebs-csi-driver-controller-f486cf7ff-jnlbv 11/11 Running 0 27s aws-ebs-csi-driver-controller-f486cf7ff-xq59m 11/11 Running 0 22 4) Check the logs again: BEFORE FIX: Log level change was not respected: $ oc -n openshift-cluster-csi-drivers logs aws-ebs-csi-driver-controller-f486cf7ff-jnlbv csi-liveness-probe I1206 12:08:23.077359 1 main.go:149] calling CSI driver to discover driver name I1206 12:08:23.080035 1 main.go:155] CSI driver name: "ebs.csi.aws.com" I1206 12:08:23.080314 1 main.go:183] ServeMux listening at "0.0.0.0:10301" AFTER FIX: Log level was changed and is now more verbose: $ oc -n openshift-cluster-csi-drivers logs pod/aws-ebs-csi-driver-controller-79bc77f685-rfpmc csi-liveness-probe I1206 13:44:10.326609 1 connection.go:154] Connecting to unix:///csi/csi.sock I1206 13:44:10.327485 1 main.go:149] calling CSI driver to discover driver name I1206 13:44:10.327510 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo I1206 13:44:10.327519 1 connection.go:184] GRPC request: {} I1206 13:44:10.330998 1 connection.go:186] GRPC response: {"name":"ebs.csi.aws.com","vendor_version":"v1.2.0"} I1206 13:44:10.331087 1 connection.go:187] GRPC error: <nil> I1206 13:44:10.331118 1 main.go:155] CSI driver name: "ebs.csi.aws.com" I1206 13:44:10.331129 1 main.go:183] ServeMux listening at "0.0.0.0:10301" I1206 13:44:26.628356 1 connection.go:154] Connecting to unix:///csi/csi.sock I1206 13:44:26.628861 1 main.go:69] Sending probe request to CSI driver "ebs.csi.aws.com" I1206 13:44:26.628884 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I1206 13:44:26.628894 1 connection.go:184] GRPC request: {} I1206 13:44:26.629624 1 connection.go:186] GRPC response: {} I1206 13:44:26.629721 1 connection.go:187] GRPC error: <nil> ...
We need to fix this in all other CSI driver operators: https://github.com/openshift/ibm-vpc-block-csi-driver-operator https://github.com/openshift/aws-efs-csi-driver-operator https://github.com/openshift/vmware-vsphere-csi-driver-operator https://github.com/openshift/csi-driver-manila-operator https://github.com/openshift/openstack-cinder-csi-driver-operator https://github.com/openshift/alibaba-disk-csi-driver-operator https://github.com/openshift/ovirt-csi-driver-operator https://github.com/openshift/gcp-pd-csi-driver-operator https://github.com/openshift/azure-file-csi-driver-operator https://github.com/openshift/azure-disk-csi-driver-operator (not all may use the liveness probe sidecar)
Moving back to POST to address the other drivers before it goes to QA: https://bugzilla.redhat.com/show_bug.cgi?id=2028484#c2
Azure-Disk and Azure-File CSI Driver Operator verified pass on 4.10.0-0.nightly-2021-12-14-083101 Azure-Disk-CSI-Driver: $ oc get deployment.apps/azure-disk-csi-driver-controller -o json | jq -r '.spec.template.spec.containers[] | select(.name=="csi-liveness-probe").args' [ "--csi-address=$(ADDRESS)", "--probe-timeout=3s", "--health-port=10301", "--v=6" ] $ oc logs deployment.apps/azure-disk-csi-driver-controller csi-liveness-probe Found 2 pods, using pod/azure-disk-csi-driver-controller-6f7fd84cc5-x7tx6 I1215 09:03:26.542980 1 connection.go:154] Connecting to unix:///var/lib/csi/sockets/pluginproxy/csi.sock I1215 09:03:26.543671 1 main.go:149] calling CSI driver to discover driver name I1215 09:03:26.543743 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo I1215 09:03:26.543776 1 connection.go:184] GRPC request: {} I1215 09:03:26.549213 1 connection.go:186] GRPC response: {"name":"disk.csi.azure.com","vendor_version":"v1.5.0"} I1215 09:03:26.549286 1 connection.go:187] GRPC error: <nil> I1215 09:03:26.549315 1 main.go:155] CSI driver name: "disk.csi.azure.com" I1215 09:03:26.549325 1 main.go:183] ServeMux listening at "0.0.0.0:10301" I1215 09:03:28.015696 1 connection.go:154] Connecting to unix:///var/lib/csi/sockets/pluginproxy/csi.sock I1215 09:03:28.016386 1 main.go:69] Sending probe request to CSI driver "disk.csi.azure.com" I1215 09:03:28.016407 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I1215 09:03:28.016413 1 connection.go:184] GRPC request: {} I1215 09:03:28.017457 1 connection.go:186] GRPC response: {"ready":{"value":true}} I1215 09:03:28.017712 1 connection.go:187] GRPC error: <nil> I1215 09:03:28.017789 1 main.go:87] Health check succeeded ... Azure-file: $ oc get deployment.apps/azure-file-csi-driver-controller -o json | jq -r '.spec.template.spec.containers[] | select(.name=="csi-liveness-probe").args' [ "--csi-address=$(ADDRESS)", "--probe-timeout=3s", "--health-port=10303", "--v=6" ] $ oc logs deployment.apps/azure-file-csi-driver-controller csi-liveness-probe Found 2 pods, using pod/azure-file-csi-driver-controller-86479945f9-lsjds I1215 10:33:45.765144 1 connection.go:154] Connecting to unix:///var/lib/csi/sockets/pluginproxy/csi.sock I1215 10:33:45.766651 1 main.go:149] calling CSI driver to discover driver name I1215 10:33:45.766701 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo I1215 10:33:45.766708 1 connection.go:184] GRPC request: {} I1215 10:33:45.773450 1 connection.go:186] GRPC response: {"name":"file.csi.azure.com","vendor_version":"v1.7.0"} I1215 10:33:45.773513 1 connection.go:187] GRPC error: <nil> I1215 10:33:45.773539 1 main.go:155] CSI driver name: "file.csi.azure.com" I1215 10:33:45.773548 1 main.go:183] ServeMux listening at "0.0.0.0:10303"
oc logs pod/ibm-vpc-block-csi-controller-5dc949cf6-9rt6c -c liveness-probe I0105 08:56:37.233425 1 main.go:149] calling CSI driver to discover driver name I0105 08:56:37.234944 1 main.go:155] CSI driver name: "vpc.block.csi.ibm.io" I0105 08:56:37.234959 1 main.go:183] ServeMux listening at "0.0.0.0:9808" oc logs pod/ibm-vpc-block-csi-controller-56bcb4b544-bgj9k -c liveness-probe I0105 09:00:11.245474 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:00:12.247027 1 main.go:149] calling CSI driver to discover driver name I0105 09:00:12.247048 1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo I0105 09:00:12.247053 1 connection.go:184] GRPC request: {} I0105 09:00:12.249924 1 connection.go:186] GRPC response: {"name":"vpc.block.csi.ibm.io","vendor_version":"vpcBlockDriver-279a88c2795e0ff8ee88784c0140cf7f0492a176"} I0105 09:00:12.249979 1 connection.go:187] GRPC error: <nil> I0105 09:00:12.250001 1 main.go:155] CSI driver name: "vpc.block.csi.ibm.io" I0105 09:00:12.250009 1 main.go:183] ServeMux listening at "0.0.0.0:9808" I0105 09:00:24.452228 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:00:24.544548 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:00:24.544570 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:00:24.544573 1 connection.go:184] GRPC request: {} I0105 09:00:24.545287 1 connection.go:186] GRPC response: {} I0105 09:00:24.545344 1 connection.go:187] GRPC error: <nil> I0105 09:00:24.545351 1 main.go:87] Health check succeeded I0105 09:00:34.451823 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:00:34.453343 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:00:34.453377 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:00:34.453382 1 connection.go:184] GRPC request: {} I0105 09:00:34.453934 1 connection.go:186] GRPC response: {} I0105 09:00:34.453966 1 connection.go:187] GRPC error: <nil> I0105 09:00:34.453975 1 main.go:87] Health check succeeded I0105 09:00:44.451224 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:00:44.451883 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:00:44.452011 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:00:44.452020 1 connection.go:184] GRPC request: {} I0105 09:00:44.452554 1 connection.go:186] GRPC response: {} I0105 09:00:44.452584 1 connection.go:187] GRPC error: <nil> I0105 09:00:44.452591 1 main.go:87] Health check succeeded I0105 09:00:54.450858 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:00:54.451272 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:00:54.451300 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:00:54.451304 1 connection.go:184] GRPC request: {} I0105 09:00:54.451779 1 connection.go:186] GRPC response: {} I0105 09:00:54.451817 1 connection.go:187] GRPC error: <nil> I0105 09:00:54.451825 1 main.go:87] Health check succeeded I0105 09:01:04.451802 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:01:04.452320 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:01:04.452352 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:01:04.452357 1 connection.go:184] GRPC request: {} I0105 09:01:04.452895 1 connection.go:186] GRPC response: {} I0105 09:01:04.452925 1 connection.go:187] GRPC error: <nil> I0105 09:01:04.452933 1 main.go:87] Health check succeeded I0105 09:01:14.453262 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:01:14.453758 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:01:14.453791 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:01:14.453795 1 connection.go:184] GRPC request: {} I0105 09:01:14.454289 1 connection.go:186] GRPC response: {} I0105 09:01:14.454342 1 connection.go:187] GRPC error: <nil> I0105 09:01:14.454349 1 main.go:87] Health check succeeded I0105 09:01:24.451366 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:01:24.451828 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:01:24.451863 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:01:24.451867 1 connection.go:184] GRPC request: {} I0105 09:01:24.452305 1 connection.go:186] GRPC response: {} I0105 09:01:24.452348 1 connection.go:187] GRPC error: <nil> I0105 09:01:24.452356 1 main.go:87] Health check succeeded I0105 09:01:34.451908 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:01:34.452343 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:01:34.452372 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:01:34.452377 1 connection.go:184] GRPC request: {} I0105 09:01:34.452886 1 connection.go:186] GRPC response: {} I0105 09:01:34.452915 1 connection.go:187] GRPC error: <nil> I0105 09:01:34.452923 1 main.go:87] Health check succeeded I0105 09:01:44.451317 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:01:44.451753 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:01:44.451785 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:01:44.451790 1 connection.go:184] GRPC request: {} I0105 09:01:44.452250 1 connection.go:186] GRPC response: {} I0105 09:01:44.452277 1 connection.go:187] GRPC error: <nil> I0105 09:01:44.452284 1 main.go:87] Health check succeeded I0105 09:01:54.451356 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:01:54.451825 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:01:54.451856 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:01:54.451861 1 connection.go:184] GRPC request: {} I0105 09:01:54.452382 1 connection.go:186] GRPC response: {} I0105 09:01:54.452412 1 connection.go:187] GRPC error: <nil> I0105 09:01:54.452420 1 main.go:87] Health check succeeded I0105 09:02:04.450841 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:02:04.451328 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:02:04.451359 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:02:04.451363 1 connection.go:184] GRPC request: {} I0105 09:02:04.451858 1 connection.go:186] GRPC response: {} I0105 09:02:04.451890 1 connection.go:187] GRPC error: <nil> I0105 09:02:04.451900 1 main.go:87] Health check succeeded I0105 09:02:14.451839 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:02:14.452665 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:02:14.452696 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:02:14.452712 1 connection.go:184] GRPC request: {} I0105 09:02:14.453212 1 connection.go:186] GRPC response: {} I0105 09:02:14.453246 1 connection.go:187] GRPC error: <nil> I0105 09:02:14.453253 1 main.go:87] Health check succeeded I0105 09:02:24.451227 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:02:24.451750 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:02:24.451780 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:02:24.451785 1 connection.go:184] GRPC request: {} I0105 09:02:24.452236 1 connection.go:186] GRPC response: {} I0105 09:02:24.452269 1 connection.go:187] GRPC error: <nil> I0105 09:02:24.452276 1 main.go:87] Health check succeeded I0105 09:02:34.451095 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:02:34.451544 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:02:34.451607 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:02:34.451612 1 connection.go:184] GRPC request: {} I0105 09:02:34.452186 1 connection.go:186] GRPC response: {} I0105 09:02:34.452213 1 connection.go:187] GRPC error: <nil> I0105 09:02:34.452221 1 main.go:87] Health check succeeded I0105 09:02:44.451110 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:02:44.451525 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:02:44.451608 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:02:44.451619 1 connection.go:184] GRPC request: {} I0105 09:02:44.452099 1 connection.go:186] GRPC response: {} I0105 09:02:44.452146 1 connection.go:187] GRPC error: <nil> I0105 09:02:44.452153 1 main.go:87] Health check succeeded I0105 09:02:54.451003 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:02:54.451422 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:02:54.451454 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:02:54.451459 1 connection.go:184] GRPC request: {} I0105 09:02:54.451943 1 connection.go:186] GRPC response: {} I0105 09:02:54.451982 1 connection.go:187] GRPC error: <nil> I0105 09:02:54.451990 1 main.go:87] Health check succeeded I0105 09:03:04.451293 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:03:04.451720 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:03:04.451796 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:03:04.451808 1 connection.go:184] GRPC request: {} I0105 09:03:04.452303 1 connection.go:186] GRPC response: {} I0105 09:03:04.452331 1 connection.go:187] GRPC error: <nil> I0105 09:03:04.452339 1 main.go:87] Health check succeeded I0105 09:03:14.451850 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:03:14.452335 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:03:14.452362 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:03:14.452366 1 connection.go:184] GRPC request: {} I0105 09:03:14.452807 1 connection.go:186] GRPC response: {} I0105 09:03:14.452839 1 connection.go:187] GRPC error: <nil> I0105 09:03:14.452846 1 main.go:87] Health check succeeded I0105 09:03:24.451235 1 connection.go:154] Connecting to unix:///csi/csi.sock I0105 09:03:24.451714 1 main.go:69] Sending probe request to CSI driver "vpc.block.csi.ibm.io" I0105 09:03:24.451741 1 connection.go:183] GRPC call: /csi.v1.Identity/Probe I0105 09:03:24.451746 1 connection.go:184] GRPC request: {} I0105 09:03:24.452223 1 connection.go:186] GRPC response: {} I0105 09:03:24.452252 1 connection.go:187] GRPC error: <nil> I0105 09:03:24.452261 1 main.go:87] Health check succeeded passed with 4.10.0-0.nightly-2021-12-23-153012
Verified pass on Ali CSI Driver.
Mark it as Verified.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (Moderate: OpenShift Container Platform 4.10.3 security update), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2022:0056