From 9487e4e8cad9542e8be0c69aa7a2736870d197ce Mon Sep 17 00:00:00 2001
From: Nir Soffer <nsoffer@redhat.com>
Date: Sun, 1 Dec 2024 23:49:22 +0200
Subject: [PATCH] Avoid bogus errors during deletion

When deleting the DRPC we may need to adopt the VRG, delete the
secondary VRG, wait until the secondary VRG is deleted, delete the
primary VRG, and wait until the primary VRG is deleted. This takes 60-90
seconds and many reconciles (18 seen in e2e test), and creates huge
amount of noise in the log.

Suppress the noise by introducing the deleteInProgress error. When the
reconcile is successful but it is still in progress, we return a
deleteInProgress error describing the current progression. The top level
error handle logs an INFO message and requeue the request.

With this change we will see multiple logs for the secondary VRG:

    INFO    Deleting DRPC in progress {"reason", "secondary VRG deletion in progress"}
    ...

And finally more logs for the primary VRG:

    INFO    Deleting DRPC in progress {"reason", "primary VRG deletion in progress"}
    ...

Notes:

- We logged errors during finalizeDRPC twice; once as INFO log, and once
  as ERROR with a stacktrace when we return error from the reconcile.
  Remove the duplicate INFO log.

- The linter is not happy about the new nested if. We can avoid this by
  extracting a helper to handle finalize errors, but I want to keep the
  change minimal for easy backport. We can improve this later upstream.

Signed-off-by: Nir Soffer <nsoffer@redhat.com>
---
 .../drplacementcontrol_controller.go          | 38 ++++++++++++++-----
 1 file changed, 29 insertions(+), 9 deletions(-)

diff --git a/internal/controller/drplacementcontrol_controller.go b/internal/controller/drplacementcontrol_controller.go
index 753bfd8a8..fd357a31a 100644
--- a/internal/controller/drplacementcontrol_controller.go
+++ b/internal/controller/drplacementcontrol_controller.go
@@ -65,6 +65,18 @@ var InitialWaitTimeForDRPCPlacementRule = errorswrapper.New("Waiting for DRPC Pl
 // ProgressCallback of function type
 type ProgressCallback func(string, string)
 
+// DeleteInProgress error is returned during DRPC deletion when we need to wait and try later.
+type deleteInProgress struct{ string }
+
+func (e deleteInProgress) Error() string { return e.string }
+
+// Is called by errors.Is() to match errors of same type.
+func (deleteInProgress) Is(target error) bool {
+	_, ok := target.(deleteInProgress)
+
+	return ok
+}
+
 // DRPlacementControlReconciler reconciles a DRPlacementControl object
 type DRPlacementControlReconciler struct {
 	client.Client
@@ -119,7 +131,7 @@ func (r *DRPlacementControlReconciler) SetupWithManager(mgr ctrl.Manager) error
 // For more details, check Reconcile and its Result here:
 // - https://pkg.go.dev/sigs.k8s.io/controller-runtime@v0.7.0/pkg/reconcile
 //
-//nolint:funlen,gocognit,gocyclo,cyclop
+//nolint:funlen,gocognit,gocyclo,cyclop,nestif
 func (r *DRPlacementControlReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
 	logger := r.Log.WithValues("DRPC", req.NamespacedName, "rid", uuid.New())
 
@@ -166,13 +178,21 @@ func (r *DRPlacementControlReconciler) Reconcile(ctx context.Context, req ctrl.R
 		// then the DRPC should be deleted as well. The least we should do here is to clean up DPRC.
 		err := r.processDeletion(ctx, drpc, placementObj, logger)
 		if err != nil {
-			logger.Info(fmt.Sprintf("Error in deleting DRPC: (%v)", err))
-
 			statusErr := r.setDeletionStatusAndUpdate(ctx, drpc)
 			if statusErr != nil {
 				err = fmt.Errorf("drpc deletion failed: %w and status update failed: %w", err, statusErr)
+
+				return ctrl.Result{}, err
+			}
+
+			// Is this an expected condition?
+			if errorswrapper.Is(err, deleteInProgress{}) {
+				logger.Info("Deleting DRPC in progress", "reason", err)
+
+				return ctrl.Result{Requeue: true}, nil
 			}
 
+			// Unexpected error.
 			return ctrl.Result{}, err
 		}
 
@@ -736,7 +756,7 @@ func (r *DRPlacementControlReconciler) cleanupVRGs(
 	}
 
 	if len(vrgs) != 0 {
-		return fmt.Errorf("waiting for VRGs count to go to zero")
+		return deleteInProgress{"waiting for VRGs count to go to zero"}
 	}
 
 	// delete MCVs
@@ -756,24 +776,24 @@ func (r *DRPlacementControlReconciler) ensureVRGsDeleted(
 	vrgNamespace string,
 	replicationState rmn.ReplicationState,
 ) error {
-	var deleteInProgress bool
+	var inProgress bool
 
 	for cluster, vrg := range vrgs {
 		if vrg.Spec.ReplicationState == replicationState {
 			if !ensureVRGsManagedByDRPC(r.Log, mwu, vrgs, drpc, vrgNamespace) {
-				return fmt.Errorf("%s VRG adoption in progress", replicationState)
+				return deleteInProgress{fmt.Sprintf("%s VRG adoption in progress", replicationState)}
 			}
 
 			if err := mwu.DeleteManifestWork(mwu.BuildManifestWorkName(rmnutil.MWTypeVRG), cluster); err != nil {
 				return fmt.Errorf("failed to delete %s VRG manifestwork for cluster %q: %w", replicationState, cluster, err)
 			}
 
-			deleteInProgress = true
+			inProgress = true
 		}
 	}
 
-	if deleteInProgress {
-		return fmt.Errorf("%s VRG manifestwork deletion in progress", replicationState)
+	if inProgress {
+		return deleteInProgress{fmt.Sprintf("%s VRG manifestwork deletion in progress", replicationState)}
 	}
 
 	return nil