improve logging for the machine provisioning workflow

kubernetes-sigs · Aug 2, 2022 · dbb6218 · dbb6218
1 parent d761e1b
commit dbb6218
Show file tree

Hide file tree

Showing 3 changed files with 18 additions and 9 deletions.
diff --git a/internal/controllers/machine/machine_controller_noderef.go b/internal/controllers/machine/machine_controller_noderef.go
@@ -23,7 +23,6 @@ import (
 	"github.com/pkg/errors"
 	corev1 "k8s.io/api/core/v1"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
-	"k8s.io/klog/v2"
 	ctrl "sigs.k8s.io/controller-runtime"
 	"sigs.k8s.io/controller-runtime/pkg/client"
 
@@ -46,7 +45,7 @@ func (r *Reconciler) reconcileNode(ctx context.Context, cluster *clusterv1.Clust
 
 	// Check that the Machine has a valid ProviderID.
 	if machine.Spec.ProviderID == nil || *machine.Spec.ProviderID == "" {
-		log.Info("Cannot reconcile Machine's Node, no valid ProviderID yet")
+		log.Info("Waiting for infrastructure provider to report spec.providerID", util.LowerCamelCase(machine.Spec.InfrastructureRef.Kind), klog.KRef(machine.Spec.InfrastructureRef.Namespace, machine.Spec.InfrastructureRef.Name))
 		conditions.MarkFalse(machine, clusterv1.MachineNodeHealthyCondition, clusterv1.WaitingForNodeRefReason, clusterv1.ConditionSeverityInfo, "")
 		return ctrl.Result{}, nil
 	}
@@ -88,7 +87,7 @@ func (r *Reconciler) reconcileNode(ctx context.Context, cluster *clusterv1.Clust
 			Name:       node.Name,
 			UID:        node.UID,
 		}
-		log.Info("Set Machine's NodeRef", "noderef", machine.Status.NodeRef.Name)
+		log.Info("Infrastructure provider reporting spec.providerID, Kubernetes node is now available", util.LowerCamelCase(machine.Spec.InfrastructureRef.Kind), klog.KRef(machine.Spec.InfrastructureRef.Namespace, machine.Spec.InfrastructureRef.Name), "providerID", providerID, "node", klog.KRef("", machine.Status.NodeRef.Name))
 		r.recorder.Event(machine, corev1.EventTypeNormal, "SuccessfulSetNodeRef", machine.Status.NodeRef.Name)
 	}
 

diff --git a/internal/controllers/machine/machine_controller_phases.go b/internal/controllers/machine/machine_controller_phases.go
@@ -219,7 +219,7 @@ func (r *Reconciler) reconcileBootstrap(ctx context.Context, cluster *clusterv1.
 
 	// If the bootstrap provider is not ready, requeue.
 	if !ready {
-		log.Info("Bootstrap provider is not ready, requeuing")
+		log.Info("Waiting for bootstrap provider to generate data secret and report status.ready, requeing", util.LowerCamelCaseKind(bootstrapConfig), klog.KObj(bootstrapConfig))
 		return ctrl.Result{RequeueAfter: externalReadyWait}, nil
 	}
 
@@ -230,8 +230,10 @@ func (r *Reconciler) reconcileBootstrap(ctx context.Context, cluster *clusterv1.
 	} else if secretName == "" {
 		return ctrl.Result{}, errors.Errorf("retrieved empty dataSecretName from bootstrap provider for Machine %q in namespace %q", m.Name, m.Namespace)
 	}
-
 	m.Spec.Bootstrap.DataSecretName = pointer.StringPtr(secretName)
+	if !m.Status.BootstrapReady {
+		log.Info("Bootstrap provider generated data secret and reports status.ready", util.LowerCamelCaseKind(bootstrapConfig), klog.KObj(bootstrapConfig), "secret", klog.KRef(m.Namespace, secretName))
+	}
 	m.Status.BootstrapReady = true
 	return ctrl.Result{}, nil
 }
@@ -271,6 +273,9 @@ func (r *Reconciler) reconcileInfrastructure(ctx context.Context, cluster *clust
 	if err != nil {
 		return ctrl.Result{}, err
 	}
+	if ready && !m.Status.InfrastructureReady {
+		log.Info("Infrastructure provider has completed machine infrastructure provisioning and reports status.ready", util.LowerCamelCaseKind(infraConfig), klog.KObj(infraConfig))
+	}
 	m.Status.InfrastructureReady = ready
 
 	// Report a summary of current status of the infrastructure object defined for this machine.
@@ -281,7 +286,7 @@ func (r *Reconciler) reconcileInfrastructure(ctx context.Context, cluster *clust
 
 	// If the infrastructure provider is not ready, return early.
 	if !ready {
-		log.Info("Infrastructure provider is not ready, requeuing")
+		log.Info("Waiting for infrastructure provider to create machine infrastructure and report status.ready, requeing", util.LowerCamelCaseKind(infraConfig), klog.KObj(infraConfig))
 		return ctrl.Result{RequeueAfter: externalReadyWait}, nil
 	}
 

diff --git a/util/util.go b/util/util.go
@@ -608,9 +608,14 @@ func IsNil(i interface{}) bool {
 // LowerCamelCaseKind mirrors how controller runtime formats the object's kind when used as a logging key
 // for the object being reconciled.
 func LowerCamelCaseKind(obj runtime.Object) string {
-	kind := obj.GetObjectKind().GroupVersionKind().Kind
-	if kind != "" {
-		return strings.ToLower(kind[:1]) + kind[1:]
+	return LowerCamelCase(obj.GetObjectKind().GroupVersionKind().Kind)
+}
+
+// LowerCamelCase mirrors how controller runtime formats the object's kind when used as a logging key
+// for the object being reconciled.
+func LowerCamelCase(s string) string {
+	if s != "" {
+		return strings.ToLower(s[:1]) + s[1:]
 	}
 	return ""
 }