Using klog for structured logging

Signed-off-by: Omer Aplatony <[email protected]>

cmd/main.go

@@ -17,6 +17,7 @@ limitations under the License.
 package main
 
 import (
+ "context"
  "flag"
  "os"
  "strings"
@@ -28,12 +29,12 @@ 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"
  "sigs.k8s.io/controller-runtime/pkg/metrics/server"
  secretsstorecsiv1 "sigs.k8s.io/secrets-store-csi-driver/apis/v1"
-
  secretsyncv1alpha1 "sigs.k8s.io/secrets-store-sync-controller/api/v1alpha1"
  "sigs.k8s.io/secrets-store-sync-controller/internal/controller"
  "sigs.k8s.io/secrets-store-sync-controller/pkg/k8s"
@@ -44,7 +45,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.")
  probeAddr = flag.String("health-probe-bind-address", ":8081", "The address the probe endpoint binds to.")
@@ -64,18 +64,24 @@ func init() {
 }
 
 func runMain() error {
- opts := zap.Options{
- Development: true,
- }
- opts.BindFlags(flag.CommandLine)
+ klog.InitFlags(nil)
  flag.Parse()
-
- ctrl.SetLogger(zap.New(zap.UseFlagOptions(&opts)))
+ defer mlog.Setup()()
+ mlogLevel := convertKlogLevelToMlogLevel(getKlogLevel())
+ ctx := withShutdownSignal(context.Background())
+ err := mlog.ValidateAndSetLogLevelAndFormatGlobally(ctx, mlog.LogSpec{
+ Format: mlog.FormatJSON,
+ Level: mlogLevel,
+ })
+ if err != nil {
+ klog.ErrorS(err, "failed to validate log level")
+ return err
+ }
 
  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
@@ -93,7 +99,7 @@ func runMain() error {
  LeaderElectionID: "29f1d54e.secret-sync.x-k8s.io",
  })
  if err != nil {
- setupLog.Error(err, "unable to start manager")
+ klog.ErrorS(err, "Unable to start manager")
  return err
  }
 
@@ -123,23 +129,23 @@ 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
  }
 
@@ -153,3 +159,35 @@ func main() {
 
  os.Exit(0)
 }
+
+// hack around klog not exposing a Get method
+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 convertKlogLevelToMlogLevel(klogLevel klog.Level) mlog.LogLevel {
+ if klogLevel >= 0 && klogLevel < 2 {
+ return mlog.LevelWarning
+ } else if klogLevel >= 2 && klogLevel < 4 {
+ return mlog.LevelInfo
+ } else if klogLevel >= 4 && klogLevel < 6 {
+ return mlog.LevelDebug
+ } else {
+ return mlog.LevelAll
+ }
+}
+
+// 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
+}

go.mod

@@ -21,6 +21,12 @@ require (
  sigs.k8s.io/secrets-store-csi-driver v1.4.4
 )
 
+require (
+ github.com/blang/semver/v4 v4.0.0 // indirect
+ github.com/inconshreveable/mousetrap v1.1.0 // indirect
+ github.com/spf13/cobra v1.7.0 // indirect
+)
+
 require (
  github.com/beorn7/perks v1.0.1 // indirect
  github.com/cespare/xxhash/v2 v2.2.0 // indirect
@@ -79,6 +85,7 @@ require (
  k8s.io/apiextensions-apiserver v0.28.3 // indirect
  k8s.io/component-base v0.28.3 // indirect
  k8s.io/kube-openapi v0.0.0-20230717233707-2695361300d9 // indirect
+ monis.app/mlog v0.0.4
  sigs.k8s.io/json v0.0.0-20221116044647-bc3834ca7abd // indirect
  sigs.k8s.io/structured-merge-diff/v4 v4.2.3 // indirect
  sigs.k8s.io/yaml v1.3.0 // 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=
@@ -54,6 +57,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=
@@ -99,6 +104,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=
@@ -233,6 +241,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.3 h1:2TuvuokmfXvDUamSx1SuAOO3eTyye+47mJCigwG62c4=
 sigs.k8s.io/controller-runtime v0.16.3/go.mod h1:j7bialYoSn142nv9sCOJmQgDXQXxnroFU4VnX/brVJ0=
 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(4).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(4).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(4).InfoS("Updated status", "condition", condition)
 }

internal/controller/secretsync_controller.go

@@ -28,6 +28,8 @@ import (
  "strings"
  "time"
 
+ "k8s.io/klog/v2"
+
  "golang.org/x/crypto/pbkdf2"
  corev1 "k8s.io/api/core/v1"
  "k8s.io/apimachinery/pkg/api/meta"
@@ -39,7 +41,6 @@ import (
  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 +108,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.V(4).InfoS("Reconciling SecretSync", "namespace", req.Namespace, "name", req.Name)
 
  // 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 +130,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 +143,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 +158,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 +180,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", "parameters", parameters)
+ klog.ErrorS(err, "Failed to marshal parameters", "parameters", 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 +197,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 +206,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 +263,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 +296,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("Status updated", "syncHash", syncHash, "lastSuccessfulSyncTime", ss.Status.LastSuccessfulSyncTime)
  return ctrl.Result{}, nil
 }
 

pkg/metrics/exporter.go

@@ -32,7 +32,7 @@ const prometheusExporter = "prometheus"
 
 func InitMetricsExporter() error {
  mb := strings.ToLower(*metricsBackend)
- klog.InfoS("initializing metrics backend", "backend", mb)
+ klog.InfoS("Initializing metrics backend", "backend", mb)
  switch mb {
  // Prometheus is the only supported exporter
  case prometheusExporter: