Merge pull request openshift#670 from kevinrizza/backport-e2es

[release-4.15] OCPBUGS-25798: Fix snapshot failure, backport e2es

Author: openshift-merge-bot[bot]

staging/operator-lifecycle-manager/pkg/controller/operators/catalog/operator.go

@@ -346,7 +346,7 @@ func NewOperator(ctx context.Context, kubeconfigPath string, clock utilclock.Clo
 		subscription.WithAppendedReconcilers(subscription.ReconcilerFromLegacySyncHandler(op.syncSubscriptions, nil)),
 		subscription.WithRegistryReconcilerFactory(op.reconciler),
 		subscription.WithGlobalCatalogNamespace(op.namespace),
-		subscription.WithSourceProvider(resolverSourceProvider),
+		subscription.WithSourceProvider(op.sourceInvalidator),
 	)
 	if err != nil {
 		return nil, err

staging/operator-lifecycle-manager/test/e2e/csv_e2e_test.go

@@ -4441,6 +4441,7 @@ func fetchCSV(c versioned.Interface, namespace, name string, checker csvConditio
 	var lastPhase operatorsv1alpha1.ClusterServiceVersionPhase
 	var lastReason operatorsv1alpha1.ConditionReason
 	var lastMessage string
+	var lastError string
 	lastTime := time.Now()
 	var csv *operatorsv1alpha1.ClusterServiceVersion
 
@@ -4449,7 +4450,10 @@ func fetchCSV(c versioned.Interface, namespace, name string, checker csvConditio
 		var err error
 		csv, err = c.OperatorsV1alpha1().ClusterServiceVersions(namespace).Get(context.TODO(), name, metav1.GetOptions{})
 		if err != nil || csv == nil {
-			ctx.Ctx().Logf("error getting csv %s/%s: %v", namespace, name, err)
+			if lastError != err.Error() {
+				ctx.Ctx().Logf("error getting csv %s/%s: %v", namespace, name, err)
+				lastError = err.Error()
+			}
 			return false, nil
 		}
 		phase, reason, message := csv.Status.Phase, csv.Status.Reason, csv.Status.Message

staging/operator-lifecycle-manager/test/e2e/installplan_e2e_test.go

@@ -2792,10 +2792,13 @@ var _ = Describe("Install Plan", func() {
 		_, err := fetchCatalogSourceOnStatus(crc, mainCatalogSourceName, generatedNamespace.GetName(), catalogSourceRegistryPodSynced())
 		require.NoError(GinkgoT(), err)
 
+		By("Creating a Subscription")
 		subscriptionName := genName("sub-nginx-")
-		subscriptionCleanup := createSubscriptionForCatalog(crc, generatedNamespace.GetName(), subscriptionName, mainCatalogSourceName, packageName, stableChannel, "", operatorsv1alpha1.ApprovalAutomatic)
-		defer subscriptionCleanup()
+		// Subscription is explitly deleted as part of the test to avoid CSV being recreated,
+		// so ignore cleanup function
+		_ = createSubscriptionForCatalog(crc, generatedNamespace.GetName(), subscriptionName, mainCatalogSourceName, packageName, stableChannel, "", operatorsv1alpha1.ApprovalAutomatic)
 
+		By("Attempt to get Subscription")
 		subscription, err := fetchSubscription(crc, generatedNamespace.GetName(), subscriptionName, subscriptionHasInstallPlanChecker())
 		require.NoError(GinkgoT(), err)
 		require.NotNil(GinkgoT(), subscription)
@@ -2867,22 +2870,38 @@ var _ = Describe("Install Plan", func() {
 		By("Should have removed every matching step")
 		require.Equal(GinkgoT(), 0, len(expectedSteps), "Actual resource steps do not match expected: %#v", expectedSteps)
 
-		GinkgoT().Logf("deleting csv %s/%s", generatedNamespace.GetName(), stableCSVName)
-		By("Explicitly delete the CSV")
-		err = crc.OperatorsV1alpha1().ClusterServiceVersions(generatedNamespace.GetName()).Delete(context.Background(), stableCSVName, metav1.DeleteOptions{})
+		By(fmt.Sprintf("Explicitly deleting subscription %s/%s", generatedNamespace.GetName(), subscriptionName))
+		err = crc.OperatorsV1alpha1().Subscriptions(generatedNamespace.GetName()).Delete(context.Background(), subscriptionName, metav1.DeleteOptions{})
 		By("Looking for no error OR IsNotFound error")
-		if err != nil && apierrors.IsNotFound(err) {
-			err = nil
-		}
-		require.NoError(GinkgoT(), err)
+		require.NoError(GinkgoT(), client.IgnoreNotFound(err))
+
+		By("Waiting for the Subscription to delete")
+		err = waitForSubscriptionToDelete(generatedNamespace.GetName(), subscriptionName, crc)
+		require.NoError(GinkgoT(), client.IgnoreNotFound(err))
 
+		By(fmt.Sprintf("Explicitly deleting csv %s/%s", generatedNamespace.GetName(), stableCSVName))
+		err = crc.OperatorsV1alpha1().ClusterServiceVersions(generatedNamespace.GetName()).Delete(context.Background(), stableCSVName, metav1.DeleteOptions{})
+		By("Looking for no error OR IsNotFound error")
+		require.NoError(GinkgoT(), client.IgnoreNotFound(err))
+		By("Waiting for the CSV to delete")
+		err = waitForCsvToDelete(generatedNamespace.GetName(), stableCSVName, crc)
+		require.NoError(GinkgoT(), client.IgnoreNotFound(err))
+
+		nCrs := 0
+		nCrbs := 0
+		By("Waiting for CRBs and CRs and SAs to delete")
 		Eventually(func() bool {
+
 			crbs, err := c.KubernetesInterface().RbacV1().ClusterRoleBindings().List(context.Background(), metav1.ListOptions{LabelSelector: fmt.Sprintf("%v=%v", ownerutil.OwnerKey, stableCSVName)})
 			if err != nil {
 				GinkgoT().Logf("error getting crbs: %v", err)
 				return false
 			}
-			if len(crbs.Items) != 0 {
+			if n := len(crbs.Items); n != 0 {
+				if n != nCrbs {
+					GinkgoT().Logf("CRBs remaining:  %v", n)
+					nCrbs = n
+				}
 				return false
 			}
 
@@ -2891,18 +2910,23 @@ var _ = Describe("Install Plan", func() {
 				GinkgoT().Logf("error getting crs: %v", err)
 				return false
 			}
-			if len(crs.Items) != 0 {
+			if n := len(crs.Items); n != 0 {
+				if n != nCrs {
+					GinkgoT().Logf("CRs remaining: %v", n)
+					nCrs = n
+				}
 				return false
 			}
 
 			_, err = c.KubernetesInterface().CoreV1().ServiceAccounts(generatedNamespace.GetName()).Get(context.Background(), serviceAccountName, metav1.GetOptions{})
-			if err != nil && !apierrors.IsNotFound(err) {
+			if client.IgnoreNotFound(err) != nil {
 				GinkgoT().Logf("error getting sa %s/%s: %v", generatedNamespace.GetName(), serviceAccountName, err)
 				return false
 			}
 
 			return true
 		}, pollDuration*2, pollInterval).Should(BeTrue())
+		By("Cleaning up the test")
 	})
 
 	It("CRD validation", func() {

staging/operator-lifecycle-manager/test/e2e/subscription_e2e_test.go

@@ -38,7 +38,6 @@ import (
 	"github.com/operator-framework/operator-lifecycle-manager/pkg/controller/install"
 	"github.com/operator-framework/operator-lifecycle-manager/pkg/controller/registry"
 	"github.com/operator-framework/operator-lifecycle-manager/pkg/controller/registry/resolver/projection"
-	"github.com/operator-framework/operator-lifecycle-manager/pkg/lib/comparison"
 	"github.com/operator-framework/operator-lifecycle-manager/pkg/lib/operatorclient"
 	"github.com/operator-framework/operator-lifecycle-manager/test/e2e/ctx"
 	registryapi "github.com/operator-framework/operator-registry/pkg/api"
@@ -328,7 +327,7 @@ var _ = Describe("Subscription", func() {
 		subscriptionCleanup, _ := createSubscription(GinkgoT(), crc, generatedNamespace.GetName(), "manual-subscription", testPackageName, stableChannel, operatorsv1alpha1.ApprovalManual)
 		defer subscriptionCleanup()
 
-		subscription, err := fetchSubscription(crc, generatedNamespace.GetName(), "manual-subscription", subscriptionStateUpgradePendingChecker())
+		subscription, err := fetchSubscription(crc, generatedNamespace.GetName(), "manual-subscription", subscriptionHasCondition(operatorsv1alpha1.SubscriptionInstallPlanPending, corev1.ConditionTrue, string(operatorsv1alpha1.InstallPlanPhaseRequiresApproval), ""))
 		require.NoError(GinkgoT(), err)
 		require.NotNil(GinkgoT(), subscription)
 
@@ -1029,29 +1028,7 @@ var _ = Describe("Subscription", func() {
 	})
 
 	It("can reconcile InstallPlan status", func() {
-		By(`TestSubscriptionInstallPlanStatus ensures that a Subscription has the appropriate status conditions for possible referenced`)
-		By(`InstallPlan states.`)
-		By(`	BySteps:`)
-		By(`- Utilize the namespace and OG targeting that namespace created in the BeforeEach clause`)
-		By(`- Create CatalogSource, cs, in ns`)
-		By(`- Create Subscription to a package of cs in ns, sub`)
-		By(`- Wait for the package from sub to install successfully with no remaining InstallPlan status conditions`)
-		By(`- Store conditions for later comparision`)
-		By(`- Get the InstallPlan`)
-		By(`- Set the InstallPlan's approval mode to Manual`)
-		By(`- Set the InstallPlan's phase to None`)
-		By(`- Wait for sub to have status condition SubscriptionInstallPlanPending true and reason InstallPlanNotYetReconciled`)
-		By(`- Get the latest IntallPlan and set the phase to InstallPlanPhaseRequiresApproval`)
-		By(`- Wait for sub to have status condition SubscriptionInstallPlanPending true and reason RequiresApproval`)
-		By(`- Get the latest InstallPlan and set the phase to InstallPlanPhaseInstalling`)
-		By(`- Wait for sub to have status condition SubscriptionInstallPlanPending true and reason Installing`)
-		By(`- Get the latest InstallPlan and set the phase to InstallPlanPhaseFailed and remove all status conditions`)
-		By(`- Wait for sub to have status condition SubscriptionInstallPlanFailed true and reason InstallPlanFailed`)
-		By(`- Get the latest InstallPlan and set status condition of type Installed to false with reason InstallComponentFailed`)
-		By(`- Wait for sub to have status condition SubscriptionInstallPlanFailed true and reason InstallComponentFailed`)
-		By(`- Delete the referenced InstallPlan`)
-		By(`- Wait for sub to have status condition SubscriptionInstallPlanMissing true`)
-		By(`- Ensure original non-InstallPlan status conditions remain after InstallPlan transitions`)
+		By(`TestSubscriptionInstallPlanStatus ensures that a Subscription has the appropriate status conditions for possible referenced InstallPlan states.`)
 		c := newKubeClient()
 		crc := newCRClient()
 
@@ -1099,6 +1076,7 @@ var _ = Describe("Subscription", func() {
 		ref := sub.Status.InstallPlanRef
 		Expect(ref).ToNot(BeNil())
 
+		By(`Get the InstallPlan`)
 		plan := &operatorsv1alpha1.InstallPlan{}
 		plan.SetNamespace(ref.Namespace)
 		plan.SetName(ref.Name)
@@ -1151,14 +1129,14 @@ var _ = Describe("Subscription", func() {
 				return true
 			}
 
-			By(`Sometimes the transition from installing to complete can be so quick that the test does not capture`)
-			By(`the condition in the subscription before it is removed. To mitigate this, we check if the installplan`)
-			By(`has transitioned to complete and exit out the fetch subscription loop if so.`)
-			By(`This is a mitigation. We should probably fix this test appropriately.`)
-			By(`issue: https://github.com/operator-framework/operator-lifecycle-manager/issues/2667`)
+			// Sometimes the transition from installing to complete can be so quick that the test does not capture
+			// the condition in the subscription before it is removed. To mitigate this, we check if the installplan
+			// has transitioned to complete and exit out the fetch subscription loop if so.
+			// This is a mitigation. We should probably fix this test appropriately.
+			// issue: https://github.com/operator-framework/operator-lifecycle-manager/issues/2667
 			ip, err := crc.OperatorsV1alpha1().InstallPlans(generatedNamespace.GetName()).Get(context.TODO(), plan.Name, metav1.GetOptions{})
 			if err != nil {
-				By(`retry on failure`)
+				// retry on failure
 				return false
 			}
 			isInstallPlanComplete := ip.Status.Phase == operatorsv1alpha1.InstallPlanPhaseComplete
@@ -1210,16 +1188,13 @@ var _ = Describe("Subscription", func() {
 		Expect(err).ToNot(HaveOccurred())
 		Expect(sub).ToNot(BeNil())
 
-		By(`Ensure original non-InstallPlan status conditions remain after InstallPlan transitions`)
-		hashEqual := comparison.NewHashEqualitor()
+		By(`Ensure InstallPlan-related status conditions match what we're expecting`)
 		for _, cond := range conds {
 			switch condType := cond.Type; condType {
 			case operatorsv1alpha1.SubscriptionInstallPlanPending, operatorsv1alpha1.SubscriptionInstallPlanFailed:
 				require.FailNowf(GinkgoT(), "failed", "subscription contains unexpected installplan condition: %v", cond)
 			case operatorsv1alpha1.SubscriptionInstallPlanMissing:
 				require.Equal(GinkgoT(), operatorsv1alpha1.ReferencedInstallPlanNotFound, cond.Reason)
-			default:
-				require.True(GinkgoT(), hashEqual(cond, sub.Status.GetCondition(condType)), "non-installplan status condition changed")
 			}
 		}
 	})
@@ -3218,27 +3193,53 @@ func subscriptionHasCurrentCSV(currentCSV string) subscriptionStateChecker {
 }
 
 func subscriptionHasCondition(condType operatorsv1alpha1.SubscriptionConditionType, status corev1.ConditionStatus, reason, message string) subscriptionStateChecker {
+	var lastCond operatorsv1alpha1.SubscriptionCondition
+	lastTime := time.Now()
+	// if status/reason/message meet expectations, then subscription state is considered met/true
+	// IFF this is the result of a recent change of status/reason/message
+	// else, cache the current status/reason/message for next loop/comparison
 	return func(subscription *operatorsv1alpha1.Subscription) bool {
 		cond := subscription.Status.GetCondition(condType)
 		if cond.Status == status && cond.Reason == reason && cond.Message == message {
-			fmt.Printf("subscription condition met %v\n", cond)
+			if lastCond.Status != cond.Status && lastCond.Reason != cond.Reason && lastCond.Message == cond.Message {
+				GinkgoT().Logf("waited %s subscription condition met %v\n", time.Since(lastTime), cond)
+				lastTime = time.Now()
+				lastCond = cond
+			}
 			return true
 		}
 
-		fmt.Printf("subscription condition not met: %v\n", cond)
+		if lastCond.Status != cond.Status && lastCond.Reason != cond.Reason && lastCond.Message == cond.Message {
+			GinkgoT().Logf("waited %s subscription condition not met: %v\n", time.Since(lastTime), cond)
+			lastTime = time.Now()
+			lastCond = cond
+		}
 		return false
 	}
 }
 
 func subscriptionDoesNotHaveCondition(condType operatorsv1alpha1.SubscriptionConditionType) subscriptionStateChecker {
+	var lastStatus corev1.ConditionStatus
+	lastTime := time.Now()
+	// if status meets expectations, then subscription state is considered met/true
+	// IFF this is the result of a recent change of status
+	// else, cache the current status for next loop/comparison
 	return func(subscription *operatorsv1alpha1.Subscription) bool {
 		cond := subscription.Status.GetCondition(condType)
 		if cond.Status == corev1.ConditionUnknown {
-			fmt.Printf("subscription condition not found\n")
+			if cond.Status != lastStatus {
+				GinkgoT().Logf("waited %s subscription condition not found\n", time.Since(lastTime))
+				lastStatus = cond.Status
+				lastTime = time.Now()
+			}
 			return true
 		}
 
-		fmt.Printf("subscription condition found: %v\n", cond)
+		if cond.Status != lastStatus {
+			GinkgoT().Logf("waited %s subscription condition found: %v\n", time.Since(lastTime), cond)
+			lastStatus = cond.Status
+			lastTime = time.Now()
+		}
 		return false
 	}
 }
@@ -3365,6 +3366,35 @@ func createSubscriptionForCatalogWithSpec(t GinkgoTInterface, crc versioned.Inte
 	return buildSubscriptionCleanupFunc(crc, subscription)
 }
 
+func waitForSubscriptionToDelete(namespace, name string, c versioned.Interface) error {
+	var lastState operatorsv1alpha1.SubscriptionState
+	var lastReason operatorsv1alpha1.ConditionReason
+	lastTime := time.Now()
+
+	ctx.Ctx().Logf("waiting for subscription %s/%s to delete", namespace, name)
+	err := wait.Poll(pollInterval, pollDuration, func() (bool, error) {
+		sub, err := c.OperatorsV1alpha1().Subscriptions(namespace).Get(context.TODO(), name, metav1.GetOptions{})
+		if apierrors.IsNotFound(err) {
+			ctx.Ctx().Logf("subscription %s/%s deleted", namespace, name)
+			return true, nil
+		}
+		if err != nil {
+			ctx.Ctx().Logf("error getting subscription %s/%s: %v", namespace, name, err)
+		}
+		if sub != nil {
+			state, reason := sub.Status.State, sub.Status.Reason
+			if state != lastState || reason != lastReason {
+				ctx.Ctx().Logf("waited %s for subscription %s/%s status: %s (%s)", time.Since(lastTime), namespace, name, state, reason)
+				lastState, lastReason = state, reason
+				lastTime = time.Now()
+			}
+		}
+		return false, nil
+	})
+
+	return err
+}
+
 func checkDeploymentHasPodConfigNodeSelector(t GinkgoTInterface, client operatorclient.ClientInterface, csv *operatorsv1alpha1.ClusterServiceVersion, nodeSelector map[string]string) error {
 	resolver := install.StrategyResolver{}
 

staging/operator-lifecycle-manager/test/e2e/util.go

@@ -677,8 +677,10 @@ func createInternalCatalogSource(
 	ctx.Ctx().Logf("Catalog source %s created", name)
 
 	cleanupInternalCatalogSource := func() {
+		ctx.Ctx().Logf("Cleaning catalog source %s", name)
 		configMapCleanup()
 		buildCatalogSourceCleanupFunc(c, crc, namespace, catalogSource)()
+		ctx.Ctx().Logf("Done cleaning catalog source %s", name)
 	}
 	return catalogSource, cleanupInternalCatalogSource
 }