Add slog structured logging to various controllers and utility functions

- Integrated `slog` logging into the `MirrorPeerSecretReconciler`, `MirrorPeerReconciler`, and `DRPolicyReconciler` controllers.
- Improved error handling and logging for better observability and debugging.
- Replaced klog with slog for consistency across the codebase.

Changes include:
- Added `Logger` field to controller structs to pass and use `slog.Logger`.
- Enhanced logging messages to provide more context, including function names, object names, namespaces, and error details.
- Ensured logs capture both normal operation (e.g., successful updates) and error conditions.

Signed-off-by: vbadrina <vbadrina@redhat.com>

Author: vbnrh

controllers/common_controller_utils.go

@@ -23,6 +23,7 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
+	"log/slog"
 	"os"
 	"reflect"
 	"testing"
@@ -262,12 +263,13 @@ func TestMirrorPeerSecretReconcile(t *testing.T) {
 	}
 
 	fakeClient := getFakeClient(t, mgrScheme)
+	fakeLogger := slog.New(slog.NewTextHandler(os.Stdout, nil))
 	for _, c := range cases {
 		os.Setenv("POD_NAMESPACE", c.ramenNamespace)
 		ctx := context.TODO()
-		err := createOrUpdateSecretsFromInternalSecret(ctx, fakeClient, fakeS3InternalSecret(t, TestSourceManagedClusterEast), fakeMirrorPeers(c.manageS3))
+		err := createOrUpdateSecretsFromInternalSecret(ctx, fakeClient, fakeS3InternalSecret(t, TestSourceManagedClusterEast), fakeMirrorPeers(c.manageS3), fakeLogger)
 		assert.NoError(t, err)
-		err = createOrUpdateSecretsFromInternalSecret(ctx, fakeClient, fakeS3InternalSecret(t, TestDestinationManagedClusterWest), fakeMirrorPeers(c.manageS3))
+		err = createOrUpdateSecretsFromInternalSecret(ctx, fakeClient, fakeS3InternalSecret(t, TestDestinationManagedClusterWest), fakeMirrorPeers(c.manageS3), fakeLogger)
 		assert.NoError(t, err)
 
 		if c.ignoreS3Profile {

controllers/common_controller_utils_test.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
+	"log/slog"
 	"time"
 
 	"sigs.k8s.io/controller-runtime/pkg/controller/controllerutil"
@@ -12,13 +13,11 @@ import (
 	ramenv1alpha1 "github.com/ramendr/ramen/api/v1alpha1"
 	multiclusterv1alpha1 "github.com/red-hat-storage/odf-multicluster-orchestrator/api/v1alpha1"
 	"github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils"
-	"k8s.io/apimachinery/pkg/api/errors"
 	k8serrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/apimachinery/pkg/runtime/schema"
 	"k8s.io/apimachinery/pkg/types"
-	"k8s.io/klog/v2"
 	workv1 "open-cluster-management.io/api/work/v1"
 	ctrl "sigs.k8s.io/controller-runtime"
 	"sigs.k8s.io/controller-runtime/pkg/builder"
@@ -46,87 +45,110 @@ const (
 type DRPolicyReconciler struct {
 	HubClient client.Client
 	Scheme    *runtime.Scheme
+	Logger    *slog.Logger
 }
 
 // SetupWithManager sets up the controller with the Manager.
 func (r *DRPolicyReconciler) SetupWithManager(mgr ctrl.Manager) error {
+	r.Logger.Info("Setting up DRPolicyReconciler with manager")
+
 	dpPredicate := utils.ComposePredicates(predicate.GenerationChangedPredicate{})
-	return ctrl.NewControllerManagedBy(mgr).
+	err := ctrl.NewControllerManagedBy(mgr).
 		For(&ramenv1alpha1.DRPolicy{}, builder.WithPredicates(dpPredicate)).
 		Complete(r)
+
+	if err != nil {
+		r.Logger.Error("Failed to set up DRPolicyReconciler with manager", "error", err)
+		return err
+	}
+
+	r.Logger.Info("Successfully set up DRPolicyReconciler with manager")
+	return nil
 }
 
 func (r *DRPolicyReconciler) getMirrorPeerForClusterSet(ctx context.Context, clusterSet []string) (*multiclusterv1alpha1.MirrorPeer, error) {
+	logger := r.Logger.With("method", "getMirrorPeerForClusterSet", "ClusterSet", clusterSet)
+
 	var mpList multiclusterv1alpha1.MirrorPeerList
 	err := r.HubClient.List(ctx, &mpList)
 	if err != nil {
-		klog.Error("could not list mirrorpeers on hub")
+		logger.Error("Could not list MirrorPeers on hub", "error", err)
 		return nil, err
 	}
 
 	if len(mpList.Items) == 0 {
-		klog.Info("no mirrorpeers found on hub yet")
+		logger.Info("No MirrorPeers found on hub yet")
 		return nil, k8serrors.NewNotFound(schema.GroupResource{Group: multiclusterv1alpha1.GroupVersion.Group, Resource: "MirrorPeer"}, "MirrorPeerList")
 	}
+
 	for _, mp := range mpList.Items {
 		if (mp.Spec.Items[0].ClusterName == clusterSet[0] && mp.Spec.Items[1].ClusterName == clusterSet[1]) ||
 			(mp.Spec.Items[1].ClusterName == clusterSet[0] && mp.Spec.Items[0].ClusterName == clusterSet[1]) {
-			klog.Infof("found mirrorpeer %q for drpolicy", mp.Name)
+			logger.Info("Found MirrorPeer for DRPolicy", "MirrorPeerName", mp.Name)
 			return &mp, nil
 		}
 	}
 
-	klog.Info("could not find any mirrorpeer for drpolicy")
+	logger.Info("Could not find any MirrorPeer for DRPolicy")
 	return nil, k8serrors.NewNotFound(schema.GroupResource{Group: multiclusterv1alpha1.GroupVersion.Group, Resource: "MirrorPeer"}, fmt.Sprintf("ClusterSet-%s-%s", clusterSet[0], clusterSet[1]))
 }
+
 func (r *DRPolicyReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
-	klog.Infof("running DRPolicy reconciler on hub cluster")
-	// Fetch DRPolicy for given Request
+	r.Logger.Info("Running DRPolicy reconciler on hub cluster", "RequestNamespace", req.Namespace, "RequestName", req.Name)
+
+	// Fetch DRPolicy for the given request
 	var drpolicy ramenv1alpha1.DRPolicy
 	err := r.HubClient.Get(ctx, req.NamespacedName, &drpolicy)
 	if err != nil {
-		if errors.IsNotFound(err) {
-			klog.Info("Could not find DRPolicy. Ignoring since object must have been deleted")
+		if k8serrors.IsNotFound(err) {
+			r.Logger.Info("DRPolicy not found. Ignoring since the object must have been deleted", "RequestNamespace", req.Namespace, "RequestName", req.Name)
 			return ctrl.Result{}, nil
 		}
-		klog.Error(err, "Failed to get DRPolicy")
+		r.Logger.Error("Failed to get DRPolicy", "error", err, "RequestNamespace", req.Namespace, "RequestName", req.Name)
 		return ctrl.Result{}, err
 	}
 
-	// find mirrorpeer for clusterset for the storagecluster namespaces
+	// Find MirrorPeer for clusterset for the storagecluster namespaces
 	mirrorPeer, err := r.getMirrorPeerForClusterSet(ctx, drpolicy.Spec.DRClusters)
 	if err != nil {
 		if k8serrors.IsNotFound(err) {
+			r.Logger.Info("MirrorPeer not found. Requeuing", "DRClusters", drpolicy.Spec.DRClusters)
 			return ctrl.Result{RequeueAfter: time.Second * 10}, nil
 		}
-		klog.Error("error occurred while trying to fetch MirrorPeer for given DRPolicy")
+		r.Logger.Error("Error occurred while trying to fetch MirrorPeer for given DRPolicy", "error", err)
 		return ctrl.Result{}, err
 	}
 
 	if mirrorPeer.Spec.Type == multiclusterv1alpha1.Async {
 		clusterFSIDs := make(map[string]string)
-		klog.Infof("Fetching clusterFSIDs")
+		r.Logger.Info("Fetching cluster FSIDs")
 		err = r.fetchClusterFSIDs(ctx, mirrorPeer, clusterFSIDs)
 		if err != nil {
-			if errors.IsNotFound(err) {
+			if k8serrors.IsNotFound(err) {
+				r.Logger.Info("Cluster FSIDs not found, requeuing")
 				return ctrl.Result{RequeueAfter: 10 * time.Second}, nil
 			}
-			return ctrl.Result{}, fmt.Errorf("an unknown error occured while fetching the cluster fsids, retrying again: %v", err)
+			r.Logger.Error("An unknown error occurred while fetching the cluster FSIDs, retrying", "error", err)
+			return ctrl.Result{}, fmt.Errorf("an unknown error occurred while fetching the cluster FSIDs, retrying: %v", err)
 		}
 
 		err = r.createOrUpdateManifestWorkForVRC(ctx, mirrorPeer, &drpolicy, clusterFSIDs)
 		if err != nil {
+			r.Logger.Error("Failed to create VolumeReplicationClass via ManifestWork", "error", err)
 			return ctrl.Result{}, fmt.Errorf("failed to create VolumeReplicationClass via ManifestWork: %v", err)
 		}
 	}
 
+	r.Logger.Info("Successfully reconciled DRPolicy", "RequestNamespace", req.Namespace, "RequestName", req.Name)
 	return ctrl.Result{}, nil
 }
 
 func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Context, mp *multiclusterv1alpha1.MirrorPeer, dp *ramenv1alpha1.DRPolicy, clusterFSIDs map[string]string) error {
+	logger := r.Logger.With("method", "createOrUpdateManifestWorkForVRC", "DRPolicy", dp.Name, "MirrorPeer", mp.Name)
 
 	replicationId, err := utils.CreateUniqueReplicationId(clusterFSIDs)
 	if err != nil {
+		logger.Error("Failed to create unique replication ID", "error", err)
 		return err
 	}
 
@@ -144,25 +166,30 @@ func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Contex
 
 		switch {
 		case err == nil:
-			klog.Infof("%s already exists. updating...", manifestWorkName)
-		case !errors.IsNotFound(err):
-			klog.Error(err, "failed to get ManifestWork: %s", manifestWorkName)
+			logger.Info("ManifestWork already exists, updating", "ManifestWorkName", manifestWorkName)
+		case !k8serrors.IsNotFound(err):
+			logger.Error("Failed to get ManifestWork", "ManifestWorkName", manifestWorkName, "error", err)
 			return err
 		}
 
 		interval := dp.Spec.SchedulingInterval
-		params := make(map[string]string)
-		params[MirroringModeKey] = DefaultMirroringMode
-		params[SchedulingIntervalKey] = interval
-		params[ReplicationSecretNameKey] = RBDReplicationSecretName
-		params[ReplicationSecretNamespaceKey] = pr.StorageClusterRef.Namespace
+		params := map[string]string{
+			MirroringModeKey:              DefaultMirroringMode,
+			SchedulingIntervalKey:         interval,
+			ReplicationSecretNameKey:      RBDReplicationSecretName,
+			ReplicationSecretNamespaceKey: pr.StorageClusterRef.Namespace,
+		}
+
 		vrcName := fmt.Sprintf(RBDVolumeReplicationClassNameTemplate, utils.FnvHash(interval))
-		labels := make(map[string]string)
-		labels[fmt.Sprintf(RamenLabelTemplate, ReplicationIDKey)] = replicationId
-		labels[fmt.Sprintf(RamenLabelTemplate, "maintenancemodes")] = "Failover"
+		labels := map[string]string{
+			fmt.Sprintf(RamenLabelTemplate, ReplicationIDKey):   replicationId,
+			fmt.Sprintf(RamenLabelTemplate, "maintenancemodes"): "Failover",
+		}
+
 		vrc := replicationv1alpha1.VolumeReplicationClass{
 			TypeMeta: metav1.TypeMeta{
-				Kind: "VolumeReplicationClass", APIVersion: "replication.storage.openshift.io/v1alpha1",
+				Kind:       "VolumeReplicationClass",
+				APIVersion: "replication.storage.openshift.io/v1alpha1",
 			},
 			ObjectMeta: metav1.ObjectMeta{
 				Name:   vrcName,
@@ -179,6 +206,7 @@ func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Contex
 
 		objJson, err := json.Marshal(vrc)
 		if err != nil {
+			logger.Error("Failed to marshal VolumeReplicationClass to JSON", "VolumeReplicationClass", vrcName, "error", err)
 			return fmt.Errorf("failed to marshal %v to JSON, error %w", vrc, err)
 		}
 
@@ -210,7 +238,7 @@ func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Contex
 		mw := workv1.ManifestWork{
 			ObjectMeta: metav1.ObjectMeta{
 				Name:      manifestWorkName,
-				Namespace: pr.ClusterName, //target cluster
+				Namespace: pr.ClusterName,
 				OwnerReferences: []metav1.OwnerReference{
 					{
 						Kind:       dp.Kind,
@@ -221,6 +249,7 @@ func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Contex
 				},
 			},
 		}
+
 		_, err = controllerutil.CreateOrUpdate(ctx, r.HubClient, &mw, func() error {
 			mw.Spec = workv1.ManifestWorkSpec{
 				Workload: workv1.ManifestsTemplate{
@@ -231,35 +260,44 @@ func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Contex
 		})
 
 		if err != nil {
-			klog.Error(err, "failed to create/update ManifestWork: %s", manifestWorkName)
+			logger.Error("Failed to create/update ManifestWork", "ManifestWorkName", manifestWorkName, "error", err)
 			return err
 		}
 
-		klog.Infof("ManifestWork created for %s", vrcName)
+		logger.Info("ManifestWork created/updated successfully", "ManifestWorkName", manifestWorkName, "VolumeReplicationClassName", vrcName)
 	}
 
 	return nil
 }
 
 func (r *DRPolicyReconciler) fetchClusterFSIDs(ctx context.Context, peer *multiclusterv1alpha1.MirrorPeer, clusterFSIDs map[string]string) error {
+	logger := r.Logger.With("method", "fetchClusterFSIDs", "MirrorPeer", peer.Name)
+
 	for _, pr := range peer.Spec.Items {
 		rookSecretName := utils.GetSecretNameByPeerRef(pr)
-		klog.Info("Fetching rook secret ", "Secret Name:", rookSecretName)
+		logger.Info("Fetching rook secret", "SecretName", rookSecretName, "ClusterName", pr.ClusterName)
+
 		hs, err := utils.FetchSecretWithName(ctx, r.HubClient, types.NamespacedName{Name: rookSecretName, Namespace: pr.ClusterName})
 		if err != nil {
-			if errors.IsNotFound(err) {
-				klog.Infof("could not find secret %q. will attempt to fetch it again after a delay", rookSecretName)
+			if k8serrors.IsNotFound(err) {
+				logger.Info("Secret not found, will attempt to fetch again after a delay", "SecretName", rookSecretName, "ClusterName", pr.ClusterName)
+				return err
 			}
+			logger.Error("Failed to fetch rook secret", "SecretName", rookSecretName, "ClusterName", pr.ClusterName, "error", err)
 			return err
 		}
-		klog.Info("Unmarshalling rook secret ", "Secret Name:", rookSecretName)
+
+		logger.Info("Unmarshalling rook secret", "SecretName", rookSecretName, "ClusterName", pr.ClusterName)
 		rt, err := utils.UnmarshalHubSecret(hs)
 		if err != nil {
-			klog.Error(err, "Failed to unmarshal rook secret", "Secret", rookSecretName)
+			logger.Error("Failed to unmarshal rook secret", "SecretName", rookSecretName, "ClusterName", pr.ClusterName, "error", err)
 			return err
 		}
+
 		clusterFSIDs[pr.ClusterName] = rt.FSID
+		logger.Info("Successfully fetched FSID for cluster", "ClusterName", pr.ClusterName, "FSID", rt.FSID)
 	}
 
+	logger.Info("Successfully fetched all cluster FSIDs", "MirrorPeer", peer.Name)
 	return nil
 }

controllers/drpolicy_controller.go

@@ -3,6 +3,8 @@ package controllers
 import (
 	"context"
 	"fmt"
+	"log/slog"
+	"os"
 	"testing"
 
 	ramenv1alpha1 "github.com/ramendr/ramen/api/v1alpha1"
@@ -146,6 +148,7 @@ func getFakeDRPolicyReconciler(drpolicy *ramenv1alpha1.DRPolicy, mp *multicluste
 	r := DRPolicyReconciler{
 		HubClient: fakeClient,
 		Scheme:    scheme,
+		Logger:    slog.New(slog.NewTextHandler(os.Stdout, nil)),
 	}
 
 	return r

controllers/drpolicy_controller_test.go

@@ -3,6 +3,7 @@ package controllers
 import (
 	"context"
 	"flag"
+	"log/slog"
 	"os"
 
 	consolev1alpha1 "github.com/openshift/api/console/v1alpha1"
@@ -120,9 +121,11 @@ func (o *ManagerOptions) runManager() {
 
 	namespace := os.Getenv("POD_NAMESPACE")
 
+	logger := slog.New(slog.NewTextHandler(os.Stdout, nil))
 	if err = (&MirrorPeerReconciler{
 		Client: mgr.GetClient(),
 		Scheme: mgr.GetScheme(),
+		Logger: logger,
 	}).SetupWithManager(mgr); err != nil {
 		setupLog.Error(err, "unable to create controller", "controller", "MirrorPeer")
 		os.Exit(1)
@@ -132,6 +135,7 @@ func (o *ManagerOptions) runManager() {
 	if err = (&MirrorPeerSecretReconciler{
 		Client: mgr.GetClient(),
 		Scheme: mgr.GetScheme(),
+		Logger: logger,
 	}).SetupWithManager(mgr); err != nil {
 		setupLog.Error(err, "unable to create controller", "controller", "MirrorPeer")
 		os.Exit(1)
@@ -224,6 +228,7 @@ func (o *ManagerOptions) runManager() {
 	if err = (&DRPolicyReconciler{
 		HubClient: mgr.GetClient(),
 		Scheme:    mgr.GetScheme(),
+		Logger:    logger,
 	}).SetupWithManager(mgr); err != nil {
 		setupLog.Error(err, "unable to create controller", "controller", "DRPolicy")
 		os.Exit(1)