Repository: kubernetes-csi/csi-driver-smb
Pull request #212 (2021-01-20 14:10:08)

fix: reduce driver logs
<!--  Thanks for sending a pull request!  Here are some tips for you:

1. If this is your first time, please read our contributor guidelines: https://git.k8s.io/community/contributors/guide#your-first-contribution and developer guide https://git.k8s.io/community/contributors/devel/development.md#development-guide
2. Please label this pull request according to what type of issue you are addressing, especially if this is a release targeted pull request. For reference on required PR/issue labels, read here:
https://git.k8s.io/community/contributors/devel/release.md#issue-kind-label
3. Ensure you have added or ran the appropriate tests for your PR: https://git.k8s.io/community/contributors/devel/testing.md
4. If you want *faster* PR reviews, read how: https://git.k8s.io/community/contributors/guide/pull-requests.md#best-practices-for-faster-reviews
5. Follow the instructions for writing a release note: https://git.k8s.io/community/contributors/guide/release-notes.md
6. If the PR is unfinished, see how to mark it: https://git.k8s.io/community/contributors/guide/pull-requests.md#marking-unfinished-pull-requests
-->

**What type of PR is this?**
/kind bug

**What this PR does / why we need it**:
fix: reduce driver logs

 - don't print following method logs by default
following 3 method logs constitute 99.8% logs of all driver logs, this PR set the log level of following 3 methods as `10`, and it would not show in driver logs by default(<= `5` will show in driver logs)
```
/csi.v1.Identity/Probe
/csi.v1.Node/NodeGetCapabilities
/csi.v1.Node/NodeGetVolumeStats
```

 - set log level of csi side car contains as 2
This could reduce `17,280` logs every day of csi-provisioner, csi-resizer, etc which has lease election, following logs would show every 5s:
```
I0119 12:57:02.073355       1 leaderelection.go:282] successfully renewed lease kube-system/blob-csi-azure-com
I0119 12:57:07.081182       1 leaderelection.go:282] successfully renewed lease kube-system/blob-csi-azure-com
I0119 12:57:12.097738       1 leaderelection.go:282] successfully renewed lease kube-system/blob-csi-azure-com
```

**Which issue(s) this PR fixes**:
<!-- 
*Automatically closes linked issue when PR is merged.
Usage: `Fixes #<issue number>`, or `Fixes (paste link of issue)`.
_If PR is about `failing-tests or flakes`, please post the related issues/tests in a comment and do not use `Fixes`_*
-->
Fixes #

