Repository: kubernetes-csi/csi-driver-nfs
Pull request #138 (2021-01-20 06:54:28)

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. Follow the instructions for writing a release note: https://git.k8s.io/community/contributors/guide/release-notes.md
3. 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 #

**Special notes for your reviewer**:

**Does this PR introduce a user-facing change?**:
<!--
If no, just write "NONE" in the release-note block below.
If yes, a release note is required:
Enter your extended release note in the block below. If the PR requires additional action from users switching to the new release, include the string "action required".
-->
```release-note
fix: reduce driver logs
```



Patch:
diff --git a/.github/workflows/darwin.yaml b/.github/workflows/darwin.yaml
index 9be5a98e..84fc5423 100644
--- a/.github/workflows/darwin.yaml
+++ b/.github/workflows/darwin.yaml
@@ -10,7 +10,7 @@ jobs:
     - name: Set up Go 1.x
       uses: actions/setup-go@v2
       with:
-        go-version: ^1.13
+        go-version: ^1.15
       id: go
     - name: Check out code into the Go module directory
       uses: actions/checkout@v2
diff --git a/.github/workflows/linux.yaml b/.github/workflows/linux.yaml
index f90f73ab..43567a68 100644
--- a/.github/workflows/linux.yaml
+++ b/.github/workflows/linux.yaml
@@ -13,7 +13,7 @@ jobs:
     - name: Set up Go 1.x
       uses: actions/setup-go@v2
       with:
-        go-version: ^1.13
+        go-version: ^1.15
       id: go
 
     - name: Check out code into the Go module directory
diff --git a/deploy/csi-nfs-controller.yaml b/deploy/csi-nfs-controller.yaml
index d7f44bec..67b3184c 100644
--- a/deploy/csi-nfs-controller.yaml
+++ b/deploy/csi-nfs-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=29652
-            - --v=5
+            - --v=2
           volumeMounts:
             - name: socket-dir
               mountPath: /csi
diff --git a/deploy/csi-nfs-node.yaml b/deploy/csi-nfs-node.yaml
index dd66fa8d..5f4184c7 100644
--- a/deploy/csi-nfs-node.yaml
+++ b/deploy/csi-nfs-node.yaml
@@ -26,7 +26,7 @@ spec:
             - --csi-address=/csi/csi.sock
             - --probe-timeout=3s
             - --health-port=29653
-            - --v=5
+            - --v=2
           volumeMounts:
             - name: socket-dir
               mountPath: /csi
@@ -44,7 +44,7 @@ spec:
               exec:
                 command: ["/bin/sh", "-c", "rm -rf /registration/csi-nfsplugin /registration/csi-nfsplugin-reg.sock"]
           args:
-            - --v=5
+            - --v=2
             - --csi-address=/csi/csi.sock
             - --kubelet-registration-path=/var/lib/kubelet/plugins/csi-nfsplugin/csi.sock
           env:
diff --git a/hack/verify-examples.sh b/hack/verify-examples.sh
index 1c248d43..bd071110 100755
--- a/hack/verify-examples.sh
+++ b/hack/verify-examples.sh
@@ -24,6 +24,9 @@ kubectl apply -f ./deploy/example/statefulset.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-nfs
 kubectl get pods --field-selector status.phase=Running | grep statefulset-nfs-0
 
diff --git a/pkg/nfs/indentityserver.go b/pkg/nfs/indentityserver.go
index f7f1db3c..52d6943a 100644
--- a/pkg/nfs/indentityserver.go
+++ b/pkg/nfs/indentityserver.go
@@ -22,8 +22,6 @@ import (
 	"golang.org/x/net/context"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/status"
-
-	"k8s.io/klog/v2"
 )
 
 type IdentityServer struct {
@@ -31,8 +29,6 @@ type IdentityServer struct {
 }
 
 func (ids *IdentityServer) 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")
 	}
@@ -56,7 +52,6 @@ func (ids *IdentityServer) Probe(ctx context.Context, req *csi.ProbeRequest) (*c
 }
 
 func (ids *IdentityServer) 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/nfs/utils.go b/pkg/nfs/utils.go
index d89204ab..97eb83b3 100644
--- a/pkg/nfs/utils.go
+++ b/pkg/nfs/utils.go
@@ -70,14 +70,25 @@ func ParseEndpoint(ep string) (string, string, error) {
 	return "", "", fmt.Errorf("Invalid endpoint: %v", ep)
 }
 
+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-nfs/templates/csi-nfs-controller.yaml b/charts/latest/csi-driver-nfs/templates/csi-nfs-controller.yaml
index e3dcfa95..4bb90875 100644
--- a/charts/latest/csi-driver-nfs/templates/csi-nfs-controller.yaml
+++ b/charts/latest/csi-driver-nfs/templates/csi-nfs-controller.yaml
@@ -28,7 +28,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:
@@ -51,7 +51,7 @@ spec:
             - --csi-address=/csi/csi.sock
             - --probe-timeout=3s
             - --health-port=29652
-            - --v=5
+            - --v=2
           imagePullPolicy: {{ .Values.image.livenessProbe.pullPolicy }}
           volumeMounts:
             - name: socket-dir
diff --git a/charts/latest/csi-driver-nfs/templates/csi-nfs-node.yaml b/charts/latest/csi-driver-nfs/templates/csi-nfs-node.yaml
index bc23f7d7..6c621af1 100644
--- a/charts/latest/csi-driver-nfs/templates/csi-nfs-node.yaml
+++ b/charts/latest/csi-driver-nfs/templates/csi-nfs-node.yaml
@@ -26,7 +26,7 @@ spec:
             - --csi-address=/csi/csi.sock
             - --probe-timeout=3s
             - --health-port=29653
-            - --v=5
+            - --v=2
           imagePullPolicy: {{ .Values.image.livenessProbe.pullPolicy }}
           volumeMounts:
             - name: socket-dir
@@ -45,7 +45,7 @@ spec:
               exec:
                 command: ["/bin/sh", "-c", "rm -rf /registration/csi-nfsplugin /registration/csi-nfsplugin-reg.sock"]
           args:
-            - --v=5
+            - --v=2
             - --csi-address=/csi/csi.sock
             - --kubelet-registration-path=/var/lib/kubelet/plugins/csi-nfsplugin/csi.sock
           env:
diff --git a/pkg/nfs/utils_test.go b/pkg/nfs/utils_test.go
index 536f8065..1177373d 100644
--- a/pkg/nfs/utils_test.go
+++ b/pkg/nfs/utils_test.go
@@ -83,3 +83,38 @@ func TestParseEndpoint(t *testing.T) {
 		})
 	}
 }
+
+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)
+		}
+	}
+}