fix: reconfigure controllers to use klog via logr (#1551)

Author: karlkfi

cmd/admission-webhook/main.go

@@ -47,10 +47,11 @@ func main() {
 	flag.DurationVar(&cacheSyncTimeout, "cache-sync-timeout", configuration.CacheSyncTimeout, "The duration of time to wait while informers synchronize.")
 
 	log.Setup()
-	setupLog := textlogger.NewLogger(textlogger.NewConfig()).WithName("setup")
+	logger := textlogger.NewLogger(textlogger.NewConfig())
+	setupLog := logger.WithName("setup")
 
 	profiler.Service()
-	ctrl.SetLogger(textlogger.NewLogger(textlogger.NewConfig()))
+	ctrl.SetLogger(logger)
 
 	setupLog.Info("starting manager")
 	mgr, err := ctrl.NewManager(ctrl.GetConfigOrDie(), ctrl.Options{
@@ -64,6 +65,7 @@ func main() {
 		Controller: config.Controller{
 			CacheSyncTimeout: cacheSyncTimeout,
 		},
+		Logger: logger.WithName("controller-manager"),
 	})
 	if err != nil {
 		setupLog.Error(err, "starting manager")

cmd/reconciler-manager/main.go

@@ -68,10 +68,11 @@ func main() {
 			"Enabling this will ensure there is only one active controller manager.")
 
 	log.Setup()
-	setupLog := textlogger.NewLogger(textlogger.NewConfig()).WithName("setup")
+	logger := textlogger.NewLogger(textlogger.NewConfig())
+	setupLog := logger.WithName("setup")
 
 	profiler.Service()
-	ctrl.SetLogger(textlogger.NewLogger(textlogger.NewConfig()))
+	ctrl.SetLogger(logger)
 
 	setupLog.Info(fmt.Sprintf("running with flags --cluster-name=%s; --reconciler-polling-period=%s; --hydration-polling-period=%s",
 		*clusterName, *reconcilerPollingPeriod, *hydrationPollingPeriod))
@@ -85,6 +86,7 @@ func main() {
 	}
 
 	mgr, err := ctrl.NewManager(cfg, ctrl.Options{
+		Logger: logger.WithName("controller-manager"),
 		Scheme: core.Scheme,
 		MapperProvider: func(_ *rest.Config, _ *http.Client) (meta.RESTMapper, error) {
 			return mapper, nil
@@ -114,7 +116,7 @@ func main() {
 	watchFleetMembership := fleetMembershipCRDExists(dynamicClient, mapper, &setupLog)
 
 	crdController := &controllers.CRDController{}
-	crdControllerLogger := textlogger.NewLogger(textlogger.NewConfig()).WithName("controllers").WithName("CRD")
+	crdControllerLogger := logger.WithName("controllers").WithName("CRD")
 	crdMetaController := controllers.NewCRDMetaController(crdController,
 		mgr.GetCache(), mapper, crdControllerLogger)
 	if err := crdMetaController.Register(mgr); err != nil {
@@ -126,7 +128,7 @@ func main() {
 	repoSyncController := controllers.NewRepoSyncReconciler(*clusterName,
 		*reconcilerPollingPeriod, *hydrationPollingPeriod,
 		mgr.GetClient(), watcher, dynamicClient,
-		textlogger.NewLogger(textlogger.NewConfig()).WithName("controllers").WithName(configsync.RepoSyncKind),
+		logger.WithName("controllers").WithName(configsync.RepoSyncKind),
 		mgr.GetScheme())
 	crdController.SetReconciler(kinds.RepoSyncV1Beta1().GroupKind(), func(_ context.Context, crd *apiextensionsv1.CustomResourceDefinition) error {
 		if customresource.IsEstablished(crd) {
@@ -144,7 +146,7 @@ func main() {
 	rootSyncController := controllers.NewRootSyncReconciler(*clusterName,
 		*reconcilerPollingPeriod, *hydrationPollingPeriod,
 		mgr.GetClient(), watcher, dynamicClient,
-		textlogger.NewLogger(textlogger.NewConfig()).WithName("controllers").WithName(configsync.RootSyncKind),
+		logger.WithName("controllers").WithName(configsync.RootSyncKind),
 		mgr.GetScheme())
 	crdController.SetReconciler(kinds.RootSyncV1Beta1().GroupKind(), func(_ context.Context, crd *apiextensionsv1.CustomResourceDefinition) error {
 		if customresource.IsEstablished(crd) {
@@ -164,7 +166,7 @@ func main() {
 	}
 
 	otel := controllers.NewOtelReconciler(mgr.GetClient(),
-		textlogger.NewLogger(textlogger.NewConfig()).WithName("controllers").WithName("Otel"),
+		logger.WithName("controllers").WithName("Otel"),
 		otelCredentialProvider)
 	if err := otel.Register(mgr); err != nil {
 		setupLog.Error(err, "failed to register controller", "controller", "Otel")
@@ -173,7 +175,7 @@ func main() {
 	setupLog.Info("Otel controller registration successful")
 
 	otelSA := controllers.NewOtelSAReconciler(*clusterName, mgr.GetClient(),
-		textlogger.NewLogger(textlogger.NewConfig()).WithName("controllers").WithName(controllers.OtelSALoggerName))
+		logger.WithName("controllers").WithName(controllers.OtelSALoggerName))
 	if err := otelSA.Register(mgr); err != nil {
 		setupLog.Error(err, "failed to register controller", "controller", "OtelSA")
 		os.Exit(1)

cmd/reconciler/main.go

@@ -132,7 +132,8 @@ var flags = struct {
 func main() {
 	log.Setup()
 	profiler.Service()
-	ctrl.SetLogger(textlogger.NewLogger(textlogger.NewConfig()))
+	logger := textlogger.NewLogger(textlogger.NewConfig())
+	ctrl.SetLogger(logger)
 
 	if *debug {
 		status.EnablePanicOnMisuse()
@@ -183,6 +184,7 @@ func main() {
 	}
 
 	opts := reconciler.Options{
+		Logger:                   logger,
 		ClusterName:              *clusterName,
 		FightDetectionThreshold:  *fightDetectionThreshold,
 		NumWorkers:               *workers,

pkg/reconciler/reconciler.go

@@ -19,11 +19,11 @@ import (
 	"net/http"
 	"time"
 
+	"github.com/go-logr/logr"
 	"k8s.io/apimachinery/pkg/api/meta"
 	"k8s.io/client-go/dynamic"
 	"k8s.io/client-go/rest"
 	"k8s.io/klog/v2"
-	"k8s.io/klog/v2/textlogger"
 	"k8s.io/utils/clock"
 	"kpt.dev/configsync/pkg/api/configsync"
 	"kpt.dev/configsync/pkg/applier"
@@ -56,6 +56,8 @@ import (
 
 // Options contains the settings for a reconciler process.
 type Options struct {
+	// Logger to be used by the controller-manager and controllers.
+	Logger logr.Logger
 	// ClusterName is the name of the cluster we are parsing configuration for.
 	ClusterName string
 	// FightDetectionThreshold is the rate of updates per minute to an API
@@ -326,8 +328,8 @@ func Run(opts Options) {
 	signalCtx := signals.SetupSignalHandler()
 
 	// Create the ControllerManager
-	ctrl.SetLogger(textlogger.NewLogger(textlogger.NewConfig()))
 	mgrOptions := ctrl.Options{
+		Logger: opts.Logger.WithName("controller-manager"),
 		Scheme: core.Scheme,
 		MapperProvider: func(_ *rest.Config, _ *http.Client) (meta.RESTMapper, error) {
 			return mapper, nil
@@ -350,7 +352,7 @@ func Run(opts Options) {
 		klog.Fatalf("Instantiating Controller Manager: %v", err)
 	}
 
-	crdControllerLogger := textlogger.NewLogger(textlogger.NewConfig()).WithName("controllers").WithName("CRD")
+	crdControllerLogger := opts.Logger.WithName("controllers").WithName("CRD")
 	crdMetaController := controllers.NewCRDMetaController(crdController,
 		mgr.GetCache(), mapper, crdControllerLogger)
 	if err := crdMetaController.Register(mgr); err != nil {

pkg/reconcilermanager/controllers/crd_controller.go

@@ -94,7 +94,7 @@ func (s *CRDController) getReconciler(gk schema.GroupKind) CRDReconcileFunc {
 
 // CRDMetaController watches CRDs and delegates reconciliation to a CRDControllerManager.
 type CRDMetaController struct {
-	loggingController
+	*LoggingController
 	cache             cache.Cache
 	mapper            utilwatch.ResettableRESTMapper
 	delegate          *CRDController
@@ -111,9 +111,7 @@ func NewCRDMetaController(
 	log logr.Logger,
 ) *CRDMetaController {
 	return &CRDMetaController{
-		loggingController: loggingController{
-			log: log,
-		},
+		LoggingController: NewLoggingController(log),
 		cache:             cache,
 		mapper:            mapper,
 		delegate:          delegate,
@@ -128,7 +126,7 @@ func NewCRDMetaController(
 // resources by calling Reset on the RESTMapper, as needed.
 func (r *CRDMetaController) Reconcile(ctx context.Context, req reconcile.Request) (reconcile.Result, error) {
 	crdName := req.Name
-	ctx = r.setLoggerValues(ctx, "crd", crdName)
+	ctx = r.SetLoggerValues(ctx, "crd", crdName)
 
 	// Established if CRD exists and .status.conditions[type="Established"].status = "True"
 	var kind schema.GroupKind
@@ -167,7 +165,7 @@ func (r *CRDMetaController) Reconcile(ctx context.Context, req reconcile.Request
 		r.observedResources[resource] = kind
 	}
 
-	r.logger(ctx).Info("CRDMetaController handling CRD status update", "name", crdName)
+	r.Logger(ctx).V(3).Info("CRDMetaController handling CRD status update", "name", crdName)
 
 	if customresource.IsEstablished(crdObj) {
 		if err := discoverResourceForKind(r.mapper, kind); err != nil {
@@ -186,7 +184,7 @@ func (r *CRDMetaController) Reconcile(ctx context.Context, req reconcile.Request
 		return reconcile.Result{}, err
 	}
 
-	r.logger(ctx).V(3).Info("CRDMetaController handled CRD status update", "name", crdName)
+	r.Logger(ctx).V(3).Info("CRDMetaController handled CRD status update", "name", crdName)
 
 	return reconcile.Result{}, nil
 }

pkg/reconcilermanager/controllers/garbage_collector.go

@@ -63,7 +63,7 @@ func (r *reconcilerBase) cleanup(ctx context.Context, obj client.Object) error {
 	uObj.SetName(id.Name)
 	uObj.SetNamespace(id.Namespace)
 	uObj.SetGroupVersionKind(gvk)
-	r.logger(ctx).Info("Deleting managed object",
+	r.Logger(ctx).V(3).Info("Deleting managed object",
 		logFieldObjectRef, id.ObjectKey.String(),
 		logFieldObjectKind, id.Kind)
 	err = watch.DeleteAndWait(ctx, r.watcher, uObj, deleteWaitTimeout)
@@ -86,7 +86,7 @@ func (r *reconcilerBase) cleanup(ctx context.Context, obj client.Object) error {
 		// If not a timeout, assume the delete failed.
 		return NewObjectOperationErrorWithID(err, id, OperationDelete)
 	}
-	r.logger(ctx).Info("Managed object delete successful",
+	r.Logger(ctx).Info("Deleting managed object successful",
 		logFieldObjectRef, id.ObjectKey.String(),
 		logFieldObjectKind, id.Kind)
 	return nil
@@ -152,7 +152,7 @@ func (r *RepoSyncReconciler) deleteSharedRoleBinding(ctx context.Context, reconc
 	if err := r.client.Get(ctx, rbKey, rb); err != nil {
 		if apierrors.IsNotFound(err) {
 			// already deleted
-			r.logger(ctx).Info("Managed object already deleted",
+			r.Logger(ctx).V(3).Info("Managed object already deleted",
 				logFieldObjectRef, rbKey.String(),
 				logFieldObjectKind, "RoleBinding")
 			return nil
@@ -169,9 +169,15 @@ func (r *RepoSyncReconciler) deleteSharedRoleBinding(ctx context.Context, reconc
 		// Delete the whole RB
 		return r.cleanup(ctx, rb)
 	}
+	r.Logger(ctx).V(3).Info("Updating managed object",
+		logFieldObjectRef, rbKey.String(),
+		logFieldObjectKind, "RoleBinding")
 	if err := r.client.Update(ctx, rb, client.FieldOwner(reconcilermanager.FieldManager)); err != nil {
 		return NewObjectOperationError(err, rb, OperationUpdate)
 	}
+	r.Logger(ctx).Info("Updating managed object successful",
+		logFieldObjectRef, rbKey.String(),
+		logFieldObjectKind, "RoleBinding")
 	return nil
 }
 
@@ -244,7 +250,7 @@ func (r *reconcilerBase) deleteSharedClusterRoleBinding(ctx context.Context, nam
 	if err := r.client.Get(ctx, crbKey, crb); err != nil {
 		if apierrors.IsNotFound(err) {
 			// already deleted
-			r.logger(ctx).Info("Managed object already deleted",
+			r.Logger(ctx).V(3).Info("Managed object already deleted",
 				logFieldObjectRef, crbKey.String(),
 				logFieldObjectKind, "ClusterRoleBinding")
 			return nil
@@ -261,8 +267,14 @@ func (r *reconcilerBase) deleteSharedClusterRoleBinding(ctx context.Context, nam
 		// No change
 		return nil
 	}
+	r.Logger(ctx).V(3).Info("Updating managed object",
+		logFieldObjectRef, crbKey.String(),
+		logFieldObjectKind, "ClusterRoleBinding")
 	if err := r.client.Update(ctx, crb, client.FieldOwner(reconcilermanager.FieldManager)); err != nil {
 		return NewObjectOperationError(err, crb, OperationUpdate)
 	}
+	r.Logger(ctx).Info("Updating managed object successful",
+		logFieldObjectRef, crbKey.String(),
+		logFieldObjectKind, "ClusterRoleBinding")
 	return nil
 }

pkg/reconcilermanager/controllers/helm_value_files.go

@@ -136,6 +136,9 @@ func (r *RepoSyncReconciler) upsertHelmConfigMap(ctx context.Context, cmsCMRef,
 	cmsConfigMap.Name = cmsCMRef.Name
 	cmsConfigMap.Namespace = cmsCMRef.Namespace
 
+	r.Logger(ctx).V(3).Info("Upserting managed object",
+		logFieldObjectRef, cmsCMRef.String(),
+		logFieldObjectKind, "ConfigMap")
 	op, err := CreateOrUpdate(ctx, r.client, cmsConfigMap, func() error {
 		// TODO: Eventually remove the annotations and use the labels for list filtering, to optimize cleanup.
 		// We can't remove the annotations until v1.16.0 is no longer supported.
@@ -156,7 +159,7 @@ func (r *RepoSyncReconciler) upsertHelmConfigMap(ctx context.Context, cmsCMRef,
 		return op, err
 	}
 	if op != controllerutil.OperationResultNone {
-		r.logger(ctx).Info("Managed object upsert successful",
+		r.Logger(ctx).Info("Upserting managed object successful",
 			logFieldObjectRef, cmsCMRef.String(),
 			logFieldObjectKind, "ConfigMap",
 			logFieldOperation, op)

pkg/reconcilermanager/controllers/logger.go renamed to pkg/reconcilermanager/controllers/logging_controller.go

@@ -33,28 +33,35 @@ func (c contextKey) String() string {
 // values, in the context.Context.
 const contextKeyLogger = contextKey("logger")
 
-// loggingController is a parent class for a controller that logs.
+// LoggingController is a parent class for a controller that logs.
 // The logger can be stored in the context with contextual values.
 //
 // Use lc.logger(ctx) to retrieve the logger.
 // Use ctx = lc.setLoggerValues(ctx, key, value) to add key/value pairs.
-type loggingController struct {
+type LoggingController struct {
 	log logr.Logger
 }
 
-// logger returns a logr.Logger, either from the context or from
+// NewLoggingController constructs a new LoggingController
+func NewLoggingController(log logr.Logger) *LoggingController {
+	return &LoggingController{
+		log: log,
+	}
+}
+
+// Logger returns a logr.Logger, either from the context or from
 // reconcilerBase.log.
-func (lc *loggingController) logger(ctx context.Context) logr.Logger {
+func (lc *LoggingController) Logger(ctx context.Context) logr.Logger {
 	logger := ctx.Value(contextKeyLogger)
 	if logger != nil {
 		return logger.(logr.Logger)
 	}
 	return lc.log
 }
 
-// setLoggerValues sets key/value pairs on the logger stored in the context.
+// SetLoggerValues sets key/value pairs on the logger stored in the context.
 // If not initially present, the default logger is added to the context.
 // See logr.Logger.WithValues for more details about how values work.
-func (lc *loggingController) setLoggerValues(ctx context.Context, keysAndValues ...interface{}) context.Context {
-	return context.WithValue(ctx, contextKeyLogger, lc.logger(ctx).WithValues(keysAndValues...))
+func (lc *LoggingController) SetLoggerValues(ctx context.Context, keysAndValues ...interface{}) context.Context {
+	return context.WithValue(ctx, contextKeyLogger, lc.Logger(ctx).WithValues(keysAndValues...))
 }

pkg/reconcilermanager/controllers/otel_base_controller.go

@@ -27,7 +27,7 @@ import (
 
 // otelBaseController implements common functionality for otel controllers.
 type otelBaseController struct {
-	loggingController
+	*LoggingController
 
 	client client.Client
 }
@@ -52,7 +52,7 @@ func (r *otelBaseController) updateDeploymentAnnotation(ctx context.Context, ann
 		return nil
 	}
 
-	r.logger(ctx).V(3).Info("Patching object",
+	r.Logger(ctx).V(3).Info("Patching object",
 		logFieldObjectRef, key.String(),
 		logFieldObjectKind, "Deployment",
 		annotationKey, annotationValue)
@@ -61,7 +61,7 @@ func (r *otelBaseController) updateDeploymentAnnotation(ctx context.Context, ann
 	if err != nil {
 		return status.APIServerErrorf(err, "failed to patch Deployment: %s", key)
 	}
-	r.logger(ctx).Info("Patching object successful",
+	r.Logger(ctx).Info("Patching object successful",
 		logFieldObjectRef, key.String(),
 		logFieldObjectKind, "Deployment",
 		annotationKey, annotationValue)