From 7c881fd99b33a7b4a9ca2cad34716c62be33758d Mon Sep 17 00:00:00 2001 From: vbadrina Date: Wed, 19 Jun 2024 13:29:48 +0530 Subject: [PATCH] Add slog structured logging to main controllers 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. Signed-off-by: vbadrina --- .golangci.yaml | 5 + addons/agent_mirrorpeer_controller.go | 224 +++++++++----- addons/agent_mirrorpeer_controller_test.go | 4 + addons/blue_secret_controller.go | 15 +- addons/blue_secret_controller_test.go | 1 - addons/green_secret_controller.go | 17 +- addons/green_secret_controller_test.go | 1 - addons/maintenance_mode_controller.go | 93 +++--- addons/manager.go | 91 +++--- addons/rook_secret_handler.go | 39 +-- addons/rook_secret_handler_test.go | 1 - addons/s3_controller.go | 16 +- addons/s3_secret_handler.go | 26 +- addons/s3_secret_handler_test.go | 1 - addons/secret_exchange_handler_utils.go | 28 +- addons/setup/common.go | 22 +- controllers/common_controller_utils.go | 277 ++++++++++-------- controllers/common_controller_utils_test.go | 5 +- controllers/drpolicy_controller.go | 83 ++++-- controllers/drpolicy_controller_test.go | 6 +- controllers/manager.go | 64 ++-- controllers/mirrorpeer_controller.go | 277 ++++++++++++------ controllers/mirrorpeer_controller_test.go | 1 + controllers/mirrorpeersecret_controller.go | 82 +++--- controllers/named_peerref_with_data.go | 18 +- controllers/utils/logging.go | 22 ++ go.mod | 5 +- go.sum | 6 +- .../integration/mirrorpeer_controller_test.go | 2 + tests/integration/mirrorpeer_status_test.go | 3 +- tests/integration/ramen_test.go | 3 +- tests/integration/suite_test.go | 4 + 32 files changed, 892 insertions(+), 550 deletions(-) delete mode 100644 addons/blue_secret_controller_test.go delete mode 100644 addons/green_secret_controller_test.go delete mode 100644 addons/rook_secret_handler_test.go delete mode 100644 addons/s3_secret_handler_test.go create mode 100644 controllers/utils/logging.go diff --git a/.golangci.yaml b/.golangci.yaml index ef43e41a..5efbb2a6 100644 --- a/.golangci.yaml +++ b/.golangci.yaml @@ -5,6 +5,11 @@ run: timeout: 5m modules-download-mode: readonly + +linters: + enable: + - sloglint + linters-settings: errcheck: # report about not checking of errors in type assertions: `a := b.(MyStruct)`; diff --git a/addons/agent_mirrorpeer_controller.go b/addons/agent_mirrorpeer_controller.go index f71378fa..ceb22457 100644 --- a/addons/agent_mirrorpeer_controller.go +++ b/addons/agent_mirrorpeer_controller.go @@ -21,6 +21,7 @@ import ( "crypto/sha1" "encoding/hex" "fmt" + "log/slog" "strconv" "time" @@ -35,7 +36,6 @@ import ( metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/types" - "k8s.io/klog/v2" ctrl "sigs.k8s.io/controller-runtime" "sigs.k8s.io/controller-runtime/pkg/builder" "sigs.k8s.io/controller-runtime/pkg/client" @@ -49,6 +49,7 @@ type MirrorPeerReconciler struct { Scheme *runtime.Scheme SpokeClient client.Client SpokeClusterName string + Logger *slog.Logger } // Reconcile is part of the main kubernetes reconciliation loop which aims to @@ -57,37 +58,37 @@ type MirrorPeerReconciler struct { // For more details, check Reconcile and its Result here: // - https://pkg.go.dev/sigs.k8s.io/controller-runtime@v0.8.3/pkg/reconcile func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { - klog.Infof("Running MirrorPeer reconciler on spoke cluster") - // Fetch MirrorPeer for given Request + logger := r.Logger.With("MirrorPeer", req.NamespacedName.String()) + logger.Info("Running MirrorPeer reconciler on spoke cluster") + var mirrorPeer multiclusterv1alpha1.MirrorPeer err := r.HubClient.Get(ctx, req.NamespacedName, &mirrorPeer) if err != nil { if errors.IsNotFound(err) { - klog.Info("Could not find MirrorPeer. Ignoring since object must have been deleted") + logger.Info("MirrorPeer not found, ignoring since object must have been deleted") return ctrl.Result{}, nil } - klog.Error(err, "Failed to get MirrorPeer") + logger.Error("Failed to retrieve MirrorPeer", "error", err) return ctrl.Result{}, err } scr, err := utils.GetCurrentStorageClusterRef(&mirrorPeer, r.SpokeClusterName) if err != nil { - klog.Error(err, "Failed to get current storage cluster ref") + logger.Error("Failed to get current storage cluster ref", "error", err) return ctrl.Result{}, err } agentFinalizer := r.SpokeClusterName + "." + SpokeMirrorPeerFinalizer - if len(agentFinalizer) > 63 { agentFinalizer = fmt.Sprintf("%s.%s", r.SpokeClusterName[0:10], SpokeMirrorPeerFinalizer) } if mirrorPeer.GetDeletionTimestamp().IsZero() { if !utils.ContainsString(mirrorPeer.GetFinalizers(), agentFinalizer) { - klog.Infof("Finalizer not found on MirrorPeer. Adding Finalizer %q", agentFinalizer) + logger.Info("Adding finalizer to MirrorPeer", "finalizer", agentFinalizer) mirrorPeer.Finalizers = append(mirrorPeer.Finalizers, agentFinalizer) if err := r.HubClient.Update(ctx, &mirrorPeer); err != nil { - klog.Errorf("Failed to add finalizer to MirrorPeer %q", mirrorPeer.Name) + logger.Error("Failed to add finalizer to MirrorPeer", "error", err) return ctrl.Result{}, err } } @@ -99,44 +100,44 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) err = r.HubClient.Get(ctx, req.NamespacedName, &mirrorPeer) if err != nil { if errors.IsNotFound(err) { - klog.Info("Could not find MirrorPeer. Ignoring since object must have been deleted") + logger.Info("MirrorPeer deleted during reconciling, skipping") return ctrl.Result{}, nil } - klog.Error(err, "Failed to get MirrorPeer") + logger.Error("Failed to retrieve MirrorPeer after deletion", "error", err) return ctrl.Result{}, err } mirrorPeer.Finalizers = utils.RemoveString(mirrorPeer.Finalizers, agentFinalizer) if err := r.HubClient.Update(ctx, &mirrorPeer); err != nil { - klog.Error("failed to remove finalizer from MirrorPeer ", err) + logger.Error("Failed to remove finalizer from MirrorPeer", "error", err) return ctrl.Result{}, err } - klog.Info("MirrorPeer deleted, skipping reconcilation") + logger.Info("MirrorPeer deletion complete") return ctrl.Result{}, nil } - klog.Infof("creating s3 buckets") + logger.Info("Creating S3 buckets") err = r.createS3(ctx, mirrorPeer, scr.Namespace) if err != nil { - klog.Error(err, "Failed to create ODR S3 resources") + logger.Error("Failed to create ODR S3 resources", "error", err) return ctrl.Result{}, err } if mirrorPeer.Spec.Type == multiclusterv1alpha1.Async { clusterFSIDs := make(map[string]string) - klog.Infof("Fetching clusterFSIDs") + logger.Info("Fetching clusterFSIDs") err = r.fetchClusterFSIDs(ctx, &mirrorPeer, clusterFSIDs) if err != nil { if errors.IsNotFound(err) { return ctrl.Result{RequeueAfter: 60 * time.Second}, nil } - return ctrl.Result{}, fmt.Errorf("an unknown error occured while fetching the cluster fsids, retrying again: %v", err) + return ctrl.Result{}, fmt.Errorf("an unknown error occurred while fetching the cluster fsids, retrying again: %v", err) } - klog.Infof("enabling async mode dependencies") + logger.Info("Enabling async mode dependencies") err = r.labelCephClusters(ctx, scr, clusterFSIDs) if err != nil { - klog.Errorf("failed to label cephcluster. err=%v", err) + logger.Error("Failed to label cephcluster", "error", err) return ctrl.Result{}, err } err = r.enableCSIAddons(ctx, scr.Namespace) @@ -146,13 +147,13 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) err = r.enableMirroring(ctx, scr.Name, scr.Namespace, &mirrorPeer) if err != nil { - return ctrl.Result{}, fmt.Errorf("failed to enable mirroring the storagecluster %q in namespace %q in managed cluster. Error %v", scr.Name, scr.Namespace, err) + return ctrl.Result{}, fmt.Errorf("failed to enable mirroring the storagecluster %q in namespace %q in managed cluster: %v", scr.Name, scr.Namespace, err) } - klog.Infof("labeling rbd storageclasses") + logger.Info("Labeling RBD storageclasses") errs := r.labelRBDStorageClasses(ctx, scr.Namespace, clusterFSIDs) if len(errs) > 0 { - return ctrl.Result{}, fmt.Errorf("few failures occured while labeling RBD StorageClasses: %v", errs) + return ctrl.Result{}, fmt.Errorf("few failures occurred while labeling RBD StorageClasses: %v", errs) } } return ctrl.Result{}, nil @@ -162,22 +163,26 @@ func (r *MirrorPeerReconciler) fetchClusterFSIDs(ctx context.Context, mp *multic for _, pr := range mp.Spec.Items { clusterType, err := utils.GetClusterType(pr.StorageClusterRef.Name, pr.StorageClusterRef.Namespace, r.SpokeClient) if err != nil { + r.Logger.Error("Failed to get cluster type", "clusterName", pr.StorageClusterRef.Name, "namespace", pr.StorageClusterRef.Namespace, "error", err) return err } secretName := r.getSecretNameByType(clusterType, pr) - klog.Info("Checking secret: ", secretName, " Mode:", clusterType) + r.Logger.Info("Checking secret", "secretName", secretName, "mode", clusterType, "clusterName", pr.StorageClusterRef.Name, "namespace", pr.StorageClusterRef.Namespace) secret, err := utils.FetchSecretWithName(ctx, r.SpokeClient, types.NamespacedName{Name: secretName, Namespace: pr.StorageClusterRef.Namespace}) if err != nil { + r.Logger.Error("Failed to fetch secret", "secretName", secretName, "namespace", pr.StorageClusterRef.Namespace, "error", err) return err } fsid, err := r.getFsidFromSecretByType(clusterType, secret) if err != nil { + r.Logger.Error("Failed to extract FSID from secret", "secretName", secretName, "namespace", pr.StorageClusterRef.Namespace, "error", err) return err } clusterFSIDs[pr.ClusterName] = fsid + r.Logger.Info("FSID fetched for cluster", "clusterName", pr.ClusterName, "FSID", fsid) } return nil } @@ -187,17 +192,19 @@ func (r *MirrorPeerReconciler) getFsidFromSecretByType(clusterType utils.Cluster if clusterType == utils.CONVERGED { token, err := utils.UnmarshalRookSecret(secret) if err != nil { - klog.Error(err, "Error while unmarshalling converged mode peer secret; ", "peerSecret ", secret.Name) + r.Logger.Error("Failed to unmarshal converged mode peer secret", "peerSecret", secret.Name, "error", err) return "", err } fsid = token.FSID + r.Logger.Info("FSID retrieved for converged mode", "FSID", fsid, "secret", secret.Name) } else if clusterType == utils.EXTERNAL { token, err := utils.UnmarshalRookSecretExternal(secret) if err != nil { - klog.Error(err, "Error while unmarshalling external mode peer secret; ", "peerSecret ", secret.Name) + r.Logger.Error("Failed to unmarshal external mode peer secret", "peerSecret", secret.Name, "error", err) return "", err } fsid = token.FSID + r.Logger.Info("FSID retrieved for external mode", "FSID", fsid, "secret", secret.Name) } return fsid, nil } @@ -217,30 +224,36 @@ func (r *MirrorPeerReconciler) getSecretNameByType(clusterType utils.ClusterType } func (r *MirrorPeerReconciler) labelRBDStorageClasses(ctx context.Context, storageClusterNamespace string, clusterFSIDs map[string]string) []error { - klog.Info(clusterFSIDs) + r.Logger.Info("Fetching cluster FSIDs", "clusterFSIDs", clusterFSIDs) // Get all StorageClasses in storageClusterNamespace scs := &storagev1.StorageClassList{} err := r.SpokeClient.List(ctx, scs) var errs []error if err != nil { errs = append(errs, err) + r.Logger.Error("Failed to list StorageClasses", "namespace", storageClusterNamespace, "error", err) return errs } - klog.Infof("Found %d StorageClasses", len(scs.Items)) + r.Logger.Info("Found StorageClasses", "count", len(scs.Items), "namespace", storageClusterNamespace) + key := r.SpokeClusterName for _, sc := range scs.Items { - if _, ok := clusterFSIDs[key]; !ok { - errs = append(errs, fmt.Errorf("no value found for key: %s, unable to update StorageClass for %s", key, key)) + if fsid, ok := clusterFSIDs[key]; !ok { + errMsg := fmt.Errorf("no FSID found for key: %s, unable to update StorageClass", key) + errs = append(errs, errMsg) + r.Logger.Error("Missing FSID for StorageClass update", "key", key, "StorageClass", sc.Name) continue - } - if sc.Provisioner == fmt.Sprintf(RBDProvisionerTemplate, storageClusterNamespace) || sc.Provisioner == fmt.Sprintf(CephFSProvisionerTemplate, storageClusterNamespace) { - klog.Infof("Updating StorageClass %q with label storageid %q", sc.Name, clusterFSIDs[key]) - sc.Labels = make(map[string]string) - sc.Labels[fmt.Sprintf(RamenLabelTemplate, StorageIDKey)] = clusterFSIDs[key] - err = r.SpokeClient.Update(ctx, &sc) - if err != nil { - klog.Error(err, "Failed to update StorageClass: %s", sc.Name) - errs = append(errs, err) + } else { + if sc.Provisioner == fmt.Sprintf(RBDProvisionerTemplate, storageClusterNamespace) || sc.Provisioner == fmt.Sprintf(CephFSProvisionerTemplate, storageClusterNamespace) { + r.Logger.Info("Updating StorageClass with FSID", "StorageClass", sc.Name, "FSID", fsid) + if sc.Labels == nil { + sc.Labels = make(map[string]string) + } + sc.Labels[fmt.Sprintf(RamenLabelTemplate, StorageIDKey)] = fsid + if err = r.SpokeClient.Update(ctx, &sc); err != nil { + errs = append(errs, err) + r.Logger.Error("Failed to update StorageClass with FSID", "StorageClass", sc.Name, "FSID", fsid, "error", err) + } } } } @@ -252,18 +265,20 @@ func (r *MirrorPeerReconciler) createS3(ctx context.Context, mirrorPeer multiclu noobaaOBC, err := r.getS3bucket(ctx, mirrorPeer, scNamespace) if err != nil { if errors.IsNotFound(err) { - klog.Info("Could not find ODR ObjectBucketClaim, creating") + r.Logger.Info("ODR ObjectBucketClaim not found, creating new one", "MirrorPeer", mirrorPeer.Name, "namespace", scNamespace) err = r.SpokeClient.Create(ctx, noobaaOBC) if err != nil { - klog.Error(err, "Failed to create ODR ObjectBucketClaim") + r.Logger.Error("Failed to create ODR ObjectBucketClaim", "error", err, "MirrorPeer", mirrorPeer.Name, "namespace", scNamespace) return err } } else { - klog.Error(err, "Failed to get ODR ObjectBucketClaim") + r.Logger.Error("Failed to retrieve ODR ObjectBucketClaim", "error", err, "MirrorPeer", mirrorPeer.Name, "namespace", scNamespace) return err } + } else { + r.Logger.Info("ODR ObjectBucketClaim already exists, no action needed", "MirrorPeer", mirrorPeer.Name, "namespace", scNamespace) } - return err + return nil } func (r *MirrorPeerReconciler) getS3bucket(ctx context.Context, mirrorPeer multiclusterv1alpha1.MirrorPeer, scNamespace string) (*obv1alpha1.ObjectBucketClaim, error) { @@ -288,12 +303,23 @@ func (r *MirrorPeerReconciler) getS3bucket(ctx context.Context, mirrorPeer multi StorageClassName: namespace + ".noobaa.io", }, } + err := r.SpokeClient.Get(ctx, types.NamespacedName{Name: bucket, Namespace: namespace}, noobaaOBC) + if err != nil { + if errors.IsNotFound(err) { + r.Logger.Info("ObjectBucketClaim not found, will be created", "bucket", bucket, "namespace", namespace) + } else { + r.Logger.Error("Failed to get ObjectBucketClaim", "error", err, "bucket", bucket, "namespace", namespace) + } + } else { + r.Logger.Info("ObjectBucketClaim retrieved successfully", "bucket", bucket, "namespace", namespace) + } return noobaaOBC, err } // enableMirroring is a wrapper function around toggleMirroring to enable mirroring in a storage cluster func (r *MirrorPeerReconciler) enableMirroring(ctx context.Context, storageClusterName string, namespace string, mp *multiclusterv1alpha1.MirrorPeer) error { + r.Logger.Info("Enabling mirroring on StorageCluster", "storageClusterName", storageClusterName, "namespace", namespace) return r.toggleMirroring(ctx, storageClusterName, namespace, true, mp) } @@ -307,23 +333,33 @@ func (r *MirrorPeerReconciler) toggleMirroring(ctx context.Context, storageClust if err != nil { if errors.IsNotFound(err) { - return fmt.Errorf("could not find storagecluster %q in namespace %v: %v", storageClusterName, namespace, err) + return fmt.Errorf("could not find StorageCluster %q in namespace %v: %v", storageClusterName, namespace, err) } + r.Logger.Error("Failed to retrieve StorageCluster", "storageClusterName", storageClusterName, "namespace", namespace, "error", err) return err } + + // Determine if mirroring should be enabled or disabled if enabled { oppPeers := getOppositePeerRefs(mp, r.SpokeClusterName) if hasRequiredSecret(sc.Spec.Mirroring.PeerSecretNames, oppPeers) { sc.Spec.Mirroring.Enabled = true - klog.Info("Enabled mirroring on StorageCluster ", storageClusterName) + r.Logger.Info("Mirroring enabled on StorageCluster", "storageClusterName", storageClusterName) } else { - klog.Error(err, "StorageCluster does not have required PeerSecrets") - return err + return fmt.Errorf("StorageCluster %q does not have required PeerSecrets", storageClusterName) } } else { sc.Spec.Mirroring.Enabled = false + r.Logger.Info("Mirroring disabled on StorageCluster", "storageClusterName", storageClusterName) + } + + err = r.SpokeClient.Update(ctx, &sc) + if err != nil { + r.Logger.Error("Failed to update StorageCluster mirroring settings", "storageClusterName", storageClusterName, "enabled", sc.Spec.Mirroring.Enabled, "error", err) + return err } - return r.SpokeClient.Update(ctx, &sc) + + return nil } func getOppositePeerRefs(mp *multiclusterv1alpha1.MirrorPeer, spokeClusterName string) []multiclusterv1alpha1.PeerRef { @@ -347,11 +383,10 @@ func hasRequiredSecret(peerSecrets []string, oppositePeerRef []multiclusterv1alp func (r *MirrorPeerReconciler) enableCSIAddons(ctx context.Context, namespace string) error { err := r.toggleCSIAddons(ctx, namespace, true) if err != nil { - klog.Error(err, "failed to enable CSI addons") + r.Logger.Error("Failed to enable CSI addons", "namespace", namespace, "error", err) return err - } else { - klog.Info("CSI addons enabled successfully ") } + r.Logger.Info("CSI addons enabled successfully", "namespace", namespace) return nil } @@ -364,17 +399,24 @@ func (r *MirrorPeerReconciler) toggleCSIAddons(ctx context.Context, namespace st if err != nil { if errors.IsNotFound(err) { - return fmt.Errorf("could not find rook-ceph-config-map: %v", err) + return fmt.Errorf("could not find rook-ceph-config-map in namespace %q: %v", namespace, err) } + r.Logger.Error("Failed to retrieve rook-ceph-config-map", "namespace", namespace, "error", err) return err } if rcm.Data == nil { - rcm.Data = make(map[string]string, 0) + rcm.Data = make(map[string]string) } rcm.Data[RookCSIEnableKey] = strconv.FormatBool(enabled) + err = r.SpokeClient.Update(ctx, &rcm) + if err != nil { + r.Logger.Error("Failed to update rook-ceph-config-map with CSI addon settings", "namespace", namespace, "enabled", enabled, "error", err) + return err + } - return r.SpokeClient.Update(ctx, &rcm) + r.Logger.Info("Rook-Ceph ConfigMap updated with new CSI addons setting", "namespace", namespace, "CSIEnabled", enabled) + return nil } func (r *MirrorPeerReconciler) hasSpokeCluster(obj client.Object) bool { @@ -407,6 +449,7 @@ func (r *MirrorPeerReconciler) SetupWithManager(mgr ctrl.Manager) error { }, } + r.Logger.Info("Setting up controller with manager") mpPredicate := utils.ComposePredicates(predicate.GenerationChangedPredicate{}, mirrorPeerSpokeClusterPredicate) return ctrl.NewControllerManagedBy(mgr). For(&multiclusterv1alpha1.MirrorPeer{}, builder.WithPredicates(mpPredicate)). @@ -414,17 +457,17 @@ func (r *MirrorPeerReconciler) SetupWithManager(mgr ctrl.Manager) error { } func (r *MirrorPeerReconciler) disableMirroring(ctx context.Context, storageClusterName string, namespace string, mp *multiclusterv1alpha1.MirrorPeer) error { + r.Logger.Info("Disabling mirroring on StorageCluster", "storageClusterName", storageClusterName, "namespace", namespace) return r.toggleMirroring(ctx, storageClusterName, namespace, false, mp) } func (r *MirrorPeerReconciler) disableCSIAddons(ctx context.Context, namespace string) error { err := r.toggleCSIAddons(ctx, namespace, false) if err != nil { - klog.Error(err, "Failed to disable CSI addons") + r.Logger.Error("Failed to disable CSI addons", "namespace", namespace, "error", err) return err - } else { - klog.Info("CSI addons disabled successfully ") } + r.Logger.Info("CSI addons disabled successfully", "namespace", namespace) return nil } @@ -439,16 +482,16 @@ func (r *MirrorPeerReconciler) deleteGreenSecret(ctx context.Context, spokeClust Namespace: scrNamespace, }, } - if err := r.SpokeClient.Delete(ctx, &secret); err != nil { + err := r.SpokeClient.Delete(ctx, &secret) + if err != nil { if errors.IsNotFound(err) { - klog.Info("failed to find green secret ", secretName) + r.Logger.Info("Green secret not found, no action needed", "secretName", secretName, "namespace", scrNamespace) return nil - } else { - klog.Error(err, "failed to delete green secret ", secretName) - return err } + r.Logger.Error("Failed to delete green secret", "secretName", secretName, "namespace", scrNamespace, "error", err) + return err } - klog.Info("Succesfully deleted ", secretName, " in namespace ", scrNamespace) + r.Logger.Info("Successfully deleted green secret", "secretName", secretName, "namespace", scrNamespace) } } return nil @@ -460,94 +503,113 @@ func (r *MirrorPeerReconciler) deleteS3(ctx context.Context, mirrorPeer multiclu noobaaOBC, err := r.getS3bucket(ctx, mirrorPeer, scNamespace) if err != nil { if errors.IsNotFound(err) { - klog.Info("Could not find ODR ObjectBucketClaim, skipping deletion") + r.Logger.Info("ODR ObjectBucketClaim not found, skipping deletion", "namespace", scNamespace, "MirrorPeer", mirrorPeer.Name) return nil } else { - klog.Error(err, "Failed to get ODR ObjectBucketClaim") + r.Logger.Error("Failed to retrieve ODR ObjectBucketClaim", "namespace", scNamespace, "MirrorPeer", mirrorPeer.Name, "error", err) return err } } err = r.SpokeClient.Delete(ctx, noobaaOBC) if err != nil { - klog.Error(err, "Failed to delete ODR ObjectBucketClaim") + r.Logger.Error("Failed to delete ODR ObjectBucketClaim", "ObjectBucketClaim", noobaaOBC.Name, "namespace", scNamespace, "error", err) return err } - return err + r.Logger.Info("Successfully deleted ODR ObjectBucketClaim", "ObjectBucketClaim", noobaaOBC.Name, "namespace", scNamespace) + return nil } func (r *MirrorPeerReconciler) deleteMirrorPeer(ctx context.Context, mirrorPeer multiclusterv1alpha1.MirrorPeer, scr *multiclusterv1alpha1.StorageClusterRef) (ctrl.Result, error) { - klog.Infof("Mirrorpeer is being deleted %q", mirrorPeer.Name) + r.Logger.Info("MirrorPeer is being deleted", "MirrorPeer", mirrorPeer.Name) + peerRef, err := utils.GetPeerRefForSpokeCluster(&mirrorPeer, r.SpokeClusterName) if err != nil { - klog.Errorf("Failed to get current PeerRef %q %v", mirrorPeer.Name, err) + r.Logger.Error("Failed to get current PeerRef", "MirrorPeer", mirrorPeer.Name, "error", err) return ctrl.Result{}, err } peerRefUsed, err := utils.DoesAnotherMirrorPeerPointToPeerRef(ctx, r.HubClient, peerRef) if err != nil { - klog.Errorf("failed to check if another peer uses peer ref %v", err) + r.Logger.Error("Failed to check if another MirrorPeer uses PeerRef", "error", err) + return ctrl.Result{}, err } + if !peerRefUsed { if err := r.disableMirroring(ctx, scr.Name, scr.Namespace, &mirrorPeer); err != nil { - return ctrl.Result{}, fmt.Errorf("failed to disable mirroring for the storagecluster %q in namespace %q. Error %v", scr.Name, scr.Namespace, err) + r.Logger.Error("Failed to disable mirroring for the StorageCluster", "StorageCluster", scr.Name, "namespace", scr.Namespace, "error", err) + return ctrl.Result{}, fmt.Errorf("failed to disable mirroring for the StorageCluster %q in namespace %q. Error %v", scr.Name, scr.Namespace, err) } if err := r.disableCSIAddons(ctx, scr.Namespace); err != nil { + r.Logger.Error("Failed to disable CSI Addons for Rook", "namespace", scr.Namespace, "error", err) return ctrl.Result{}, fmt.Errorf("failed to disable CSI Addons for rook: %v", err) } } if err := r.deleteGreenSecret(ctx, r.SpokeClusterName, scr.Namespace, &mirrorPeer); err != nil { + r.Logger.Error("Failed to delete green secrets", "namespace", scr.Namespace, "error", err) return ctrl.Result{}, fmt.Errorf("failed to delete green secrets: %v", err) } if err := r.deleteS3(ctx, mirrorPeer, scr.Namespace); err != nil { - return ctrl.Result{}, fmt.Errorf("failed to delete s3 buckets") + r.Logger.Error("Failed to delete S3 buckets", "namespace", scr.Namespace, "error", err) + return ctrl.Result{}, fmt.Errorf("failed to delete S3 buckets") } + + r.Logger.Info("Successfully completed the deletion of MirrorPeer resources", "MirrorPeer", mirrorPeer.Name) return ctrl.Result{}, nil } func (r *MirrorPeerReconciler) labelCephClusters(ctx context.Context, scr *multiclusterv1alpha1.StorageClusterRef, clusterFSIDs map[string]string) error { - klog.Info("Labelling cephclusters with replication id") + r.Logger.Info("Labelling CephClusters with replication ID") cephClusters, err := utils.FetchAllCephClusters(ctx, r.SpokeClient) if err != nil { - klog.Errorf("failed to fetch all cephclusters. err=%v", err) + r.Logger.Error("Failed to fetch all CephClusters", "error", err) return err } if cephClusters == nil || len(cephClusters.Items) == 0 { - klog.Info("failed to find any cephclusters to label") + r.Logger.Info("No CephClusters found to label") return nil } + var found rookv1.CephCluster + foundFlag := false for _, cc := range cephClusters.Items { for _, ref := range cc.OwnerReferences { - if ref.Kind != "StorageCluster" { - continue - } - - if ref.Name == scr.Name { + if ref.Kind == "StorageCluster" && ref.Name == scr.Name { found = cc + foundFlag = true break } } + if foundFlag { + break + } } + if !foundFlag { + r.Logger.Info("No CephCluster matched the StorageCluster reference", "StorageClusterRef", scr.Name) + return nil + } + if found.Labels == nil { found.Labels = make(map[string]string) } replicationId, err := utils.CreateUniqueReplicationId(clusterFSIDs) if err != nil { + r.Logger.Error("Failed to create a unique replication ID", "error", err) return err } if found.Labels[utils.CephClusterReplicationIdLabel] != replicationId { - klog.Infof("adding label %s/%s to cephcluster %s", utils.CephClusterReplicationIdLabel, replicationId, found.Name) + r.Logger.Info("Adding label to CephCluster", "label", utils.CephClusterReplicationIdLabel, "replicationId", replicationId, "CephCluster", found.Name) found.Labels[utils.CephClusterReplicationIdLabel] = replicationId err = r.SpokeClient.Update(ctx, &found) if err != nil { + r.Logger.Error("Failed to update CephCluster with new label", "CephCluster", found.Name, "label", utils.CephClusterReplicationIdLabel, "error", err) return err } } else { - klog.Infof("cephcluster %s is already labeled with replicationId=%q", found.Name, replicationId) + r.Logger.Info("CephCluster already labeled with replication ID", "CephCluster", found.Name, "replicationId", replicationId) } return nil diff --git a/addons/agent_mirrorpeer_controller_test.go b/addons/agent_mirrorpeer_controller_test.go index 8a715de3..2b8c0095 100644 --- a/addons/agent_mirrorpeer_controller_test.go +++ b/addons/agent_mirrorpeer_controller_test.go @@ -148,6 +148,7 @@ func TestMirrorPeerReconcile(t *testing.T) { SpokeClient: fakeSpokeClient, Scheme: scheme, SpokeClusterName: pr.ClusterName, + Logger: utils.GetLogger(utils.GetZapLogger(true)), } req := ctrl.Request{ @@ -209,6 +210,7 @@ func TestDisableMirroring(t *testing.T) { SpokeClient: fakeSpokeClient, Scheme: scheme, SpokeClusterName: pr.ClusterName, + Logger: utils.GetLogger(utils.GetZapLogger(true)), } if err := r.disableMirroring(ctx, pr.StorageClusterRef.Name, pr.StorageClusterRef.Namespace, &mirrorpeer1); err != nil { t.Error("failed to disable mirroring", err) @@ -258,6 +260,7 @@ func TestDeleteGreenSecret(t *testing.T) { SpokeClient: fakeSpokeClient, Scheme: scheme, SpokeClusterName: pr.ClusterName, + Logger: utils.GetLogger(utils.GetZapLogger(true)), } if err := r.deleteGreenSecret(ctx, pr.ClusterName, pr.StorageClusterRef.Namespace, &mirrorpeer1); err != nil { @@ -297,6 +300,7 @@ func TestDeleteS3(t *testing.T) { SpokeClient: fakeSpokeClient, Scheme: scheme, SpokeClusterName: pr.ClusterName, + Logger: utils.GetLogger(utils.GetZapLogger(true)), } if err := r.deleteS3(ctx, mirrorpeer1, pr.StorageClusterRef.Namespace); err != nil { t.Errorf("failed to delete s3 bucket") diff --git a/addons/blue_secret_controller.go b/addons/blue_secret_controller.go index 816bbcd5..383543f5 100644 --- a/addons/blue_secret_controller.go +++ b/addons/blue_secret_controller.go @@ -2,6 +2,7 @@ package addons import ( "context" + "log/slog" ctrl "sigs.k8s.io/controller-runtime" "sigs.k8s.io/controller-runtime/pkg/builder" @@ -13,7 +14,6 @@ import ( corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" "k8s.io/apimachinery/pkg/runtime" - "k8s.io/klog/v2" ) // BlueSecretReconciler reconciles a MirrorPeer object @@ -22,6 +22,7 @@ type BlueSecretReconciler struct { HubClient client.Client SpokeClient client.Client SpokeClusterName string + Logger *slog.Logger } // SetupWithManager sets up the controller with the Manager. @@ -45,6 +46,8 @@ func (r *BlueSecretReconciler) SetupWithManager(mgr ctrl.Manager) error { }, } + r.Logger.Info("Setting up controller with manager") + return ctrl.NewControllerManagedBy(mgr). Named("bluesecret_controller"). Watches(&corev1.Secret{}, &handler.EnqueueRequestForObject{}, @@ -55,22 +58,26 @@ func (r *BlueSecretReconciler) SetupWithManager(mgr ctrl.Manager) error { func (r *BlueSecretReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { var err error var secret corev1.Secret + logger := r.Logger.With("secret", req.NamespacedName.String()) - klog.Info("Reconciling blue secret", "secret", req.NamespacedName.String()) + logger.Info("Starting reconciliation for BlueSecret") err = r.SpokeClient.Get(ctx, req.NamespacedName, &secret) if err != nil { if errors.IsNotFound(err) { - klog.Infof("Could not find secret. Ignoring since it must have been deleted") + logger.Info("BlueSecret not found, possibly deleted") return ctrl.Result{}, nil } - klog.Error("Failed to get secret.", err) + logger.Error("Failed to retrieve BlueSecret", "error", err) return ctrl.Result{}, err } + logger.Info("Successfully retrieved BlueSecret") err = r.syncBlueSecretForRook(ctx, secret) if err != nil { + logger.Error("Failed to synchronize BlueSecret", "error", err) return ctrl.Result{}, err } + logger.Info("Reconciliation complete for BlueSecret") return ctrl.Result{}, nil } diff --git a/addons/blue_secret_controller_test.go b/addons/blue_secret_controller_test.go deleted file mode 100644 index 18905618..00000000 --- a/addons/blue_secret_controller_test.go +++ /dev/null @@ -1 +0,0 @@ -package addons diff --git a/addons/green_secret_controller.go b/addons/green_secret_controller.go index 320269b3..ecf5c6a5 100644 --- a/addons/green_secret_controller.go +++ b/addons/green_secret_controller.go @@ -3,13 +3,13 @@ package addons import ( "context" "fmt" + "log/slog" "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/runtime" - "k8s.io/klog/v2" ctrl "sigs.k8s.io/controller-runtime" "sigs.k8s.io/controller-runtime/pkg/builder" "sigs.k8s.io/controller-runtime/pkg/client" @@ -24,6 +24,7 @@ type GreenSecretReconciler struct { HubClient client.Client SpokeClient client.Client SpokeClusterName string + Logger *slog.Logger } // SetupWithManager sets up the controller with the Manager. @@ -51,6 +52,8 @@ func (r *GreenSecretReconciler) SetupWithManager(mgr ctrl.Manager) error { }, } + r.Logger.Info("Setting up controller with manager") + return ctrl.NewControllerManagedBy(mgr). Named("greensecret_controller"). Watches(&corev1.Secret{}, &handler.EnqueueRequestForObject{}, @@ -61,26 +64,30 @@ func (r *GreenSecretReconciler) SetupWithManager(mgr ctrl.Manager) error { func (r *GreenSecretReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { var err error var greenSecret corev1.Secret + logger := r.Logger.With("secret", req.NamespacedName.String()) - klog.Info("Reconciling green secret", "secret", req.NamespacedName.String()) + logger.Info("Reconciling green secret") err = r.HubClient.Get(ctx, req.NamespacedName, &greenSecret) if err != nil { if errors.IsNotFound(err) { - klog.Infof("Could not find secret. Ignoring since it must have been deleted") + logger.Info("Green secret not found, likely deleted") return ctrl.Result{}, nil } - klog.Error("Failed to get secret.", err) + logger.Error("Failed to retrieve green secret", "error", err) return ctrl.Result{}, err } if err = validateGreenSecret(greenSecret); err != nil { - return ctrl.Result{}, fmt.Errorf("failed to validate secret %q", greenSecret.Name) + logger.Error("Validation failed for green secret", "error", err) + return ctrl.Result{}, fmt.Errorf("failed to validate green secret %q: %v", greenSecret.Name, err) } err = r.syncGreenSecretForRook(ctx, greenSecret) if err != nil { + logger.Error("Failed to sync green secret for Rook", "error", err) return ctrl.Result{}, err } + logger.Info("Successfully reconciled and synced green secret") return ctrl.Result{}, nil } diff --git a/addons/green_secret_controller_test.go b/addons/green_secret_controller_test.go deleted file mode 100644 index 18905618..00000000 --- a/addons/green_secret_controller_test.go +++ /dev/null @@ -1 +0,0 @@ -package addons diff --git a/addons/maintenance_mode_controller.go b/addons/maintenance_mode_controller.go index 4f6fdfe4..b1c363a4 100644 --- a/addons/maintenance_mode_controller.go +++ b/addons/maintenance_mode_controller.go @@ -3,6 +3,7 @@ package addons import ( "context" "fmt" + "log/slog" ramenv1alpha1 "github.com/ramendr/ramen/api/v1alpha1" ocsv1 "github.com/red-hat-storage/ocs-operator/api/v1" @@ -16,7 +17,6 @@ import ( "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/selection" "k8s.io/apimachinery/pkg/types" - "k8s.io/klog/v2" ctrl "sigs.k8s.io/controller-runtime" "sigs.k8s.io/controller-runtime/pkg/builder" "sigs.k8s.io/controller-runtime/pkg/client" @@ -28,9 +28,12 @@ type MaintenanceModeReconciler struct { Scheme *runtime.Scheme SpokeClient client.Client SpokeClusterName string + Logger *slog.Logger } func (r *MaintenanceModeReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger.Info("Setting up controller with manager") + return ctrl.NewControllerManagedBy(mgr). Named("maintenancemode_controller"). Watches(&ramenv1alpha1.MaintenanceMode{}, &handler.EnqueueRequestForObject{}, @@ -39,34 +42,34 @@ func (r *MaintenanceModeReconciler) SetupWithManager(mgr ctrl.Manager) error { } func (r *MaintenanceModeReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { - klog.Info("starting reconcile for maintenancemode") - // Fetch MaintenanceMode for given Request + logger := r.Logger.With("MaintenanceMode", req.NamespacedName) + logger.Info("Starting reconcile for MaintenanceMode") + var mmode ramenv1alpha1.MaintenanceMode err := r.SpokeClient.Get(ctx, req.NamespacedName, &mmode) if err != nil { if k8serrors.IsNotFound(err) { - klog.Infof("Could not find MaintenanceMode. Ignoring since object must have been deleted.") + logger.Info("MaintenanceMode not found, ignoring since object must have been deleted") return ctrl.Result{}, nil } - klog.Error("Failed to get MaintenanceMode.", err) + logger.Error("Failed to get MaintenanceMode", "error", err) return ctrl.Result{}, err } cephClusters, err := utils.FetchAllCephClusters(ctx, r.SpokeClient) if err != nil { + logger.Error("Failed to fetch all CephClusters", "error", err) return ctrl.Result{}, err } - if cephClusters == nil || len(cephClusters.Items) == 0 { - klog.Infof("No CephClusters available on the cluster.") + if len(cephClusters.Items) == 0 { + logger.Info("No CephClusters available on the cluster") return ctrl.Result{Requeue: true}, nil } actionableCephCluster := filterCephClustersByStorageIdOrReplicationId(cephClusters, mmode.Spec.TargetID, mmode.Spec.StorageProvisioner) - if actionableCephCluster == nil { - klog.Infof("No CephCluster present with required parameters for maintenance. StorageId/ReplicationId=%s , Provisioner=%s ", mmode.Spec.TargetID, mmode.Spec.StorageProvisioner) - // Requeueing the request as the cephcluster can be potentially found if it is labeled later. + logger.Info("No CephCluster present with required parameters for maintenance", "StorageId/ReplicationId", mmode.Spec.TargetID, "Provisioner", mmode.Spec.StorageProvisioner) return ctrl.Result{Requeue: true}, nil } @@ -76,26 +79,25 @@ func (r *MaintenanceModeReconciler) Reconcile(ctx context.Context, req ctrl.Requ } result, err := r.startMaintenanceActions(ctx, &mmode, actionableCephCluster, false) if err != nil { - klog.Errorf("failed to complete maintenance actions on %s. err=%v", mmode.Name, err) + logger.Error("Failed to complete maintenance actions", "error", err) return result, err } if !result.Requeue { mmode.Finalizers = utils.RemoveString(mmode.Finalizers, MaintenanceModeFinalizer) - err = r.SpokeClient.Update(ctx, &mmode) - if err != nil { - klog.Errorf("failed to remove finalizer from MaintenanceMode %s. err=%v", mmode.Name, err) + if err := r.SpokeClient.Update(ctx, &mmode); err != nil { + logger.Error("Failed to remove finalizer from MaintenanceMode", "error", err) return ctrl.Result{}, err } + logger.Info("MaintenanceMode disabled") } - klog.Info("MaintenanceMode disabled") return result, nil } if !utils.ContainsString(mmode.GetFinalizers(), MaintenanceModeFinalizer) { - klog.Infof("finalizer not found on MaintenanceMode. adding Finalizer=%s", MaintenanceModeFinalizer) + r.Logger.Info("Adding finalizer to MaintenanceMode", "finalizer", MaintenanceModeFinalizer) mmode.Finalizers = append(mmode.Finalizers, MaintenanceModeFinalizer) if err := r.SpokeClient.Update(ctx, &mmode); err != nil { - klog.Errorf("failed to add finalizer to MaintenanceMode=%s. err=%v ", mmode.Name, err) + r.Logger.Error("Failed to add finalizer to MaintenanceMode", "error", err) return ctrl.Result{}, err } } @@ -105,42 +107,44 @@ func (r *MaintenanceModeReconciler) Reconcile(ctx context.Context, req ctrl.Requ } result, err := r.startMaintenanceActions(ctx, &mmode, actionableCephCluster, true) - statusErr := r.SpokeClient.Status().Update(ctx, &mmode) - if statusErr != nil { - klog.Errorf("failed to update status of maintenancemode=%s. err=%v", mmode.Name, statusErr) + if statusErr := r.SpokeClient.Status().Update(ctx, &mmode); statusErr != nil { + r.Logger.Error("Failed to update status of MaintenanceMode", "error", statusErr) return result, statusErr } if err != nil { - klog.Errorf("failed to complete maintenance actions on %s. err=%v", mmode.Name, err) + r.Logger.Error("Failed to complete maintenance actions", "error", err) } return result, err } func (r *MaintenanceModeReconciler) startMaintenanceActions(ctx context.Context, mmode *ramenv1alpha1.MaintenanceMode, cluster *rookv1.CephCluster, scaleDown bool) (ctrl.Result, error) { - klog.Infof("starting actions on MaintenanceMode %q", mmode.Name) + r.Logger.Info("Starting actions on MaintenanceMode", "MaintenanceMode", mmode.Name) for _, mode := range mmode.Spec.Modes { - SetStatus(mmode, mode, ramenv1alpha1.MModeStateProgressing, nil) + SetStatus(r.Logger, mmode, mode, ramenv1alpha1.MModeStateProgressing, nil) switch mode { case ramenv1alpha1.MModeFailover: var replicas int if scaleDown { - klog.Info("Scaling down RBD mirror deployments") + r.Logger.Info("Scaling down RBD mirror deployments") replicas = 0 } else { - klog.Info("Scaling up RBD mirror deployments") + r.Logger.Info("Scaling up RBD mirror deployments") replicas = 1 } result, err := r.scaleRBDMirrorDeployment(ctx, *cluster, replicas) if err != nil { - SetStatus(mmode, mode, ramenv1alpha1.MModeStateError, err) + r.Logger.Error("Failed to scale RBD mirror deployments", "error", err) + SetStatus(r.Logger, mmode, mode, ramenv1alpha1.MModeStateError, err) return result, err } if !result.Requeue { - SetStatus(mmode, mode, ramenv1alpha1.MModeStateCompleted, nil) + SetStatus(r.Logger, mmode, mode, ramenv1alpha1.MModeStateCompleted, nil) } - return result, err + return result, nil default: - return ctrl.Result{}, fmt.Errorf("no actions found for %q mode", mode) + err := fmt.Errorf("no actions found for %q mode", mode) + r.Logger.Error("No actions found for specified mode", "mode", mode, "error", err) + return ctrl.Result{}, err } } return ctrl.Result{}, nil @@ -149,21 +153,27 @@ func (r *MaintenanceModeReconciler) startMaintenanceActions(ctx context.Context, func (r *MaintenanceModeReconciler) scaleRBDMirrorDeployment(ctx context.Context, cluster rookv1.CephCluster, replicas int) (ctrl.Result, error) { isMirroringEnabled, err := r.isStorageClusterMirroringEnabled(ctx, cluster) if err != nil { - klog.Errorf("error occurred on checking mirroring enablement on storagecluster for cephcluster %s", cluster.Name) + r.Logger.Error("Error checking mirroring enablement on StorageCluster", "CephCluster", cluster.Name, "error", err) return ctrl.Result{}, err } if !isMirroringEnabled { - klog.Info("storagecluster mirroring is not enabled yet. please enable it manually or wait for it to be enabled to perform further maintenance actions") + r.Logger.Info("StorageCluster mirroring is not enabled yet. Please enable it manually or wait for it to be enabled to perform further maintenance actions") return ctrl.Result{Requeue: true}, nil } - deployments, err := GetDeploymentsStartingWith(ctx, r.SpokeClient, cluster.Namespace, RBDMirrorDeploymentNamePrefix) + + deployments, err := GetDeploymentsStartingWith(ctx, r.SpokeClient, cluster.Namespace, RBDMirrorDeploymentNamePrefix, r.Logger) if err != nil { + r.Logger.Error("Failed to get deployments starting with prefix", "namespace", cluster.Namespace, "prefix", RBDMirrorDeploymentNamePrefix, "error", err) return ctrl.Result{}, err } for _, deploymentName := range deployments { + r.Logger.Info("Scaling deployment", "deploymentName", deploymentName, "namespace", cluster.Namespace, "replicas", replicas) requeue, err := utils.ScaleDeployment(ctx, r.SpokeClient, deploymentName, cluster.Namespace, int32(replicas)) - return ctrl.Result{Requeue: requeue}, err + if err != nil { + r.Logger.Error("Failed to scale deployment", "deploymentName", deploymentName, "namespace", cluster.Namespace, "error", err) + return ctrl.Result{Requeue: requeue}, err + } } return ctrl.Result{}, nil } @@ -173,13 +183,16 @@ func (r *MaintenanceModeReconciler) isStorageClusterMirroringEnabled(ctx context var sc ocsv1.StorageCluster scName := getOwnerName(cephCluster) if scName == "" { - return false, fmt.Errorf("no storagecluster found for given cephcluster %s", cephCluster.Name) + return false, fmt.Errorf("no StorageCluster found for given CephCluster %s", cephCluster.Name) } + err := r.SpokeClient.Get(ctx, types.NamespacedName{Name: scName, Namespace: cephCluster.Namespace}, &sc) if err != nil { - klog.Errorf("no storagecluster found for given cephcluster %s", cephCluster.Name) + r.Logger.Error("No StorageCluster found for CephCluster", "CephCluster", cephCluster.Name, "error", err) return false, err } + + r.Logger.Info("StorageCluster mirroring is enabled", "CephCluster", cephCluster.Name, "StorageCluster", sc.Name) return true, nil } @@ -193,8 +206,7 @@ func getOwnerName(cluster rookv1.CephCluster) string { return "" } -func SetStatus(mmode *ramenv1alpha1.MaintenanceMode, mode ramenv1alpha1.MMode, state ramenv1alpha1.MModeState, err error) { - klog.Infof("mode: %s, status: %s, generation: %d, error: %v ", mode, state, mmode.Generation, err) +func SetStatus(logger *slog.Logger, mmode *ramenv1alpha1.MaintenanceMode, mode ramenv1alpha1.MMode, state ramenv1alpha1.MModeState, err error) { mmode.Status.State = state mmode.Status.ObservedGeneration = mmode.Generation k8smeta.SetStatusCondition(&mmode.Status.Conditions, newCondition(state, mode, mmode.Generation, err)) @@ -232,11 +244,12 @@ func newCondition(state ramenv1alpha1.MModeState, mode ramenv1alpha1.MMode, gene } } -func GetDeploymentsStartingWith(ctx context.Context, spokeClient client.Client, namespace string, prefix string) ([]string, error) { +func GetDeploymentsStartingWith(ctx context.Context, spokeClient client.Client, namespace string, prefix string, logger *slog.Logger) ([]string, error) { deploymentList := &appsv1.DeploymentList{} rookMirrorDeploymentLabel, err := labels.NewRequirement("app", selection.Equals, []string{"rook-ceph-rbd-mirror"}) if err != nil { - klog.Error(err, "cannot parse new requirement") + logger.Error("Cannot parse new requirement", "error", err) + return nil, err } deploymentSelector := labels.NewSelector().Add(*rookMirrorDeploymentLabel) @@ -247,6 +260,7 @@ func GetDeploymentsStartingWith(ctx context.Context, spokeClient client.Client, err = spokeClient.List(ctx, deploymentList, listOpts) if err != nil { + logger.Error("Failed to list deployments", "namespace", namespace, "error", err) return nil, err } @@ -259,6 +273,7 @@ func GetDeploymentsStartingWith(ctx context.Context, spokeClient client.Client, deploymentNames = append(deploymentNames, deployment.ObjectMeta.Name) } + logger.Info("Deployments found with specified prefix", "prefix", prefix, "deploymentNames", deploymentNames) return deploymentNames, nil } diff --git a/addons/manager.go b/addons/manager.go index f47ca768..678d80a3 100644 --- a/addons/manager.go +++ b/addons/manager.go @@ -2,18 +2,20 @@ package addons import ( "context" - "flag" "fmt" + "log/slog" "os" "time" replicationv1alpha1 "github.com/csi-addons/kubernetes-csi-addons/apis/replication.storage/v1alpha1" + "github.com/go-logr/zapr" obv1alpha1 "github.com/kube-object-storage/lib-bucket-provisioner/pkg/apis/objectbucket.io/v1alpha1" routev1 "github.com/openshift/api/route/v1" ramenv1alpha1 "github.com/ramendr/ramen/api/v1alpha1" ocsv1 "github.com/red-hat-storage/ocs-operator/api/v1" "github.com/red-hat-storage/odf-multicluster-orchestrator/addons/setup" multiclusterv1alpha1 "github.com/red-hat-storage/odf-multicluster-orchestrator/api/v1alpha1" + "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" rookv1 "github.com/rook/rook/pkg/apis/ceph.rook.io/v1" "github.com/spf13/cobra" appsv1 "k8s.io/api/apps/v1" @@ -35,7 +37,6 @@ import ( ctrl "sigs.k8s.io/controller-runtime" "sigs.k8s.io/controller-runtime/pkg/cache" "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log/zap" "sigs.k8s.io/controller-runtime/pkg/manager" "sigs.k8s.io/controller-runtime/pkg/metrics/server" ) @@ -86,7 +87,7 @@ type AddonAgentOptions struct { HubKubeconfigFile string SpokeClusterName string DRMode string - ZapOpts zap.Options + DevMode bool } func (o *AddonAgentOptions) AddFlags(cmd *cobra.Command) { @@ -99,29 +100,38 @@ func (o *AddonAgentOptions) AddFlags(cmd *cobra.Command) { flags.StringVar(&o.HubKubeconfigFile, "hub-kubeconfig", o.HubKubeconfigFile, "Location of kubeconfig file to connect to hub cluster.") flags.StringVar(&o.SpokeClusterName, "cluster-name", o.SpokeClusterName, "Name of spoke cluster.") flags.StringVar(&o.DRMode, "mode", o.DRMode, "The DR mode of token exchange addon. Valid values are: 'sync', 'async'") - gfs := flag.NewFlagSet("", flag.ExitOnError) - o.ZapOpts = zap.Options{ - Development: true, - } - o.ZapOpts.BindFlags(gfs) - flags.AddGoFlagSet(gfs) + flags.BoolVar(&o.DevMode, "dev", false, "Set to true for dev environment (Text logging)") } // RunAgent starts the controllers on agent to process work from hub. func (o *AddonAgentOptions) RunAgent(ctx context.Context) { - klog.Infof("Starting addon agents.") - + zapLogger := utils.GetZapLogger(o.DevMode) + defer func() { + if err := zapLogger.Sync(); err != nil { + zapLogger.Error("Failed to sync zap logger") + } + }() + ctrl.SetLogger(zapr.NewLogger(zapLogger)) + logger := utils.GetLogger(zapLogger) + logger.Info("Starting addon agents.") cc, err := addonutils.NewConfigChecker("agent kubeconfig checker", o.HubKubeconfigFile) if err != nil { - klog.Error(err, "ConfigChecker could not be created") + logger.Error("ConfigChecker could not be created", "error", err) os.Exit(1) } - go setup.ServeHealthProbes(ctx.Done(), ":8000", cc.Check) - go runSpokeManager(ctx, *o) - go runHubManager(ctx, *o) + logger.Info("Serving health probes on port 8000") + go setup.ServeHealthProbes(ctx.Done(), ":8000", cc.Check, logger) + + logger.Info("Starting spoke manager") + go runSpokeManager(ctx, *o, logger) + + logger.Info("Starting hub manager") + go runHubManager(ctx, *o, logger) + logger.Info("Addon agent is running, waiting for context cancellation") <-ctx.Done() + logger.Info("Addon agent has stopped") } // GetClientFromConfig returns a controller-runtime Client for a rest.Config @@ -142,16 +152,16 @@ func GetClientConfig(kubeConfigFile string) (*rest.Config, error) { return clientconfig, nil } -func runHubManager(ctx context.Context, options AddonAgentOptions) { +func runHubManager(ctx context.Context, options AddonAgentOptions, logger *slog.Logger) { hubConfig, err := GetClientConfig(options.HubKubeconfigFile) if err != nil { - klog.Error(err, "unable to get kubeconfig") + logger.Error("Failed to get kubeconfig", "error", err) os.Exit(1) } spokeClient, err := GetClientFromConfig(ctrl.GetConfigOrDie()) if err != nil { - klog.Error(err, "unable to get spoke client") + logger.Error("Failed to get spoke client", "error", err) os.Exit(1) } @@ -169,7 +179,7 @@ func runHubManager(ctx context.Context, options AddonAgentOptions) { }, }) if err != nil { - klog.Error(err, "unable to start manager") + logger.Error("Failed to start manager", "error", err) os.Exit(1) } @@ -178,8 +188,9 @@ func runHubManager(ctx context.Context, options AddonAgentOptions) { HubClient: mgr.GetClient(), SpokeClient: spokeClient, SpokeClusterName: options.SpokeClusterName, + Logger: logger.With("controller", "MirrorPeerReconciler"), }).SetupWithManager(mgr); err != nil { - klog.Error(err, "unable to create controller", "controller", "MirrorPeer") + logger.Error("Failed to create MirrorPeer controller", "controller", "MirrorPeer", "error", err) os.Exit(1) } @@ -188,28 +199,29 @@ func runHubManager(ctx context.Context, options AddonAgentOptions) { HubClient: mgr.GetClient(), SpokeClient: spokeClient, SpokeClusterName: options.SpokeClusterName, + Logger: logger.With("controller", "GreenSecretReconciler"), }).SetupWithManager(mgr); err != nil { - klog.Error(err, "unable to create controller", "controller", "GreenSecret") + logger.Error("Failed to create GreenSecret controller", "controller", "GreenSecret", "error", err) os.Exit(1) } - klog.Info("starting hub controller manager") + logger.Info("Starting hub controller manager") if err := mgr.Start(ctx); err != nil { - klog.Error(err, "problem running hub controller manager") + logger.Error("Problem running hub controller manager", "error", err) os.Exit(1) } } -func runSpokeManager(ctx context.Context, options AddonAgentOptions) { +func runSpokeManager(ctx context.Context, options AddonAgentOptions, logger *slog.Logger) { hubConfig, err := GetClientConfig(options.HubKubeconfigFile) if err != nil { - klog.Error(err, "unable to get kubeconfig") + logger.Error("Failed to get kubeconfig", "error", err) os.Exit(1) } hubClient, err := GetClientFromConfig(hubConfig) if err != nil { - klog.Error(err, "unable to get spoke client") + logger.Error("Failed to get spoke client", "error", err) os.Exit(1) } @@ -223,28 +235,28 @@ func runSpokeManager(ctx context.Context, options AddonAgentOptions) { }) if err != nil { - klog.Error(err, "unable to start manager") + logger.Error("Failed to start manager", "error", err) os.Exit(1) } spokeKubeConfig := mgr.GetConfig() spokeKubeClient, err := kubernetes.NewForConfig(spokeKubeConfig) if err != nil { - klog.Error(err, "unable to get spoke kube client") + logger.Error("Failed to get spoke kube client", "error", err) os.Exit(1) } currentNamespace := os.Getenv("POD_NAMESPACE") if err = mgr.Add(manager.RunnableFunc(func(ctx context.Context) error { - klog.Infof("Waiting for MaintenanceMode CRD to be created. MaintenanceMode controller is not running yet.") + logger.Info("Waiting for MaintenanceMode CRD to be established. MaintenanceMode controller is not running yet.") // Wait for 45s as it takes time for MaintenanceMode CRD to be created. return runtimewait.PollUntilContextCancel(ctx, 15*time.Second, true, func(ctx context.Context) (done bool, err error) { var crd extv1.CustomResourceDefinition readErr := mgr.GetAPIReader().Get(ctx, types.NamespacedName{Name: "maintenancemodes.ramendr.openshift.io"}, &crd) if readErr != nil { - klog.Error("Unable to get MaintenanceMode CRD", readErr) + logger.Error("Unable to get MaintenanceMode CRD", readErr) // Do not initialize err as we want to retry. // err!=nil or done==true will end polling. done = false @@ -255,11 +267,12 @@ func runSpokeManager(ctx context.Context, options AddonAgentOptions) { Scheme: mgr.GetScheme(), SpokeClient: mgr.GetClient(), SpokeClusterName: options.SpokeClusterName, + Logger: logger.With("controller", "MaintenanceModeReconciler"), }).SetupWithManager(mgr); err != nil { klog.Error("Unable to create MaintenanceMode controller.", err) return } - klog.Infof("MaintenanceMode CRD exists. MaintenanceMode controller is now running.") + logger.Info("MaintenanceMode CRD exists and controller is now running") done = true return } @@ -267,12 +280,12 @@ func runSpokeManager(ctx context.Context, options AddonAgentOptions) { return }) })); err != nil { - klog.Error("unable to poll MaintenanceMode", err) + logger.Error("Failed to poll MaintenanceMode", "error", err) os.Exit(1) } if err = mgr.Add(manager.RunnableFunc(func(ctx context.Context) error { - klog.Infof("Starting lease updater.") + logger.Info("Starting lease updater") leaseUpdater := lease.NewLeaseUpdater( spokeKubeClient, setup.TokenExchangeName, @@ -282,7 +295,7 @@ func runSpokeManager(ctx context.Context, options AddonAgentOptions) { <-ctx.Done() return nil })); err != nil { - klog.Error("unable to start lease updater", err) + logger.Error("Failed to start lease updater", "error", err) os.Exit(1) } @@ -291,8 +304,9 @@ func runSpokeManager(ctx context.Context, options AddonAgentOptions) { HubClient: hubClient, SpokeClient: mgr.GetClient(), SpokeClusterName: options.SpokeClusterName, + Logger: logger.With("controller", "BlueSecretReconciler"), }).SetupWithManager(mgr); err != nil { - klog.Error(err, "unable to create controller", "controller", "BlueSecret") + logger.Error("Failed to create BlueSecret controller", "controller", "BlueSecret", "error", err) os.Exit(1) } @@ -301,14 +315,15 @@ func runSpokeManager(ctx context.Context, options AddonAgentOptions) { HubClient: hubClient, SpokeClient: mgr.GetClient(), SpokeClusterName: options.SpokeClusterName, + Logger: logger.With("controller", "S3SecretReconciler"), }).SetupWithManager(mgr); err != nil { - klog.Error(err, "unable to create controller", "controller", "S3Secret") + logger.Error("Failed to create S3Secret controller", "controller", "S3Secret", "error", err) os.Exit(1) } - klog.Info("starting spoke controller manager") + logger.Info("Starting spoke controller manager") if err := mgr.Start(ctx); err != nil { - klog.Error(err, "problem running spoke controller manager") + logger.Error("Problem running spoke controller manager", "error", err) os.Exit(1) } } diff --git a/addons/rook_secret_handler.go b/addons/rook_secret_handler.go index f4edca51..7b56e521 100644 --- a/addons/rook_secret_handler.go +++ b/addons/rook_secret_handler.go @@ -13,9 +13,9 @@ import ( rookv1 "github.com/rook/rook/pkg/apis/ceph.rook.io/v1" corev1 "k8s.io/api/core/v1" + "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/types" - "k8s.io/klog/v2" "sigs.k8s.io/controller-runtime/pkg/client" ) @@ -53,6 +53,7 @@ func getBlueSecretFilterForRook(obj interface{}) bool { } func (r *BlueSecretReconciler) syncBlueSecretForRook(ctx context.Context, secret corev1.Secret) error { + logger := r.Logger.With("secret", secret.Name, "namespace", secret.Namespace) // fetch storage cluster name storageClusterName, err := getStorageClusterFromRookSecret(ctx, r.SpokeClient, secret) if err != nil { @@ -64,12 +65,11 @@ func (r *BlueSecretReconciler) syncBlueSecretForRook(ctx context.Context, secret return fmt.Errorf("failed to get the cluster type (converged, external) for the spoke cluster. Error %v", err) } - klog.Infof("detected cluster type: %s", string(clusterType)) + logger.Info("Detected cluster type", "clusterType", string(clusterType)) var customData map[string][]byte var labelType utils.SecretLabelType var blueSecret *corev1.Secret - // Accept secret with converged mode and secret name should not be rook-ceph-mon if clusterType == utils.CONVERGED && secret.Name != DefaultExternalSecretName { customData = map[string][]byte{ utils.SecretOriginKey: []byte(utils.OriginMap["RookOrigin"]), @@ -81,35 +81,35 @@ func (r *BlueSecretReconciler) syncBlueSecretForRook(ctx context.Context, secret if err != nil { return fmt.Errorf("failed to create secret from the managed cluster secret %q from namespace %v for the hub cluster in namespace %q err: %v", secret.Name, secret.Namespace, r.SpokeClusterName, err) } - // Accept secret if the cluster is external and secret name is rook-ceph-mon } else if clusterType == utils.EXTERNAL && secret.Name == DefaultExternalSecretName { customData = map[string][]byte{ utils.SecretOriginKey: []byte(utils.OriginMap["RookOrigin"]), utils.ClusterTypeKey: []byte(utils.EXTERNAL), } labelType = utils.InternalLabel + blueSecret, err = generateBlueSecretForExternal(secret, labelType, utils.CreateUniqueSecretName(r.SpokeClusterName, secret.Namespace, storageClusterName), storageClusterName, r.SpokeClusterName, customData) if err != nil { return fmt.Errorf("failed to create secret from the managed cluster secret %q from namespace %v for the hub cluster in namespace %q err: %v", secret.Name, secret.Namespace, r.SpokeClusterName, err) } - // If both the parameters above don't match, then it is unknown secret which is either in external or converged mode. } else if clusterType == utils.CONVERGED && secret.Name == DefaultExternalSecretName { - klog.Info("**Skip external secret in converged mode**") - // detects rook-ceph-mon in converged mode cluster. Likely scenario but we do not need to process this secret. + logger.Info("Skip external secret in converged mode") return nil } else { - // any other case than the above return fmt.Errorf("failed to create secret from the managed cluster secret %q from namespace %v for the hub cluster in namespace %q err: ClusterType is unknown, should be converged or external", secret.Name, secret.Namespace, r.SpokeClusterName) } - // Create secrete on hub cluster + // Create secret on hub cluster err = r.HubClient.Create(ctx, blueSecret, &client.CreateOptions{}) if err != nil { + if errors.IsAlreadyExists(err) { + logger.Info("Secret already exists on hub cluster, not creating again") + return nil + } return fmt.Errorf("failed to sync managed cluster secret %q from namespace %v to the hub cluster in namespace %q err: %v", secret.Name, secret.Namespace, r.SpokeClusterName, err) } - klog.Infof("successfully synced managed cluster secret %q from namespace %v to the hub cluster in namespace %q", secret.Name, secret.Namespace, r.SpokeClusterName) - + logger.Info("Successfully synced managed cluster secret to hub cluster", "hubNamespace", r.SpokeClusterName) return nil } @@ -119,7 +119,7 @@ func (r *GreenSecretReconciler) syncGreenSecretForRook(ctx context.Context, secr data := make(map[string][]byte) err = json.Unmarshal(secret.Data[utils.SecretDataKey], &data) if err != nil { - return fmt.Errorf("failed to unmarshal secret data for the secret %q in namespace %q. %v", secret.Name, secret.Namespace, err) + return fmt.Errorf("failed to unmarshal secret data for the secret %q in namespace %q: %v", secret.Name, secret.Namespace, err) } toNamespace := string(secret.Data["namespace"]) @@ -135,17 +135,20 @@ func (r *GreenSecretReconciler) syncGreenSecretForRook(ctx context.Context, secr // Create secret on spoke cluster err = r.SpokeClient.Create(ctx, newSecret, &client.CreateOptions{}) if err != nil { - return fmt.Errorf("failed to sync hub secret %q in managed cluster in namespace %q. %v", newSecret.Name, toNamespace, err) + if errors.IsAlreadyExists(err) { + r.Logger.Info("Secret already exists on spoke cluster, not creating again", "secret", newSecret.Name, "namespace", newSecret.Namespace) + return nil + } + return fmt.Errorf("failed to sync hub secret %q to managed cluster in namespace %q: %v", newSecret.Name, toNamespace, err) } storageClusterName := string(secret.Data[utils.StorageClusterNameKey]) err = updateStorageCluster(newSecret.Name, storageClusterName, toNamespace, r.SpokeClient) if err != nil { - return fmt.Errorf("failed to update secret name %q in the storageCluster %q in namespace %q. %v", newSecret.Name, storageClusterName, toNamespace, err) + return fmt.Errorf("failed to update secret %q in the storageCluster %q in namespace %q: %v", newSecret.Name, storageClusterName, toNamespace, err) } - klog.Infof("Synced hub secret %q to managed cluster in namespace %q", newSecret.Name, toNamespace) - + r.Logger.Info("Successfully synced hub secret to managed cluster", "secret", newSecret.Name, "namespace", toNamespace) return nil } @@ -159,7 +162,7 @@ func getStorageClusterFromRookSecret(ctx context.Context, client client.Client, var cephCluster rookv1.CephCluster err := client.Get(ctx, types.NamespacedName{Namespace: secret.Namespace, Name: v.Name}, &cephCluster) if err != nil { - return "", fmt.Errorf("unable to fetch ceph cluster err: %v", err) + return "", fmt.Errorf("failed to fetch CephCluster '%s' referenced by secret '%s' in namespace '%s': %v", v.Name, secret.Name, secret.Namespace, err) } for _, owner := range cephCluster.ObjectMeta.OwnerReferences { @@ -179,7 +182,7 @@ func getStorageClusterFromRookSecret(ctx context.Context, client client.Client, } if storageCluster == "" { - return storageCluster, fmt.Errorf("could not get storageCluster name") + return "", fmt.Errorf("could not determine storageCluster name from secret '%s' in namespace '%s'", secret.Name, secret.Namespace) } return storageCluster, nil diff --git a/addons/rook_secret_handler_test.go b/addons/rook_secret_handler_test.go deleted file mode 100644 index 18905618..00000000 --- a/addons/rook_secret_handler_test.go +++ /dev/null @@ -1 +0,0 @@ -package addons diff --git a/addons/s3_controller.go b/addons/s3_controller.go index 7c1e3a1f..e833ced8 100644 --- a/addons/s3_controller.go +++ b/addons/s3_controller.go @@ -2,6 +2,7 @@ package addons import ( "context" + "log/slog" "os" "strings" "time" @@ -11,7 +12,6 @@ import ( "k8s.io/apimachinery/pkg/api/errors" "k8s.io/apimachinery/pkg/runtime" - "k8s.io/klog/v2" ctrl "sigs.k8s.io/controller-runtime" "sigs.k8s.io/controller-runtime/pkg/builder" "sigs.k8s.io/controller-runtime/pkg/client" @@ -26,6 +26,7 @@ type S3SecretReconciler struct { HubClient client.Client SpokeClient client.Client SpokeClusterName string + Logger *slog.Logger } // SetupWithManager sets up the controller with the Manager. @@ -56,6 +57,8 @@ func (r *S3SecretReconciler) SetupWithManager(mgr ctrl.Manager) error { }, } + r.Logger.Info("Setting up controller with manager") + return ctrl.NewControllerManagedBy(mgr). Named("s3secret_controller"). Watches(&obv1alpha1.ObjectBucketClaim{}, &handler.EnqueueRequestForObject{}, @@ -66,26 +69,29 @@ func (r *S3SecretReconciler) SetupWithManager(mgr ctrl.Manager) error { func (r *S3SecretReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { var err error var obc obv1alpha1.ObjectBucketClaim - - klog.Info("Reconciling OBC", "OBC", req.NamespacedName.String()) + logger := r.Logger.With("OBC", req.NamespacedName.String()) + logger.Info("Reconciling OBC") err = r.SpokeClient.Get(ctx, req.NamespacedName, &obc) if err != nil { if errors.IsNotFound(err) { - klog.Info("Could not find OBC. Ignoring since object must have been deleted.") + logger.Info("OBC not found, likely deleted") return ctrl.Result{}, nil } - klog.Error("Failed to get OBC.", err) + logger.Error("Failed to retrieve OBC", "error", err) return ctrl.Result{}, err } if obc.Status.Phase != obv1alpha1.ObjectBucketClaimStatusPhaseBound { + logger.Info("OBC is not in 'Bound' status, requeuing", "st,atus", obc.Status.Phase) return ctrl.Result{RequeueAfter: 15 * time.Second}, nil } err = r.syncBlueSecretForS3(ctx, obc.Name, obc.Namespace) if err != nil { + logger.Error("Failed to sync Blue Secret for S3", "OBC", "error", err) return ctrl.Result{}, err } + logger.Info("Successfully reconciled OBC and synced Blue Secret") return ctrl.Result{}, nil } diff --git a/addons/s3_secret_handler.go b/addons/s3_secret_handler.go index 1ced9a76..f72f469c 100644 --- a/addons/s3_secret_handler.go +++ b/addons/s3_secret_handler.go @@ -9,9 +9,9 @@ import ( "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" corev1 "k8s.io/api/core/v1" + "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/types" - "k8s.io/klog/v2" "sigs.k8s.io/controller-runtime/pkg/client" ) @@ -26,23 +26,23 @@ const ( ) func (r *S3SecretReconciler) syncBlueSecretForS3(ctx context.Context, name string, namespace string) error { - // cofig map and secret name and bucket claim name is same in nooba // fetch obc secret var secret corev1.Secret err := r.SpokeClient.Get(ctx, types.NamespacedName{Namespace: namespace, Name: name}, &secret) if err != nil { - return fmt.Errorf("failed to get the secret %q in namespace %q in managed cluster. Error %v", name, namespace, err) + return fmt.Errorf("failed to retrieve the secret %q in namespace %q in managed cluster: %v", name, namespace, err) } // fetch obc config map var configMap corev1.ConfigMap err = r.SpokeClient.Get(ctx, types.NamespacedName{Namespace: namespace, Name: name}, &configMap) if err != nil { - return fmt.Errorf("failed to get the config map %q in namespace %q in managed cluster. Error %v", name, namespace, err) + return fmt.Errorf("failed to retrieve the config map %q in namespace %q in managed cluster: %v", name, namespace, err) } mirrorPeers, err := utils.FetchAllMirrorPeers(context.TODO(), r.HubClient) if err != nil { + r.Logger.Error("Failed to fetch all mirror peers") return err } @@ -55,21 +55,21 @@ func (r *S3SecretReconciler) syncBlueSecretForS3(ctx context.Context, name strin } if storageClusterRef == nil { - klog.Errorf("failed to find storage cluster ref using spoke cluster name %s from mirrorpeers ", r.SpokeClusterName) - return err + return fmt.Errorf("failed to find storage cluster ref using spoke cluster name %s from mirrorpeers: %v", r.SpokeClusterName, err) } // fetch s3 endpoint route := &routev1.Route{} err = r.SpokeClient.Get(ctx, types.NamespacedName{Name: S3RouteName, Namespace: storageClusterRef.Namespace}, route) if err != nil { - return fmt.Errorf("failed to get the s3 endpoint in namespace %q in managed cluster. Error %v", namespace, err) + return fmt.Errorf("failed to retrieve the S3 endpoint in namespace %q in managed cluster: %v", storageClusterRef.Namespace, err) } s3Region := configMap.Data[S3BucketRegion] if s3Region == "" { s3Region = DefaultS3Region } + // s3 secret s3Secret := corev1.Secret{ ObjectMeta: metav1.ObjectMeta{ @@ -93,15 +93,19 @@ func (r *S3SecretReconciler) syncBlueSecretForS3(ctx context.Context, name strin newSecret, err := generateBlueSecret(s3Secret, utils.InternalLabel, utils.CreateUniqueSecretName(r.SpokeClusterName, storageClusterRef.Namespace, storageClusterRef.Name, utils.S3ProfilePrefix), storageClusterRef.Name, r.SpokeClusterName, customData) if err != nil { - return fmt.Errorf("failed to create secret from the managed cluster secret %q from namespace %v for the hub cluster in namespace %q err: %v", secret.Name, secret.Namespace, r.SpokeClusterName, err) + return fmt.Errorf("failed to create secret from the managed cluster secret %q in namespace %q for the hub cluster in namespace %q: %v", secret.Name, secret.Namespace, r.SpokeClusterName, err) } err = r.HubClient.Create(ctx, newSecret, &client.CreateOptions{}) if err != nil { - return fmt.Errorf("failed to sync managed cluster secret %q from namespace %v to the hub cluster in namespace %q err: %v", name, namespace, r.SpokeClusterName, err) + if errors.IsAlreadyExists(err) { + // Log that the secret already exists and is not created again + r.Logger.Info("Secret already exists on hub cluster, not creating again", "secret", newSecret.Name, "namespace", newSecret.Namespace) + return nil + } + return fmt.Errorf("failed to sync managed cluster secret %q from namespace %v to the hub cluster in namespace %q: %v", name, namespace, r.SpokeClusterName, err) } - klog.Infof("successfully synced managed cluster s3 bucket secret %q from namespace %v to the hub cluster in namespace %q", name, namespace, r.SpokeClusterName) - + r.Logger.Info("Successfully synced managed cluster s3 bucket secret to the hub cluster", "secret", name, "namespace", namespace, "hubNamespace", r.SpokeClusterName) return nil } diff --git a/addons/s3_secret_handler_test.go b/addons/s3_secret_handler_test.go deleted file mode 100644 index 18905618..00000000 --- a/addons/s3_secret_handler_test.go +++ /dev/null @@ -1 +0,0 @@ -package addons diff --git a/addons/secret_exchange_handler_utils.go b/addons/secret_exchange_handler_utils.go index f42f628b..c6bf1832 100644 --- a/addons/secret_exchange_handler_utils.go +++ b/addons/secret_exchange_handler_utils.go @@ -13,7 +13,7 @@ import ( func generateBlueSecret(secret corev1.Secret, secretType utils.SecretLabelType, uniqueName string, sc string, managedCluster string, customData map[string][]byte) (nsecret *corev1.Secret, err error) { secretData, err := json.Marshal(secret.Data) if err != nil { - return nsecret, fmt.Errorf("cannot create secret on the hub, marshalling failed") + return nsecret, fmt.Errorf("failed to marshal secret data for secret '%s' in namespace '%s': %v", secret.Name, secret.Namespace, err) } data := make(map[string][]byte) @@ -44,7 +44,7 @@ func generateBlueSecret(secret corev1.Secret, secretType utils.SecretLabelType, func generateBlueSecretForExternal(rookCephMon corev1.Secret, labelType utils.SecretLabelType, name string, sc string, managedClusterName string, customData map[string][]byte) (*corev1.Secret, error) { secretData, err := json.Marshal(rookCephMon.Data) if err != nil { - return nil, fmt.Errorf("failed to marshal secret data err: %v", err) + return nil, fmt.Errorf("failed to marshal data from Rook-Ceph monitor: error: %v, data source: %q", err, rookCephMon.Name) } data := make(map[string][]byte) @@ -74,24 +74,32 @@ func generateBlueSecretForExternal(rookCephMon corev1.Secret, labelType utils.Se } func validateGreenSecret(secret corev1.Secret) error { + // Validate the secret type label if secret.GetLabels()[utils.SecretLabelTypeKey] != string(utils.DestinationLabel) { - return fmt.Errorf("secret %q in namespace %q is not a green secret. Skip syncing with the spoke cluster", secret.Name, secret.Namespace) + return fmt.Errorf("validation failed: expected label '%s' with value '%s' for GreenSecret, but found '%s' or no label. Secret '%s' in namespace '%s' will be skipped for syncing", + utils.SecretLabelTypeKey, utils.DestinationLabel, secret.GetLabels()[utils.SecretLabelTypeKey], secret.Name, secret.Namespace) } + // Validate the presence of secret data if secret.Data == nil { - return fmt.Errorf("secret data not found for the secret %q in namespace %q", secret.Name, secret.Namespace) + return fmt.Errorf("validation failed: no data found in the secret '%s' in namespace '%s'. A non-empty data field is required", + secret.Name, secret.Namespace) } - if string(secret.Data["namespace"]) == "" { - return fmt.Errorf("missing storageCluster namespace info in secret %q in namespace %q", secret.Name, secret.Namespace) + // Validate specific data fields for completeness + if namespace, ok := secret.Data["namespace"]; !ok || string(namespace) == "" { + return fmt.Errorf("validation failed: missing or empty 'namespace' key in the data of the secret '%s' in namespace '%s'. This key is required for proper functionality", + secret.Name, secret.Namespace) } - if string(secret.Data[utils.StorageClusterNameKey]) == "" { - return fmt.Errorf("missing storageCluster name info in secret %q in namespace %q", secret.Name, secret.Namespace) + if clusterName, ok := secret.Data[utils.StorageClusterNameKey]; !ok || string(clusterName) == "" { + return fmt.Errorf("validation failed: missing or empty '%s' key in the data of the secret '%s' in namespace '%s'. This key is required for identifying the storage cluster", + utils.StorageClusterNameKey, secret.Name, secret.Namespace) } - if string(secret.Data[utils.SecretDataKey]) == "" { - return fmt.Errorf("missing secret-data info in secret %q in namespace %q", secret.Name, secret.Namespace) + if secretData, ok := secret.Data[utils.SecretDataKey]; !ok || string(secretData) == "" { + return fmt.Errorf("validation failed: missing or empty '%s' key in the data of the secret '%s' in namespace '%s'. This key is essential for the operation", + utils.SecretDataKey, secret.Name, secret.Namespace) } return nil diff --git a/addons/setup/common.go b/addons/setup/common.go index 789a511e..8d1f80b4 100644 --- a/addons/setup/common.go +++ b/addons/setup/common.go @@ -2,9 +2,10 @@ package setup import ( "context" - "k8s.io/klog/v2" + "log/slog" "net" "net/http" + "sigs.k8s.io/controller-runtime/pkg/healthz" ) @@ -14,7 +15,7 @@ const ( ) // ServeHealthProbes starts a server to check healthz and readyz probes -func ServeHealthProbes(stop <-chan struct{}, healthProbeBindAddress string, configCheck healthz.Checker) { +func ServeHealthProbes(stop <-chan struct{}, healthProbeBindAddress string, configCheck healthz.Checker, logger *slog.Logger) { healthzHandler := &healthz.Handler{Checks: map[string]healthz.Checker{ "healthz-ping": healthz.Ping, "configz-ping": configCheck, @@ -33,21 +34,26 @@ func ServeHealthProbes(stop <-chan struct{}, healthProbeBindAddress string, conf ln, err := net.Listen("tcp", healthProbeBindAddress) if err != nil { - klog.Errorf("error listening on %s: %v", healthProbeBindAddress, err) + logger.Error("Failed to listen on address", "address", healthProbeBindAddress, "error", err) return } + logger.Info("Server listening", "address", healthProbeBindAddress) - klog.Infof("Health probes server is running.") - // Run server + // Run server in a goroutine go func() { - if err := server.Serve(ln); err != nil && err != http.ErrServerClosed { - klog.Fatal(err) + err := server.Serve(ln) + if err != nil && err != http.ErrServerClosed { + logger.Error("Server failed", "error", err) } }() + logger.Info("Health probes server is running") + // Shutdown the server when stop is closed <-stop if err := server.Shutdown(context.Background()); err != nil { - klog.Fatal(err) + logger.Error("Failed to shutdown server", "error", err) + } else { + logger.Info("Server shutdown successfully") } } diff --git a/controllers/common_controller_utils.go b/controllers/common_controller_utils.go index dec50526..8dacad9e 100644 --- a/controllers/common_controller_utils.go +++ b/controllers/common_controller_utils.go @@ -5,6 +5,7 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "os" "reflect" @@ -17,7 +18,6 @@ import ( "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/controller/controllerutil" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/yaml" ) @@ -26,61 +26,76 @@ import ( // If a list of MirrorPeer objects are provided, it will check // the mapping from the provided MirrorPeers. // If no MirrorPeers are provided, it will fetch all the MirrorPeers in the HUB. -func createOrUpdateDestinationSecretsFromSource(ctx context.Context, rc client.Client, sourceSecret *corev1.Secret, mirrorPeers ...multiclusterv1alpha1.MirrorPeer) error { - logger := log.FromContext(ctx) +func createOrUpdateDestinationSecretsFromSource(ctx context.Context, rc client.Client, sourceSecret *corev1.Secret, logger *slog.Logger, mirrorPeers ...multiclusterv1alpha1.MirrorPeer) error { + logger.Info("Validating source secret", "Secret", sourceSecret.Name, "Namespace", sourceSecret.Namespace) + err := utils.ValidateSourceSecret(sourceSecret) if err != nil { - logger.Error(err, "Updating secrets failed. Invalid secret type.", "secret", sourceSecret.Name, "namespace", sourceSecret.Namespace) + logger.Error("Updating secrets failed due to invalid source secret type", "error", err, "Secret", sourceSecret.Name, "Namespace", sourceSecret.Namespace) return err } if mirrorPeers == nil { + logger.Info("Fetching all MirrorPeer objects as none were provided") mirrorPeers, err = utils.FetchAllMirrorPeers(ctx, rc) if err != nil { - logger.Error(err, "Unable to get the list of MirrorPeer objects") + logger.Error("Unable to retrieve the list of MirrorPeer objects", "error", err) return err } - logger.V(2).Info("Successfully got the list of MirrorPeers", "MirrorPeerListObj", mirrorPeers) + logger.Info("Successfully retrieved the list of MirrorPeers", "Count", len(mirrorPeers)) } + logger.Info("Determining peers connected to the source secret", "Secret", sourceSecret.Name) uniqueConnectedPeers, err := PeersConnectedToSecret(sourceSecret, mirrorPeers) if err != nil { - logger.Error(err, "ConnectedPeers returned an error", "secret", sourceSecret.Name, "namespace", sourceSecret.Namespace, "mirrorpeers", mirrorPeers) + logger.Error("Error determining connected peers for the source secret", "error", err, "Secret", sourceSecret.Name, "Namespace", sourceSecret.Namespace) return err } - logger.V(2).Info("Listing all the Peers connected to the Source", "SourceSecret", sourceSecret.Name, "namespace", sourceSecret.Namespace, "connected-peers-length", len(uniqueConnectedPeers)) + logger.Info("Peers connected to the source secret identified", "ConnectedPeersCount", len(uniqueConnectedPeers)) - // anyErr will have the last found error var anyErr error for _, eachConnectedPeer := range uniqueConnectedPeers { + logger.Info("Creating or updating destination secret for peer", "PeerRef", eachConnectedPeer) namedPeerRef := NewNamedPeerRefWithSecretData(sourceSecret, eachConnectedPeer) - err := namedPeerRef.CreateOrUpdateDestinationSecret(ctx, rc) + err := namedPeerRef.CreateOrUpdateDestinationSecret(ctx, rc, logger) if err != nil { - logger.Error(err, "Unable to update the destination secret", "secret", sourceSecret.Name, "namespace", sourceSecret.Namespace, "PeerRef", eachConnectedPeer) + logger.Error("Failed to create or update destination secret", "error", err, "SourceSecret", sourceSecret.Name, "DestinationPeerRef", eachConnectedPeer) anyErr = err } } + if anyErr != nil { + logger.Error("One or more errors occurred while updating destination secrets", "lastError", anyErr) + } else { + logger.Info("All destination secrets updated successfully") + } + return anyErr } -func processDestinationSecretUpdation(ctx context.Context, rc client.Client, destSecret *corev1.Secret) error { - logger := log.FromContext(ctx) +func processDestinationSecretUpdation(ctx context.Context, rc client.Client, destSecret *corev1.Secret, logger *slog.Logger) error { + logger.Info("Validating destination secret", "Secret", destSecret.Name, "Namespace", destSecret.Namespace) + err := utils.ValidateDestinationSecret(destSecret) if err != nil { - logger.Error(err, "Destination secret validation failed", "secret", destSecret.Name, "namespace", destSecret.Namespace) + logger.Error("Destination secret validation failed", "error", err, "Secret", destSecret.Name, "Namespace", destSecret.Namespace) return err } + + logger.Info("Fetching all MirrorPeers for secret update", "Secret", destSecret.Name) mirrorPeers, err := utils.FetchAllMirrorPeers(ctx, rc) if err != nil { - logger.Error(err, "Failed to get the list of MirrorPeer objects") + logger.Error("Failed to get the list of MirrorPeer objects", "error", err) return err } + + logger.Info("Determining peers connected to the destination secret", "Secret", destSecret.Name) uniqueConnectedPeers, err := PeersConnectedToSecret(destSecret, mirrorPeers) if err != nil { - logger.Error(err, "Failed to get the peers connected to the secret", "secret", destSecret.Name, "namespace", destSecret.Namespace) + logger.Error("Failed to get the peers connected to the secret", "error", err, "Secret", destSecret.Name, "Namespace", destSecret.Namespace) return err } + var connectedSource *corev1.Secret for _, eachConnectedPeer := range uniqueConnectedPeers { var connectedSecret corev1.Secret @@ -88,9 +103,10 @@ func processDestinationSecretUpdation(ctx context.Context, rc client.Client, des err := nPeerRef.GetAssociatedSecret(ctx, rc, &connectedSecret) if err != nil { if k8serrors.IsNotFound(err) { + logger.Info("Associated source secret not found, skipping", "PeerRef", eachConnectedPeer, "Secret", destSecret.Name) continue } - logger.Error(err, "Unexpected error while finding the source secret", "peer-ref", eachConnectedPeer, "secret", destSecret.Name, "namespace", destSecret.Namespace) + logger.Error("Unexpected error while finding the source secret", "error", err, "PeerRef", eachConnectedPeer, "Secret", destSecret.Name, "Namespace", destSecret.Namespace) return err } if utils.IsSecretSource(&connectedSecret) { @@ -100,36 +116,50 @@ func processDestinationSecretUpdation(ctx context.Context, rc client.Client, des } if connectedSource == nil { - logger.Error(nil, "No connected source found. Removing the dangling destination secret", "secret", destSecret.Name, "namespace", destSecret.Namespace) + logger.Info("No connected source found, potentially removing the dangling destination secret", "Secret", destSecret.Name, "Namespace", destSecret.Namespace) err = rc.Delete(ctx, destSecret) + if err != nil { + logger.Error("Failed to delete the dangling destination secret", "error", err, "Secret", destSecret.Name, "Namespace", destSecret.Namespace) + } return err } - err = createOrUpdateDestinationSecretsFromSource(ctx, rc, connectedSource, mirrorPeers...) + + logger.Info("Updating destination secret from the connected source", "SourceSecret", connectedSource.Name, "DestinationSecret", destSecret.Name) + err = createOrUpdateDestinationSecretsFromSource(ctx, rc, connectedSource, logger, mirrorPeers...) + if err != nil { + logger.Error("Failed to update destination secret from the source", "error", err, "SourceSecret", connectedSource.Name, "DestinationSecret", destSecret.Name) + } + return err } -func processDestinationSecretCleanup(ctx context.Context, rc client.Client) error { - logger := log.FromContext(ctx) +func processDestinationSecretCleanup(ctx context.Context, rc client.Client, logger *slog.Logger) error { allDestinationSecrets, err := fetchAllDestinationSecrets(ctx, rc, "") if err != nil { - logger.Error(err, "Unable to get all the destination secrets") + logger.Error("Unable to fetch all destination secrets", "error", err) return err } + var anyError error for _, eachDSecret := range allDestinationSecrets { - err = processDestinationSecretUpdation(ctx, rc, &eachDSecret) + logger.Info("Processing update for destination secret", "SecretName", eachDSecret.Name, "Namespace", eachDSecret.Namespace) + err = processDestinationSecretUpdation(ctx, rc, &eachDSecret, logger) if err != nil { anyError = err - logger.Error(err, "Failed to update destination secret", "secret", eachDSecret.Name, "namespace", eachDSecret.Namespace) + logger.Error("Failed to update destination secret", "error", err, "SecretName", eachDSecret.Name, "Namespace", eachDSecret.Namespace) } } + + if anyError != nil { + logger.Error("One or more errors occurred during the cleanup of destination secrets", "error", anyError) + } else { + logger.Info("All destination secrets processed successfully") + } return anyError } -func createOrUpdateRamenS3Secret(ctx context.Context, rc client.Client, secret *corev1.Secret, data map[string][]byte, ramenHubNamespace string) error { - logger := log.FromContext(ctx) +func createOrUpdateRamenS3Secret(ctx context.Context, rc client.Client, secret *corev1.Secret, data map[string][]byte, ramenHubNamespace string, logger *slog.Logger) error { - // convert aws s3 secret from s3 origin secret into ramen secret expectedSecret := corev1.Secret{ ObjectMeta: metav1.ObjectMeta{ Name: secret.Name, @@ -150,33 +180,42 @@ func createOrUpdateRamenS3Secret(ctx context.Context, rc client.Client, secret * Name: secret.Name, Namespace: ramenHubNamespace, } + + logger = logger.With("SecretName", expectedSecret.Name, "SecretNamespace", expectedSecret.Namespace, "RamenHubNamespace", ramenHubNamespace) + err := rc.Get(ctx, namespacedName, &localSecret) if err != nil { if k8serrors.IsNotFound(err) { - // creating new s3 secret on ramen openshift-dr-system namespace - logger.Info("Creating a s3 secret", "secret", expectedSecret.Name, "namespace", expectedSecret.Namespace) - return rc.Create(ctx, &expectedSecret) + logger.Info("Creating a new S3 secret") + if createErr := rc.Create(ctx, &expectedSecret); createErr != nil { + logger.Error("Failed to create the S3 secret", "error", createErr) + return createErr + } + return nil } - logger.Error(err, "unable to fetch the s3 secret", "secret", secret.Name, "namespace", ramenHubNamespace) + logger.Error("Failed to fetch the S3 secret", "error", err) return err } if !reflect.DeepEqual(expectedSecret.Data, localSecret.Data) { - // updating existing s3 secret on ramen openshift-dr-system namespace - logger.Info("Updating the s3 secret", "secret", expectedSecret.Name, "namespace", ramenHubNamespace) - _, err := controllerutil.CreateOrUpdate(ctx, rc, &localSecret, func() error { + logger.Info("Updating the existing S3 secret") + _, updateErr := controllerutil.CreateOrUpdate(ctx, rc, &localSecret, func() error { localSecret.Data = expectedSecret.Data return nil }) - return err + if updateErr != nil { + logger.Error("Failed to update the S3 secret", "error", updateErr) + return updateErr + } + } else { + logger.Info("No updates required for the S3 secret") } - // no changes return nil } -func createOrUpdateExternalSecret(ctx context.Context, rc client.Client, secret *corev1.Secret, data map[string][]byte, namespace string) error { - logger := log.FromContext(ctx) +func createOrUpdateExternalSecret(ctx context.Context, rc client.Client, secret *corev1.Secret, data map[string][]byte, namespace string, logger *slog.Logger) error { + logger.Info("Processing external secret", "SecretName", secret.Name, "Namespace", namespace) expectedSecret := corev1.Secret{ ObjectMeta: metav1.ObjectMeta{ @@ -188,7 +227,6 @@ func createOrUpdateExternalSecret(ctx context.Context, rc client.Client, secret }, Type: corev1.SecretTypeOpaque, Data: map[string][]byte{ - // May add more parameters for external mode "fsid": data["fsid"], }, } @@ -198,25 +236,34 @@ func createOrUpdateExternalSecret(ctx context.Context, rc client.Client, secret Name: secret.Name, Namespace: namespace, } + err := rc.Get(ctx, namespacedName, &localSecret) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Creating a external; secret", "secret", expectedSecret.Name, "namespace", expectedSecret.Namespace) - return rc.Create(ctx, &expectedSecret) + logger.Info("External secret not found, creating new one", "SecretName", expectedSecret.Name, "Namespace", namespace) + if createErr := rc.Create(ctx, &expectedSecret); createErr != nil { + logger.Error("Failed to create the external secret", "error", createErr, "SecretName", expectedSecret.Name, "Namespace", namespace) + return createErr + } + return nil } - logger.Error(err, "unable to fetch the external secret", "secret", secret.Name, "namespace", namespace) + logger.Error("Failed to fetch the external secret", "error", err, "SecretName", secret.Name, "Namespace", namespace) return err } if !reflect.DeepEqual(expectedSecret.Data, localSecret.Data) { - logger.Info("Updating the external secret", "secret", expectedSecret.Name, "namespace", namespace) - _, err := controllerutil.CreateOrUpdate(ctx, rc, &localSecret, func() error { + logger.Info("Data mismatch found, updating external secret", "SecretName", expectedSecret.Name, "Namespace", namespace) + _, updateErr := controllerutil.CreateOrUpdate(ctx, rc, &localSecret, func() error { localSecret.Data = expectedSecret.Data return nil }) - return err + if updateErr != nil { + logger.Error("Failed to update the external secret", "error", updateErr, "SecretName", expectedSecret.Name, "Namespace", namespace) + } + return updateErr } + logger.Info("No updates required for the external secret", "SecretName", expectedSecret.Name, "Namespace", namespace) return nil } @@ -264,41 +311,38 @@ func areS3ProfileFieldsEqual(expected rmn.S3StoreProfile, found rmn.S3StoreProfi return true } -func updateRamenHubOperatorConfig(ctx context.Context, rc client.Client, secret *corev1.Secret, data map[string][]byte, mirrorPeers []multiclusterv1alpha1.MirrorPeer, ramenHubNamespace string) error { - logger := log.FromContext(ctx) +func updateRamenHubOperatorConfig(ctx context.Context, rc client.Client, secret *corev1.Secret, data map[string][]byte, mirrorPeers []multiclusterv1alpha1.MirrorPeer, ramenHubNamespace string, logger *slog.Logger) error { + logger.Info("Starting to update Ramen Hub Operator config", "SecretName", secret.Name, "Namespace", secret.Namespace) clusterPeerRef, err := utils.CreatePeerRefFromSecret(secret) if err != nil { - logger.Error(err, "unable to create peerref", "secret", secret.Name, "namespace", secret.Namespace) + logger.Error("Failed to create peer reference from secret", "error", err, "SecretName", secret.Name, "Namespace", secret.Namespace) return err } + if mirrorPeers == nil { mirrorPeers, err = utils.FetchAllMirrorPeers(ctx, rc) - } - if err != nil { - logger.Error(err, "unable to get the list of MirrorPeer objects") - return err + if err != nil { + logger.Error("Failed to fetch all MirrorPeers", "error", err) + return err + } } - // filter mirror peer using clusterPeerRef if !isS3ProfileManagedPeerRef(clusterPeerRef, mirrorPeers) { - // ManageS3 is disabled on MirrorPeer spec, skip ramen hub operator config update + logger.Info("Manage S3 is disabled on MirrorPeer spec, skipping update", "PeerRef", clusterPeerRef) return nil } - // converting s3 bucket config into ramen s3 profile expectedS3Profile := rmn.S3StoreProfile{ S3ProfileName: string(data[utils.S3ProfileName]), S3Bucket: string(data[utils.S3BucketName]), S3Region: string(data[utils.S3Region]), S3CompatibleEndpoint: string(data[utils.S3Endpoint]), - // referenceing ramen secret S3SecretRef: corev1.SecretReference{ Name: secret.Name, }, } - // fetch ramen hub operator configmap currentRamenConfigMap := corev1.ConfigMap{} namespacedName := types.NamespacedName{ Name: utils.RamenHubOperatorConfigName, @@ -306,99 +350,99 @@ func updateRamenHubOperatorConfig(ctx context.Context, rc client.Client, secret } err = rc.Get(ctx, namespacedName, ¤tRamenConfigMap) if err != nil { - logger.Error(err, "unable to fetch DR hub operator config", "config", utils.RamenHubOperatorConfigName, "namespace", ramenHubNamespace) + logger.Error("Failed to fetch Ramen Hub Operator config map", "error", err, "ConfigMapName", namespacedName) return err } - // extract ramen manager config str from configmap ramenConfigData, ok := currentRamenConfigMap.Data["ramen_manager_config.yaml"] if !ok { - return fmt.Errorf("DR hub operator config data is empty for the config %q in namespace %q", utils.RamenHubOperatorConfigName, ramenHubNamespace) + err = fmt.Errorf("DR hub operator config data is empty for the config %q in namespace %q", utils.RamenHubOperatorConfigName, ramenHubNamespace) + logger.Error("DR hub operator config data is missing", "error", err) + return err } - // converting ramen manager config str into RamenConfig ramenConfig := rmn.RamenConfig{} err = yaml.Unmarshal([]byte(ramenConfigData), &ramenConfig) if err != nil { - logger.Error(err, "failed to unmarshal DR hub operator config data", "config", utils.RamenHubOperatorConfigName, "namespace", ramenHubNamespace) + logger.Error("Failed to unmarshal DR hub operator config data", "error", err) return err } isUpdated := false for i, currentS3Profile := range ramenConfig.S3StoreProfiles { if currentS3Profile.S3ProfileName == expectedS3Profile.S3ProfileName { - if areS3ProfileFieldsEqual(expectedS3Profile, currentS3Profile) { - // no change detected on already exiting s3 profile in RamenConfig + logger.Info("No change detected in S3 profile, skipping update", "S3ProfileName", expectedS3Profile.S3ProfileName) return nil } - // changes deducted on existing s3 profile updateS3ProfileFields(&expectedS3Profile, &ramenConfig.S3StoreProfiles[i]) isUpdated = true + logger.Info("S3 profile updated", "S3ProfileName", expectedS3Profile.S3ProfileName) break } } if !isUpdated { - // new s3 profile is deducted ramenConfig.S3StoreProfiles = append(ramenConfig.S3StoreProfiles, expectedS3Profile) + logger.Info("New S3 profile added", "S3ProfileName", expectedS3Profile.S3ProfileName) } - // converting RamenConfig into ramen manager config str ramenConfigDataStr, err := yaml.Marshal(ramenConfig) if err != nil { - logger.Error(err, "failed to marshal DR hub operator config data", "config", utils.RamenHubOperatorConfigName, "namespace", ramenHubNamespace) + logger.Error("Failed to marshal Ramen config", "error", err) return err } - // update ramen hub operator configmap - logger.Info("Updating DR hub operator config with S3 profile", utils.RamenHubOperatorConfigName, expectedS3Profile.S3ProfileName) _, err = controllerutil.CreateOrUpdate(ctx, rc, ¤tRamenConfigMap, func() error { - // attach ramen manager config str into configmap currentRamenConfigMap.Data["ramen_manager_config.yaml"] = string(ramenConfigDataStr) return nil }) + if err != nil { + logger.Error("Failed to update Ramen Hub Operator config map", "error", err) + return err + } - return err + logger.Info("Ramen Hub Operator config updated successfully", "ConfigMapName", namespacedName) + return nil } -func createOrUpdateSecretsFromInternalSecret(ctx context.Context, rc client.Client, secret *corev1.Secret, mirrorPeers []multiclusterv1alpha1.MirrorPeer) error { - logger := log.FromContext(ctx) +func createOrUpdateSecretsFromInternalSecret(ctx context.Context, rc client.Client, secret *corev1.Secret, mirrorPeers []multiclusterv1alpha1.MirrorPeer, logger *slog.Logger) error { + logger.Info("Validating internal secret", "SecretName", secret.Name, "Namespace", secret.Namespace) if err := utils.ValidateInternalSecret(secret, utils.InternalLabel); err != nil { - logger.Error(err, "Provided internal secret is not valid", "secret", secret.Name, "namespace", secret.Namespace) + logger.Error("Provided internal secret is not valid", "error", err, "SecretName", secret.Name, "Namespace", secret.Namespace) return err } data := make(map[string][]byte) - err := json.Unmarshal(secret.Data[utils.SecretDataKey], &data) - if err != nil { - logger.Error(err, "failed to unmarshal secret data", "secret", secret.Name, "namespace", secret.Namespace) + if err := json.Unmarshal(secret.Data[utils.SecretDataKey], &data); err != nil { + logger.Error("Failed to unmarshal secret data", "error", err, "SecretName", secret.Name, "Namespace", secret.Namespace) return err } - if string(secret.Data[utils.SecretOriginKey]) == utils.OriginMap["S3Origin"] { + secretOrigin := string(secret.Data[utils.SecretOriginKey]) + logger.Info("Processing secret based on origin", "Origin", secretOrigin, "SecretName", secret.Name) + + if secretOrigin == utils.OriginMap["S3Origin"] { if ok := utils.ValidateS3Secret(data); !ok { - return fmt.Errorf("invalid S3 secret format for secret name %q in namesapce %q", secret.Name, secret.Namespace) + err := fmt.Errorf("invalid S3 secret format for secret name %q in namespace %q", secret.Name, secret.Namespace) + logger.Error("Invalid S3 secret format", "error", err, "SecretName", secret.Name, "Namespace", secret.Namespace) + return err } currentNamespace := os.Getenv("POD_NAMESPACE") - // S3 origin secret has two part 1. s3 bucket secret 2. s3 bucket config - // create ramen s3 secret using s3 bucket secret - err := createOrUpdateRamenS3Secret(ctx, rc, secret, data, currentNamespace) - if err != nil { + if err := createOrUpdateRamenS3Secret(ctx, rc, secret, data, currentNamespace, logger); err != nil { + logger.Error("Failed to create or update Ramen S3 secret", "error", err, "SecretName", secret.Name, "Namespace", currentNamespace) return err } - // update ramen hub operator config using s3 bucket config and ramen s3 secret reference - err = updateRamenHubOperatorConfig(ctx, rc, secret, data, mirrorPeers, currentNamespace) - if err != nil { + if err := updateRamenHubOperatorConfig(ctx, rc, secret, data, mirrorPeers, currentNamespace, logger); err != nil { + logger.Error("Failed to update Ramen Hub Operator config", "error", err, "SecretName", secret.Name, "Namespace", currentNamespace) return err } - } - if string(secret.Data[utils.SecretOriginKey]) == utils.OriginMap["RookOrigin"] { + } else if secretOrigin == utils.OriginMap["RookOrigin"] { currentNamespace := os.Getenv("POD_NAMESPACE") - err := createOrUpdateExternalSecret(ctx, rc, secret, data, currentNamespace) - if err != nil { + if err := createOrUpdateExternalSecret(ctx, rc, secret, data, currentNamespace, logger); err != nil { + logger.Error("Failed to create or update external secret", "error", err, "SecretName", secret.Name, "Namespace", currentNamespace) return err } } @@ -408,30 +452,26 @@ func createOrUpdateSecretsFromInternalSecret(ctx context.Context, rc client.Clie // processDeletedSecrets finds out which type of secret is deleted // and do appropriate action -func processDeletedSecrets(ctx context.Context, rc client.Client, req types.NamespacedName) error { - var err error - logger := log.FromContext(ctx, "controller", "MirrorPeerController") - // get all the secrets with the same name +func processDeletedSecrets(ctx context.Context, rc client.Client, req types.NamespacedName, logger *slog.Logger) error { + logger.Info("Processing deleted secrets", "SecretName", req.Name, "Namespace", req.Namespace) + + // Fetch all secrets with a specific label, excluding those with the IgnoreLabel allSecrets, err := utils.FetchAllSecretsWithLabel(ctx, rc, "", utils.IgnoreLabel) if err != nil { - logger.Error(err, "Unable to get the list of secrets") + logger.Error("Failed to fetch secrets", "error", err) return err } - // sameNamedDestinationSecrets will collect the same named destination secrets + var sameNamedDestinationSecrets []corev1.Secret - // sourceSecretPointer will point to the source secret var sourceSecretPointer *corev1.Secret - // append all the secrets which have the same requested name + + // Filter secrets by name and type for _, eachSecret := range allSecrets { if eachSecret.Name == req.Name { - // check similarly named secret is present (or not) - if secretType := eachSecret.Labels[utils.SecretLabelTypeKey]; secretType == string(utils.SourceLabel) { - // if 'sourceSecretPointer' already points to a source secret, - // it is an error. We should not have TWO source - // secrets of same name. + if eachSecret.Labels[utils.SecretLabelTypeKey] == string(utils.SourceLabel) { if sourceSecretPointer != nil { - err = errors.New("multiple source secrets detected") - logger.Error(err, "Cannot have more than one source secrets with the same name", "request", req, "source-secret", sourceSecretPointer.Name, "namespace", sourceSecretPointer.Namespace) + err = errors.New("multiple source secrets detected with the same name") + logger.Error("Multiple source secrets found", "error", err, "SecretName", req.Name, "Namespace", req.Namespace) return err } sourceSecretPointer = eachSecret.DeepCopy() @@ -441,37 +481,26 @@ func processDeletedSecrets(ctx context.Context, rc client.Client, req types.Name } } - logger.V(2).Info("List of secrets with requested name", "secret-name", req.Name, "secret-length", len(sameNamedDestinationSecrets)) - if sourceSecretPointer == nil { - // if there is neither source secret nor any other similarly named secrets, - // that means all 'req.Name'-ed secrets are cleaned up and nothing to be done if len(sameNamedDestinationSecrets) == 0 { + logger.Info("No related secrets need cleaning", "SecretName", req.Name) return nil } - logger.Info("A SOURCE secret deletion detected", "secret-name", req.Name, "namespace", req.Namespace) + logger.Info("Source secret deletion detected, cleaning up destination secrets", "SecretName", req.Name) var anyErr error - // if source secret is not present, remove all the destinations|GREENs for _, eachDestSecret := range sameNamedDestinationSecrets { err = rc.Delete(ctx, &eachDestSecret) if err != nil { - logger.Error(err, "Deletion failed", "secret", eachDestSecret.Name, "namespace", eachDestSecret.Namespace) + logger.Error("Failed to delete destination secret", "error", err, "SecretName", eachDestSecret.Name, "Namespace", eachDestSecret.Namespace) anyErr = err } } - // if any error has happened, - // we will return the last found error - if anyErr != nil { - return anyErr - } + return anyErr } else { - logger.Info("A DESTINATION secret deletion detected", "secret-name", req.Name, "namespace", req.Namespace) - // in this section, one of the destination is removed - // action: use the source secret pointed by 'sourceSecretPointer' - // and restore the missing destination secret - err = createOrUpdateDestinationSecretsFromSource(ctx, rc, sourceSecretPointer) + logger.Info("Destination secret deletion detected, attempting to restore", "SecretName", req.Name) + err = createOrUpdateDestinationSecretsFromSource(ctx, rc, sourceSecretPointer, logger) if err != nil { - logger.Error(err, "Unable to update the destination secret", "source-secret", sourceSecretPointer.Name, "namespace", sourceSecretPointer.Namespace) + logger.Error("Failed to update destination secret from source", "error", err, "SourceSecretName", sourceSecretPointer.Name, "Namespace", sourceSecretPointer.Namespace) return err } } diff --git a/controllers/common_controller_utils_test.go b/controllers/common_controller_utils_test.go index 40d5c491..32baf944 100644 --- a/controllers/common_controller_utils_test.go +++ b/controllers/common_controller_utils_test.go @@ -262,12 +262,13 @@ func TestMirrorPeerSecretReconcile(t *testing.T) { } fakeClient := getFakeClient(t, mgrScheme) + fakeLogger := utils.GetLogger(utils.GetZapLogger(true)) 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 { diff --git a/controllers/drpolicy_controller.go b/controllers/drpolicy_controller.go index 836be79c..173381a5 100644 --- a/controllers/drpolicy_controller.go +++ b/controllers/drpolicy_controller.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,104 @@ 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). For(&ramenv1alpha1.DRPolicy{}, builder.WithPredicates(dpPredicate)). Complete(r) } func (r *DRPolicyReconciler) getMirrorPeerForClusterSet(ctx context.Context, clusterSet []string) (*multiclusterv1alpha1.MirrorPeer, error) { + logger := r.Logger + 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 + logger := r.Logger.With("Request", req.NamespacedName.String()) + logger.Info("Running DRPolicy reconciler on hub cluster") + + // 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) { + logger.Info("DRPolicy not found. Ignoring since the object must have been deleted") return ctrl.Result{}, nil } - klog.Error(err, "Failed to get DRPolicy") + logger.Error("Failed to get DRPolicy", "error", err) 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) { + 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") + 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") + logger.Info("Fetching cluster FSIDs") err = r.fetchClusterFSIDs(ctx, mirrorPeer, clusterFSIDs) if err != nil { - if errors.IsNotFound(err) { + if k8serrors.IsNotFound(err) { + 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) + 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 { + logger.Error("Failed to create VolumeReplicationClass via ManifestWork", "error", err) return ctrl.Result{}, fmt.Errorf("failed to create VolumeReplicationClass via ManifestWork: %v", err) } } + logger.Info("Successfully reconciled DRPolicy") 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("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,9 +160,9 @@ 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 } @@ -162,7 +178,8 @@ func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Contex labels[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 +196,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 +228,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 +239,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,11 +250,11 @@ 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 @@ -243,23 +262,31 @@ func (r *DRPolicyReconciler) createOrUpdateManifestWorkForVRC(ctx context.Contex func (r *DRPolicyReconciler) fetchClusterFSIDs(ctx context.Context, peer *multiclusterv1alpha1.MirrorPeer, clusterFSIDs map[string]string) error { for _, pr := range peer.Spec.Items { + logger := r.Logger.With("MirrorPeer", peer.Name, "ClusterName", pr.ClusterName) rookSecretName := utils.GetSecretNameByPeerRef(pr) - klog.Info("Fetching rook secret ", "Secret Name:", rookSecretName) + logger.Info("Fetching rook secret", "SecretName", rookSecretName) + 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) + return err } + logger.Error("Failed to fetch rook secret", "SecretName", rookSecretName, "error", err) return err } - klog.Info("Unmarshalling rook secret ", "Secret Name:", rookSecretName) + + logger.Info("Unmarshalling rook secret", "SecretName", rookSecretName) 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, "error", err) return err } + clusterFSIDs[pr.ClusterName] = rt.FSID + logger.Info("Successfully fetched FSID for cluster", "FSID", rt.FSID) } + r.Logger.Info("Successfully fetched all cluster FSIDs", "MirrorPeer", peer.Name) return nil } diff --git a/controllers/drpolicy_controller_test.go b/controllers/drpolicy_controller_test.go index ed4e7de0..1d21a398 100644 --- a/controllers/drpolicy_controller_test.go +++ b/controllers/drpolicy_controller_test.go @@ -9,7 +9,6 @@ import ( multiclusterv1alpha1 "github.com/red-hat-storage/odf-multicluster-orchestrator/api/v1alpha1" "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" corev1 "k8s.io/api/core/v1" - v1 "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/types" workv1 "open-cluster-management.io/api/work/v1" @@ -101,12 +100,12 @@ func TestDRPolicyReconcile(t *testing.T) { func getFakeDRPolicyReconciler(drpolicy *ramenv1alpha1.DRPolicy, mp *multiclusterv1alpha1.MirrorPeer) DRPolicyReconciler { scheme := mgrScheme - ns1 := &v1.Namespace{ + ns1 := &corev1.Namespace{ ObjectMeta: metav1.ObjectMeta{ Name: cName1, }, } - ns2 := &v1.Namespace{ + ns2 := &corev1.Namespace{ ObjectMeta: metav1.ObjectMeta{ Name: cName2, }, @@ -146,6 +145,7 @@ func getFakeDRPolicyReconciler(drpolicy *ramenv1alpha1.DRPolicy, mp *multicluste r := DRPolicyReconciler{ HubClient: fakeClient, Scheme: scheme, + Logger: utils.GetLogger(utils.GetZapLogger(true)), } return r diff --git a/controllers/manager.go b/controllers/manager.go index f5e66766..dfcf1af3 100644 --- a/controllers/manager.go +++ b/controllers/manager.go @@ -2,15 +2,16 @@ package controllers import ( "context" - "flag" "os" + "github.com/go-logr/zapr" consolev1alpha1 "github.com/openshift/api/console/v1alpha1" "github.com/openshift/library-go/pkg/operator/events" ramenv1alpha1 "github.com/ramendr/ramen/api/v1alpha1" "github.com/red-hat-storage/odf-multicluster-orchestrator/addons/setup" multiclusterv1alpha1 "github.com/red-hat-storage/odf-multicluster-orchestrator/api/v1alpha1" "github.com/red-hat-storage/odf-multicluster-orchestrator/console" + "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" "github.com/spf13/cobra" "golang.org/x/sync/errgroup" "k8s.io/apimachinery/pkg/runtime" @@ -23,7 +24,6 @@ import ( workv1 "open-cluster-management.io/api/work/v1" 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/manager" "sigs.k8s.io/controller-runtime/pkg/metrics/server" "sigs.k8s.io/controller-runtime/pkg/webhook" @@ -57,7 +57,7 @@ type ManagerOptions struct { EnableLeaderElection bool ProbeAddr string MulticlusterConsolePort int - ZapOpts zap.Options + DevMode bool } func NewManagerOptions() *ManagerOptions { @@ -72,12 +72,7 @@ func (o *ManagerOptions) AddFlags(cmd *cobra.Command) { flags.BoolVar(&o.EnableLeaderElection, "leader-elect", false, "Enable leader election for controller manager. "+ "Enabling this will ensure there is only one active controller manager.") - gfs := flag.NewFlagSet("", flag.ExitOnError) - o.ZapOpts = zap.Options{ - Development: true, - } - o.ZapOpts.BindFlags(gfs) - flags.AddGoFlagSet(gfs) + flags.BoolVar(&o.DevMode, "dev", false, "Set to true for dev environment (Text logging)") } func NewManagerCommand() *cobra.Command { @@ -94,8 +89,14 @@ func NewManagerCommand() *cobra.Command { } func (o *ManagerOptions) runManager() { - ctrl.SetLogger(zap.New(zap.UseFlagOptions(&o.ZapOpts))) - setupLog := ctrl.Log.WithName("setup") + zapLogger := utils.GetZapLogger(o.DevMode) + defer func() { + if err := zapLogger.Sync(); err != nil { + zapLogger.Error("Failed to sync zap logger") + } + }() + ctrl.SetLogger(zapr.NewLogger(zapLogger)) + logger := utils.GetLogger(zapLogger) srv := webhook.NewServer(webhook.Options{ CertDir: WebhookCertDir, @@ -114,7 +115,7 @@ func (o *ManagerOptions) runManager() { WebhookServer: srv, }) if err != nil { - setupLog.Error(err, "unable to start manager") + logger.Error("Failed to start manager", "error", err) os.Exit(1) } @@ -123,8 +124,9 @@ func (o *ManagerOptions) runManager() { if err = (&MirrorPeerReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger.With("controller", "MirrorPeerReconciler"), }).SetupWithManager(mgr); err != nil { - setupLog.Error(err, "unable to create controller", "controller", "MirrorPeer") + logger.Error("Failed to create MirrorPeer controller", "error", err) os.Exit(1) } //+kubebuilder:scaffold:builder @@ -132,41 +134,42 @@ func (o *ManagerOptions) runManager() { if err = (&MirrorPeerSecretReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger.With("controller", "MirrorPeerSecretReconciler"), }).SetupWithManager(mgr); err != nil { - setupLog.Error(err, "unable to create controller", "controller", "MirrorPeer") + logger.Error("Failed to create MirrorPeer controller", "error", err) os.Exit(1) } if err := mgr.Add(manager.RunnableFunc(func(ctx context.Context) error { err = console.InitConsole(ctx, mgr.GetClient(), o.MulticlusterConsolePort, namespace) if err != nil { - setupLog.Error(err, "unable to initialize multicluster console to manager") + logger.Error("Failed to initialize multicluster console to manager", "error", err) return err } return nil })); err != nil { - setupLog.Error(err, "unable to add multicluster console to manager") + logger.Error("Failed to add multicluster console to manager", "error", err) os.Exit(1) } if err := mgr.AddHealthzCheck("healthz", healthz.Ping); err != nil { - setupLog.Error(err, "unable to set up health check") + logger.Error("Failed to set up health check", "error", err) os.Exit(1) } if err := mgr.AddReadyzCheck("readyz", healthz.Ping); err != nil { - setupLog.Error(err, "unable to set up ready check") + logger.Error("Failed to set up ready check", "error", err) os.Exit(1) } - setupLog.Info("initializing token exchange addon") + logger.Info("Initializing token exchange addon") kubeClient, err := kubernetes.NewForConfig(mgr.GetConfig()) if err != nil { - setupLog.Error(err, "problem getting kubeclient") + logger.Error("Failed to get kubeclient", "error", err) } controllerRef, err := events.GetControllerReferenceForCurrentPod(context.TODO(), kubeClient, namespace, nil) if err != nil { - setupLog.Info("unable to get owner reference (falling back to namespace)", "error", err) + logger.Info("Failed to get owner reference (falling back to namespace)", "error", err) } teEventRecorder := events.NewKubeRecorder(kubeClient.CoreV1().Events(namespace), setup.TokenExchangeName, controllerRef) mEventRecorder := events.NewKubeRecorder(kubeClient.CoreV1().Events(namespace), setup.MaintainAgentName, controllerRef) @@ -202,49 +205,50 @@ func (o *ManagerOptions) runManager() { err = (&multiclusterv1alpha1.MirrorPeer{}).SetupWebhookWithManager(mgr) if err != nil { - setupLog.Error(err, "unable to create webhook", "webhook", "MirrorPeer") + logger.Error("Unable to create MirrorPeer webhook", "error", err) os.Exit(1) } - setupLog.Info("creating addon manager") + logger.Info("Creating addon manager") addonMgr, err := addonmanager.New(mgr.GetConfig()) if err != nil { - setupLog.Error(err, "problem creating addon manager") + logger.Error("Failed to create addon manager", "error", err) } err = addonMgr.AddAgent(&tokenExchangeAddon) if err != nil { - setupLog.Error(err, "problem adding token exchange addon to addon manager") + logger.Error("Failed to add token exchange addon to addon manager", "error", err) } err = addonMgr.AddAgent(&maintainenceModeAddon) if err != nil { - setupLog.Error(err, "problem adding maintainence addon to addon manager") + logger.Error("Failed to add maintainence addon to addon manager", "error", err) } if err = (&DRPolicyReconciler{ HubClient: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger.With("controller", "DRPolicyReconciler"), }).SetupWithManager(mgr); err != nil { - setupLog.Error(err, "unable to create controller", "controller", "DRPolicy") + logger.Error("Failed to create DRPolicy controller", "error", err) os.Exit(1) } g, ctx := errgroup.WithContext(ctrl.SetupSignalHandler()) - setupLog.Info("starting manager") + logger.Info("Starting manager") g.Go(func() error { err := mgr.Start(ctx) return err }) - setupLog.Info("starting addon manager") + logger.Info("Starting addon manager") g.Go(func() error { err := addonMgr.Start(ctx) return err }) if err := g.Wait(); err != nil { - setupLog.Error(err, "received an error. exiting..") + logger.Error("Received an error while waiting. exiting..", "error", err) os.Exit(1) } } diff --git a/controllers/mirrorpeer_controller.go b/controllers/mirrorpeer_controller.go index 951c03bf..aa5a1f5f 100644 --- a/controllers/mirrorpeer_controller.go +++ b/controllers/mirrorpeer_controller.go @@ -18,6 +18,7 @@ package controllers import ( "context" + "log/slog" "os" "github.com/red-hat-storage/odf-multicluster-orchestrator/addons/setup" @@ -41,7 +42,6 @@ import ( "sigs.k8s.io/controller-runtime/pkg/builder" "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/controller/controllerutil" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/predicate" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) @@ -50,6 +50,7 @@ import ( type MirrorPeerReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } const mirrorPeerFinalizer = "hub.multicluster.odf.openshift.io" @@ -80,8 +81,8 @@ const spokeClusterRoleBindingName = "spoke-clusterrole-bindings" // For more details, check Reconcile and its Result here: // - https://pkg.go.dev/sigs.k8s.io/controller-runtime@v0.8.3/pkg/reconcile func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { - logger := log.FromContext(ctx) - + logger := r.Logger.With("MirrorPeer", req.NamespacedName.String()) + logger.Info("Reconciling request") // Fetch MirrorPeer for given Request var mirrorPeer multiclusterv1alpha1.MirrorPeer err := r.Get(ctx, req.NamespacedName, &mirrorPeer) @@ -94,33 +95,35 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) return ctrl.Result{}, nil } // Error reading the object - requeue the request. - logger.Error(err, "Failed to get MirrorPeer") + logger.Error("Failed to get MirrorPeer", "error", err) return ctrl.Result{}, err } - logger.V(2).Info("Validating MirrorPeer", "MirrorPeer", req.NamespacedName) + logger.Info("Validating MirrorPeer") // Validate MirrorPeer // MirrorPeer.Spec must be defined if err := undefinedMirrorPeerSpec(mirrorPeer.Spec); err != nil { + logger.Error("MirrorPeer spec is undefined", "error", err) return ctrl.Result{Requeue: false}, err } // MirrorPeer.Spec.Items must be unique if err := uniqueSpecItems(mirrorPeer.Spec); err != nil { + logger.Error("MirrorPeer spec items are not unique", "error", err) return ctrl.Result{Requeue: false}, err } for i := range mirrorPeer.Spec.Items { // MirrorPeer.Spec.Items must not have empty fields if err := emptySpecItems(mirrorPeer.Spec.Items[i]); err != nil { - // return error and do not requeue since user needs to update the spec - // when user updates the spec, new reconcile will be triggered + logger.Error("MirrorPeer spec items have empty fields", "error", err) return reconcile.Result{Requeue: false}, err } // MirrorPeer.Spec.Items[*].ClusterName must be a valid ManagedCluster if err := isManagedCluster(ctx, r.Client, mirrorPeer.Spec.Items[i].ClusterName); err != nil { + logger.Error("Invalid ManagedCluster", "ClusterName", mirrorPeer.Spec.Items[i].ClusterName, "error", err) return ctrl.Result{}, err } } - logger.V(2).Info("All validations for MirrorPeer passed", "MirrorPeer", req.NamespacedName) + logger.Info("All validations for MirrorPeer passed") if mirrorPeer.GetDeletionTimestamp().IsZero() { if !utils.ContainsString(mirrorPeer.GetFinalizers(), mirrorPeerFinalizer) { @@ -132,7 +135,7 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) mirrorPeer.Status.Phase = multiclusterv1alpha1.Deleting statusErr := r.Client.Status().Update(ctx, &mirrorPeer) if statusErr != nil { - logger.Error(statusErr, "Error occurred while updating the status of mirrorpeer", "MirrorPeer", mirrorPeer) + logger.Error("Error occurred while updating the status of mirrorpeer", "Error", statusErr) return ctrl.Result{Requeue: true}, nil } if utils.ContainsString(mirrorPeer.GetFinalizers(), mirrorPeerFinalizer) { @@ -141,12 +144,12 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) return reconcile.Result{Requeue: true}, err } if err := r.deleteSecrets(ctx, mirrorPeer); err != nil { - logger.Error(err, "Failed to delete resources") + logger.Error("Failed to delete resources", "error", err) return reconcile.Result{Requeue: true}, err } mirrorPeer.Finalizers = utils.RemoveString(mirrorPeer.Finalizers, mirrorPeerFinalizer) if err := r.Client.Update(ctx, &mirrorPeer); err != nil { - logger.Info("Failed to remove finalizer from MirrorPeer") + logger.Error("Failed to remove finalizer from MirrorPeer", "error", err) return reconcile.Result{}, err } } @@ -165,9 +168,10 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) err = r.Client.Update(ctx, mirrorPeerCopy) if err != nil { - return checkK8sUpdateErrors(err, mirrorPeerCopy) + logger.Error("Failed to update mirrorpeer with disaster recovery label", "error", err) + return checkK8sUpdateErrors(err, mirrorPeerCopy, logger) } - logger.Info("Successfully added label to mirrorpeer for disaster recovery", "Mirrorpeer", mirrorPeerCopy.Name) + logger.Info("Successfully added label to mirrorpeer for disaster recovery. Requeing request...") return ctrl.Result{Requeue: true}, nil } @@ -179,19 +183,20 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) } statusErr := r.Client.Status().Update(ctx, &mirrorPeer) if statusErr != nil { - logger.Error(statusErr, "Error occurred while updating the status of mirrorpeer", "MirrorPeer", mirrorPeer) + logger.Error("Error occurred while updating the status of mirrorpeer. Requeing request...", "Error ", statusErr) // Requeue, but don't throw return ctrl.Result{Requeue: true}, nil } } if err := r.processManagedClusterAddon(ctx, mirrorPeer); err != nil { + logger.Error("Failed to process managedclusteraddon", "error", err) return ctrl.Result{}, err } err = r.createClusterRoleBindingsForSpoke(ctx, mirrorPeer) if err != nil { - logger.Error(err, "Failed to create cluster role bindings for spoke") + logger.Error("Failed to create cluster role bindings for spoke", "error", err) return ctrl.Result{}, err } @@ -206,31 +211,32 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) err = r.Client.Get(ctx, namespacedName, &s3Secret) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("s3 secret is not yet synchronised. retrying till it is available", "peerref", peerRef.ClusterName, "MirrorPeer", mirrorPeer) + logger.Info("S3 secret is not yet synchronised. retrying till it is available. Requeing request...", "Cluster", peerRef.ClusterName) return ctrl.Result{Requeue: true}, nil } - logger.Error(err, "error in fetching s3 internal secret", "peerref", peerRef.ClusterName, "MirrorPeer", mirrorPeer) + logger.Error("Error in fetching s3 internal secret", "Cluster", peerRef.ClusterName, "error", err) return ctrl.Result{}, err } - err = createOrUpdateSecretsFromInternalSecret(ctx, r.Client, &s3Secret, []multiclusterv1alpha1.MirrorPeer{mirrorPeer}) + err = createOrUpdateSecretsFromInternalSecret(ctx, r.Client, &s3Secret, []multiclusterv1alpha1.MirrorPeer{mirrorPeer}, logger) if err != nil { - logger.Error(err, "error in updating S3 profile", "peerref", peerRef.ClusterName, "MirrorPeer", mirrorPeer) + logger.Error("Error in updating S3 profile", "Cluster", peerRef.ClusterName, "error", err) return ctrl.Result{}, err } } } - if err = processMirrorPeerSecretChanges(ctx, r.Client, mirrorPeer); err != nil { + if err = r.processMirrorPeerSecretChanges(ctx, r.Client, mirrorPeer); err != nil { + logger.Error("Error processing MirrorPeer secret changes", "error", err) return ctrl.Result{}, err } err = r.createDRClusters(ctx, &mirrorPeer) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("secret not synchronised yet, retrying to create DRCluster", "MirrorPeer", mirrorPeer) + logger.Info("Secret not synchronised yet, retrying to create DRCluster", "MirrorPeer", mirrorPeer.Name) return ctrl.Result{Requeue: true}, nil } - logger.Error(err, "failed to create DRClusters for MirrorPeer", "MirrorPeer", mirrorPeer.Name) + logger.Error("Failed to create DRClusters for MirrorPeer", "error", err) return ctrl.Result{}, err } @@ -240,37 +246,53 @@ func (r *MirrorPeerReconciler) Reconcile(ctx context.Context, req ctrl.Request) // processManagedClusterAddon creates an addon for the cluster management in all the peer refs, // the resources gets an owner ref of the mirrorpeer to let the garbage collector handle it if the mirrorpeer gets deleted func (r *MirrorPeerReconciler) processManagedClusterAddon(ctx context.Context, mirrorPeer multiclusterv1alpha1.MirrorPeer) error { - logger := log.FromContext(ctx) - // Create or Update ManagedClusterAddon - for i := range mirrorPeer.Spec.Items { + logger := r.Logger.With("MirrorPeer", mirrorPeer.Name) + logger.Info("Processing ManagedClusterAddons for MirrorPeer") + + for _, item := range mirrorPeer.Spec.Items { + logger.Info("Handling ManagedClusterAddon for cluster", "ClusterName", item.ClusterName) + var managedClusterAddOn addonapiv1alpha1.ManagedClusterAddOn - if err := r.Client.Get(ctx, types.NamespacedName{ + namespacedName := types.NamespacedName{ Name: setup.TokenExchangeName, - Namespace: mirrorPeer.Spec.Items[i].ClusterName, - }, &managedClusterAddOn); err != nil { + Namespace: item.ClusterName, + } + + err := r.Client.Get(ctx, namespacedName, &managedClusterAddOn) + if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Cannot find managedClusterAddon, creating") + logger.Info("ManagedClusterAddon not found, will create a new one", "ClusterName", item.ClusterName) + annotations := make(map[string]string) annotations[utils.DRModeAnnotationKey] = string(mirrorPeer.Spec.Type) - managedClusterAddOn = addonapiv1alpha1.ManagedClusterAddOn{ ObjectMeta: metav1.ObjectMeta{ Name: setup.TokenExchangeName, - Namespace: mirrorPeer.Spec.Items[i].ClusterName, + Namespace: item.ClusterName, Annotations: annotations, }, } } } - _, err := controllerutil.CreateOrUpdate(ctx, r.Client, &managedClusterAddOn, func() error { - managedClusterAddOn.Spec.InstallNamespace = mirrorPeer.Spec.Items[i].StorageClusterRef.Namespace - return controllerutil.SetOwnerReference(&mirrorPeer, &managedClusterAddOn, r.Scheme) + + _, err = controllerutil.CreateOrUpdate(ctx, r.Client, &managedClusterAddOn, func() error { + managedClusterAddOn.Spec.InstallNamespace = item.StorageClusterRef.Namespace + if err := controllerutil.SetOwnerReference(&mirrorPeer, &managedClusterAddOn, r.Scheme); err != nil { + logger.Error("Failed to set owner reference on ManagedClusterAddon", "error", err, "ClusterName", item.ClusterName) + return err + } + return nil }) + if err != nil { - logger.Error(err, "Failed to reconcile ManagedClusterAddOn.", "ManagedClusterAddOn", klog.KRef(managedClusterAddOn.Namespace, managedClusterAddOn.Name)) + logger.Error("Failed to reconcile ManagedClusterAddOn", "ManagedClusterAddOn", klog.KRef(managedClusterAddOn.Namespace, managedClusterAddOn.Name), "error", err) return err } + + logger.Info("Successfully reconciled ManagedClusterAddOn", "ClusterName", item.ClusterName) } + + logger.Info("Successfully processed all ManagedClusterAddons for MirrorPeer") return nil } @@ -279,26 +301,33 @@ func (r *MirrorPeerReconciler) processManagedClusterAddon(ctx context.Context, m // If two mirrorpeers are pointing to the same peer ref, but only gets deleted the orphan green secret in // the still standing peer ref gets deleted by the mirrorpeer secret controller func (r *MirrorPeerReconciler) deleteSecrets(ctx context.Context, mirrorPeer multiclusterv1alpha1.MirrorPeer) error { - logger := log.FromContext(ctx) - for i := range mirrorPeer.Spec.Items { + logger := r.Logger + logger.Info("Starting deletion of secrets for MirrorPeer", "MirrorPeer", mirrorPeer.Name) + + for i, peerRef := range mirrorPeer.Spec.Items { + logger.Info("Checking if PeerRef is used by another MirrorPeer", "PeerRef", peerRef.ClusterName) + peerRefUsed, err := utils.DoesAnotherMirrorPeerPointToPeerRef(ctx, r.Client, &mirrorPeer.Spec.Items[i]) if err != nil { + logger.Error("Error checking if PeerRef is used by another MirrorPeer", "PeerRef", peerRef.ClusterName, "error", err) return err } + if !peerRefUsed { - secretLabels := []string{string(utils.SourceLabel), string(utils.DestinationLabel)} + logger.Info("PeerRef is not used by another MirrorPeer, proceeding to delete secrets", "PeerRef", peerRef.ClusterName) + secretLabels := []string{string(utils.SourceLabel), string(utils.DestinationLabel)} if mirrorPeer.Spec.ManageS3 { secretLabels = append(secretLabels, string(utils.InternalLabel)) } secretRequirement, err := labels.NewRequirement(utils.SecretLabelTypeKey, selection.In, secretLabels) if err != nil { - logger.Error(err, "cannot parse new requirement") + logger.Error("Cannot create label requirement for deleting secrets", "error", err) + return err } secretSelector := labels.NewSelector().Add(*secretRequirement) - deleteOpt := client.DeleteAllOfOptions{ ListOptions: client.ListOptions{ Namespace: mirrorPeer.Spec.Items[i].ClusterName, @@ -308,152 +337,190 @@ func (r *MirrorPeerReconciler) deleteSecrets(ctx context.Context, mirrorPeer mul var secret corev1.Secret if err := r.DeleteAllOf(ctx, &secret, &deleteOpt); err != nil { - logger.Error(err, "Error while deleting secrets for MirrorPeer", "MirrorPeer", mirrorPeer.Name) + logger.Error("Error while deleting secrets for MirrorPeer", "MirrorPeer", mirrorPeer.Name, "PeerRef", peerRef.ClusterName, "error", err) } + + logger.Info("Secrets successfully deleted", "PeerRef", peerRef.ClusterName) + } else { + logger.Info("PeerRef is still used by another MirrorPeer, skipping deletion", "PeerRef", peerRef.ClusterName) } } + + logger.Info("Completed deletion of secrets for MirrorPeer", "MirrorPeer", mirrorPeer.Name) return nil } -func processMirrorPeerSecretChanges(ctx context.Context, rc client.Client, mirrorPeerObj multiclusterv1alpha1.MirrorPeer) error { - logger := log.FromContext(ctx) +func (r *MirrorPeerReconciler) processMirrorPeerSecretChanges(ctx context.Context, rc client.Client, mirrorPeerObj multiclusterv1alpha1.MirrorPeer) error { + logger := r.Logger + logger.Info("Processing mirror peer secret changes", "MirrorPeer", mirrorPeerObj.Name) + var anyErr error for _, eachPeerRef := range mirrorPeerObj.Spec.Items { + logger.Info("Fetching all source secrets", "ClusterName", eachPeerRef.ClusterName) sourceSecrets, err := fetchAllSourceSecrets(ctx, rc, eachPeerRef.ClusterName) if err != nil { - logger.Error(err, "Unable to get a list of source secrets", "namespace", eachPeerRef.ClusterName) + logger.Error("Unable to get a list of source secrets", "error", err, "namespace", eachPeerRef.ClusterName) anyErr = err continue } + // get the source secret associated with the PeerRef matchingSourceSecret := utils.FindMatchingSecretWithPeerRef(eachPeerRef, sourceSecrets) - // if no match found (ie; no source secret found); just continue if matchingSourceSecret == nil { + logger.Info("No matching source secret found for peer ref", "PeerRef", eachPeerRef.ClusterName) continue } - err = createOrUpdateDestinationSecretsFromSource(ctx, rc, matchingSourceSecret, mirrorPeerObj) + err = createOrUpdateDestinationSecretsFromSource(ctx, rc, matchingSourceSecret, logger, mirrorPeerObj) if err != nil { - logger.Error(err, "Error while updating Destination secrets", "source-secret", matchingSourceSecret.Name, "namespace", matchingSourceSecret.Namespace) + logger.Error("Error while updating destination secrets", "source-secret", matchingSourceSecret.Name, "namespace", matchingSourceSecret.Namespace, "error", err) anyErr = err } } + if anyErr == nil { - // if there are no other errors, - // cleanup any other orphan destination secrets - anyErr = processDestinationSecretCleanup(ctx, rc) + logger.Info("Cleaning up any orphan destination secrets") + anyErr = processDestinationSecretCleanup(ctx, rc, logger) + if anyErr != nil { + logger.Error("Error cleaning up orphan destination secrets", "error", anyErr) + } + } else { + logger.Info("Errors encountered in updating secrets; skipping cleanup") } + return anyErr } func (r *MirrorPeerReconciler) checkTokenExchangeStatus(ctx context.Context, mp multiclusterv1alpha1.MirrorPeer) (bool, error) { - logger := log.FromContext(ctx) + logger := r.Logger - //TODO Add support for more peer refs when applicable + logger.Info("Checking token exchange status for MirrorPeer", "MirrorPeer", mp.Name) + + // Assuming pr1 and pr2 are defined as first two peer refs in spec pr1 := mp.Spec.Items[0] pr2 := mp.Spec.Items[1] + // Check for source secret for pr1 err := r.checkForSourceSecret(ctx, pr1) if err != nil { - logger.Error(err, "Failed to find valid source secret", "PeerRef", pr1) + logger.Error("Failed to find valid source secret for the first peer reference", "PeerRef", pr1.ClusterName, "error", err) return false, err } + // Check for destination secret for pr1 in pr2's cluster err = r.checkForDestinationSecret(ctx, pr1, pr2.ClusterName) if err != nil { - logger.Error(err, "Failed to find valid destination secret", "PeerRef", pr1) + logger.Error("Failed to find valid destination secret for the first peer reference", "PeerRef", pr1.ClusterName, "DestinationCluster", pr2.ClusterName, "error", err) return false, err } + // Check for source secret for pr2 err = r.checkForSourceSecret(ctx, pr2) if err != nil { - logger.Error(err, "Failed to find valid source secret", "PeerRef", pr2) + logger.Error("Failed to find valid source secret for the second peer reference", "PeerRef", pr2.ClusterName, "error", err) return false, err } + // Check for destination secret for pr2 in pr1's cluster err = r.checkForDestinationSecret(ctx, pr2, pr1.ClusterName) if err != nil { - logger.Error(err, "Failed to find destination secret", "PeerRef", pr2) + logger.Error("Failed to find valid destination secret for the second peer reference", "PeerRef", pr2.ClusterName, "DestinationCluster", pr1.ClusterName, "error", err) return false, err } + logger.Info("Successfully validated token exchange status for all peer references", "MirrorPeer", mp.Name) return true, nil } func (r *MirrorPeerReconciler) checkForSourceSecret(ctx context.Context, peerRef multiclusterv1alpha1.PeerRef) error { - logger := log.FromContext(ctx) + logger := r.Logger prSecretName := utils.GetSecretNameByPeerRef(peerRef) var peerSourceSecret corev1.Secret err := r.Client.Get(ctx, types.NamespacedName{ - Name: prSecretName, - // Source Namespace for the secret - Namespace: peerRef.ClusterName, + Name: prSecretName, + Namespace: peerRef.ClusterName, // Source Namespace for the secret }, &peerSourceSecret) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Source secret not found", "Secret", prSecretName) + logger.Info("Source secret not found", "Secret", prSecretName, "Namespace", peerRef.ClusterName) return err } + logger.Error("Failed to fetch source secret", "error", err, "Secret", prSecretName, "Namespace", peerRef.ClusterName) + return err } err = utils.ValidateSourceSecret(&peerSourceSecret) if err != nil { + logger.Error("Validation failed for source secret", "error", err, "Secret", prSecretName, "Namespace", peerRef.ClusterName) return err } + logger.Info("Source secret validated successfully", "Secret", prSecretName, "Namespace", peerRef.ClusterName) return nil } + func (r *MirrorPeerReconciler) checkForDestinationSecret(ctx context.Context, peerRef multiclusterv1alpha1.PeerRef, destNamespace string) error { - logger := log.FromContext(ctx) + logger := r.Logger prSecretName := utils.GetSecretNameByPeerRef(peerRef) var peerDestinationSecret corev1.Secret + err := r.Client.Get(ctx, types.NamespacedName{ - Name: prSecretName, - // Destination Namespace for the secret - Namespace: destNamespace, + Name: prSecretName, + Namespace: destNamespace, // Destination Namespace for the secret }, &peerDestinationSecret) + if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Destination secret not found", "Secret", prSecretName) + logger.Info("Destination secret not found", "Secret", prSecretName, "Namespace", destNamespace) return err } + logger.Error("Failed to fetch destination secret", "error", err, "Secret", prSecretName, "Namespace", destNamespace) + return err } + err = utils.ValidateDestinationSecret(&peerDestinationSecret) if err != nil { + logger.Error("Validation failed for destination secret", "error", err, "Secret", prSecretName, "Namespace", destNamespace) return err } + logger.Info("Destination secret validated successfully", "Secret", prSecretName, "Namespace", destNamespace) return nil - } // SetupWithManager sets up the controller with the Manager. func (r *MirrorPeerReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger.Info("Setting up controller for MirrorPeer") + mpPredicate := utils.ComposePredicates(predicate.GenerationChangedPredicate{}) + return ctrl.NewControllerManagedBy(mgr). For(&multiclusterv1alpha1.MirrorPeer{}, builder.WithPredicates(mpPredicate)). Complete(r) + } // CheckK8sUpdateErrors checks what type of error occurs when trying to update a k8s object // and logs according to the object -func checkK8sUpdateErrors(err error, obj client.Object) (ctrl.Result, error) { +func checkK8sUpdateErrors(err error, obj client.Object, logger *slog.Logger) (ctrl.Result, error) { if k8serrors.IsConflict(err) { - klog.Info("Object is being updated by another process. Retrying", obj.GetObjectKind(), obj.GetName()) + logger.Info("Object is being updated by another process. Retrying", "Kind", obj.GetObjectKind().GroupVersionKind().Kind, "Name", obj.GetName()) return ctrl.Result{Requeue: true}, nil } else if k8serrors.IsNotFound(err) { - klog.Info("Object no longer exists. Ignoring since object must have been deleted", obj.GetObjectKind(), obj.GetName()) + logger.Info("Object no longer exists. Ignoring since object must have been deleted", "Kind", obj.GetObjectKind().GroupVersionKind().Kind, "Name", obj.GetName()) return ctrl.Result{}, nil } else if err != nil { - klog.Info("Warning: Failed to update object", obj.GetName(), "Error", err) + logger.Error("Failed to update object", "error", err, "Name", obj.GetName()) + return ctrl.Result{}, err } return ctrl.Result{}, nil } func (r *MirrorPeerReconciler) createDRClusters(ctx context.Context, mp *multiclusterv1alpha1.MirrorPeer) error { - logger := log.FromContext(ctx) + logger := r.Logger currentNamespace := os.Getenv("POD_NAMESPACE") + for _, pr := range mp.Spec.Items { clusterName := pr.ClusterName s3SecretName := utils.GetSecretNameByPeerRef(pr, utils.S3ProfilePrefix) @@ -466,15 +533,16 @@ func (r *MirrorPeerReconciler) createDRClusters(ctx context.Context, mp *multicl var fsid string if mp.Spec.Type == multiclusterv1alpha1.Sync { - logger.Info("Fetching rook secret ", "Secret Name:", rookSecretName) + logger.Info("Fetching rook secret ", "Secret", rookSecretName) hs, err := utils.FetchSecretWithName(ctx, r.Client, types.NamespacedName{Name: rookSecretName, Namespace: currentNamespace}) if err != nil { + logger.Error("Failed to fetch Rook secret", "error", err, "SecretName", rookSecretName, "Namespace", currentNamespace) return err } logger.Info("Unmarshalling rook secret ", "Secret Name:", rookSecretName) rt, err := utils.UnmarshalRookSecretExternal(hs) if err != nil { - logger.Error(err, "Failed to unmarshal rook secret", "Secret", rookSecretName) + logger.Error("Failed to unmarshal Rook secret", "error", err, "SecretName", rookSecretName) return err } fsid = rt.FSID @@ -487,7 +555,7 @@ func (r *MirrorPeerReconciler) createDRClusters(ctx context.Context, mp *multicl logger.Info("Unmarshalling rook secret ", "Secret Name:", rookSecretName) rt, err := utils.UnmarshalHubSecret(hs) if err != nil { - logger.Error(err, "Failed to unmarshal rook secret", "Secret", rookSecretName) + logger.Error("Failed to unmarshal Hub secret", "error", err, "SecretName", rookSecretName) return err } fsid = rt.FSID @@ -497,37 +565,44 @@ func (r *MirrorPeerReconciler) createDRClusters(ctx context.Context, mp *multicl logger.Info("Fetching s3 secret ", "Secret Name:", s3SecretName) ss, err := utils.FetchSecretWithName(ctx, r.Client, types.NamespacedName{Name: s3SecretName, Namespace: clusterName}) if err != nil { + logger.Error("Failed to fetch S3 secret", "error", err, "SecretName", s3SecretName, "Namespace", clusterName) return err } - logger.Info("Unmarshalling s3 secret ", "Secret Name:", s3SecretName) + logger.Info("Unmarshalling S3 secret", "SecretName", s3SecretName) st, err := utils.UnmarshalS3Secret(ss) if err != nil { + logger.Error("Failed to unmarshal S3 secret", "error", err, "SecretName", s3SecretName) return err } - logger.Info("creating and updating dr clusters") + logger.Info("Creating and updating DR clusters", "ClusterName", clusterName) _, err = controllerutil.CreateOrUpdate(ctx, r.Client, &dc, func() error { dc.Spec.S3ProfileName = st.S3ProfileName return nil }) - if err != nil { + logger.Error("Failed to create/update DR cluster", "error", err, "ClusterName", clusterName) return err } - } return nil } func (r *MirrorPeerReconciler) createClusterRoleBindingsForSpoke(ctx context.Context, peer multiclusterv1alpha1.MirrorPeer) error { + logger := r.Logger + logger.Info("Starting to create or update ClusterRoleBindings for the spoke", "MirrorPeerName", peer.Name) + crb := rbacv1.ClusterRoleBinding{} err := r.Client.Get(ctx, types.NamespacedName{Name: spokeClusterRoleBindingName}, &crb) if err != nil { if !k8serrors.IsNotFound(err) { + logger.Error("Failed to get ClusterRoleBinding", "error", err, "ClusterRoleBindingName", spokeClusterRoleBindingName) return err } + logger.Info("ClusterRoleBinding not found, will be created", "ClusterRoleBindingName", spokeClusterRoleBindingName) } + var subjects []rbacv1.Subject if crb.Subjects != nil { subjects = crb.Subjects @@ -539,10 +614,12 @@ func (r *MirrorPeerReconciler) createClusterRoleBindingsForSpoke(ctx context.Con gsub := getSubjectByPeerRef(pr, "Group") if !utils.ContainsSubject(subjects, usub) { subjects = append(subjects, *usub) + logger.Info("Adding user subject to ClusterRoleBinding", "User", usub.Name) } if !utils.ContainsSubject(subjects, gsub) { subjects = append(subjects, *gsub) + logger.Info("Adding group subject to ClusterRoleBinding", "Group", gsub.Name) } } @@ -555,49 +632,53 @@ func (r *MirrorPeerReconciler) createClusterRoleBindingsForSpoke(ctx context.Con spokeRoleBinding.Subjects = subjects if spokeRoleBinding.CreationTimestamp.IsZero() { - // RoleRef is immutable. So inject it only while creating new object. + // RoleRef is immutable, so it's set only while creating new object spokeRoleBinding.RoleRef = rbacv1.RoleRef{ APIGroup: "rbac.authorization.k8s.io", Kind: "ClusterRole", Name: "open-cluster-management:token-exchange:agent", } + logger.Info("Setting RoleRef for new ClusterRoleBinding", "RoleRef", spokeRoleBinding.RoleRef.Name) } return nil }) if err != nil { + logger.Error("Failed to create or update ClusterRoleBinding", "error", err, "ClusterRoleBindingName", spokeClusterRoleBindingName) return err } + + logger.Info("Successfully created or updated ClusterRoleBinding", "ClusterRoleBindingName", spokeClusterRoleBindingName) return nil } func (r *MirrorPeerReconciler) updateMirrorPeerStatus(ctx context.Context, mirrorPeer multiclusterv1alpha1.MirrorPeer) (ctrl.Result, error) { - logger := log.FromContext(ctx) + logger := r.Logger + if mirrorPeer.Spec.Type == multiclusterv1alpha1.Async { tokensExchanged, err := r.checkTokenExchangeStatus(ctx, mirrorPeer) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Secrets not found; Attempting to reconcile again") + logger.Info("Secrets not found; Attempting to reconcile again", "MirrorPeer", mirrorPeer.Name) return ctrl.Result{Requeue: true}, nil } - logger.Info("Error while exchanging tokens", "MirrorPeer", mirrorPeer) + logger.Error("Error while exchanging tokens", "error", err, "MirrorPeer", mirrorPeer.Name) mirrorPeer.Status.Message = err.Error() statusErr := r.Client.Status().Update(ctx, &mirrorPeer) if statusErr != nil { - logger.Error(statusErr, "Error occurred while updating the status of mirrorpeer", "MirrorPeer", mirrorPeer) + logger.Error("Error occurred while updating the status of mirrorpeer", "error", statusErr, "MirrorPeer", mirrorPeer.Name) } return ctrl.Result{}, err } if tokensExchanged { - logger.Info("Tokens exchanged", "MirrorPeer", mirrorPeer) + logger.Info("Tokens exchanged", "MirrorPeer", mirrorPeer.Name) mirrorPeer.Status.Phase = multiclusterv1alpha1.ExchangedSecret mirrorPeer.Status.Message = "" statusErr := r.Client.Status().Update(ctx, &mirrorPeer) if statusErr != nil { - logger.Error(statusErr, "Error occured while updating the status of mirrorpeer", "MirrorPeer", mirrorPeer) - // Requeue, but don't throw + logger.Error("Error occurred while updating the status of mirrorpeer", "error", statusErr, "MirrorPeer", mirrorPeer.Name) return ctrl.Result{Requeue: true}, nil } return ctrl.Result{}, nil @@ -607,25 +688,24 @@ func (r *MirrorPeerReconciler) updateMirrorPeerStatus(ctx context.Context, mirro s3ProfileSynced, err := r.checkS3ProfileStatus(ctx, mirrorPeer) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Secrets not found; Attempting to reconcile again") + logger.Info("S3 secrets not found; Attempting to reconcile again", "MirrorPeer", mirrorPeer.Name) return ctrl.Result{Requeue: true}, nil } - logger.Info("Error while syncing S3 Profile", "MirrorPeer", mirrorPeer) + logger.Error("Error while syncing S3 Profile", "error", err, "MirrorPeer", mirrorPeer.Name) statusErr := r.Client.Status().Update(ctx, &mirrorPeer) if statusErr != nil { - logger.Error(statusErr, "Error occurred while updating the status of mirrorpeer", "MirrorPeer", mirrorPeer) + logger.Error("Error occurred while updating the status of mirrorpeer", "error", statusErr, "MirrorPeer", mirrorPeer.Name) } return ctrl.Result{}, err } if s3ProfileSynced { - logger.Info("S3Profile synced to hub", "MirrorPeer", mirrorPeer) + logger.Info("S3 Profile synced to hub", "MirrorPeer", mirrorPeer.Name) mirrorPeer.Status.Phase = multiclusterv1alpha1.S3ProfileSynced mirrorPeer.Status.Message = "" statusErr := r.Client.Status().Update(ctx, &mirrorPeer) if statusErr != nil { - logger.Error(statusErr, "Error occurred while updating the status of mirrorpeer", "MirrorPeer", mirrorPeer) - // Requeue, but don't throw + logger.Error("Error occurred while updating the status of mirrorpeer", "error", statusErr, "MirrorPeer", mirrorPeer.Name) return ctrl.Result{Requeue: true}, nil } return ctrl.Result{}, nil @@ -636,15 +716,24 @@ func (r *MirrorPeerReconciler) updateMirrorPeerStatus(ctx context.Context, mirro } func (r *MirrorPeerReconciler) checkS3ProfileStatus(ctx context.Context, mp multiclusterv1alpha1.MirrorPeer) (bool, error) { - // If S3Profile secret can be fetched for each peerref in the MirrorPeer then the sync is successful + logger := r.Logger + logger.Info("Checking S3 profile status for each peer reference in the MirrorPeer", "MirrorPeerName", mp.Name) + for _, pr := range mp.Spec.Items { clusterName := pr.ClusterName s3SecretName := utils.GetSecretNameByPeerRef(pr, utils.S3ProfilePrefix) + logger.Info("Attempting to fetch S3 secret", "SecretName", s3SecretName, "ClusterName", clusterName) + _, err := utils.FetchSecretWithName(ctx, r.Client, types.NamespacedName{Name: s3SecretName, Namespace: clusterName}) if err != nil { + logger.Error("Failed to fetch S3 secret", "error", err, "SecretName", s3SecretName, "ClusterName", clusterName) return false, err } + + logger.Info("Successfully fetched S3 secret", "SecretName", s3SecretName, "ClusterName", clusterName) } + + logger.Info("Successfully verified S3 profile status for all peer references", "MirrorPeerName", mp.Name) return true, nil } diff --git a/controllers/mirrorpeer_controller_test.go b/controllers/mirrorpeer_controller_test.go index 4181bafe..8f95a834 100644 --- a/controllers/mirrorpeer_controller_test.go +++ b/controllers/mirrorpeer_controller_test.go @@ -111,6 +111,7 @@ func getFakeMirrorPeerReconciler(mirrorpeer multiclusterv1alpha1.MirrorPeer) Mir r := MirrorPeerReconciler{ Client: fakeClient, Scheme: scheme, + Logger: utils.GetLogger(utils.GetZapLogger(true)), } return r } diff --git a/controllers/mirrorpeersecret_controller.go b/controllers/mirrorpeersecret_controller.go index df48f0d2..cab5313a 100644 --- a/controllers/mirrorpeersecret_controller.go +++ b/controllers/mirrorpeersecret_controller.go @@ -18,6 +18,7 @@ package controllers import ( "context" + "log/slog" "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" @@ -27,13 +28,11 @@ import ( "k8s.io/apimachinery/pkg/labels" "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/selection" - "k8s.io/klog/v2" ctrl "sigs.k8s.io/controller-runtime" "sigs.k8s.io/controller-runtime/pkg/builder" "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/controller/controllerutil" "sigs.k8s.io/controller-runtime/pkg/handler" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" "sigs.k8s.io/yaml" ) @@ -43,6 +42,7 @@ import ( type MirrorPeerSecretReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=multicluster.odf.openshift.io,resources=mirrorpeers,verbs=get;list;watch;create;update;patch;delete @@ -57,12 +57,22 @@ type MirrorPeerSecretReconciler struct { // Reconcile standard reconcile function for MirrorPeerSecret controller func (r *MirrorPeerSecretReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { - // reconcile for 'Secrets' (source or destination) - return mirrorPeerSecretReconcile(ctx, r.Client, req) + logger := r.Logger.With("Request", req.String()) + logger.Info("Starting reconciliation for Secret") + + result, err := r.mirrorPeerSecretReconcile(ctx, r.Client, req) + + if err != nil { + logger.Error("Reconciliation error for Secret", "error", err) + } else { + logger.Info("Reconciliation completed for Secret") + } + + return result, err } -func updateSecretWithHubRecoveryLabel(ctx context.Context, rc client.Client, peerSecret corev1.Secret) error { - logger := log.FromContext(ctx, "controller", "MirrorPeerSecret") +func updateSecretWithHubRecoveryLabel(ctx context.Context, rc client.Client, logger *slog.Logger, peerSecret corev1.Secret) error { + logger = logger.With("SecretName", peerSecret.Name, "Namespace", peerSecret.Namespace) logger.Info("Adding backup labels to the secret") if peerSecret.ObjectMeta.Labels == nil { @@ -74,72 +84,75 @@ func updateSecretWithHubRecoveryLabel(ctx context.Context, rc client.Client, pee return nil }) + if err != nil { + logger.Error("Failed to add or update hub recovery label", "error", err) + } + return err } -func mirrorPeerSecretReconcile(ctx context.Context, rc client.Client, req ctrl.Request) (ctrl.Result, error) { - var err error - logger := log.FromContext(ctx, "controller", "MirrorPeerSecret") +func (r *MirrorPeerSecretReconciler) mirrorPeerSecretReconcile(ctx context.Context, rc client.Client, req ctrl.Request) (ctrl.Result, error) { + logger := r.Logger.With("Request", req.NamespacedName) + logger.Info("Reconciling secret") + var peerSecret corev1.Secret - err = rc.Get(ctx, req.NamespacedName, &peerSecret) + err := rc.Get(ctx, req.NamespacedName, &peerSecret) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Secret not found", "req", req) - return ctrl.Result{}, processDeletedSecrets(ctx, rc, req.NamespacedName) + logger.Info("Secret not found, processing deletion", "Request", req.NamespacedName) + return ctrl.Result{}, processDeletedSecrets(ctx, rc, req.NamespacedName, logger) } - logger.Error(err, "Error in getting secret", "request", req) + logger.Error("Error retrieving secret", "error", err, "Request", req.NamespacedName) return ctrl.Result{}, err } + if utils.IsSecretSource(&peerSecret) { if err := utils.ValidateSourceSecret(&peerSecret); err != nil { - logger.Error(err, "Provided source secret is not valid", "secret", peerSecret.Name, "namespace", peerSecret.Namespace) + logger.Error("Source secret validation failed", "error", err, "Secret", peerSecret.Name) return ctrl.Result{}, err } if !utils.HasHubRecoveryLabels(&peerSecret) { - err = updateSecretWithHubRecoveryLabel(ctx, rc, peerSecret) + err = updateSecretWithHubRecoveryLabel(ctx, rc, logger, peerSecret) if err != nil { - logger.Error(err, "Error occured while adding backup labels to secret. Requeing the request") + logger.Error("Failed to add hub recovery labels", "error", err, "Secret", peerSecret.Name) return ctrl.Result{}, err } } - err = createOrUpdateDestinationSecretsFromSource(ctx, rc, &peerSecret) + err = createOrUpdateDestinationSecretsFromSource(ctx, rc, &peerSecret, logger) if err != nil { - logger.Error(err, "Updating the destination secret failed", "secret", peerSecret.Name, "namespace", peerSecret.Namespace) + logger.Error("Failed to update destination secret", "error", err, "Secret", peerSecret.Name) return ctrl.Result{}, err } } else if utils.IsSecretDestination(&peerSecret) { - // a destination secret updation happened - err = processDestinationSecretUpdation(ctx, rc, &peerSecret) + err = processDestinationSecretUpdation(ctx, rc, &peerSecret, logger) if err != nil { - logger.Error(err, "Restoring destination secret failed", "secret", peerSecret.Name, "namespace", peerSecret.Namespace) + logger.Error("Failed to restore destination secret", "error", err, "Secret", peerSecret.Name) return ctrl.Result{}, err } } else if utils.IsSecretInternal(&peerSecret) { - err = createOrUpdateSecretsFromInternalSecret(ctx, rc, &peerSecret, nil) - if !utils.HasHubRecoveryLabels(&peerSecret) { - err = updateSecretWithHubRecoveryLabel(ctx, rc, peerSecret) - if err != nil { - logger.Error(err, "Error occured while adding backup labels to secret. Requeing the request") - return ctrl.Result{}, err - } - } + err = createOrUpdateSecretsFromInternalSecret(ctx, rc, &peerSecret, nil, logger) if err != nil { - logger.Error(err, "Updating the secret from internal secret is failed", "secret", peerSecret.Name, "namespace", peerSecret.Namespace) + logger.Error("Failed to update from internal secret", "error", err, "Secret", peerSecret.Name) return ctrl.Result{}, err } } + return ctrl.Result{}, nil } // SetupWithManager sets up the controller with the Manager. func (r *MirrorPeerSecretReconciler) SetupWithManager(mgr ctrl.Manager) error { + logger := r.Logger + logger.Info("Setting up controller with manager") return ctrl.NewControllerManagedBy(mgr). For(&corev1.Secret{}, builder.WithPredicates(utils.SourceOrDestinationPredicate)). Watches(&corev1.ConfigMap{}, handler.EnqueueRequestsFromMapFunc(r.secretConfigMapFunc)). Complete(r) + } func (r *MirrorPeerSecretReconciler) secretConfigMapFunc(ctx context.Context, obj client.Object) []reconcile.Request { + logger := r.Logger ConfigMapRamenConfigKeyName := "ramen_manager_config.yaml" var cm *corev1.ConfigMap cm, ok := obj.(*corev1.ConfigMap) @@ -154,13 +167,13 @@ func (r *MirrorPeerSecretReconciler) secretConfigMapFunc(ctx context.Context, ob ramenConfig := &ramendrv1alpha1.RamenConfig{} err := yaml.Unmarshal([]byte(cm.Data[ConfigMapRamenConfigKeyName]), ramenConfig) if err != nil { + logger.Error("Failed to unmarshal RamenConfig from ConfigMap", "error", err, "ConfigMapName", cm.Name) return []reconcile.Request{} } - secrets := &corev1.SecretList{} internalSecretLabel, err := labels.NewRequirement(utils.SecretLabelTypeKey, selection.Equals, []string{string(utils.InternalLabel)}) if err != nil { - klog.Error(err, "cannot parse new requirement") + logger.Error("Failed to create label requirement for internal secrets", "error", err) return []reconcile.Request{} } @@ -170,7 +183,9 @@ func (r *MirrorPeerSecretReconciler) secretConfigMapFunc(ctx context.Context, ob LabelSelector: internalSecretSelector, } - if err := r.Client.List(context.TODO(), secrets, listOpts); err != nil { + secrets := &corev1.SecretList{} + if err := r.Client.List(ctx, secrets, listOpts); err != nil { + logger.Error("Failed to list secrets based on label selector", "error", err, "Selector", internalSecretSelector) return []reconcile.Request{} } @@ -180,5 +195,6 @@ func (r *MirrorPeerSecretReconciler) secretConfigMapFunc(ctx context.Context, ob requests[i].Namespace = secret.GetNamespace() } + logger.Info("Generated reconcile requests from internal secrets", "NumberOfRequests", len(requests)) return requests } diff --git a/controllers/named_peerref_with_data.go b/controllers/named_peerref_with_data.go index fc3d7333..07fb9e22 100644 --- a/controllers/named_peerref_with_data.go +++ b/controllers/named_peerref_with_data.go @@ -3,6 +3,7 @@ package controllers import ( "context" "errors" + "log/slog" "reflect" multiclusterv1alpha1 "github.com/red-hat-storage/odf-multicluster-orchestrator/api/v1alpha1" @@ -12,7 +13,6 @@ import ( "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/controller/controllerutil" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) @@ -103,33 +103,37 @@ func (nPR *NamedPeerRefWithSecretData) GetAssociatedSecret(ctx context.Context, } // CreateOrUpdateDestinationSecret creates/updates the destination secret from NamedPeerRefWithSecretData object -func (nPR *NamedPeerRefWithSecretData) CreateOrUpdateDestinationSecret(ctx context.Context, rc client.Client) error { +func (nPR *NamedPeerRefWithSecretData) CreateOrUpdateDestinationSecret(ctx context.Context, rc client.Client, logger *slog.Logger) error { err := nPR.ErrorOnNilReceiver() if err != nil { + logger.Error("Receiver is nil", "error", err) return err } - logger := log.FromContext(ctx) expectedDest := nPR.GenerateSecret(utils.DestinationLabel) var currentDest corev1.Secret err = nPR.GetAssociatedSecret(ctx, rc, ¤tDest) if err != nil { if k8serrors.IsNotFound(err) { - logger.Info("Creating destination secret", "secret", expectedDest.Name, "namespace", expectedDest.Namespace) + logger.Info("Creating destination secret", "SecretName", expectedDest.Name, "Namespace", expectedDest.Namespace) return rc.Create(ctx, expectedDest) } - logger.Error(err, "Unable to get the destination secret", "destination-ref", nPR.PeerRef) + logger.Error("Unable to get the destination secret", "DestinationRef", nPR.PeerRef, "error", err) return err } - // recieved a destination secret, now compare if !reflect.DeepEqual(expectedDest.Data, currentDest.Data) { - logger.Info("Updating the destination secret", "secret", currentDest.Name, "namespace", currentDest.Namespace) + logger.Info("Updating the destination secret", "SecretName", currentDest.Name, "Namespace", currentDest.Namespace) _, err := controllerutil.CreateOrUpdate(ctx, rc, ¤tDest, func() error { currentDest.Data = expectedDest.Data return nil }) + if err != nil { + logger.Error("Failed to update destination secret", "SecretName", currentDest.Name, "Namespace", currentDest.Namespace, "error", err) + } return err } + + logger.Info("Destination secret is up-to-date", "SecretName", currentDest.Name, "Namespace", currentDest.Namespace) return nil } diff --git a/controllers/utils/logging.go b/controllers/utils/logging.go new file mode 100644 index 00000000..05444be8 --- /dev/null +++ b/controllers/utils/logging.go @@ -0,0 +1,22 @@ +package utils + +import ( + "log/slog" + + "go.uber.org/zap" + "go.uber.org/zap/exp/zapslog" +) + +func GetLogger(zapL *zap.Logger) *slog.Logger { + return slog.New(zapslog.NewHandler(zapL.Core(), nil)) +} + +func GetZapLogger(dev bool) *zap.Logger { + var zapL *zap.Logger + if dev { + zapL = zap.Must(zap.NewDevelopment()) + } else { + zapL = zap.Must(zap.NewProduction()) + } + return zapL +} diff --git a/go.mod b/go.mod index 028e5ce6..0e4c3c18 100644 --- a/go.mod +++ b/go.mod @@ -4,6 +4,7 @@ go 1.21 require ( github.com/csi-addons/kubernetes-csi-addons v0.8.0 + github.com/go-logr/zapr v1.3.0 github.com/kube-object-storage/lib-bucket-provisioner v0.0.0-20221122204822-d1a8c34382f1 github.com/onsi/ginkgo v1.16.5 github.com/onsi/gomega v1.31.1 @@ -14,6 +15,8 @@ require ( github.com/rook/rook/pkg/apis v0.0.0-20231204200402-5287527732f7 github.com/spf13/cobra v1.8.0 github.com/stretchr/testify v1.8.4 + go.uber.org/zap v1.27.0 + go.uber.org/zap/exp v0.2.0 golang.org/x/sync v0.5.0 k8s.io/api v0.29.2 k8s.io/apiextensions-apiserver v0.29.2 @@ -41,7 +44,6 @@ require ( github.com/ghodss/yaml v1.0.1-0.20220118164431-d8423dcdf344 // indirect github.com/go-jose/go-jose/v3 v3.0.3 // indirect github.com/go-logr/logr v1.4.1 // indirect - github.com/go-logr/zapr v1.3.0 // indirect github.com/go-openapi/jsonpointer v0.20.0 // indirect github.com/go-openapi/jsonreference v0.20.2 // indirect github.com/go-openapi/swag v0.22.4 // indirect @@ -94,7 +96,6 @@ require ( github.com/spf13/pflag v1.0.5 // indirect github.com/stolostron/multicloud-operators-placementrule v1.2.4-1-20220311-8eedb3f.0.20230828200208-cd3c119a7fa0 // indirect go.uber.org/multierr v1.11.0 // indirect - go.uber.org/zap v1.26.0 // indirect golang.org/x/crypto v0.19.0 // indirect golang.org/x/exp v0.0.0-20230817173708-d852ddb80c63 // indirect golang.org/x/net v0.19.0 // indirect diff --git a/go.sum b/go.sum index 9d8e2f89..e4b18c64 100644 --- a/go.sum +++ b/go.sum @@ -820,8 +820,10 @@ go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0= go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= go.uber.org/zap v1.9.1/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= -go.uber.org/zap v1.26.0 h1:sI7k6L95XOKS281NhVKOFCUNIvv9e0w4BF8N3u+tCRo= -go.uber.org/zap v1.26.0/go.mod h1:dtElttAiwGvoJ/vj4IwHBS/gXsEu/pZ50mUIRWuG0so= +go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8= +go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E= +go.uber.org/zap/exp v0.2.0 h1:FtGenNNeCATRB3CmB/yEUnjEFeJWpB/pMcy7e2bKPYs= +go.uber.org/zap/exp v0.2.0/go.mod h1:t0gqAIdh1MfKv9EwN/dLwfZnJxe9ITAZN78HEWPFWDQ= golang.org/x/crypto v0.0.0-20180820150726-614d502a4dac/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20181029021203-45a5f77698d3/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= diff --git a/tests/integration/mirrorpeer_controller_test.go b/tests/integration/mirrorpeer_controller_test.go index 4dbb8bfd..be24b80c 100644 --- a/tests/integration/mirrorpeer_controller_test.go +++ b/tests/integration/mirrorpeer_controller_test.go @@ -21,6 +21,7 @@ package integration_test import ( "context" + "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" . "github.com/onsi/ginkgo" @@ -338,6 +339,7 @@ var _ = Describe("MirrorPeerReconciler Reconcile", func() { r := controllers.MirrorPeerReconciler{ Client: k8sClient, Scheme: k8sClient.Scheme(), + Logger: utils.GetLogger(utils.GetZapLogger(true)), } req := ctrl.Request{ diff --git a/tests/integration/mirrorpeer_status_test.go b/tests/integration/mirrorpeer_status_test.go index 7990a536..2d27285f 100644 --- a/tests/integration/mirrorpeer_status_test.go +++ b/tests/integration/mirrorpeer_status_test.go @@ -21,6 +21,8 @@ package integration_test import ( "context" + "time" + . "github.com/onsi/ginkgo" . "github.com/onsi/gomega" multiclusterv1alpha1 "github.com/red-hat-storage/odf-multicluster-orchestrator/api/v1alpha1" @@ -30,7 +32,6 @@ import ( "k8s.io/apimachinery/pkg/types" clusterv1 "open-cluster-management.io/api/cluster/v1" "sigs.k8s.io/controller-runtime/pkg/client" - "time" ) var _ = Describe("MirrorPeer Status Tests", func() { diff --git a/tests/integration/ramen_test.go b/tests/integration/ramen_test.go index 411dae4a..d5a26457 100644 --- a/tests/integration/ramen_test.go +++ b/tests/integration/ramen_test.go @@ -20,6 +20,8 @@ package integration_test import ( "context" + "time" + . "github.com/onsi/ginkgo" . "github.com/onsi/gomega" ramenv1alpha1 "github.com/ramendr/ramen/api/v1alpha1" @@ -30,7 +32,6 @@ import ( "k8s.io/apimachinery/pkg/types" clusterv1 "open-cluster-management.io/api/cluster/v1" "sigs.k8s.io/controller-runtime/pkg/client" - "time" ) var _ = Describe("Ramen Resource Tests", func() { diff --git a/tests/integration/suite_test.go b/tests/integration/suite_test.go index 3d848f74..24145ae5 100644 --- a/tests/integration/suite_test.go +++ b/tests/integration/suite_test.go @@ -29,6 +29,7 @@ import ( . "github.com/onsi/gomega" multiclusterv1alpha1 "github.com/red-hat-storage/odf-multicluster-orchestrator/api/v1alpha1" "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers" + "github.com/red-hat-storage/odf-multicluster-orchestrator/controllers/utils" "k8s.io/client-go/kubernetes/scheme" "k8s.io/client-go/rest" addonapiv1alpha1 "open-cluster-management.io/api/addon/v1alpha1" @@ -98,15 +99,18 @@ var _ = BeforeSuite(func() { Expect(err).NotTo(HaveOccurred()) Expect(mgr).NotTo(BeNil()) + fakeLogger := utils.GetLogger(utils.GetZapLogger(true)) err = (&controllers.MirrorPeerReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: fakeLogger, }).SetupWithManager(mgr) Expect(err).NotTo(HaveOccurred()) err = (&controllers.MirrorPeerSecretReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: fakeLogger, }).SetupWithManager(mgr) Expect(err).NotTo(HaveOccurred())