Merge branch 'main' into metadata-logging

Author: komer3

internal/driver/controllerserver.go

@@ -17,6 +17,7 @@ import (
 
 	linodeclient "github.com/linode/linode-blockstorage-csi-driver/pkg/linode-client"
 	linodevolumes "github.com/linode/linode-blockstorage-csi-driver/pkg/linode-volumes"
+	"github.com/linode/linode-blockstorage-csi-driver/pkg/logger"
 )
 
 // MinVolumeSizeBytes is the smallest allowed size for a Linode block storage
@@ -91,19 +92,28 @@ type ControllerServer struct {
 // If driver or client are nil, NewControllerServer returns a non-nil error.
 //
 // [Controller Service RPC]: https://github.com/container-storage-interface/spec/blob/master/spec.md#controller-service-rpc
-func NewControllerServer(driver *LinodeDriver, client linodeclient.LinodeClient, metadata Metadata) (*ControllerServer, error) {
+func NewControllerServer(ctx context.Context, driver *LinodeDriver, client linodeclient.LinodeClient, metadata Metadata) (*ControllerServer, error) {
+	log := logger.GetLogger(ctx)
+
+	log.V(4).Info("Creating new ControllerServer")
+
 	if driver == nil {
+		log.Error(nil, "LinodeDriver is nil")
 		return nil, errNilDriver
 	}
 	if client == nil {
+		log.Error(nil, "Linode client is nil")
 		return nil, errors.New("nil client")
 	}
 
-	return &ControllerServer{
+	cs := &ControllerServer{
 		driver:   driver,
 		client:   client,
 		metadata: metadata,
-	}, nil
+	}
+
+	log.V(4).Info("ControllerServer created successfully")
+	return cs, nil
 }
 
 // CreateVolume will be called by the CO to provision a new volume on behalf of a user (to be consumed

internal/driver/driver.go

@@ -58,15 +58,22 @@ type LinodeDriver struct {
 // prefix.
 const MaxVolumeLabelPrefixLength = 12
 
-func GetLinodeDriver() *LinodeDriver {
-	return &LinodeDriver{
+func GetLinodeDriver(ctx context.Context) *LinodeDriver {
+	log, _, done := logger.GetLogger(ctx).WithMethod("GetLinodeDriver")
+	defer done()
+
+	log.V(2).Info("Creating LinodeDriver")
+	driver := &LinodeDriver{
 		vcap:  VolumeCapabilityAccessModes(),
 		cscap: ControllerServiceCapabilities(),
 		nscap: NodeServiceCapabilities(),
 	}
+	log.V(2).Info("LinodeDriver created successfully")
+	return driver
 }
 
 func (linodeDriver *LinodeDriver) SetupLinodeDriver(
+	ctx context.Context,
 	linodeClient linodeclient.LinodeClient,
 	mounter *mount.SafeFormatAndMount,
 	deviceUtils mountmanager.DeviceUtils,
@@ -76,20 +83,19 @@ func (linodeDriver *LinodeDriver) SetupLinodeDriver(
 	volumeLabelPrefix string,
 	encrypt Encryption,
 ) error {
+	log, ctx, done := logger.GetLogger(ctx).WithMethod("SetupLinodeDriver")
+	defer done()
+
+	log.V(2).Info("Setting up LinodeDriver")
+
 	if name == "" {
 		return fmt.Errorf("driver name missing")
 	}
 
 	linodeDriver.name = name
 	linodeDriver.vendorVersion = vendorVersion
 
-	// Validate the volume label prefix, if it is set.
-	//
-	// First, we want to make sure it is the right length, then we will make
-	// sure it only contains the acceptable characters.
-	//
-	// When checking the length, we will convert it to a []rune first, to count
-	// the number of unicode characters.
+	log.V(3).Info("Validating volume label prefix", "prefix", volumeLabelPrefix)
 	if r := []rune(volumeLabelPrefix); len(r) > MaxVolumeLabelPrefixLength {
 		return fmt.Errorf("volume label prefix is too long: length=%d max=%d", len(r), MaxVolumeLabelPrefixLength)
 	}
@@ -102,33 +108,41 @@ func (linodeDriver *LinodeDriver) SetupLinodeDriver(
 	}
 	linodeDriver.volumeLabelPrefix = volumeLabelPrefix
 
-	// Set up RPC Servers
-	linodeDriver.ns, err = NewNodeServer(linodeDriver, mounter, deviceUtils, linodeClient, metadata, encrypt)
+	log.V(2).Info("Setting up RPC Servers")
+	linodeDriver.ns, err = NewNodeServer(ctx, linodeDriver, mounter, deviceUtils, linodeClient, metadata, encrypt)
 	if err != nil {
 		return fmt.Errorf("new node server: %w", err)
 	}
 
-	linodeDriver.ids, err = NewIdentityServer(linodeDriver)
+	linodeDriver.ids, err = NewIdentityServer(ctx, linodeDriver)
 	if err != nil {
 		return fmt.Errorf("new identity server: %w", err)
 	}
 
-	cs, err := NewControllerServer(linodeDriver, linodeClient, metadata)
+	cs, err := NewControllerServer(ctx, linodeDriver, linodeClient, metadata)
 	if err != nil {
 		return fmt.Errorf("new controller server: %w", err)
 	}
 	linodeDriver.cs = cs
 
+	log.V(2).Info("LinodeDriver setup completed successfully")
 	return nil
 }
 
-func (linodeDriver *LinodeDriver) ValidateControllerServiceRequest(c csi.ControllerServiceCapability_RPC_Type) error {
+func (linodeDriver *LinodeDriver) ValidateControllerServiceRequest(ctx context.Context, c csi.ControllerServiceCapability_RPC_Type) error {
+	log, _, done := logger.GetLogger(ctx).WithMethod("ValidateControllerServiceRequest")
+	defer done()
+
+	log.V(4).Info("Validating controller service request", "type", c)
+
 	if c == csi.ControllerServiceCapability_RPC_UNKNOWN {
+		log.V(4).Info("Unknown controller service capability, skipping validation")
 		return nil
 	}
 
 	for _, cap := range linodeDriver.cscap {
 		if c == cap.GetRpc().Type {
+			log.V(4).Info("Controller service request validated successfully")
 			return nil
 		}
 	}
@@ -137,8 +151,10 @@ func (linodeDriver *LinodeDriver) ValidateControllerServiceRequest(c csi.Control
 }
 
 func (linodeDriver *LinodeDriver) Run(ctx context.Context, endpoint string) {
-	log := logger.GetLogger(ctx)
-	log.V(4).Info("Driver", "name", linodeDriver.name)
+	log, _, done := logger.GetLogger(ctx).WithMethod("Run")
+	defer done()
+
+	log.V(2).Info("Starting LinodeDriver", "name", linodeDriver.name)
 	if len(linodeDriver.volumeLabelPrefix) > 0 {
 		log.V(4).Info("BS Volume Prefix", "prefix", linodeDriver.volumeLabelPrefix)
 	}
@@ -147,12 +163,10 @@ func (linodeDriver *LinodeDriver) Run(ctx context.Context, endpoint string) {
 	linodeDriver.ready = true
 	linodeDriver.readyMu.Unlock()
 
-	// Start the nonblocking GRPC
+	log.V(2).Info("Starting non-blocking GRPC server")
 	s := NewNonBlockingGRPCServer()
-	// TODO(#34): Only start specific servers based on a flag.
-	// In the future have this only run specific combinations of servers depending on which version this is.
-	// The schema for that was in util. basically it was just s.start but with some nil servers.
-
 	s.Start(endpoint, linodeDriver.ids, linodeDriver.cs, linodeDriver.ns)
+	log.V(2).Info("GRPC server started successfully")
 	s.Wait()
+	log.V(2).Info("LinodeDriver run completed")
 }

internal/driver/driver_test.go

@@ -73,8 +73,8 @@ func TestDriverSuite(t *testing.T) {
 		Region: fake.Instance.Region,
 		Memory: 4 << 30, // 4GiB
 	}
-	linodeDriver := GetLinodeDriver()
-	if err := linodeDriver.SetupLinodeDriver(fakeCloudProvider, mounter, deviceUtils, md, driver, vendorVersion, bsPrefix, encrypt); err != nil {
+	linodeDriver := GetLinodeDriver(context.Background())
+	if err := linodeDriver.SetupLinodeDriver(context.Background(), fakeCloudProvider, mounter, deviceUtils, md, driver, vendorVersion, bsPrefix, encrypt); err != nil {
 		t.Fatalf("Failed to setup Linode Driver: %v", err)
 	}
 

internal/driver/identityserver.go

@@ -18,6 +18,7 @@ import (
 	"fmt"
 
 	csi "github.com/container-storage-interface/spec/lib/go/csi"
+	"github.com/linode/linode-blockstorage-csi-driver/pkg/logger"
 	"golang.org/x/net/context"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/status"
@@ -31,13 +32,22 @@ type IdentityServer struct {
 	csi.UnimplementedIdentityServer
 }
 
-func NewIdentityServer(linodeDriver *LinodeDriver) (*IdentityServer, error) {
+func NewIdentityServer(ctx context.Context, linodeDriver *LinodeDriver) (*IdentityServer, error) {
+	log := logger.GetLogger(ctx)
+
+	log.V(4).Info("Creating new IdentityServer")
+
 	if linodeDriver == nil {
+		log.Error(nil, "LinodeDriver is nil")
 		return nil, fmt.Errorf("linodeDriver cannot be nil")
 	}
-	return &IdentityServer{
+
+	identityServer := &IdentityServer{
 		driver: linodeDriver,
-	}, nil
+	}
+
+	log.V(4).Info("IdentityServer created successfully")
+	return identityServer, nil
 }
 
 // GetPluginInfo(context.Context, *GetPluginInfoRequest) (*GetPluginInfoResponse, error)

internal/driver/identityserver_test.go

@@ -15,6 +15,7 @@ limitations under the License.
 package driver
 
 import (
+	"context"
 	"reflect"
 	"testing"
 )
@@ -50,7 +51,7 @@ func TestNewIdentityServer(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			got, err := NewIdentityServer(tt.args.linodeDriver)
+			got, err := NewIdentityServer(context.Background(), tt.args.linodeDriver)
 			if (err != nil) != tt.wantErr {
 				t.Errorf("NewIdentityServer() error = %v, wantErr %v", err, tt.wantErr)
 				return

internal/driver/nodeserver.go

@@ -45,28 +45,39 @@ type NodeServer struct {
 
 var _ csi.NodeServer = &NodeServer{}
 
-func NewNodeServer(linodeDriver *LinodeDriver, mounter *mount.SafeFormatAndMount, deviceUtils mountmanager.DeviceUtils, client linodeclient.LinodeClient, metadata Metadata, encrypt Encryption) (*NodeServer, error) {
+func NewNodeServer(ctx context.Context, linodeDriver *LinodeDriver, mounter *mount.SafeFormatAndMount, deviceUtils mountmanager.DeviceUtils, client linodeclient.LinodeClient, metadata Metadata, encrypt Encryption) (*NodeServer, error) {
+	log := logger.GetLogger(ctx)
+
+	log.V(4).Info("Creating new NodeServer")
+
 	if linodeDriver == nil {
+		log.Error(nil, "LinodeDriver is nil")
 		return nil, fmt.Errorf("linodeDriver is nil")
 	}
 	if mounter == nil {
+		log.Error(nil, "Mounter is nil")
 		return nil, fmt.Errorf("mounter is nil")
 	}
 	if deviceUtils == nil {
+		log.Error(nil, "DeviceUtils is nil")
 		return nil, fmt.Errorf("deviceUtils is nil")
 	}
 	if client == nil {
+		log.Error(nil, "Linode client is nil")
 		return nil, fmt.Errorf("linode client is nil")
 	}
 
-	return &NodeServer{
+	ns := &NodeServer{
 		driver:      linodeDriver,
 		mounter:     mounter,
 		deviceutils: deviceUtils,
 		client:      client,
 		metadata:    metadata,
 		encrypt:     encrypt,
-	}, nil
+	}
+
+	log.V(4).Info("NodeServer created successfully")
+	return ns, nil
 }
 
 func (ns *NodeServer) NodePublishVolume(ctx context.Context, req *csi.NodePublishVolumeRequest) (*csi.NodePublishVolumeResponse, error) {

internal/driver/nodeserver_test.go

@@ -1,6 +1,7 @@
 package driver
 
 import (
+	"context"
 	"reflect"
 	"testing"
 
@@ -100,7 +101,7 @@ func TestNewNodeServer(t *testing.T) {
 	}
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
-			got, err := NewNodeServer(tt.args.linodeDriver, tt.args.mounter, tt.args.deviceUtils, tt.args.client, tt.args.metadata, tt.args.encrypt)
+			got, err := NewNodeServer(context.Background(), tt.args.linodeDriver, tt.args.mounter, tt.args.deviceUtils, tt.args.client, tt.args.metadata, tt.args.encrypt)
 			if (err != nil) != tt.wantErr {
 				t.Errorf("NewNodeServer() error = %v, wantErr %v", err, tt.wantErr)
 				return

internal/driver/nodeserver_windows.go

@@ -1,13 +1,14 @@
 package driver
 
 import (
+	"context"
 	"fmt"
 
 	"github.com/container-storage-interface/spec/lib/go/csi"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/status"
 )
 
-func nodeGetVolumeStats(req *csi.NodeGetVolumeStatsRequest) (*csi.NodeGetVolumeStatsResponse, error) {
+func nodeGetVolumeStats(ctx context.Context, req *csi.NodeGetVolumeStatsRequest) (*csi.NodeGetVolumeStatsResponse, error) {
 	return nil, status.Error(codes.Unimplemented, fmt.Sprintf("NodeGetVolumeStats is not yet implemented on Windows"))
 }

main.go

@@ -96,7 +96,7 @@ func handle(ctx context.Context) error {
 		return errors.New("linode token required")
 	}
 
-	linodeDriver := driver.GetLinodeDriver()
+	linodeDriver := driver.GetLinodeDriver(ctx)
 
 	// Initialize Linode Driver (Move setup to main?)
 	uaPrefix := fmt.Sprintf("LinodeCSI/%s", vendorVersion)
@@ -119,6 +119,7 @@ func handle(ctx context.Context) error {
 	}
 
 	if err := linodeDriver.SetupLinodeDriver(
+		ctx,
 		cloudProvider,
 		mounter,
 		deviceUtils,

pkg/logger/logger.go

@@ -21,7 +21,7 @@ func NewLogger(ctx context.Context) *Logger {
 	}
 }
 
-// WithMethod returns a new Logger with method and traceID values, 
+// WithMethod returns a new Logger with method and traceID values,
 // a context containing the new Logger, and a function to log method completion.
 func (l *Logger) WithMethod(method string) (*Logger, context.Context, func()) {
 	traceID := uuid.New().String()
@@ -53,4 +53,4 @@ func GetLogger(ctx context.Context) *Logger {
 		return logger
 	}
 	return NewLogger(ctx)
-}
+}