controller: add more logging to labelling

Signed-off-by: Steve Kuznetsov <skuznets@redhat.com>

Author: stevekuznetsov

pkg/controller/operators/catalog/operator.go

@@ -399,6 +399,8 @@ func NewOperator(ctx context.Context, kubeconfigPath string, clock utilclock.Clo
 			idx = 0
 			complete[gvr] = []bool{false}
 		}
+		logger := op.logger.WithFields(logrus.Fields{"gvr": gvr.String(), "index": idx})
+		logger.Info("registering labeller")
 
 		queue := workqueue.NewRateLimitingQueueWithConfig(workqueue.DefaultControllerRateLimiter(), workqueue.RateLimitingQueueConfig{
 			Name: gvr.String(),
@@ -415,6 +417,7 @@ func NewOperator(ctx context.Context, kubeconfigPath string, clock utilclock.Clo
 				// when every action we know about has been completed, we re-start the process to allow the future
 				// invocation of this process to filter informers (canFilter = true) and elide all this logic
 				completeLock.Lock()
+				logger.Info("labeller complete")
 				complete[gvr][idx] = true
 				allDone := true
 				for _, items := range complete {

pkg/controller/operators/labeller/labels.go

@@ -78,6 +78,7 @@ func ObjectLabeler[T metav1.Object, A ApplyConfig[A]](
 				return nil
 			}
 
+			logger.WithFields(logrus.Fields{"namespace": cast.GetNamespace(), "name": cast.GetName()}).Info("applying ownership label")
 			cfg := applyConfigFor(cast.GetName(), cast.GetNamespace())
 			cfg.WithLabels(map[string]string{
 				install.OLMManagedLabelKey: install.OLMManagedLabelValue,
@@ -159,6 +160,7 @@ func ObjectPatchLabeler(
 				return fmt.Errorf("failed to Marshal old data for %s/%s: %w", updated.GetNamespace(), updated.GetName(), err)
 			}
 
+			logger.WithFields(logrus.Fields{"namespace": cast.GetNamespace(), "name": cast.GetName()}).Info("patching ownership label")
 			patchBytes, err := jsonpatch.CreateMergePatch(oldData, newData)
 			if err != nil {
 				return fmt.Errorf("failed to create patch for %s/%s: %w", cast.GetNamespace(), cast.GetName(), err)

pkg/controller/operators/labeller/rbac.go

@@ -5,9 +5,7 @@ import (
 	"fmt"
 	"os"
 
-	"github.com/operator-framework/api/pkg/operators/v1alpha1"
 	"github.com/operator-framework/operator-lifecycle-manager/pkg/controller/registry/resolver"
-	"github.com/operator-framework/operator-lifecycle-manager/pkg/lib/ownerutil"
 	"github.com/operator-framework/operator-lifecycle-manager/pkg/lib/queueinformer"
 	"github.com/sirupsen/logrus"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -37,7 +35,7 @@ func ContentHashLabeler[T metav1.Object, A ApplyConfig[A]](
 				return fmt.Errorf("casting failed: %w", err)
 			}
 
-			if _, _, ok := ownerutil.GetOwnerByKindLabel(cast, v1alpha1.ClusterServiceVersionKind); !ok {
+			if !check(cast) || hasHashLabel(cast) {
 				// if the object we're processing does not need us to label it, it's possible that every object that requires
 				// the label already has it; in which case we should exit the process, so the Pod that succeeds us can filter
 				// the informers used to drive the controller and stop having to track extraneous objects
@@ -60,15 +58,12 @@ func ContentHashLabeler[T metav1.Object, A ApplyConfig[A]](
 				return nil
 			}
 
-			if !check(cast) || hasHashLabel(cast) {
-				return nil
-			}
-
 			hash, err := hasher(cast)
 			if err != nil {
 				return fmt.Errorf("failed to calculate hash: %w", err)
 			}
 
+			logger.WithFields(logrus.Fields{"namespace": cast.GetNamespace(), "name": cast.GetName()}).Info("applying content hash label")
 			cfg := applyConfigFor(cast.GetName(), cast.GetNamespace())
 			cfg.WithLabels(map[string]string{
 				resolver.ContentHashLabelKey: hash,

pkg/controller/operators/olm/operator.go

@@ -515,6 +515,9 @@ func newOperatorWithConfig(ctx context.Context, config *operatorConfig) (*Operat
 			idx = 0
 			complete[gvr] = []bool{false}
 		}
+		logger := op.logger.WithFields(logrus.Fields{"gvr": gvr.String(), "index": idx})
+		logger.Info("registering labeller")
+
 		queue := workqueue.NewRateLimitingQueueWithConfig(workqueue.DefaultControllerRateLimiter(), workqueue.RateLimitingQueueConfig{
 			Name: gvr.String(),
 		})
@@ -530,6 +533,7 @@ func newOperatorWithConfig(ctx context.Context, config *operatorConfig) (*Operat
 				// when every action we know about has been completed, we re-start the process to allow the future
 				// invocation of this process to filter informers (canFilter = true) and elide all this logic
 				completeLock.Lock()
+				logger.Info("labeller complete")
 				complete[gvr][idx] = true
 				allDone := true
 				for _, items := range complete {