Merge pull request #6435 from jabellard/cluster-ctrl-logs

JSON logging for cluster controllers

Author: karmada-bot

pkg/controllers/cluster/cluster_controller.go

@@ -154,7 +154,7 @@ func (n *clusterHealthData) deepCopy() *clusterHealthData {
 // The Controller will requeue the Request to be processed again if an error is non-nil or
 // Result.Requeue is true, otherwise upon completion it will remove the work from the queue.
 func (c *Controller) Reconcile(ctx context.Context, req controllerruntime.Request) (controllerruntime.Result, error) {
-	klog.V(4).Infof("Reconciling cluster %s", req.NamespacedName.Name)
+	klog.V(4).InfoS("Reconciling cluster", "cluster", req.NamespacedName.Name)
 
 	cluster := &clusterv1alpha1.Cluster{}
 	if err := c.Client.Get(ctx, req.NamespacedName, cluster); err != nil {
@@ -175,13 +175,13 @@ func (c *Controller) Reconcile(ctx context.Context, req controllerruntime.Reques
 
 // Start starts an asynchronous loop that monitors the status of cluster.
 func (c *Controller) Start(ctx context.Context) error {
-	klog.Infof("Starting cluster health monitor")
-	defer klog.Infof("Shutting cluster health monitor")
+	klog.InfoS("Starting cluster health monitor")
+	defer klog.InfoS("Shutting cluster health monitor")
 
 	// Incorporate the results of cluster health signal pushed from cluster-status-controller to master.
 	go wait.UntilWithContext(ctx, func(ctx context.Context) {
 		if err := c.monitorClusterHealth(ctx); err != nil {
-			klog.Errorf("Error monitoring cluster health: %v", err)
+			klog.ErrorS(err, "Error monitoring cluster health")
 		}
 	}, c.ClusterMonitorPeriod)
 	<-ctx.Done()
@@ -219,18 +219,18 @@ func (c *Controller) syncCluster(ctx context.Context, cluster *clusterv1alpha1.C
 
 func (c *Controller) removeCluster(ctx context.Context, cluster *clusterv1alpha1.Cluster) (controllerruntime.Result, error) {
 	if err := c.removeExecutionSpace(ctx, cluster); err != nil {
-		klog.Errorf("Failed to remove execution space %s: %v", cluster.Name, err)
+		klog.ErrorS(err, "Failed to remove execution space", "cluster", cluster.Name)
 		c.EventRecorder.Event(cluster, corev1.EventTypeWarning, events.EventReasonRemoveExecutionSpaceFailed, err.Error())
 		return controllerruntime.Result{}, err
 	}
 	msg := fmt.Sprintf("Removed execution space for cluster(%s).", cluster.Name)
 	c.EventRecorder.Event(cluster, corev1.EventTypeNormal, events.EventReasonRemoveExecutionSpaceSucceed, msg)
 
 	if exist, err := c.ExecutionSpaceExistForCluster(ctx, cluster.Name); err != nil {
-		klog.Errorf("Failed to check weather the execution space exist in the given member cluster or not, error is: %v", err)
+		klog.ErrorS(err, "Failed to check execution space existence", "cluster", cluster.Name)
 		return controllerruntime.Result{}, err
 	} else if exist {
-		klog.Infof("Requeuing operation until the cluster(%s) execution space deleted", cluster.Name)
+		klog.InfoS("Requeuing operation until execution space deleted", "cluster", cluster.Name)
 		return controllerruntime.Result{RequeueAfter: c.CleanupCheckInterval}, nil
 	}
 
@@ -287,12 +287,12 @@ func (c *Controller) removeExecutionSpace(ctx context.Context, cluster *clusterv
 	// delete finalizers of work objects when the sync-mode is pull and cluster status is notready or unknown
 	if cluster.Spec.SyncMode == clusterv1alpha1.Pull && !util.IsClusterReady(&cluster.Status) {
 		if err := c.deleteFinalizerForWorks(ctx, executionSpaceObj); err != nil {
-			klog.Errorf("Error while deleting finalizers of work which in %s: %s", executionSpaceName, err)
+			klog.ErrorS(err, "Error while deleting finalizers of work", "namespace", executionSpaceName)
 			return err
 		}
 	}
 	if err := c.Client.Delete(ctx, executionSpaceObj); err != nil && !apierrors.IsNotFound(err) {
-		klog.Errorf("Error while deleting namespace %s: %s", executionSpaceName, err)
+		klog.ErrorS(err, "Error while deleting namespace", "namespace", executionSpaceName)
 		return err
 	}
 
@@ -306,11 +306,11 @@ func (c *Controller) ExecutionSpaceExistForCluster(ctx context.Context, clusterN
 	executionSpaceObj := &corev1.Namespace{}
 	err := c.Client.Get(ctx, types.NamespacedName{Name: executionSpaceName}, executionSpaceObj)
 	if apierrors.IsNotFound(err) {
-		klog.V(2).Infof("Execution space(%s) no longer exists", executionSpaceName)
+		klog.V(2).InfoS("Execution space no longer exists", "namespace", executionSpaceName)
 		return false, nil
 	}
 	if err != nil {
-		klog.Errorf("Failed to get execution space %v, err is %v ", executionSpaceName, err)
+		klog.ErrorS(err, "Failed to get execution space", "namespace", executionSpaceName)
 		return false, err
 	}
 	return true, nil
@@ -323,7 +323,7 @@ func (c *Controller) deleteFinalizerForWorks(ctx context.Context, workSpace *cor
 		Namespace: workSpace.Name,
 	})
 	if err != nil {
-		klog.Errorf("Failed to list works in %s: %s", workSpace.Name, err)
+		klog.ErrorS(err, "Failed to list works in namespace", "namespace", workSpace.Name)
 		return err
 	}
 
@@ -386,7 +386,7 @@ func (c *Controller) createExecutionSpace(ctx context.Context, cluster *clusterv
 	err := c.Client.Get(ctx, types.NamespacedName{Name: executionSpaceName}, executionSpaceObj)
 	if err != nil {
 		if !apierrors.IsNotFound(err) {
-			klog.Errorf("Failed to get namespace(%s): %v", executionSpaceName, err)
+			klog.ErrorS(err, "Failed to get namespace", "namespace", executionSpaceName)
 			return err
 		}
 
@@ -401,11 +401,11 @@ func (c *Controller) createExecutionSpace(ctx context.Context, cluster *clusterv
 		}
 		err = c.Client.Create(ctx, executionSpace)
 		if err != nil {
-			klog.Errorf("Failed to create execution space for cluster(%s): %v", cluster.Name, err)
+			klog.ErrorS(err, "Failed to create execution space", "cluster", cluster.Name)
 			return err
 		}
 		msg := fmt.Sprintf("Created execution space(%s) for cluster(%s).", executionSpaceName, cluster.Name)
-		klog.V(2).Info(msg)
+		klog.V(2).InfoS(msg)
 		c.EventRecorder.Event(cluster, corev1.EventTypeNormal, events.EventReasonCreateExecutionSpaceSucceed, msg)
 	}
 
@@ -438,7 +438,7 @@ func (c *Controller) monitorClusterHealth(ctx context.Context) (err error) {
 			}
 			return false, nil
 		}); err != nil {
-			klog.Errorf("Update health of Cluster '%v' from Controller error: %v. Skipping.", cluster.Name, err)
+			klog.ErrorS(err, "Failed to update health, skipping", "cluster", cluster.Name)
 			continue
 		}
 	}
@@ -531,8 +531,7 @@ func (c *Controller) tryUpdateClusterHealth(ctx context.Context, cluster *cluste
 		for _, clusterConditionType := range clusterConditionTypes {
 			currentCondition := meta.FindStatusCondition(cluster.Status.Conditions, clusterConditionType)
 			if currentCondition == nil {
-				klog.V(2).Infof("Condition %v of cluster %v was never updated by cluster-status-controller",
-					clusterConditionType, cluster.Name)
+				klog.V(2).InfoS("Condition was never updated by cluster-status-controller", "condition", clusterConditionType, "cluster", cluster.Name)
 				cluster.Status.Conditions = append(cluster.Status.Conditions, metav1.Condition{
 					Type:               clusterConditionType,
 					Status:             metav1.ConditionUnknown,
@@ -541,8 +540,9 @@ func (c *Controller) tryUpdateClusterHealth(ctx context.Context, cluster *cluste
 					LastTransitionTime: nowTimestamp,
 				})
 			} else {
-				klog.V(2).Infof("Cluster %v hasn't been updated for %+v. Last %v is: %+v",
+				message := fmt.Sprintf("Cluster %v hasn't been updated for %+v. Last %v is: %+v",
 					cluster.Name, metav1.Now().Time.Sub(clusterHealth.probeTimestamp.Time), clusterConditionType, currentCondition)
+				klog.V(2).InfoS(message, "cluster", cluster.Name)
 				if currentCondition.Status != metav1.ConditionUnknown {
 					currentCondition.Status = metav1.ConditionUnknown
 					currentCondition.Reason = "ClusterStatusUnknown"
@@ -556,7 +556,7 @@ func (c *Controller) tryUpdateClusterHealth(ctx context.Context, cluster *cluste
 
 		if !equality.Semantic.DeepEqual(currentReadyCondition, observedReadyCondition) {
 			if err := c.Status().Update(ctx, cluster); err != nil {
-				klog.Errorf("Error updating cluster %s: %v", cluster.Name, err)
+				klog.ErrorS(err, "Error updating cluster status", "cluster", cluster.Name)
 				return err
 			}
 			clusterHealth = &clusterHealthData{

pkg/controllers/cluster/taint_manager.go

@@ -67,7 +67,7 @@ type NoExecuteTaintManager struct {
 // The Controller will requeue the Request to be processed again if an error is non-nil or
 // Result.Requeue is true, otherwise upon completion it will remove the work from the queue.
 func (tc *NoExecuteTaintManager) Reconcile(ctx context.Context, req reconcile.Request) (reconcile.Result, error) {
-	klog.V(4).Infof("Reconciling cluster %s for taint manager", req.NamespacedName.Name)
+	klog.V(4).InfoS("Reconciling cluster for taint manager", "cluster", req.NamespacedName.Name)
 
 	cluster := &clusterv1alpha1.Cluster{}
 	if err := tc.Client.Get(ctx, req.NamespacedName, cluster); err != nil {
@@ -98,7 +98,7 @@ func (tc *NoExecuteTaintManager) syncCluster(ctx context.Context, cluster *clust
 	for i := range rbList.Items {
 		key, err := keys.FederatedKeyFunc(cluster.Name, &rbList.Items[i])
 		if err != nil {
-			klog.Warningf("Failed to generate key for obj: %s", rbList.Items[i].GetObjectKind().GroupVersionKind())
+			klog.ErrorS(err, "Failed to generate federated key for ResourceBinding", "gvk", rbList.Items[i].GetObjectKind().GroupVersionKind())
 			continue
 		}
 		tc.bindingEvictionWorker.Add(key)
@@ -115,7 +115,7 @@ func (tc *NoExecuteTaintManager) syncCluster(ctx context.Context, cluster *clust
 	for i := range crbList.Items {
 		key, err := keys.FederatedKeyFunc(cluster.Name, &crbList.Items[i])
 		if err != nil {
-			klog.Warningf("Failed to generate key for obj: %s", crbList.Items[i].GetObjectKind().GroupVersionKind())
+			klog.ErrorS(err, "Failed to generate federated key for ClusterResourceBinding", "gvk", crbList.Items[i].GetObjectKind().GroupVersionKind())
 			continue
 		}
 		tc.clusterBindingEvictionWorker.Add(key)
@@ -148,12 +148,12 @@ func (tc *NoExecuteTaintManager) Start(ctx context.Context) error {
 func (tc *NoExecuteTaintManager) syncBindingEviction(key util.QueueKey) error {
 	fedKey, ok := key.(keys.FederatedKey)
 	if !ok {
-		klog.Errorf("Failed to sync binding eviction as invalid key: %v", key)
-		return fmt.Errorf("invalid key")
+		err := fmt.Errorf("invalid key type %T", key)
+		klog.ErrorS(err, "Failed to sync binding eviction due to invalid key", "key", key)
+		return err
 	}
 	cluster := fedKey.Cluster
-	klog.V(4).Infof("Begin to sync ResourceBinding(%s) with taintManager for Cluster(%s)",
-		fedKey.ClusterWideKey.NamespaceKey(), cluster)
+	klog.V(4).InfoS("Begin syncing ResourceBinding for taint eviction", "binding", fedKey.ClusterWideKey.NamespaceKey(), "cluster", cluster)
 
 	binding := &workv1alpha2.ResourceBinding{}
 	if err := tc.Client.Get(context.TODO(), types.NamespacedName{Namespace: fedKey.Namespace, Name: fedKey.Name}, binding); err != nil {
@@ -205,8 +205,7 @@ func (tc *NoExecuteTaintManager) syncBindingEviction(key util.QueueKey) error {
 			klog.ErrorS(err, "Failed to update binding", "binding", klog.KObj(binding))
 			return err
 		}
-		klog.V(2).Infof("Success to evict Cluster(%s) from ResourceBinding(%s) schedule result",
-			fedKey.Cluster, fedKey.ClusterWideKey.NamespaceKey())
+		klog.V(2).InfoS("Evicted cluster from ResourceBinding", "cluster", fedKey.Cluster, "binding", fedKey.ClusterWideKey.NamespaceKey())
 	} else if tolerationTime > 0 {
 		tc.bindingEvictionWorker.AddAfter(fedKey, tolerationTime)
 	}
@@ -217,12 +216,12 @@ func (tc *NoExecuteTaintManager) syncBindingEviction(key util.QueueKey) error {
 func (tc *NoExecuteTaintManager) syncClusterBindingEviction(key util.QueueKey) error {
 	fedKey, ok := key.(keys.FederatedKey)
 	if !ok {
-		klog.Errorf("Failed to sync cluster binding eviction as invalid key: %v", key)
-		return fmt.Errorf("invalid key")
+		err := fmt.Errorf("invalid key type %T", key)
+		klog.ErrorS(err, "Failed to sync cluster binding eviction due to invalid key", "key", key)
+		return err
 	}
 	cluster := fedKey.Cluster
-	klog.V(4).Infof("Begin to sync ClusterResourceBinding(%s) with taintManager for Cluster(%s)",
-		fedKey.ClusterWideKey.NamespaceKey(), cluster)
+	klog.V(4).InfoS("Begin syncing ClusterResourceBinding with taintManager", "binding", fedKey.ClusterWideKey.NamespaceKey(), "cluster", cluster)
 
 	binding := &workv1alpha2.ClusterResourceBinding{}
 	if err := tc.Client.Get(context.TODO(), types.NamespacedName{Name: fedKey.Name}, binding); err != nil {
@@ -264,8 +263,7 @@ func (tc *NoExecuteTaintManager) syncClusterBindingEviction(key util.QueueKey) e
 			klog.ErrorS(err, "Failed to update cluster binding", "binding", binding.Name)
 			return err
 		}
-		klog.V(2).Infof("Success to evict Cluster(%s) from ClusterResourceBinding(%s) schedule result",
-			fedKey.ClusterWideKey.NamespaceKey(), fedKey.Cluster)
+		klog.V(2).InfoS("Evicted cluster from ClusterResourceBinding", "cluster", fedKey.Cluster, "binding", fedKey.ClusterWideKey.NamespaceKey())
 	} else if tolerationTime > 0 {
 		tc.clusterBindingEvictionWorker.AddAfter(fedKey, tolerationTime)
 		return nil