Merge pull request #94 from andyzhangx/log-grpc

chore: use common lib to strip secrets in logGRPC

Author: andyzhangx

go.mod

@@ -9,6 +9,7 @@ require (
 	github.com/Azure/go-autorest/autorest/to v0.3.0
 	github.com/container-storage-interface/spec v1.3.0
 	github.com/golang/protobuf v1.3.5
+	github.com/kubernetes-csi/csi-lib-utils v0.7.0
 	github.com/kubernetes-csi/csi-proxy/client v0.0.0-20200330215040-9eff16441b2a
 	github.com/kubernetes-csi/external-snapshotter/v2 v2.0.0-20200617021606-4800ca72d403
 	github.com/onsi/ginkgo v1.11.0

go.sum

@@ -257,6 +257,7 @@ github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORN
 github.com/kr/pty v1.1.5/go.mod h1:9r2w37qlBe7rQ6e1fg1S/9xpWHSnaqNdHD3WcMdbPDA=
 github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE=
 github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
+github.com/kubernetes-csi/csi-lib-utils v0.7.0 h1:t1cS7HTD7z5D7h9iAdjWuHtMxJPb9s1fIv34rxytzqs=
 github.com/kubernetes-csi/csi-lib-utils v0.7.0/go.mod h1:bze+2G9+cmoHxN6+WyG1qT4MDxgZJMLGwc7V4acPNm0=
 github.com/kubernetes-csi/csi-proxy/client v0.0.0-20200330215040-9eff16441b2a h1:oUzd0gIsXuEaPLqOBc7h7KmoQaCEDrZcgEVFIlKVzsw=
 github.com/kubernetes-csi/csi-proxy/client v0.0.0-20200330215040-9eff16441b2a/go.mod h1:AEGb6PeX4XUKjEGycToqZQxHQS01Ch3C+C42FgORhOE=

pkg/csi-common/utils.go

@@ -18,12 +18,13 @@ package csicommon
 
 import (
 	"fmt"
+	"strings"
+
 	"github.com/container-storage-interface/spec/lib/go/csi"
+	"github.com/kubernetes-csi/csi-lib-utils/protosanitizer"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc"
 	"k8s.io/klog/v2"
-	"regexp"
-	"strings"
 )
 
 func ParseEndpoint(ep string) (string, string, error) {
@@ -102,20 +103,14 @@ func RunControllerandNodePublishServer(endpoint string, d *CSIDriver, cs csi.Con
 	s.Wait()
 }
 
-// regex to mask secrets in log messages
-var reqSecretsRegex, _ = regexp.Compile("secrets\\s*:\\s*<key:\"(.*?)\"\\s*value:\".*?\"")
-
 func logGRPC(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) {
-
-	s := fmt.Sprintf("GRPC request: %+v", req)
 	klog.V(3).Infof("GRPC call: %s", info.FullMethod)
-	klog.V(5).Info(reqSecretsRegex.ReplaceAllString(s, "secrets:<key:\"$1\" value:\"****\""))
-
+	klog.V(5).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: %+v", resp)
+		klog.V(5).Infof("GRPC response: %s", protosanitizer.StripSecrets(resp))
 	}
 	return resp, err
 }

pkg/csi-common/utils_test.go

@@ -20,9 +20,10 @@ import (
 	"bytes"
 	"context"
 	"flag"
+	"testing"
+
 	"google.golang.org/grpc"
 	"k8s.io/klog/v2"
-	"testing"
 
 	"github.com/container-storage-interface/spec/lib/go/csi"
 	"github.com/stretchr/testify/assert"
@@ -118,14 +119,14 @@ func TestLogGRPC(t *testing.T) {
 				},
 				XXX_sizecache: 100,
 			},
-			`GRPC request: volume_id:"vol_1" secrets:<key:"account_key" value:"****" > secrets:<key:"account_name" value:"****" >`,
+			`GRPC request: {"secrets":"***stripped***","volume_id":"vol_1"}`,
 		},
 		{
 			"without secrets",
 			&csi.ListSnapshotsRequest{
 				StartingToken: "testtoken",
 			},
-			`GRPC request: starting_token:"testtoken"`,
+			`GRPC request: {"starting_token":"testtoken"}`,
 		},
 	}
 