**Requirements**:
- [ ] uses [conventional commit messages](https://www.conventionalcommits.org/)
  <!-- Common commit types:
        build: Build 🏭
        chore: Maintenance 🔧
        ci: Continuous Integration 💜
        docs: Documentation 📘
        feat: Features 🌈
        fix: Bug Fixes 🐞
        perf: Performance Improvements 🚀
        refactor: Code Refactoring 💎
        revert: Revert Change ◀️
        style: Code Style 🎶
        security: Security Fix 🛡️
        test: Testing 💚 -->
- [ ] includes documentation
- [ ] adds unit tests
- [ ] tested upgrade from previous version

**Special notes for your reviewer**:


**Release note**:
```
fix: reduce driver logs
```



Patch:
diff --git a/deploy/csi-smb-controller.yaml b/deploy/csi-smb-controller.yaml
index 3a4286d7a..340d21e1a 100644
--- a/deploy/csi-smb-controller.yaml
+++ b/deploy/csi-smb-controller.yaml
@@ -27,7 +27,7 @@ spec:
         - name: csi-provisioner
           image: k8s.gcr.io/sig-storage/csi-provisioner:v2.0.4
           args:
-            - "-v=5"
+            - "-v=2"
             - "--csi-address=$(ADDRESS)"
             - "--leader-election"
           env:
@@ -49,7 +49,7 @@ spec:
             - --csi-address=/csi/csi.sock
             - --probe-timeout=3s
             - --health-port=29642
-            - --v=5
+            - --v=2
           volumeMounts:
             - name: socket-dir
               mountPath: /csi
diff --git a/deploy/csi-smb-node-windows.yaml b/deploy/csi-smb-node-windows.yaml
index d452b8f0e..95446fcc8 100644
--- a/deploy/csi-smb-node-windows.yaml
+++ b/deploy/csi-smb-node-windows.yaml
@@ -26,7 +26,7 @@ spec:
             - --csi-address=$(CSI_ENDPOINT)
             - --probe-timeout=3s
             - --health-port=29643
-            - --v=5
+            - --v=2
           env:
             - name: CSI_ENDPOINT
               value: unix://C:\\csi\\csi.sock
@@ -40,7 +40,7 @@ spec:
         - name: node-driver-registrar
           image: mcr.microsoft.com/oss/kubernetes-csi/csi-node-driver-registrar:v2.0.1
           args:
-            - --v=5
+            - --v=2
             - --csi-address=$(CSI_ENDPOINT)
             - --kubelet-registration-path=C:\\var\\lib\\kubelet\\plugins\\smb.csi.k8s.io\\csi.sock
           env:
diff --git a/deploy/csi-smb-node.yaml b/deploy/csi-smb-node.yaml
index 41414a257..026c493d0 100644
--- a/deploy/csi-smb-node.yaml
+++ b/deploy/csi-smb-node.yaml
@@ -30,7 +30,7 @@ spec:
             - --csi-address=/csi/csi.sock
             - --probe-timeout=3s
             - --health-port=29643
-            - --v=5
+            - --v=2
           resources:
             limits:
               cpu: 100m
@@ -43,7 +43,7 @@ spec:
           args:
             - --csi-address=$(ADDRESS)
             - --kubelet-registration-path=$(DRIVER_REG_SOCK_PATH)
-            - --v=5
+            - --v=2
           lifecycle:
             preStop:
               exec:
diff --git a/hack/verify-examples.sh b/hack/verify-examples.sh
index 667b2ab74..8fbe481e2 100755
--- a/hack/verify-examples.sh
+++ b/hack/verify-examples.sh
@@ -25,6 +25,9 @@ kubectl apply -f deploy/example/statefulset-nonroot.yaml
 echo "sleep 60s ..."
 sleep 60
 
+echo "begin to check pod status ..."
+kubectl get pods -o wide
+
 kubectl get pods --field-selector status.phase=Running | grep deployment-smb
 kubectl get pods --field-selector status.phase=Running | grep statefulset-smb-0
 kubectl get pods --field-selector status.phase=Running | grep statefulset-smb-nonroot-0
diff --git a/pkg/csi-common/controllerserver-default.go b/pkg/csi-common/controllerserver-default.go
index 151b82055..06470cd09 100644
--- a/pkg/csi-common/controllerserver-default.go
+++ b/pkg/csi-common/controllerserver-default.go
@@ -17,9 +17,8 @@ limitations under the License.
 package csicommon
 
 import (
-	"k8s.io/klog/v2"
-
 	"context"
+
 	"github.com/container-storage-interface/spec/lib/go/csi"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/status"
@@ -46,8 +45,6 @@ func (cs *DefaultControllerServer) ControllerUnpublishVolume(ctx context.Context
 }
 
 func (cs *DefaultControllerServer) ValidateVolumeCapabilities(ctx context.Context, req *csi.ValidateVolumeCapabilitiesRequest) (*csi.ValidateVolumeCapabilitiesResponse, error) {
-	klog.V(5).Infof("Using default ValidateVolumeCapabilities")
-
 	for _, c := range req.GetVolumeCapabilities() {
 		found := false
 		for _, c1 := range cs.Driver.VC {
@@ -77,8 +74,6 @@ func (cs *DefaultControllerServer) GetCapacity(ctx context.Context, req *csi.Get
 // ControllerGetCapabilities implements the default GRPC callout.
 // Default supports all capabilities
 func (cs *DefaultControllerServer) ControllerGetCapabilities(ctx context.Context, req *csi.ControllerGetCapabilitiesRequest) (*csi.ControllerGetCapabilitiesResponse, error) {
-	klog.V(5).Infof("Using default ControllerGetCapabilities")
-
 	return &csi.ControllerGetCapabilitiesResponse{
 		Capabilities: cs.Driver.Cap,
 	}, nil
diff --git a/pkg/csi-common/identityserver-default.go b/pkg/csi-common/identityserver-default.go
index d60357df1..075e9bfc0 100644
--- a/pkg/csi-common/identityserver-default.go
+++ b/pkg/csi-common/identityserver-default.go
@@ -18,10 +18,10 @@ package csicommon
 
 import (
 	"context"
+
 	"github.com/container-storage-interface/spec/lib/go/csi"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/status"
-	"k8s.io/klog/v2"
 )
 
 type DefaultIdentityServer struct {
@@ -29,8 +29,6 @@ type DefaultIdentityServer struct {
 }
 
 func (ids *DefaultIdentityServer) GetPluginInfo(ctx context.Context, req *csi.GetPluginInfoRequest) (*csi.GetPluginInfoResponse, error) {
-	klog.V(5).Infof("Using default GetPluginInfo")
-
 	if ids.Driver.Name == "" {
 		return nil, status.Error(codes.Unavailable, "Driver name not configured")
 	}
@@ -50,7 +48,6 @@ func (ids *DefaultIdentityServer) Probe(ctx context.Context, req *csi.ProbeReque
 }
 
 func (ids *DefaultIdentityServer) GetPluginCapabilities(ctx context.Context, req *csi.GetPluginCapabilitiesRequest) (*csi.GetPluginCapabilitiesResponse, error) {
-	klog.V(5).Infof("Using default capabilities")
 	return &csi.GetPluginCapabilitiesResponse{
 		Capabilities: []*csi.PluginCapability{
 			{
diff --git a/pkg/csi-common/nodeserver-default.go b/pkg/csi-common/nodeserver-default.go
index 19fe641ad..2b52fa350 100644
--- a/pkg/csi-common/nodeserver-default.go
+++ b/pkg/csi-common/nodeserver-default.go
@@ -18,8 +18,8 @@ package csicommon
 
 import (
 	"context"
+
 	"github.com/container-storage-interface/spec/lib/go/csi"
-	"k8s.io/klog/v2"
 )
 
 type DefaultNodeServer struct {
@@ -27,16 +27,12 @@ type DefaultNodeServer struct {
 }
 
 func (ns *DefaultNodeServer) NodeGetInfo(ctx context.Context, req *csi.NodeGetInfoRequest) (*csi.NodeGetInfoResponse, error) {
-	klog.V(5).Infof("Using default NodeGetInfo")
-
 	return &csi.NodeGetInfoResponse{
 		NodeId: ns.Driver.NodeID,
 	}, nil
 }
 
 func (ns *DefaultNodeServer) NodeGetCapabilities(ctx context.Context, req *csi.NodeGetCapabilitiesRequest) (*csi.NodeGetCapabilitiesResponse, error) {
-	klog.V(2).Infof("Using default NodeGetCapabilities")
-
 	return &csi.NodeGetCapabilitiesResponse{
 		Capabilities: ns.Driver.NSCap,
 	}, nil
diff --git a/pkg/csi-common/utils.go b/pkg/csi-common/utils.go
index f71ba8900..06ff0ae4e 100644
--- a/pkg/csi-common/utils.go
+++ b/pkg/csi-common/utils.go
@@ -21,6 +21,7 @@ import (
 	"strings"
 
 	"context"
+
 	"github.com/container-storage-interface/spec/lib/go/csi"
 	"github.com/kubernetes-csi/csi-lib-utils/protosanitizer"
 	"google.golang.org/grpc"
@@ -103,14 +104,25 @@ func RunControllerandNodePublishServer(endpoint string, d *CSIDriver, cs csi.Con
 	s.Wait()
 }
 
+func getLogLevel(method string) int32 {
+	if method == "/csi.v1.Identity/Probe" ||
+		method == "/csi.v1.Node/NodeGetCapabilities" ||
+		method == "/csi.v1.Node/NodeGetVolumeStats" {
+		return 10
+	}
+	return 2
+}
+
 func logGRPC(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) {
-	klog.V(3).Infof("GRPC call: %s", info.FullMethod)
-	klog.V(5).Infof("GRPC request: %s", protosanitizer.StripSecrets(req))
+	level := klog.Level(getLogLevel(info.FullMethod))
+	klog.V(level).Infof("GRPC call: %s", info.FullMethod)
+	klog.V(level).Infof("GRPC request: %s", protosanitizer.StripSecrets(req))
+
 	resp, err := handler(ctx, req)
 	if err != nil {
 		klog.Errorf("GRPC error: %v", err)
 	} else {
-		klog.V(5).Infof("GRPC response: %s", protosanitizer.StripSecrets(resp))
+		klog.V(level).Infof("GRPC response: %s", protosanitizer.StripSecrets(resp))
 	}
 	return resp, err
 }


Test patch:
diff --git a/charts/latest/csi-driver-smb/templates/csi-smb-controller.yaml b/charts/latest/csi-driver-smb/templates/csi-smb-controller.yaml
index 1cbdc9c26..7f90bc9a9 100644
--- a/charts/latest/csi-driver-smb/templates/csi-smb-controller.yaml
+++ b/charts/latest/csi-driver-smb/templates/csi-smb-controller.yaml
@@ -29,7 +29,7 @@ spec:
         - name: csi-provisioner
           image: "{{ .Values.image.csiProvisioner.repository }}:{{ .Values.image.csiProvisioner.tag }}"
           args:
-            - "-v=5"
+            - "-v=2"
             - "--csi-address=$(ADDRESS)"
             - "--leader-election"
           env:
@@ -52,7 +52,7 @@ spec:
             - --csi-address=/csi/csi.sock
             - --probe-timeout=3s
             - --health-port=29642
-            - --v=5
+            - --v=2
           imagePullPolicy: {{ .Values.image.livenessProbe.pullPolicy }}
           volumeMounts:
             - name: socket-dir
diff --git a/charts/latest/csi-driver-smb/templates/csi-smb-node-windows.yaml b/charts/latest/csi-driver-smb/templates/csi-smb-node-windows.yaml
index 4221637f1..88d185c09 100644
--- a/charts/latest/csi-driver-smb/templates/csi-smb-node-windows.yaml
+++ b/charts/latest/csi-driver-smb/templates/csi-smb-node-windows.yaml
@@ -28,7 +28,7 @@ spec:
             - --csi-address=$(CSI_ENDPOINT)
             - --probe-timeout=3s
             - --health-port=29643
-            - --v=5
+            - --v=2
           env:
             - name: CSI_ENDPOINT
               value: unix://C:\\csi\\csi.sock
@@ -43,7 +43,7 @@ spec:
         - name: node-driver-registrar
           image: "{{ .Values.windows.image.nodeDriverRegistrar.repository }}:{{ .Values.windows.image.nodeDriverRegistrar.tag }}"
           args:
-            - --v=5
+            - --v=2
             - --csi-address=$(CSI_ENDPOINT)
             - --kubelet-registration-path={{ .Values.kubelet.windowsPath }}\\plugins\\smb.csi.k8s.io\\csi.sock
           env:
diff --git a/charts/latest/csi-driver-smb/templates/csi-smb-node.yaml b/charts/latest/csi-driver-smb/templates/csi-smb-node.yaml
index c49baea70..cc3f53c7d 100644
--- a/charts/latest/csi-driver-smb/templates/csi-smb-node.yaml
+++ b/charts/latest/csi-driver-smb/templates/csi-smb-node.yaml
@@ -32,7 +32,7 @@ spec:
             - --csi-address=/csi/csi.sock
             - --probe-timeout=3s
             - --health-port=29643
-            - --v=5
+            - --v=2
           imagePullPolicy: {{ .Values.image.livenessProbe.pullPolicy }}
           resources:
             limits:
@@ -46,7 +46,7 @@ spec:
           args:
             - --csi-address=$(ADDRESS)
             - --kubelet-registration-path=$(DRIVER_REG_SOCK_PATH)
-            - --v=5
+            - --v=2
           lifecycle:
             preStop:
               exec:
diff --git a/pkg/csi-common/utils_test.go b/pkg/csi-common/utils_test.go
index aea2bc63c..5f741f88b 100644
--- a/pkg/csi-common/utils_test.go
+++ b/pkg/csi-common/utils_test.go
@@ -30,7 +30,6 @@ import (
 )
 
 func TestParseEndpoint(t *testing.T) {
-
 	//Valid unix domain socket endpoint
 	sockType, addr, err := ParseEndpoint("unix://fake.sock")
 	assert.NoError(t, err)
@@ -254,3 +253,38 @@ func TestNewNodeServiceCapability(t *testing.T) {
 		assert.Equal(t, resp.XXX_sizecache, int32(0))
 	}
 }
+
+func TestGetLogLevel(t *testing.T) {
+	tests := []struct {
+		method string
+		level  int32
+	}{
+		{
+			method: "/csi.v1.Identity/Probe",
+			level:  10,
+		},
+		{
+			method: "/csi.v1.Node/NodeGetCapabilities",
+			level:  10,
+		},
+		{
+			method: "/csi.v1.Node/NodeGetVolumeStats",
+			level:  10,
+		},
+		{
+			method: "",
+			level:  2,
+		},
+		{
+			method: "unknown",
+			level:  2,
+		},
+	}
+
+	for _, test := range tests {
+		level := getLogLevel(test.method)
+		if level != test.level {
+			t.Errorf("returned level: (%v), expected level: (%v)", level, test.level)
+		}
+	}
+}