debug

Signed-off-by: Yuji Ito <llamerada.jp@gmail.com>

Author: llamerada-jp

internal/controller/garbage_collector_runner.go

@@ -45,13 +45,13 @@ func (r *GarbageCollectorRunner) Start(ctx context.Context) error {
 			break
 		}
 
-		logger.Info("garbage collection started")
+		// logger.Info("garbage collection started")
 
 		if err := r.deleteOrphanedPVs(ctx); err != nil {
 			logger.Error(err, "failed to delete orphaned PVs", "error", err)
 		}
 
-		logger.Info("garbage collection finished")
+		// logger.Info("garbage collection finished")
 	}
 
 	return nil

internal/controller/mantlebackup_controller.go

@@ -432,6 +432,8 @@ func (r *MantleBackupReconciler) reconcileAsSecondary(ctx context.Context, backu
 		return ctrl.Result{}, err
 	}
 
+	logger.Info("reconciling as secondary mantle-controller", "backup", backup.Name)
+
 	if !isCreatedWhenMantleControllerWasSecondary(backup) {
 		logger.Info(
 			"skipping to reconcile the MantleBackup created by a different mantle-controller to prevent accidental data loss",
@@ -440,17 +442,22 @@ func (r *MantleBackupReconciler) reconcileAsSecondary(ctx context.Context, backu
 	}
 
 	target, result, err := r.getSnapshotTarget(ctx, backup)
+	logger.Info("get target", "backup", backup.Name, "targetPVC", target.pvc.Name, "err", err)
+
 	notFound := aerrors.IsNotFound(err)
 	switch {
 	case errors.Is(err, errSkipProcessing):
+		logger.Info("skipping", "backup", backup.Name)
 		return ctrl.Result{}, nil
 	case err != nil && !notFound:
 		return ctrl.Result{}, err
 	}
 	if !result.IsZero() {
+		logger.Info("returning early", "backup", backup.Name)
 		return result, nil
 	}
 	if !backup.DeletionTimestamp.IsZero() {
+		logger.Info("deleted", "backup", backup.Name)
 		return r.finalizeSecondary(ctx, backup, target, notFound)
 	}
 	// Only the NotFound error reaches this point, so return it as is.
@@ -459,14 +466,19 @@ func (r *MantleBackupReconciler) reconcileAsSecondary(ctx context.Context, backu
 	}
 
 	if err := r.expire(ctx, backup); err != nil {
+		logger.Info("expired", "backup", backup.Name)
 		return ctrl.Result{}, err
 	}
 
 	if backup.IsReady() {
-		return r.secondaryCleanup(ctx, backup, true)
+		result, err = r.secondaryCleanup(ctx, backup, true)
+		logger.Info("cleanup called", "backup", backup.Name, "result", result, "err", err)
+		return result, err
 	}
 
-	return r.startImport(ctx, backup, target)
+	result, err = r.startImport(ctx, backup, target)
+	logger.Info("import", "backup", backup.Name, "result", result, "err", err)
+	return result, err
 }
 
 func scheduleExpire(_ context.Context, evt event.TypedGenericEvent[client.Object], q workqueue.TypedRateLimitingInterface[ctrl.Request]) {

test/e2e/Makefile

@@ -329,10 +329,28 @@ do-test-multik8s: $(GINKGO)
 	$(GINKGO) --fail-fast -v $(GINKGO_FLAGS) multik8s; \
 	if [ "$$?" -ne 0 ]; then \
 		echo "Controller logs for $(MINIKUBE_PROFILE_PRIMARY):"; \
-		$${KUBECTL_PRIMARY} logs --tail 100 -n $(CEPH_CLUSTER1_NAMESPACE) -l app.kubernetes.io/name=mantle -c mantle; \
+		$${KUBECTL_PRIMARY} logs --tail 1000 -n $(CEPH_CLUSTER1_NAMESPACE) -l app.kubernetes.io/name=mantle -c mantle; \
 		echo ""; \
 		echo "Controller logs for $(MINIKUBE_PROFILE_SECONDARY):"; \
-		$${KUBECTL_SECONDARY}  logs --tail 100 -n $(CEPH_CLUSTER1_NAMESPACE) -l app.kubernetes.io/name=mantle -c mantle; \
+		$${KUBECTL_SECONDARY}  logs --tail 1000 -n $(CEPH_CLUSTER1_NAMESPACE) -l app.kubernetes.io/name=mantle -c mantle; \
+		echo ""; \
+		echo "Primary MBs"; \
+		$${KUBECTL_PRIMARY} get mantlebackups -A -o yaml; \
+		echo ""; \
+		echo "Secondary MBs"; \
+		$${KUBECTL_SECONDARY} get mantlebackups -A -o yaml; \
+		echo ""; \
+		echo "Primary PVCs"; \
+		$${KUBECTL_PRIMARY} get pvc -A -o yaml; \
+		echo ""; \
+		echo "Secondary PVCs"; \
+		$${KUBECTL_SECONDARY} get pvc -A -o yaml; \
+		echo ""; \
+		echo "Primary PVs"; \
+		$${KUBECTL_PRIMARY} get pv -o yaml; \
+		echo ""; \
+		echo "Secondary PVs"; \
+		$${KUBECTL_SECONDARY} get pv -o yaml; \
 		# Explicitly fail the test to mark the CI job as failed. \
 		exit 1; \
 	fi

test/e2e/multik8s/incr_backup_test.go

@@ -83,6 +83,7 @@ var _ = Describe("incremental backup", Label("incr-backup"), func() {
 		// create M2.
 		writtenDataHash2 := WriteRandomDataToPV(ctx, PrimaryK8sCluster, namespace, pvcName)
 		CreateMantleBackup(PrimaryK8sCluster, namespace, pvcName, backupName2)
+		By("waiting for M2' to be synced:" + backupName2)
 		WaitMantleBackupSynced(namespace, backupName2)
 
 		primaryMB2, err := GetMB(PrimaryK8sCluster, namespace, backupName2)

test/e2e/multik8s/testutil/util.go

@@ -12,6 +12,7 @@ import (
 	"os/exec"
 	"regexp"
 	"slices"
+	"strconv"
 	"strings"
 	"time"
 
@@ -468,6 +469,8 @@ func CreatePod(cluster int, namespace, podName, pvcName string) {
 }
 
 func CreatePVC(ctx SpecContext, cluster int, namespace, name string) {
+	GinkgoHelper()
+	By("creating a PVC @ " + strconv.FormatInt(int64(cluster), 10) + " : " + namespace + "/" + name)
 	Eventually(ctx, func() error {
 		return applyPVCTemplate(cluster, namespace, name)
 	}).Should(Succeed())
@@ -493,7 +496,7 @@ func WriteRandomDataToPV(ctx SpecContext, cluster int, namespace, pvcName string
 
 func CreateMantleBackup(cluster int, namespace, pvcName, backupName string) {
 	GinkgoHelper()
-	By("creating a MantleBackup object")
+	By("creating a MantleBackup object @ " + strconv.FormatInt(int64(cluster), 10) + " : " + namespace + "/" + backupName)
 	Eventually(func() error {
 		return ApplyMantleBackupTemplate(cluster, namespace, pvcName, backupName)
 	}).Should(Succeed())