chore: use structured logging and update imports order (#135)

Signed-off-by: Anish Ramasekar <anish.ramasekar@gmail.com>

Author: aramase

cmd/server/main.go

@@ -71,7 +71,8 @@ func main() {
 	// initialize metrics exporter
 	err := metrics.InitMetricsExporter(*metricsBackend, *metricsAddress)
 	if err != nil {
-		klog.Fatalf("failed to initialize metrics exporter, error: %+v", err)
+		klog.ErrorS(err, "failed to initialize metrics exporter")
+		os.Exit(1)
 	}
 
 	klog.InfoS("Starting KeyManagementServiceServer service", "version", version.BuildVersion, "buildDate", version.BuildDate)
@@ -88,21 +89,25 @@ func main() {
 	}
 	kmsServer, err := plugin.New(ctx, pc)
 	if err != nil {
-		klog.Fatalf("failed to create server, error: %v", err)
+		klog.ErrorS(err, "failed to create server")
+		os.Exit(1)
 	}
 
 	// Initialize and run the GRPC server
 	proto, addr, err := utils.ParseEndpoint(*listenAddr)
 	if err != nil {
-		klog.Fatalf("failed to parse endpoint, err: %+v", err)
+		klog.ErrorS(err, "failed to parse endpoint")
+		os.Exit(1)
 	}
 	if err := os.Remove(addr); err != nil && !os.IsNotExist(err) {
-		klog.Fatalf("failed to remove %s, error: %s", addr, err.Error())
+		klog.ErrorS(err, "failed to remove socket file", "addr", addr)
+		os.Exit(1)
 	}
 
 	listener, err := net.Listen(proto, addr)
 	if err != nil {
-		klog.Fatalf("failed to listen: %v", err)
+		klog.ErrorS(err, "failed to listen", "addr", addr, "proto", proto)
+		os.Exit(1)
 	}
 	opts := []grpc.ServerOption{
 		grpc.UnaryInterceptor(utils.UnaryServerInterceptor),
@@ -111,7 +116,7 @@ func main() {
 	s := grpc.NewServer(opts...)
 	pb.RegisterKeyManagementServiceServer(s, kmsServer)
 
-	klog.Infof("Listening for connections on address: %v", listener.Addr())
+	klog.InfoS("Listening for connections", "addr", listener.Addr().String())
 	go s.Serve(listener)
 
 	healthz := &plugin.HealthZ{
@@ -127,7 +132,7 @@ func main() {
 
 	<-ctx.Done()
 	// gracefully stop the grpc server
-	klog.Infof("terminating the server")
+	klog.Info("terminating the server")
 	s.GracefulStop()
 
 	klog.Flush()

pkg/auth/auth.go

@@ -41,7 +41,7 @@ func GetServicePrincipalToken(config *config.AzureConfig, aadEndpoint, resource
 	}
 
 	if config.UseManagedIdentityExtension {
-		klog.V(2).Infof("using managed identity extension to retrieve access token")
+		klog.V(2).Info("using managed identity extension to retrieve access token")
 		msiEndpoint, err := adal.GetMSIVMEndpoint()
 		if err != nil {
 			return nil, fmt.Errorf("failed to get managed service identity endpoint, error: %v", err)
@@ -79,7 +79,7 @@ func GetServicePrincipalToken(config *config.AzureConfig, aadEndpoint, resource
 	}
 
 	if len(config.AADClientCertPath) > 0 && len(config.AADClientCertPassword) > 0 {
-		klog.V(2).Infof("using jwt client_assertion (client_cert+client_private_key) to retrieve access token")
+		klog.V(2).Info("using jwt client_assertion (client_cert+client_private_key) to retrieve access token")
 		certData, err := os.ReadFile(config.AADClientCertPath)
 		if err != nil {
 			return nil, fmt.Errorf("failed to read client certificate from file %s, error: %v", config.AADClientCertPath, err)

pkg/auth/auth_test.go

@@ -10,9 +10,10 @@ import (
 	"strings"
 	"testing"
 
+	"github.com/Azure/kubernetes-kms/pkg/config"
+
 	"github.com/Azure/go-autorest/autorest/adal"
 	"github.com/Azure/go-autorest/autorest/azure"
-	"github.com/Azure/kubernetes-kms/pkg/config"
 )
 
 func TestParseAzureEnvironment(t *testing.T) {

pkg/config/azure_config.go

@@ -24,7 +24,7 @@ type AzureConfig struct {
 func GetAzureConfig(configFile string) (config *AzureConfig, err error) {
 	cfg := AzureConfig{}
 
-	klog.V(5).Infof("populating AzureConfig from %s", configFile)
+	klog.V(5).InfoS("populating AzureConfig from config file", "configFile", configFile)
 	bytes, err := os.ReadFile(configFile)
 	if err != nil {
 		return nil, fmt.Errorf("failed to load config file %s, error: %+v", configFile, err)

pkg/metrics/exporter.go

@@ -14,7 +14,7 @@ const (
 // InitMetricsExporter initializes new exporter
 func InitMetricsExporter(metricsBackend, metricsAddress string) error {
 	exporter := strings.ToLower(metricsBackend)
-	klog.Infof("metrics backend: %s", exporter)
+	klog.InfoS("metrics backend", "exporter", exporter)
 
 	switch exporter {
 	// Prometheus is the only exporter supported for now

pkg/metrics/prometheus_exporter.go

@@ -3,6 +3,7 @@ package metrics
 import (
 	"fmt"
 	"net/http"
+	"os"
 
 	"go.opentelemetry.io/otel/exporters/metric/prometheus"
 	"k8s.io/klog/v2"
@@ -25,7 +26,8 @@ func initPrometheusExporter(metricsAddress string) error {
 	http.HandleFunc(fmt.Sprintf("/%s", metricsEndpoint), exporter.ServeHTTP)
 	go func() {
 		if err := http.ListenAndServe(fmt.Sprintf(":%s", metricsAddress), nil); err != nil {
-			klog.Fatalf("Failed to register prometheus endpoint - %v", err)
+			klog.ErrorS(err, "failed to register prometheus endpoint", "metricsAddress", metricsAddress)
+			os.Exit(1)
 		}
 	}()
 

pkg/plugin/healthz.go

@@ -11,13 +11,14 @@ import (
 	"net"
 	"net/http"
 	"net/url"
+	"os"
 	"time"
 
+	"github.com/Azure/kubernetes-kms/pkg/version"
+
 	"google.golang.org/grpc"
 	pb "k8s.io/apiserver/pkg/storage/value/encrypt/envelope/v1beta1"
 	"k8s.io/klog/v2"
-
-	"github.com/Azure/kubernetes-kms/pkg/version"
 )
 
 const (
@@ -36,12 +37,13 @@ func (h *HealthZ) Serve() {
 	serveMux := http.NewServeMux()
 	serveMux.HandleFunc(h.HealthCheckURL.EscapedPath(), h.ServeHTTP)
 	if err := http.ListenAndServe(h.HealthCheckURL.Host, serveMux); err != nil && err != http.ErrServerClosed {
-		klog.Fatalf("failed to start health check server, err: %+v", err)
+		klog.ErrorS(err, "failed to start health check server", "url", h.HealthCheckURL.String())
+		os.Exit(1)
 	}
 }
 
 func (h *HealthZ) ServeHTTP(w http.ResponseWriter, r *http.Request) {
-	klog.V(5).Infof("Started health check")
+	klog.V(5).Info("Started health check")
 	ctx, cancel := context.WithTimeout(context.Background(), h.RPCTimeout)
 	defer cancel()
 
@@ -78,7 +80,7 @@ func (h *HealthZ) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	}
 	w.WriteHeader(http.StatusOK)
 	w.Write([]byte("ok"))
-	klog.V(5).Infof("Completed health check")
+	klog.V(5).Info("Completed health check")
 }
 
 // checkRPC initiates a grpc request to validate the socket is responding

pkg/plugin/server.go

@@ -74,13 +74,13 @@ func (s *KeyManagementServiceServer) Encrypt(ctx context.Context, request *k8spb
 		s.reporter.ReportRequest(ctx, metrics.EncryptOperationTypeValue, status, time.Since(start).Seconds(), errors)
 	}()
 
-	klog.V(2).Infof("encrypt request started")
+	klog.V(2).Info("encrypt request started")
 	cipher, err := s.kvClient.Encrypt(ctx, request.Plain)
 	if err != nil {
 		klog.ErrorS(err, "failed to encrypt")
 		return &k8spb.EncryptResponse{}, err
 	}
-	klog.V(2).Infof("encrypt request complete")
+	klog.V(2).Info("encrypt request complete")
 	return &k8spb.EncryptResponse{Cipher: cipher}, nil
 }
 
@@ -99,12 +99,12 @@ func (s *KeyManagementServiceServer) Decrypt(ctx context.Context, request *k8spb
 		s.reporter.ReportRequest(ctx, metrics.DecryptOperationTypeValue, status, time.Since(start).Seconds(), errors)
 	}()
 
-	klog.V(2).Infof("decrypt request started")
+	klog.V(2).Info("decrypt request started")
 	plain, err := s.kvClient.Decrypt(ctx, request.Cipher)
 	if err != nil {
 		klog.ErrorS(err, "failed to decrypt")
 		return &k8spb.DecryptResponse{}, err
 	}
-	klog.V(2).Infof("decrypt request complete")
+	klog.V(2).Info("decrypt request complete")
 	return &k8spb.DecryptResponse{Plain: plain}, nil
 }

pkg/plugin/server_test.go

@@ -10,11 +10,11 @@ import (
 	"fmt"
 	"testing"
 
-	k8spb "k8s.io/apiserver/pkg/storage/value/encrypt/envelope/v1beta1"
-
 	"github.com/Azure/kubernetes-kms/pkg/metrics"
 	mockkeyvault "github.com/Azure/kubernetes-kms/pkg/plugin/mock_keyvault"
 	"github.com/Azure/kubernetes-kms/pkg/version"
+
+	k8spb "k8s.io/apiserver/pkg/storage/value/encrypt/envelope/v1beta1"
 )
 
 func TestEncrypt(t *testing.T) {

pkg/utils/grpc.go

@@ -7,6 +7,7 @@ import (
 	"time"
 
 	"github.com/Azure/kubernetes-kms/pkg/metrics"
+
 	"google.golang.org/grpc"
 	"k8s.io/klog/v2"
 )
@@ -38,7 +39,7 @@ func UnaryServerInterceptor(ctx context.Context, req interface{}, info *grpc.Una
 		reporter.ReportRequest(ctx, fmt.Sprintf("%s_%s", metrics.GrpcOperationTypeValue, getGRPCMethodName(info.FullMethod)), status, time.Since(start).Seconds(), errors)
 	}()
 
-	klog.V(5).Infof("GRPC call: %s", info.FullMethod)
+	klog.V(5).InfoS("GRPC call", "method", info.FullMethod)
 	resp, err := handler(ctx, req)
 	if err != nil {
 		klog.ErrorS(err, "GRPC request error")