@@ -138,7 +139,7 @@ func TestLogGRPC(t *testing.T) {
 			// ASSERT
 			assert.Contains(t, buf.String(), "GRPC call: fake")
 			assert.Contains(t, buf.String(), test.expStr)
-			assert.Contains(t, buf.String(), "GRPC response: <nil>")
+			assert.Contains(t, buf.String(), "GRPC response: null")
 
 			// CLEANUP
 			buf.Reset()

pkg/smb/controllerserver.go

@@ -22,12 +22,10 @@ import (
 	"github.com/container-storage-interface/spec/lib/go/csi"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/status"
-	"k8s.io/klog/v2"
 )
 
 // CreateVolume only supports static provisioning, no create volume action
 func (d *Driver) CreateVolume(ctx context.Context, req *csi.CreateVolumeRequest) (*csi.CreateVolumeResponse, error) {
-	klog.V(2).Infof("CreateVolume called with request %+v", *req)
 	volumeCapabilities := req.GetVolumeCapabilities()
 	if len(volumeCapabilities) == 0 {
 		return nil, status.Error(codes.InvalidArgument, "CreateVolume Volume capabilities must be provided")
@@ -43,7 +41,6 @@ func (d *Driver) CreateVolume(ctx context.Context, req *csi.CreateVolumeRequest)
 
 // DeleteVolume only supports static provisioning, no delete volume action
 func (d *Driver) DeleteVolume(ctx context.Context, req *csi.DeleteVolumeRequest) (*csi.DeleteVolumeResponse, error) {
-	klog.V(2).Infof("DeleteVolume called with request %v", *req)
 	if len(req.GetVolumeId()) == 0 {
 		return nil, status.Error(codes.InvalidArgument, "Volume ID missing in request")
 	}
@@ -65,8 +62,6 @@ func (d *Driver) ControllerUnpublishVolume(ctx context.Context, req *csi.Control
 
 // ControllerGetCapabilities returns the capabilities of the Controller plugin
 func (d *Driver) ControllerGetCapabilities(ctx context.Context, req *csi.ControllerGetCapabilitiesRequest) (*csi.ControllerGetCapabilitiesResponse, error) {
-	klog.V(2).Infof("ControllerGetCapabilities called with request %v", *req)
-
 	return &csi.ControllerGetCapabilitiesResponse{
 		Capabilities: d.Cap,
 	}, nil

pkg/smb/nodeserver.go

@@ -21,7 +21,6 @@ import (
 	"io/ioutil"
 	"os"
 	"path/filepath"
-	"regexp"
 	"runtime"
 	"strings"
 	"time"
@@ -47,7 +46,6 @@ const (
 
 // NodePublishVolume mount the volume from staging to target path
 func (d *Driver) NodePublishVolume(ctx context.Context, req *csi.NodePublishVolumeRequest) (*csi.NodePublishVolumeResponse, error) {
-	klog.V(2).Infof("NodePublishVolume called with request %v", *req)
 	if req.GetVolumeCapability() == nil {
 		return nil, status.Error(codes.InvalidArgument, "Volume capability missing in request")
 	}
@@ -140,11 +138,6 @@ func (d *Driver) NodeUnpublishVolume(ctx context.Context, req *csi.NodeUnpublish
 
 // NodeStageVolume mount the volume to a staging path
 func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRequest) (*csi.NodeStageVolumeResponse, error) {
-	// regex to mask username and password in log messages
-	var reqSecretsRegex, _ = regexp.Compile(`map\[password:.*? `)
-	s := fmt.Sprintf("NodeStageVolume called with request %v", *req)
-	klog.V(5).Info(reqSecretsRegex.ReplaceAllString(s, "map[password:**** "))
-
 	if len(req.GetVolumeId()) == 0 {
 		return nil, status.Error(codes.InvalidArgument, "Volume ID missing in request")
 	}
@@ -254,15 +247,13 @@ func (d *Driver) NodeUnstageVolume(ctx context.Context, req *csi.NodeUnstageVolu
 
 // NodeGetCapabilities return the capabilities of the Node plugin
 func (d *Driver) NodeGetCapabilities(ctx context.Context, req *csi.NodeGetCapabilitiesRequest) (*csi.NodeGetCapabilitiesResponse, error) {
-	klog.V(2).Infof("NodeGetCapabilities called with request %v", *req)
 	return &csi.NodeGetCapabilitiesResponse{
 		Capabilities: d.NSCap,
 	}, nil
 }
 
 // NodeGetInfo return info of the node on which this plugin is running
 func (d *Driver) NodeGetInfo(ctx context.Context, req *csi.NodeGetInfoRequest) (*csi.NodeGetInfoResponse, error) {
-	klog.V(2).Infof("NodeGetInfo called with request %v", *req)
 	return &csi.NodeGetInfoResponse{
 		NodeId: d.NodeID,
 	}, nil

test/utils/smb_log.sh

@@ -28,7 +28,7 @@ echo "==========================================================================
 LABEL='app=csi-smb-controller'
 kubectl get pods -n${NS} -l${LABEL} \
     | awk 'NR>1 {print $1}' \
-    | xargs -I {} kubectl describe po {} -n${NS}
+    | xargs -I {} kubectl logs {} --prefix -c${CONTAINER} -n${NS}
 
 echo "print out csi-smb-node logs ..."
 echo "======================================================================================"