diff --git a/staging/operator-lifecycle-manager/pkg/controller/operators/catalog/operator.go b/staging/operator-lifecycle-manager/pkg/controller/operators/catalog/operator.go index 2b0e3d592e..78d060976a 100644 --- a/staging/operator-lifecycle-manager/pkg/controller/operators/catalog/operator.go +++ b/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 diff --git a/staging/operator-lifecycle-manager/test/e2e/csv_e2e_test.go b/staging/operator-lifecycle-manager/test/e2e/csv_e2e_test.go index 0d8e3e2abc..132571910e 100644 --- a/staging/operator-lifecycle-manager/test/e2e/csv_e2e_test.go +++ b/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 diff --git a/staging/operator-lifecycle-manager/test/e2e/installplan_e2e_test.go b/staging/operator-lifecycle-manager/test/e2e/installplan_e2e_test.go index ad52f2a542..f3c8732f9f 100644 --- a/staging/operator-lifecycle-manager/test/e2e/installplan_e2e_test.go +++ b/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() { diff --git a/staging/operator-lifecycle-manager/test/e2e/subscription_e2e_test.go b/staging/operator-lifecycle-manager/test/e2e/subscription_e2e_test.go index 9a8a487873..6d499797fd 100644 --- a/staging/operator-lifecycle-manager/test/e2e/subscription_e2e_test.go +++ b/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{} diff --git a/staging/operator-lifecycle-manager/test/e2e/util.go b/staging/operator-lifecycle-manager/test/e2e/util.go index fa7e3480e5..5032e67579 100644 --- a/staging/operator-lifecycle-manager/test/e2e/util.go +++ b/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 } diff --git a/vendor/github.com/operator-framework/operator-lifecycle-manager/pkg/controller/operators/catalog/operator.go b/vendor/github.com/operator-framework/operator-lifecycle-manager/pkg/controller/operators/catalog/operator.go index 2b0e3d592e..78d060976a 100644 --- a/vendor/github.com/operator-framework/operator-lifecycle-manager/pkg/controller/operators/catalog/operator.go +++ b/vendor/github.com/operator-framework/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