chore: Use klog structured logging

cmd/main.go

@@ -17,6 +17,7 @@ limitations under the License.
 package main
 
 import (
+	"context"
 	"flag"
 	"os"
 	"strings"
@@ -28,6 +29,8 @@ import (
 	"k8s.io/client-go/kubernetes"
 	clientgoscheme "k8s.io/client-go/kubernetes/scheme"
 	"k8s.io/client-go/tools/record"
+	"k8s.io/klog/v2"
+	"monis.app/mlog"
 	ctrl "sigs.k8s.io/controller-runtime"
 	"sigs.k8s.io/controller-runtime/pkg/healthz"
 	"sigs.k8s.io/controller-runtime/pkg/log/zap"
@@ -44,7 +47,6 @@ import (
 
 var (
 	scheme                  = runtime.NewScheme()
-	setupLog                = ctrl.Log.WithName("setup")
 	metricsAddr             = flag.String("metrics-bind-address", ":8085", "The address the metric endpoint binds to.")
 	enableLeaderElection    = flag.Bool("leader-elect", false, "Enable leader election for controller manager. "+"Enabling this will ensure there is only one active controller manager.")
 	leaderElectionNamespace = flag.String("leader-election-namespace", "", "Namespace for leader election")
@@ -53,6 +55,7 @@ var (
 	providerVolumePath      = flag.String("provider-volume", "/provider", "Volume path for provider.")
 	maxCallRecvMsgSize      = flag.Int("max-call-recv-msg-size", 1024*1024*4, "maximum size in bytes of gRPC response from plugins")
 	versionInfo             = flag.Bool("version", false, "Print the version and exit")
+	logFormatJSON           = flag.Bool("log-format-json", false, "set log formatter to json")
 )
 
 func init() {
@@ -65,18 +68,31 @@ func init() {
 }
 
 func runMain() error {
+	klog.InitFlags(nil)
 	opts := zap.Options{
 		Development: true,
 	}
 	opts.BindFlags(flag.CommandLine)
 	flag.Parse()
 
+	ctx := withShutdownSignal(context.Background())
+
+	defer mlog.Setup()()
+	format := mlog.FormatText
+	if *logFormatJSON {
+		format = mlog.FormatJSON
+	}
+	if err := mlog.ValidateAndSetKlogLevelAndFormatGlobally(ctx, getKlogLevel(), format); err != nil {
+		mlog.Error("failed to validate log level", err)
+		return err
+	}
+
 	ctrl.SetLogger(zap.New(zap.UseFlagOptions(&opts)))
 
 	if *versionInfo {
 		versionErr := version.PrintVersion()
 		if versionErr != nil {
-			setupLog.Error(versionErr, "failed to print version")
+			klog.ErrorS(versionErr, "failed to print version")
 			return versionErr
 		}
 		return nil
@@ -95,7 +111,7 @@ func runMain() error {
 		LeaderElectionNamespace: *leaderElectionNamespace,
 	})
 	if err != nil {
-		setupLog.Error(err, "unable to start manager")
+		klog.ErrorS(err, "unable to start manager")
 		return err
 	}
 
@@ -125,29 +141,49 @@ func runMain() error {
 		Audiences:       audiences,
 		EventRecorder:   record.NewBroadcaster().NewRecorder(scheme, corev1.EventSource{Component: "secret-sync-controller"}),
 	}).SetupWithManager(mgr); err != nil {
-		setupLog.Error(err, "unable to create controller", "controller", "SecretSync")
+		klog.ErrorS(err, "unable to create controller", "controller", "SecretSync")
 		return err
 	}
 	//+kubebuilder:scaffold:builder
 
 	if err := mgr.AddHealthzCheck("healthz", healthz.Ping); err != nil {
-		setupLog.Error(err, "unable to set up health check")
+		klog.ErrorS(err, "unable to set up health check")
 		return err
 	}
 	if err := mgr.AddReadyzCheck("readyz", healthz.Ping); err != nil {
-		setupLog.Error(err, "unable to set up ready check")
+		klog.ErrorS(err, "unable to set up ready check")
 		return err
 	}
 
-	setupLog.Info("starting manager")
+	klog.InfoS("starting manager")
 	if err := mgr.Start(ctrl.SetupSignalHandler()); err != nil {
-		setupLog.Error(err, "problem running manager")
+		klog.ErrorS(err, "problem running manager")
 		return err
 	}
 
 	return nil
 }
 
+// withShutdownSignal returns a copy of the parent context that will close if
+// the process receives termination signals.
+func withShutdownSignal(ctx context.Context) context.Context {
+	nctx, cancel := context.WithCancel(ctx)
+	defer cancel()
+	return nctx
+}
+
+func getKlogLevel() klog.Level {
+	// hack around klog not exposing a Get method
+	for i := klog.Level(0); i < 1_000_000; i++ {
+		if klog.V(i).Enabled() {
+			continue
+		}
+		return i - 1
+	}
+
+	return -1
+}
+
 func main() {
 	if err := runMain(); err != nil {
 		os.Exit(1)

go.mod

@@ -17,12 +17,14 @@ require (
 	k8s.io/client-go v0.28.15
 	k8s.io/klog/v2 v2.100.1
 	k8s.io/utils v0.0.0-20240310230437-4693a0247e57
+	monis.app/mlog v0.0.4
 	sigs.k8s.io/controller-runtime v0.16.6
 	sigs.k8s.io/secrets-store-csi-driver v1.4.8
 )
 
 require (
 	github.com/beorn7/perks v1.0.1 // indirect
+	github.com/blang/semver/v4 v4.0.0 // indirect
 	github.com/cespare/xxhash/v2 v2.2.0 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/emicklei/go-restful/v3 v3.11.0 // indirect
@@ -42,6 +44,7 @@ require (
 	github.com/google/gofuzz v1.2.0 // indirect
 	github.com/google/uuid v1.3.1 // indirect
 	github.com/imdario/mergo v0.3.12 // indirect
+	github.com/inconshreveable/mousetrap v1.1.0 // indirect
 	github.com/josharian/intern v1.0.0 // indirect
 	github.com/json-iterator/go v1.1.12 // indirect
 	github.com/mailru/easyjson v0.7.7 // indirect
@@ -57,6 +60,7 @@ require (
 	github.com/prometheus/common v0.44.0 // indirect
 	github.com/prometheus/procfs v0.10.1 // indirect
 	github.com/rogpeppe/go-internal v1.12.0 // indirect
+	github.com/spf13/cobra v1.7.0 // indirect
 	github.com/spf13/pflag v1.0.5 // indirect
 	go.opentelemetry.io/otel v1.15.1 // indirect
 	go.opentelemetry.io/otel/sdk v1.15.1 // indirect

go.sum

@@ -3,8 +3,11 @@ github.com/benbjohnson/clock v1.3.0 h1:ip6w0uFQkncKQ979AypyG0ER7mqUSBdKLOgAle/AT
 github.com/benbjohnson/clock v1.3.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA=
 github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
 github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
+github.com/blang/semver/v4 v4.0.0 h1:1PFHFE6yCCTv8C1TeyNNarDzntLi7wMI5i/pzqYIsAM=
+github.com/blang/semver/v4 v4.0.0/go.mod h1:IbckMUScFkM3pff0VJDNKRiT6TG/YpiHIM2yvyW5YoQ=
 github.com/cespare/xxhash/v2 v2.2.0 h1:DC2CZ1Ep5Y4k3ZQ899DldepgrayRUGE6BBZ/cd9Cj44=
 github.com/cespare/xxhash/v2 v2.2.0/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs=
+github.com/cpuguy83/go-md2man/v2 v2.0.2/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o=
 github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
@@ -53,6 +56,8 @@ github.com/google/uuid v1.3.1 h1:KjJaJ9iWZ3jOFZIf1Lqf4laDRCasjl0BCmnEGxkdLb4=
 github.com/google/uuid v1.3.1/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
 github.com/imdario/mergo v0.3.12 h1:b6R2BslTbIEToALKP7LxUvijTsNI9TAe80pLWN2g/HU=
 github.com/imdario/mergo v0.3.12/go.mod h1:jmQim1M+e3UYxmgPu/WyfjB3N3VflVyUjjjwH0dnCYA=
+github.com/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8=
+github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw=
 github.com/jessevdk/go-flags v1.4.0/go.mod h1:4FA24M0QyGHXBuZZK/XkWh8h0e1EYbRYJSGM75WSRxI=
 github.com/josharian/intern v1.0.0 h1:vlS4z54oSdjm0bgjRigI+G1HpF+tI+9rE5LLzOg8HmY=
 github.com/josharian/intern v1.0.0/go.mod h1:5DoeVV0s6jJacbCEi61lwdGj/aVlrQvzHFFd8Hwg//Y=
@@ -98,6 +103,9 @@ github.com/prometheus/procfs v0.10.1 h1:kYK1Va/YMlutzCGazswoHKo//tZVlFpKYh+Pymzi
 github.com/prometheus/procfs v0.10.1/go.mod h1:nwNm2aOCAYw8uTR/9bWRREkZFxAUcWzPHWJq+XBB/FM=
 github.com/rogpeppe/go-internal v1.12.0 h1:exVL4IDcn6na9z1rAb56Vxr+CgyK3nn3O+epU5NdKM8=
 github.com/rogpeppe/go-internal v1.12.0/go.mod h1:E+RYuTGaKKdloAfM02xzb0FW3Paa99yedzYV+kq4uf4=
+github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM=
+github.com/spf13/cobra v1.7.0 h1:hyqWnYt1ZQShIddO5kBpj3vu05/++x6tJ6dg8EC572I=
+github.com/spf13/cobra v1.7.0/go.mod h1:uLxZILRyS/50WlhOIKD7W6V5bgeIt+4sICxh6uRMrb0=
 github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA=
 github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
@@ -228,6 +236,8 @@ k8s.io/kube-openapi v0.0.0-20230717233707-2695361300d9 h1:LyMgNKD2P8Wn1iAwQU5Ohx
 k8s.io/kube-openapi v0.0.0-20230717233707-2695361300d9/go.mod h1:wZK2AVp1uHCp4VamDVgBP2COHZjqD1T68Rf0CM3YjSM=
 k8s.io/utils v0.0.0-20240310230437-4693a0247e57 h1:gbqbevonBh57eILzModw6mrkbwM0gQBEuevE/AaBsHY=
 k8s.io/utils v0.0.0-20240310230437-4693a0247e57/go.mod h1:OLgZIPagt7ERELqWJFomSt595RzquPNLL48iOWgYOg0=
+monis.app/mlog v0.0.4 h1:YEzh5sguG4ApywaRWnBU+mGP6SA4WxOqiJ36u+KtoeE=
+monis.app/mlog v0.0.4/go.mod h1:LtOpnndFuRGqnLBwzBvpA1DaoKuud2/moLzYXIiNl1s=
 sigs.k8s.io/controller-runtime v0.16.6 h1:FiXwTuFF5ZJKmozfP2Z0j7dh6kmxP4Ou1KLfxgKKC3I=
 sigs.k8s.io/controller-runtime v0.16.6/go.mod h1:+dQzkZxnylD0u49e0a+7AR+vlibEBaThmPca7lTyUsI=
 sigs.k8s.io/json v0.0.0-20221116044647-bc3834ca7abd h1:EDPBXCAspyGV4jQlpZSudPeMmr1bNJefnuqLsRAsHZo=

internal/controller/conditions.go

@@ -21,7 +21,7 @@ import (
 
 	"k8s.io/apimachinery/pkg/api/meta"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
-	"sigs.k8s.io/controller-runtime/pkg/log"
+	"k8s.io/klog/v2"
 
 	secretsyncv1alpha1 "sigs.k8s.io/secrets-store-sync-controller/api/v1alpha1"
 )
@@ -89,14 +89,12 @@ var AllowedStringsToDisplayConditionErrorMessage = []string{
 }
 
 func (r *SecretSyncReconciler) updateStatusConditions(ctx context.Context, ss *secretsyncv1alpha1.SecretSync, oldConditionType string, newConditionType string, conditionReason string, shouldUpdateStatus bool) {
-	logger := log.FromContext(ctx)
-
 	if ss.Status.Conditions == nil {
 		ss.Status.Conditions = []metav1.Condition{}
 	}
 
 	if len(oldConditionType) > 0 {
-		logger.V(10).Info("Removing old condition", "oldConditionType", oldConditionType)
+		klog.V(10).InfoS("Removing old condition", "oldConditionType", oldConditionType)
 		meta.RemoveStatusCondition(&ss.Status.Conditions, oldConditionType)
 	}
 
@@ -164,16 +162,16 @@ func (r *SecretSyncReconciler) updateStatusConditions(ctx context.Context, ss *s
 		condition.Message = ConditionMessageUnknown
 	}
 
-	logger.V(10).Info("Adding new condition", "newConditionType", newConditionType, "conditionReason", conditionReason)
+	klog.V(10).InfoS("Adding new condition", "newConditionType", newConditionType, "conditionReason", conditionReason)
 	meta.SetStatusCondition(&ss.Status.Conditions, condition)
 
 	if !shouldUpdateStatus {
 		return
 	}
 
 	if err := r.Client.Status().Update(ctx, ss); err != nil {
-		logger.Error(err, "Failed to update status", "condition", condition)
+		klog.ErrorS(err, "Failed to update status", "condition", condition)
 	}
 
-	logger.V(10).Info("Updated status", "condition", condition)
+	klog.V(10).InfoS("Updated status", "condition", condition)
 }

internal/controller/secretsync_controller.go

@@ -36,10 +36,10 @@ import (
 	"k8s.io/apimachinery/pkg/types"
 	"k8s.io/client-go/kubernetes"
 	"k8s.io/client-go/tools/record"
+	"k8s.io/klog/v2"
 	ctrl "sigs.k8s.io/controller-runtime"
 	"sigs.k8s.io/controller-runtime/pkg/client"
 	"sigs.k8s.io/controller-runtime/pkg/event"
-	"sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/predicate"
 
 	secretsstorecsiv1 "sigs.k8s.io/secrets-store-csi-driver/apis/v1"
@@ -107,13 +107,12 @@ type SecretSyncReconciler struct {
 //+kubebuilder:rbac:groups=secrets-store.csi.x-k8s.io,resources=secretproviderclasses,verbs=get;list;watch
 
 func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
-	logger := log.FromContext(ctx)
-	logger.Info("Reconciling SecretSync", "namespace", req.NamespacedName.String())
+	klog.InfoS("Reconciling SecretSync", "namespace", req.NamespacedName.String())
 
 	// get the secret sync object
 	ss := &secretsyncv1alpha1.SecretSync{}
 	if err := r.Get(ctx, req.NamespacedName, ss); err != nil {
-		logger.Error(err, "unable to fetch SecretSync")
+		klog.ErrorS(err, "unable to fetch SecretSync")
 		return ctrl.Result{}, err
 	}
 
@@ -130,7 +129,7 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 	secretName := strings.TrimSpace(ss.Name)
 	secretObj := ss.Spec.SecretObject
 	if err := secretutil.ValidateSecretObject(secretName, secretObj); err != nil {
-		logger.Error(err, "failed to validate secret object", "secretName", secretName)
+		klog.ErrorS(err, "failed to validate secret object", "secretName", secretName)
 		r.updateStatusConditions(ctx, ss, ConditionTypeUnknown, conditionType, ConditionReasonUserInputValidationFailed, true)
 		return ctrl.Result{}, err
 	}
@@ -143,7 +142,7 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 	// get the service account token
 	serviceAccountTokenAttrs, err := r.TokenClient.SecretProviderServiceAccountTokenAttrs(ss.Namespace, ss.Spec.ServiceAccountName, r.Audiences)
 	if err != nil {
-		logger.Error(err, "failed to get service account token", "name", ss.Spec.ServiceAccountName)
+		klog.ErrorS(err, "failed to get service account token", "name", ss.Spec.ServiceAccountName)
 
 		conditionReason := ConditionReasonSecretPatchFailedUnknownError
 		if checkIfErrorMessageCanBeDisplayed(err.Error()) {
@@ -158,7 +157,7 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 	// get the secret provider class object
 	spc := &secretsstorecsiv1.SecretProviderClass{}
 	if err := r.Get(ctx, client.ObjectKey{Name: ss.Spec.SecretProviderClassName, Namespace: req.Namespace}, spc); err != nil {
-		logger.Error(err, "failed to get secret provider class", "name", ss.Spec.SecretProviderClassName)
+		klog.ErrorS(err, "failed to get secret provider class", "name", ss.Spec.SecretProviderClassName)
 		r.updateStatusConditions(ctx, ss, ConditionTypeUnknown, conditionType, ConditionReasonControllerSpcError, true)
 		return ctrl.Result{}, err
 	}
@@ -180,15 +179,15 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 
 	paramsJSON, err := json.Marshal(parameters)
 	if err != nil {
-		logger.Error(err, "failed to marshal parameters")
+		klog.ErrorS(err, "failed to marshal parameters")
 		r.updateStatusConditions(ctx, ss, ConditionTypeUnknown, conditionType, ConditionReasonControllerInternalError, true)
 		return ctrl.Result{}, err
 	}
 
 	providerName := string(spc.Spec.Provider)
 	providerClient, err := r.ProviderClients.Get(ctx, providerName)
 	if err != nil {
-		logger.Error(err, "failed to get provider client", "provider", providerName)
+		klog.ErrorS(err, "failed to get provider client", "provider", providerName)
 		r.updateStatusConditions(ctx, ss, ConditionTypeUnknown, conditionType, ConditionReasonControllerSpcError, true)
 		return ctrl.Result{}, err
 	}
@@ -197,7 +196,7 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 	var secretsJSON []byte
 	secretsJSON, err = json.Marshal(secretRefData)
 	if err != nil {
-		logger.Error(err, "failed to marshal secret")
+		klog.ErrorS(err, "failed to marshal secret")
 		r.updateStatusConditions(ctx, ss, ConditionTypeUnknown, conditionType, ConditionReasonControllerInternalError, true)
 		return ctrl.Result{}, err
 	}
@@ -206,23 +205,23 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 
 	objectVersions, files, err := provider.MountContent(ctx, providerClient, string(paramsJSON), string(secretsJSON), oldObjectVersions)
 	if err != nil {
-		logger.Error(err, "failed to get secrets from provider", "provider", providerName)
+		klog.ErrorS(err, "failed to get secrets from provider", "provider", providerName)
 		r.updateStatusConditions(ctx, ss, ConditionTypeUnknown, conditionType, ConditionReasonFailedProviderError, true)
 		return ctrl.Result{}, err
 	}
 
 	secretType := secretutil.GetSecretType(strings.TrimSpace(secretObj.Type))
 	var datamap map[string][]byte
 	if datamap, err = secretutil.GetSecretData(secretObj.Data, secretType, files); err != nil {
-		logger.Error(err, "failed to get secret data", "secretName", secretName)
+		klog.ErrorS(err, "failed to get secret data", "secretName", secretName)
 		r.updateStatusConditions(ctx, ss, ConditionTypeUnknown, conditionType, ConditionReasonUserInputValidationFailed, true)
 		return ctrl.Result{}, err
 	}
 
 	// Compute the hash of the secret
 	syncHash, err := r.computeSecretDataObjectHash(datamap, spc, ss)
 	if err != nil {
-		logger.Error(err, "failed to compute secret data object hash", "secretName", secretName)
+		klog.ErrorS(err, "failed to compute secret data object hash", "secretName", secretName)
 		return ctrl.Result{}, err
 	}
 
@@ -263,7 +262,7 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 
 	// Attempt to create or update the secret.
 	if err = r.serverSidePatchSecret(ctx, ss, secretName, req.Namespace, datamap, objectVersions, labels, annotations, secretType); err != nil {
-		logger.Error(err, "failed to patch secret", "secretName", secretName)
+		klog.ErrorS(err, "failed to patch secret", "secretName", secretName)
 
 		// Rollback to the previous hash and the previous last successful sync time.
 		ss.Status.SyncHash = prevSecretHash
@@ -296,7 +295,7 @@ func (r *SecretSyncReconciler) Reconcile(ctx context.Context, req ctrl.Request)
 		return ctrl.Result{}, err
 	}
 
-	logger.V(4).Info("Done... updated status", "syncHash", syncHash, "lastSuccessfulSyncTime", ss.Status.LastSuccessfulSyncTime)
+	klog.V(4).InfoS("Done... updated status", "syncHash", syncHash, "lastSuccessfulSyncTime", ss.Status.LastSuccessfulSyncTime)
 	return ctrl.Result{}, nil
 }