Adding debug logs to helm-project-operator

charts/helm-project-operator/Chart.yaml

@@ -1,8 +1,8 @@
 apiVersion: v2
 name: helm-project-operator
 description: Helm Project Operator
-version: 0.2.0
-appVersion: 0.2.0
+version: 0.2.1
+appVersion: 0.2.1
 annotations:
   catalog.cattle.io/certified: rancher
   catalog.cattle.io/display-name: Helm Project Operator

pkg/applier/applyinator.go

@@ -11,6 +11,7 @@ import (
 	"k8s.io/client-go/util/workqueue"
 )
 
+// TODO
 var (
 	defaultRateLimiter = workqueue.NewMaxOfRateLimiter(
 		workqueue.NewItemFastSlowRateLimiter(time.Millisecond, 2*time.Minute, 30),
@@ -66,6 +67,7 @@ func applyDefaultOptions(opts *Options) *Options {
 	}
 	if newOpts.RateLimiter == nil {
 		newOpts.RateLimiter = defaultRateLimiter
+		logrus.Debug("No rate limiter supplied, using default rate limiter.")
 	}
 	return &newOpts
 }
@@ -83,6 +85,8 @@ func (a *applyinator) Apply(key string) {
 
 // Run allows the applyinator to start processing items added to its workqueue
 func (a *applyinator) Run(ctx context.Context, workers int) {
+
+	logrus.Debug("Adding items to applyinator work queue. Workers: %d", workers)
 	go func() {
 		<-ctx.Done()
 		a.workqueue.ShutDown()
@@ -101,6 +105,7 @@ func (a *applyinator) processNextWorkItem() bool {
 	obj, shutdown := a.workqueue.Get()
 
 	if shutdown {
+		logrus.Debug("ProcessNextWorkItem called during shutdown. Exiting function.")
 		return false
 	}
 
@@ -132,6 +137,7 @@ func (a *applyinator) processSingleItem(obj interface{}) error {
 		return fmt.Errorf("error syncing '%s': %s, requeuing", key, err.Error())
 	}
 
+	logrus.Debug("Call to processSingleItem was successful for key: %s", key)
 	a.workqueue.Forget(obj)
 	return nil
 }

pkg/controllers/namespace/controller.go

@@ -109,13 +109,16 @@ func Register(
 func (h *handler) OnSingleNamespaceChange(name string, namespace *corev1.Namespace) (*corev1.Namespace, error) {
 	if namespace.Name != h.systemNamespace {
 		// enqueue system namespace to ensure that rolebindings are updated
+
+		logrus.Debugf("Enqueue system namespace to ensure that rolebindings are updated in OnSingleNamespaceChange: %s", h.systemNamespace)
 		h.namespaces.Enqueue(h.systemNamespace)
 		return namespace, nil
 	}
 	if namespace.DeletionTimestamp != nil {
 		// When a namespace gets deleted, the ConfigMap deployed in that namespace should also get deleted
 		// Therefore, we do not need to apply anything in this situation to avoid spamming logs with trying to apply
 		// a resource to a namespace that is being terminated
+		logrus.Debugf("OnSingleNamespaceChange %s has deletion timestamp of %d", namespace, namespace.DeletionTimestamp)
 		return namespace, nil
 	}
 	// Trigger applying the data for this projectRegistrationNamespace
@@ -128,6 +131,7 @@ func (h *handler) OnSingleNamespaceChange(name string, namespace *corev1.Namespa
 
 func (h *handler) OnMultiNamespaceChange(name string, namespace *corev1.Namespace) (*corev1.Namespace, error) {
 	if namespace == nil {
+		logrus.Debugf("OnMultiNamespaceChange() called with no namespace.")
 		return namespace, nil
 	}
 
@@ -140,18 +144,22 @@ func (h *handler) OnMultiNamespaceChange(name string, namespace *corev1.Namespac
 	case h.isProjectRegistrationNamespace(namespace):
 		err := h.enqueueProjectNamespaces(namespace)
 		if err != nil {
+			logrus.Debugf("Error in call to isProjectRegistrationNamespace() while enqueuing project namespace %s: %s", namespace, err)
 			return namespace, err
 		}
 		if namespace.DeletionTimestamp != nil {
+			logrus.Debugf("%s has deletion timestamp %d in isProjectRegistrationNamespace()", namespace, namespace.DeletionTimestamp)
 			h.projectRegistrationNamespaceTracker.Delete(namespace)
 		}
 		return namespace, nil
 	case h.isSystemNamespace(namespace):
 		// nothing to do, we always ignore system namespaces
+		logrus.Debugf("Ignoring system namespace: %s", namespace)
 		return namespace, nil
 	default:
 		err := h.applyProjectRegistrationNamespaceForNamespace(namespace)
 		if err != nil {
+			logrus.Debugf("Default error in isProjectRegistrationNamespace() %s: %s", namespace, err)
 			return namespace, err
 		}
 		return namespace, nil
@@ -180,6 +188,7 @@ func (h *handler) enqueueProjectNamespaces(projectRegistrationNamespace *corev1.
 	for _, ns := range projectNamespaces {
 		h.namespaces.Enqueue(ns.Name)
 	}
+	logrus.Debugf("ProjectRegistrationNamespace %s was modified or removed in call to enqueueProjectNamespaces(). Reenqueiing any namepsaced tied to it.", projectRegistrationNamespace.Name)
 	return nil
 }
 
@@ -190,12 +199,14 @@ func (h *handler) applyProjectRegistrationNamespaceForNamespace(namespace *corev
 	// update the namespace with the appropriate label on it
 	err := h.updateNamespaceWithHelmOperatorProjectLabel(namespace, projectID, inProject)
 	if err != nil {
+		logrus.Debugf("Error updating namespace %s with %s labels", namespace, projectID)
 		return nil
 	}
 	if !inProject {
 		return nil
 	}
 
+	logrus.Infof("Calling projectRegistrationNamespaceApplyinator for project %s", projectID)
 	// Note: why do we use an Applyinator.Apply here instead of just directly
 	// running h.applyProjectRegistrationNamespace?
 	//

pkg/controllers/namespace/reconcilers.go

@@ -5,6 +5,7 @@ import (
 
 	"github.com/rancher/wrangler/pkg/apply"
 	"github.com/rancher/wrangler/pkg/unstructured"
+	"github.com/sirupsen/logrus"
 	corev1 "k8s.io/api/core/v1"
 	"k8s.io/apimachinery/pkg/api/meta"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
@@ -22,6 +23,8 @@ func (h *handler) addReconcilers(apply apply.Apply, dynamic dynamic.Interface) a
 		NamespaceableResourceInterface: dynamic.Resource(corev1.SchemeGroupVersion.WithResource("configmaps")),
 	}
 	apply = apply.WithReconciler(corev1.SchemeGroupVersion.WithKind("ConfigMap"), r.deleteAndReplace)
+
+	logrus.Infof("Adding reconcilers on the apply object %s", apply)
 	return apply
 }
 

pkg/controllers/project/registrationdata.go

@@ -5,6 +5,7 @@ import (
 
 	v1alpha1 "github.com/rancher/helm-project-operator/pkg/apis/helm.cattle.io/v1alpha1"
 	"github.com/rancher/helm-project-operator/pkg/controllers/common"
+	"github.com/sirupsen/logrus"
 	rbacv1 "k8s.io/api/rbac/v1"
 )
 
@@ -36,6 +37,7 @@ func (h *handler) getSubjectRoleToSubjectsFromBindings(projectHelmChart *v1alpha
 		}
 		subjectRole, isDefaultRoleRef := common.IsDefaultClusterRoleRef(h.opts, rb.RoleRef.Name)
 		if !isDefaultRoleRef {
+			logrus.Debugf("Role %s is not a default role for %s", subjectRole, projectHelmChart.Namespace)
 			continue
 		}
 		filteredSubjects := common.FilterToUsersAndGroups(rb.Subjects)

pkg/controllers/project/resolvers.go

@@ -8,6 +8,7 @@ import (
 	"github.com/rancher/helm-project-operator/pkg/controllers/common"
 	"github.com/rancher/wrangler/pkg/apply"
 	"github.com/rancher/wrangler/pkg/relatedresource"
+	"github.com/sirupsen/logrus"
 	corev1 "k8s.io/api/core/v1"
 	rbacv1 "k8s.io/api/rbac/v1"
 	"k8s.io/apimachinery/pkg/labels"
@@ -82,10 +83,13 @@ func (h *handler) resolveSystemNamespaceData(namespace, name string, obj runtime
 // Project Registration Namespace Data
 
 func (h *handler) resolveProjectRegistrationNamespaceData(namespace, name string, obj runtime.Object) ([]relatedresource.Key, error) {
+	//h.projectHelmCharts, h.rolebindings, h.clusterrolebindings
+
 	if obj == nil {
 		return nil, nil
 	}
 	if rb, ok := obj.(*rbacv1.RoleBinding); ok {
+		logrus.Debugf("Resolving project registration namespace rolebindings for %s", namespace)
 		return h.resolveProjectRegistrationNamespaceRoleBinding(namespace, name, rb)
 	}
 	if crb, ok := obj.(*rbacv1.ClusterRoleBinding); ok {
@@ -97,12 +101,15 @@ func (h *handler) resolveProjectRegistrationNamespaceData(namespace, name string
 func (h *handler) resolveProjectRegistrationNamespaceRoleBinding(namespace, name string, rb *rbacv1.RoleBinding) ([]relatedresource.Key, error) {
 	namespaceObj, err := h.namespaceCache.Get(namespace)
 	if err != nil {
+		logrus.Debugf("Namespace not found %s: ", namespace)
 		return nil, err
 	}
 	isProjectRegistrationNamespace := h.projectGetter.IsProjectRegistrationNamespace(namespaceObj)
 	if !isProjectRegistrationNamespace {
+		logrus.Debugf("%s is not a project registration namespace: ", namespace)
 		return nil, nil
 	}
+
 	// we want to re-enqueue the ProjectHelmChart if the rolebinding's ref points to one of the operator default roles
 	_, isDefaultRoleRef := common.IsDefaultClusterRoleRef(h.opts, rb.RoleRef.Name)
 	if !isDefaultRoleRef {
@@ -111,6 +118,7 @@ func (h *handler) resolveProjectRegistrationNamespaceRoleBinding(namespace, name
 	// re-enqueue all HelmCharts in this project registration namespace
 	projectHelmCharts, err := h.projectHelmChartCache.List(namespace, labels.Everything())
 	if err != nil {
+		logrus.Debugf("Error in resolveProjectRegistrationNamespaceRoleBinding while re-enqueuing HelmCharts in %s", namespace)
 		return nil, err
 	}
 	var keys []relatedresource.Key
@@ -148,6 +156,7 @@ func (h *handler) resolveClusterRoleBinding(namespace, name string, crb *rbacv1.
 		}
 		projectHelmCharts, err := h.projectHelmChartCache.List(namespace.Name, labels.Everything())
 		if err != nil {
+			logrus.Debugf("Error in resolveClusterRoleBinding while re-enqueuing HelmCharts in %s", namespace)
 			return nil, err
 		}
 		for _, projectHelmChart := range projectHelmCharts {