From af7b00f684b0e17e08b208dbbaee88ea84e2adb0 Mon Sep 17 00:00:00 2001 From: Nir Magnezi Date: Sun, 23 May 2021 17:07:54 +0300 Subject: [PATCH] MGMT-6455 KubeAPI Controllers Debuggability: Add Logger Fields --- .../controllers/agent_controller.go | 90 +++++---- .../agentserviceconfig_controller.go | 3 +- .../controllers/bmh_agent_controller.go | 92 +++++---- .../clusterdeployments_controller.go | 189 ++++++++++-------- internal/controller/controllers/common.go | 9 + .../controllers/infraenv_controller.go | 89 +++++---- 6 files changed, 276 insertions(+), 196 deletions(-) diff --git a/internal/controller/controllers/agent_controller.go b/internal/controller/controllers/agent_controller.go index 42fcfadfe74..8c2fc39d2e1 100644 --- a/internal/controller/controllers/agent_controller.go +++ b/internal/controller/controllers/agent_controller.go @@ -23,6 +23,8 @@ import ( "net/http" "strings" + logutil "github.com/openshift/assisted-service/pkg/log" + "github.com/go-openapi/strfmt" "github.com/go-openapi/swag" "github.com/jinzhu/gorm" @@ -31,6 +33,7 @@ import ( aiv1beta1 "github.com/openshift/assisted-service/internal/controller/api/v1beta1" "github.com/openshift/assisted-service/internal/host" "github.com/openshift/assisted-service/models" + logutil "github.com/openshift/assisted-service/pkg/log" "github.com/openshift/assisted-service/restapi/operations/installer" conditionsv1 "github.com/openshift/custom-resource-status/conditions/v1" hivev1 "github.com/openshift/hive/apis/hive/v1" @@ -66,18 +69,29 @@ type AgentReconciler struct { // +kubebuilder:rbac:groups=agent-install.openshift.io,resources=agents/status,verbs=get;update;patch // +kubebuilder:rbac:groups=agent-install.openshift.io,resources=agents/ai-deprovision,verbs=update -func (r *AgentReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { - r.Log.Infof("Reconcile has been called for Agent name=%s namespace=%s", req.Name, req.Namespace) +func (r *AgentReconciler) Reconcile(origCtx context.Context, req ctrl.Request) (ctrl.Result, error) { + ctx := addRequestIdIfNeeded(origCtx) + log := logutil.FromContext(ctx, r.Log).WithFields( + logrus.Fields{ + "agent": req.Name, + "agent_namespace": req.Namespace, + }) + + defer func() { + log.Info("Agent Reconcile ended") + }() + + log.Info("Agent Reconcile started") agent := &aiv1beta1.Agent{} err := r.Get(ctx, req.NamespacedName, agent) if err != nil { - r.Log.WithError(err).Errorf("Failed to get resource %s", req.NamespacedName) + log.WithError(err).Errorf("Failed to get resource %s", req.NamespacedName) return ctrl.Result{}, client.IgnoreNotFound(err) } if agent.Spec.ClusterDeploymentName == nil { - r.Log.Debugf("ClusterDeploymentName not set in Agent %s. Skipping Reconcile", agent.Name) + log.Debugf("ClusterDeploymentName not set in Agent %s. Skipping Reconcile", agent.Name) return ctrl.Result{Requeue: false}, nil } @@ -86,22 +100,22 @@ func (r *AgentReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl if !funk.ContainsString(agent.GetFinalizers(), AgentFinalizerName) { controllerutil.AddFinalizer(agent, AgentFinalizerName) if err = r.Update(ctx, agent); err != nil { - r.Log.WithError(err).Errorf("failed to add finalizer %s to resource %s %s", AgentFinalizerName, agent.Name, agent.Namespace) + log.WithError(err).Errorf("failed to add finalizer %s to resource %s %s", AgentFinalizerName, agent.Name, agent.Namespace) return ctrl.Result{Requeue: true}, err } } } else { // agent is being deleted if funk.ContainsString(agent.GetFinalizers(), AgentFinalizerName) { // deletion finalizer found, deregister the backend host and delete the agent - reply, cleanUpErr := r.deregisterHostIfNeeded(ctx, req.NamespacedName) + reply, cleanUpErr := r.deregisterHostIfNeeded(ctx, log, req.NamespacedName) if cleanUpErr != nil { - r.Log.WithError(cleanUpErr).Errorf("failed to run pre-deletion cleanup for finalizer %s on resource %s %s", AgentFinalizerName, agent.Name, agent.Namespace) + log.WithError(cleanUpErr).Errorf("failed to run pre-deletion cleanup for finalizer %s on resource %s %s", AgentFinalizerName, agent.Name, agent.Namespace) return reply, err } // remove our finalizer from the list and update it. controllerutil.RemoveFinalizer(agent, AgentFinalizerName) if err = r.Update(ctx, agent); err != nil { - r.Log.WithError(err).Errorf("failed to remove finalizer %s from resource %s %s", AgentFinalizerName, agent.Name, agent.Namespace) + log.WithError(err).Errorf("failed to remove finalizer %s from resource %s %s", AgentFinalizerName, agent.Name, agent.Namespace) return ctrl.Result{Requeue: true}, err } } @@ -119,12 +133,12 @@ func (r *AgentReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl if err = r.Get(ctx, kubeKey, clusterDeployment); err != nil { if k8serrors.IsNotFound(err) { // Delete the agent, using a finalizer with pre-delete to deregister the host. - return r.deleteAgent(ctx, req.NamespacedName) + return r.deleteAgent(ctx, log, req.NamespacedName) } errMsg := fmt.Sprintf("failed to get clusterDeployment with name %s in namespace %s", agent.Spec.ClusterDeploymentName.Name, agent.Spec.ClusterDeploymentName.Namespace) // Update that we failed to retrieve the clusterDeployment - return r.updateStatus(ctx, agent, nil, errors.Wrapf(err, errMsg), !k8serrors.IsNotFound(err)) + return r.updateStatus(ctx, log, agent, nil, errors.Wrapf(err, errMsg), !k8serrors.IsNotFound(err)) } // Retrieve cluster by ClusterDeploymentName from the database @@ -132,10 +146,10 @@ func (r *AgentReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl if err != nil { if errors.Is(err, gorm.ErrRecordNotFound) { // Delete the agent, using a finalizer with pre-delete to deregister the host. - return r.deleteAgent(ctx, req.NamespacedName) + return r.deleteAgent(ctx, log, req.NamespacedName) } // Update that we failed to retrieve the cluster from the database - return r.updateStatus(ctx, agent, nil, err, !errors.Is(err, gorm.ErrRecordNotFound)) + return r.updateStatus(ctx, log, agent, nil, err, !errors.Is(err, gorm.ErrRecordNotFound)) } //Retrieve host from cluster @@ -143,24 +157,24 @@ func (r *AgentReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl if host == nil { // Host is not a part of the cluster, which may happen with newly created day2 clusters. // Delete the agent, using a finalizer with pre-delete to deregister the host. - return r.deleteAgent(ctx, req.NamespacedName) + return r.deleteAgent(ctx, log, req.NamespacedName) } // check for updates from user, compare spec and update if needed - err = r.updateIfNeeded(ctx, agent, cluster) + err = r.updateIfNeeded(ctx, log, agent, cluster) if err != nil { - return r.updateStatus(ctx, agent, host, err, !IsUserError(err)) + return r.updateStatus(ctx, log, agent, host, err, !IsUserError(err)) } - err = r.updateInventory(host, agent) + err = r.updateInventory(log, host, agent) if err != nil { - return r.updateStatus(ctx, agent, host, err, true) + return r.updateStatus(ctx, log, agent, host, err, true) } - return r.updateStatus(ctx, agent, host, nil, false) + return r.updateStatus(ctx, log, agent, host, nil, false) } -func (r *AgentReconciler) deleteAgent(ctx context.Context, agent types.NamespacedName) (ctrl.Result, error) { +func (r *AgentReconciler) deleteAgent(ctx context.Context, log logrus.FieldLogger, agent types.NamespacedName) (ctrl.Result, error) { agentToDelete := &aiv1beta1.Agent{ ObjectMeta: metav1.ObjectMeta{ Name: agent.Name, @@ -168,13 +182,13 @@ func (r *AgentReconciler) deleteAgent(ctx context.Context, agent types.Namespace }, } if delErr := r.Client.Delete(ctx, agentToDelete); delErr != nil { - r.Log.WithError(delErr).Errorf("Failed to delete resource %s %s", agent.Name, agent.Namespace) + log.WithError(delErr).Errorf("Failed to delete resource %s %s", agent.Name, agent.Namespace) return ctrl.Result{Requeue: true}, delErr } return ctrl.Result{}, nil } -func (r *AgentReconciler) deregisterHostIfNeeded(ctx context.Context, key types.NamespacedName) (ctrl.Result, error) { +func (r *AgentReconciler) deregisterHostIfNeeded(ctx context.Context, log logrus.FieldLogger, key types.NamespacedName) (ctrl.Result, error) { buildReply := func(err error) (ctrl.Result, error) { reply := ctrl.Result{} @@ -183,7 +197,7 @@ func (r *AgentReconciler) deregisterHostIfNeeded(ctx context.Context, key types. } reply.RequeueAfter = defaultRequeueAfterOnError err = errors.Wrapf(err, "failed to deregister host: %s", key.Name) - r.Log.Error(err) + log.Error(err) return reply, err } @@ -212,7 +226,7 @@ func (r *AgentReconciler) deregisterHostIfNeeded(ctx context.Context, key types. } } - r.Log.Infof("Host resource deleted, Unregistered host: %s", h.ID.String()) + log.Infof("Host resource deleted, Unregistered host: %s", h.ID.String()) return buildReply(nil) } @@ -220,7 +234,7 @@ func (r *AgentReconciler) deregisterHostIfNeeded(ctx context.Context, key types. // updateStatus is updating all the Agent Conditions. // In case that an error has occured when trying to sync the Spec, the error (syncErr) is presented in SpecSyncedCondition. // Internal bool differentiate between backend server error (internal HTTP 5XX) and user input error (HTTP 4XXX) -func (r *AgentReconciler) updateStatus(ctx context.Context, agent *aiv1beta1.Agent, h *models.Host, syncErr error, internal bool) (ctrl.Result, error) { +func (r *AgentReconciler) updateStatus(ctx context.Context, log logrus.FieldLogger, agent *aiv1beta1.Agent, h *models.Host, syncErr error, internal bool) (ctrl.Result, error) { specSynced(agent, syncErr, internal) @@ -234,7 +248,7 @@ func (r *AgentReconciler) updateStatus(ctx context.Context, agent *aiv1beta1.Age setConditionsUnknown(agent) } if updateErr := r.Status().Update(ctx, agent); updateErr != nil { - r.Log.WithError(updateErr).Error("failed to update agent Status") + log.WithError(updateErr).Error("failed to update agent Status") return ctrl.Result{Requeue: true}, nil } if internal { @@ -299,10 +313,10 @@ func specSynced(agent *aiv1beta1.Agent, syncErr error, internal bool) { }) } -func (r *AgentReconciler) updateInstallerArgs(ctx context.Context, c *common.Cluster, host *common.Host, agent *aiv1beta1.Agent) error { +func (r *AgentReconciler) updateInstallerArgs(ctx context.Context, log logrus.FieldLogger, c *common.Cluster, host *common.Host, agent *aiv1beta1.Agent) error { if agent.Spec.InstallerArgs == host.InstallerArgs { - r.Log.Debugf("Nothing to update, installer args were already set") + log.Debugf("Nothing to update, installer args were already set") return nil } @@ -316,7 +330,7 @@ func (r *AgentReconciler) updateInstallerArgs(ctx context.Context, c *common.Clu err := json.Unmarshal([]byte(agent.Spec.InstallerArgs), &agentSpecInstallerArgs.Args) if err != nil { msg := fmt.Sprintf("Fail to unmarshal installer args for host %s in cluster %s", agent.Name, c.Name) - r.Log.WithError(err).Errorf(msg) + log.WithError(err).Errorf(msg) return common.NewApiError(http.StatusBadRequest, errors.Wrapf(err, msg)) } } @@ -325,7 +339,7 @@ func (r *AgentReconciler) updateInstallerArgs(ctx context.Context, c *common.Clu argsBytes, _ := json.Marshal(agentSpecInstallerArgs.Args) // we need to validate if the equal one more after marshalling if string(argsBytes) == host.InstallerArgs { - r.Log.Debugf("Nothing to update, installer args were already set") + log.Debugf("Nothing to update, installer args were already set") return nil } @@ -470,9 +484,9 @@ func readyForInstallation(agent *aiv1beta1.Agent, status string) { }) } -func (r *AgentReconciler) updateInventory(host *models.Host, agent *aiv1beta1.Agent) error { +func (r *AgentReconciler) updateInventory(log logrus.FieldLogger, host *models.Host, agent *aiv1beta1.Agent) error { if host.Inventory == "" { - r.Log.Debugf("Skip update inventory: Host %s inventory not set", agent.Name) + log.Debugf("Skip update inventory: Host %s inventory not set", agent.Name) return nil } var inventory models.Inventory @@ -576,9 +590,9 @@ func (r *AgentReconciler) updateInventory(host *models.Host, agent *aiv1beta1.Ag return nil } -func (r *AgentReconciler) updateHostIgnition(ctx context.Context, c *common.Cluster, host *common.Host, agent *aiv1beta1.Agent) error { +func (r *AgentReconciler) updateHostIgnition(ctx context.Context, log logrus.FieldLogger, c *common.Cluster, host *common.Host, agent *aiv1beta1.Agent) error { if agent.Spec.IgnitionConfigOverrides == host.IgnitionConfigOverrides { - r.Log.Debugf("Nothing to update, ignition config override was already set") + log.Debugf("Nothing to update, ignition config override was already set") return nil } agentHostIgnitionParams := models.HostIgnitionParams{Config: ""} @@ -595,11 +609,11 @@ func (r *AgentReconciler) updateHostIgnition(ctx context.Context, c *common.Clus return err } -func (r *AgentReconciler) updateIfNeeded(ctx context.Context, agent *aiv1beta1.Agent, c *common.Cluster) error { +func (r *AgentReconciler) updateIfNeeded(ctx context.Context, log logrus.FieldLogger, agent *aiv1beta1.Agent, c *common.Cluster) error { spec := agent.Spec host := getHostFromCluster(c, agent.Name) if host == nil { - r.Log.Errorf("Host %s not found in cluster %s", agent.Name, c.Name) + log.Errorf("Host %s not found in cluster %s", agent.Name, c.Name) return errors.New("Host not found in cluster") } @@ -621,7 +635,7 @@ func (r *AgentReconciler) updateIfNeeded(ctx context.Context, agent *aiv1beta1.A } } - err = r.updateInstallerArgs(ctx, c, internalHost, agent) + err = r.updateInstallerArgs(ctx, log, c, internalHost, agent) if err != nil { if errors.Is(err, gorm.ErrRecordNotFound) { err = common.NewApiError(http.StatusNotFound, err) @@ -629,7 +643,7 @@ func (r *AgentReconciler) updateIfNeeded(ctx context.Context, agent *aiv1beta1.A return err } - err = r.updateHostIgnition(ctx, c, internalHost, agent) + err = r.updateHostIgnition(ctx, log, c, internalHost, agent) if err != nil { if errors.Is(err, gorm.ErrRecordNotFound) { err = common.NewApiError(http.StatusNotFound, err) @@ -693,7 +707,7 @@ func (r *AgentReconciler) updateIfNeeded(ctx context.Context, agent *aiv1beta1.A return err } - r.Log.Infof("Updated Agent spec %s %s", agent.Name, agent.Namespace) + log.Infof("Updated Agent spec %s %s", agent.Name, agent.Namespace) return nil } diff --git a/internal/controller/controllers/agentserviceconfig_controller.go b/internal/controller/controllers/agentserviceconfig_controller.go index 262cf80b462..1ddb186cf1b 100644 --- a/internal/controller/controllers/agentserviceconfig_controller.go +++ b/internal/controller/controllers/agentserviceconfig_controller.go @@ -92,7 +92,8 @@ type AgentServiceConfigReconciler struct { // +kubebuilder:rbac:groups=route.openshift.io,resources=routes,verbs=get;list;watch;create;update;patch;delete // +kubebuilder:rbac:groups="",resources=events,verbs=create;patch -func (r *AgentServiceConfigReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { +func (r *AgentServiceConfigReconciler) Reconcile(origCtx context.Context, req ctrl.Request) (ctrl.Result, error) { + ctx := addRequestIdIfNeeded(origCtx) instance := &aiv1beta1.AgentServiceConfig{} // NOTE: ignoring the Namespace that seems to get set on request when syncing on namespaced objects diff --git a/internal/controller/controllers/bmh_agent_controller.go b/internal/controller/controllers/bmh_agent_controller.go index b7e64e95a20..2fb9ab86484 100644 --- a/internal/controller/controllers/bmh_agent_controller.go +++ b/internal/controller/controllers/bmh_agent_controller.go @@ -23,6 +23,8 @@ import ( "sort" "strings" + logutil "github.com/openshift/assisted-service/pkg/log" + bmh_v1alpha1 "github.com/metal3-io/baremetal-operator/apis/metal3.io/v1alpha1" aiv1beta1 "github.com/openshift/assisted-service/internal/controller/api/v1beta1" "github.com/openshift/assisted-service/models" @@ -105,7 +107,19 @@ func (r reconcileError) Dirty() bool { // +kubebuilder:rbac:groups=metal3.io,resources=baremetalhosts,verbs=get;list;watch;update;patch -func (r *BMACReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { +func (r *BMACReconciler) Reconcile(origCtx context.Context, req ctrl.Request) (ctrl.Result, error) { + ctx := addRequestIdIfNeeded(origCtx) + log := logutil.FromContext(ctx, r.Log).WithFields( + logrus.Fields{ + "bare_metal_host": req.Name, + "bare_metal_host_namespace": req.Namespace, + }) + + defer func() { + log.Info("BareMetalHost Reconcile ended") + }() + + log.Info("BareMetalHost Reconcile started") bmh := &bmh_v1alpha1.BareMetalHost{} if err := r.Get(ctx, req.NamespacedName, bmh); err != nil { @@ -116,12 +130,12 @@ func (r *BMACReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl. } // Let's reconcile the BMH - result := r.reconcileBMH(ctx, bmh) + result := r.reconcileBMH(ctx, log, bmh) if result.Dirty() { - r.Log.Debugf("Updating dirty BMH %v", bmh) + log.Debugf("Updating dirty BMH %v", bmh) err := r.Client.Update(ctx, bmh) if err != nil { - r.Log.WithError(err).Errorf("Error updating after BMH reconcile") + log.WithError(err).Errorf("Error updating after BMH reconcile") return reconcileError{err}.Result() } @@ -149,16 +163,16 @@ func (r *BMACReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl. if result.Dirty() { err := r.Client.Update(ctx, bmh) if err != nil { - r.Log.WithError(err).Errorf("Error updating hardwaredetails") + log.WithError(err).Errorf("Error updating hardwaredetails") return reconcileError{err}.Result() } } - result = r.reconcileAgentSpec(bmh, agent) + result = r.reconcileAgentSpec(log, bmh, agent) if result.Dirty() { err := r.Client.Update(ctx, agent) if err != nil { - r.Log.WithError(err).Errorf("Error updating agent") + log.WithError(err).Errorf("Error updating agent") return reconcileError{err}.Result() } } @@ -169,17 +183,17 @@ func (r *BMACReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl. if result.Dirty() { err := r.Client.Update(ctx, bmh) if err != nil { - r.Log.WithError(err).Errorf("Error updating BMH detached annotation") + log.WithError(err).Errorf("Error updating BMH detached annotation") return reconcileError{err}.Result() } } - result = r.reconcileSpokeBMH(ctx, bmh, agent) + result = r.reconcileSpokeBMH(ctx, log, bmh, agent) if result.Dirty() { err := r.Client.Update(ctx, bmh) if err != nil { - r.Log.WithError(err).Errorf("Error adding BMH detached annotation after creating spoke BMH") + log.WithError(err).Errorf("Error adding BMH detached annotation after creating spoke BMH") return reconcileError{err}.Result() } } @@ -202,9 +216,9 @@ func (r *BMACReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl. // Unless there are errors, the agent should be `Approved` at the end of this // reconcile and a label should be set on it referencing the BMH. No changes to // the BMH should happen in this reconcile step. -func (r *BMACReconciler) reconcileAgentSpec(bmh *bmh_v1alpha1.BareMetalHost, agent *aiv1beta1.Agent) reconcileResult { +func (r *BMACReconciler) reconcileAgentSpec(log logrus.FieldLogger, bmh *bmh_v1alpha1.BareMetalHost, agent *aiv1beta1.Agent) reconcileResult { - r.Log.Debugf("Started Agent Spec reconcile for agent %s/%s and bmh %s/%s", agent.Namespace, agent.Name, bmh.Namespace, bmh.Name) + log.Debugf("Started Agent Spec reconcile for agent %s/%s and bmh %s/%s", agent.Namespace, agent.Name, bmh.Namespace, bmh.Name) // Do all the copying from the BMH annotations to the agent. @@ -392,38 +406,38 @@ func (r *BMACReconciler) reconcileAgentInventory(bmh *bmh_v1alpha1.BareMetalHost // The above changes will be done only if the ISODownloadURL value has already // been set in the `InfraEnv` resource and the Image.URL value has not been // set in the `BareMetalHost` -func (r *BMACReconciler) reconcileBMH(ctx context.Context, bmh *bmh_v1alpha1.BareMetalHost) reconcileResult { +func (r *BMACReconciler) reconcileBMH(ctx context.Context, log logrus.FieldLogger, bmh *bmh_v1alpha1.BareMetalHost) reconcileResult { // No need to reconcile if the image URL has been set in // the BMH already. if bmh.Spec.Image != nil && bmh.Spec.Image.URL != "" { return reconcileComplete{} } - r.Log.Debugf("Started BMH reconcile for %s/%s", bmh.Namespace, bmh.Name) - r.Log.Debugf("BMH value %v", bmh) + log.Debugf("Started BMH reconcile for %s/%s", bmh.Namespace, bmh.Name) + log.Debugf("BMH value %v", bmh) for ann, value := range bmh.Labels { - r.Log.Debugf("BMH label %s value %s", ann, value) + log.Debugf("BMH label %s value %s", ann, value) // Find the `BMH_INFRA_ENV_LABEL`, get the infraEnv configured in it // and copy the ISO Url from the InfraEnv to the BMH resource. if ann == BMH_INFRA_ENV_LABEL { infraEnv := &aiv1beta1.InfraEnv{} - r.Log.Debugf("Loading InfraEnv %s", value) + log.Debugf("Loading InfraEnv %s", value) if err := r.Get(ctx, types.NamespacedName{Name: value, Namespace: bmh.Namespace}, infraEnv); err != nil { - r.Log.WithError(err).Errorf("failed to get infraEnv resource %s/%s", bmh.Namespace, value) + log.WithError(err).Errorf("failed to get infraEnv resource %s/%s", bmh.Namespace, value) return reconcileError{client.IgnoreNotFound(err)} } if infraEnv.Status.ISODownloadURL == "" { // the image has not been created yet, try later. - r.Log.Infof("Image URL for InfraEnv (%s/%s) not available yet. Waiting for new reconcile for BareMetalHost %s/%s", + log.Infof("Image URL for InfraEnv (%s/%s) not available yet. Waiting for new reconcile for BareMetalHost %s/%s", infraEnv.Namespace, infraEnv.Name, bmh.Namespace, bmh.Name) return reconcileComplete{} } - r.Log.Debugf("Setting attributes in BMH") + log.Debugf("Setting attributes in BMH") // We'll just overwrite this at this point // since the nullness and emptyness checks // are done at the beginning of this function. @@ -455,7 +469,7 @@ func (r *BMACReconciler) reconcileBMH(ctx context.Context, bmh *bmh_v1alpha1.Bar // now needs to be removed so that Ironic can manage the host. delete(bmh.ObjectMeta.Annotations, BMH_DETACHED_ANNOTATION) - r.Log.Infof("Image URL has been set in the BareMetalHost %s/%s", bmh.Namespace, bmh.Name) + log.Infof("Image URL has been set in the BareMetalHost %s/%s", bmh.Namespace, bmh.Name) return reconcileComplete{true} } } @@ -472,10 +486,10 @@ func (r *BMACReconciler) reconcileBMH(ctx context.Context, bmh *bmh_v1alpha1.Bar // - Creates a new Machine // - Create BMH with externallyProvisioned set to true and set the newly created machine as ConsumerRef // BMH_HARDWARE_DETAILS_ANNOTATION is needed for auto approval of the CSR. -func (r *BMACReconciler) reconcileSpokeBMH(ctx context.Context, bmh *bmh_v1alpha1.BareMetalHost, agent *aiv1beta1.Agent) reconcileResult { +func (r *BMACReconciler) reconcileSpokeBMH(ctx context.Context, log logrus.FieldLogger, bmh *bmh_v1alpha1.BareMetalHost, agent *aiv1beta1.Agent) reconcileResult { // Only worker role is supported for day2 operation if agent.Spec.Role != models.HostRoleWorker || agent.Spec.ClusterDeploymentName == nil { - r.Log.Debugf("Skipping spoke BareMetalHost reconcile for agent %s/%s, role %s and clusterDeployment %s.", agent.Namespace, agent.Name, agent.Spec.Role, agent.Spec.ClusterDeploymentName) + log.Debugf("Skipping spoke BareMetalHost reconcile for agent %s/%s, role %s and clusterDeployment %s.", agent.Namespace, agent.Name, agent.Spec.Role, agent.Spec.ClusterDeploymentName) return reconcileComplete{} } @@ -485,13 +499,13 @@ func (r *BMACReconciler) reconcileSpokeBMH(ctx context.Context, bmh *bmh_v1alpha } clusterDeployment := &hivev1.ClusterDeployment{} if err := r.Get(ctx, cdKey, clusterDeployment); err != nil { - r.Log.WithError(err).Errorf("failed to get clusterDeployment resource %s/%s", cdKey.Namespace, cdKey.Name) + log.WithError(err).Errorf("failed to get clusterDeployment resource %s/%s", cdKey.Namespace, cdKey.Name) return reconcileError{err} } // If the cluster is not installed yet, we can't get kubeconfig for the cluster yet. if !clusterDeployment.Spec.Installed { - r.Log.Infof("ClusterDeployment %s/%s for agent %s/%s is not installed yet", clusterDeployment.Namespace, clusterDeployment.Name, agent.Namespace, agent.Name) + log.Infof("ClusterDeployment %s/%s for agent %s/%s is not installed yet", clusterDeployment.Namespace, clusterDeployment.Name, agent.Namespace, agent.Name) // If cluster is not Installed, wait until a reconcile is trigged by a ClusterDeployment watch event instead return reconcileComplete{} } @@ -501,7 +515,7 @@ func (r *BMACReconciler) reconcileSpokeBMH(ctx context.Context, bmh *bmh_v1alpha name := fmt.Sprintf(adminKubeConfigStringTemplate, clusterDeployment.Name) err := r.Get(ctx, types.NamespacedName{Namespace: clusterDeployment.Namespace, Name: name}, secret) if err != nil && errors.IsNotFound(err) { - r.Log.WithError(err).Errorf("failed to get secret resource %s/%s", clusterDeployment.Namespace, name) + log.WithError(err).Errorf("failed to get secret resource %s/%s", clusterDeployment.Namespace, name) // TODO: If secret is not found, wait until a reconcile is trigged by a watch event instead return reconcileComplete{} } else if err != nil { @@ -510,25 +524,25 @@ func (r *BMACReconciler) reconcileSpokeBMH(ctx context.Context, bmh *bmh_v1alpha spokeClient, err := r.getSpokeClient(secret) if err != nil { - r.Log.WithError(err).Errorf("failed to create spoke kubeclient") + log.WithError(err).Errorf("failed to create spoke kubeclient") return reconcileError{err} } - machine, err := r.ensureSpokeMachine(ctx, spokeClient, bmh, clusterDeployment) + machine, err := r.ensureSpokeMachine(ctx, log, spokeClient, bmh, clusterDeployment) if err != nil { - r.Log.WithError(err).Errorf("failed to create or update spoke Machine") + log.WithError(err).Errorf("failed to create or update spoke Machine") return reconcileError{err} } - _, err = r.ensureSpokeBMHSecret(ctx, spokeClient, bmh) + _, err = r.ensureSpokeBMHSecret(ctx, log, spokeClient, bmh) if err != nil { - r.Log.WithError(err).Errorf("failed to create or update spoke BareMetalHost Secret") + log.WithError(err).Errorf("failed to create or update spoke BareMetalHost Secret") return reconcileError{err} } - _, err = r.ensureSpokeBMH(ctx, spokeClient, bmh, machine, agent) + _, err = r.ensureSpokeBMH(ctx, log, spokeClient, bmh, machine, agent) if err != nil { - r.Log.WithError(err).Errorf("failed to create or update spoke BareMetalHost") + log.WithError(err).Errorf("failed to create or update spoke BareMetalHost") return reconcileError{err} } @@ -762,27 +776,27 @@ func (r *BMACReconciler) findBMHByInfraEnv(ctx context.Context, infraEnv *aiv1be return bmhs, nil } -func (r *BMACReconciler) ensureSpokeBMH(ctx context.Context, spokeClient client.Client, bmh *bmh_v1alpha1.BareMetalHost, machine *machinev1beta1.Machine, agent *aiv1beta1.Agent) (*bmh_v1alpha1.BareMetalHost, error) { +func (r *BMACReconciler) ensureSpokeBMH(ctx context.Context, log logrus.FieldLogger, spokeClient client.Client, bmh *bmh_v1alpha1.BareMetalHost, machine *machinev1beta1.Machine, agent *aiv1beta1.Agent) (*bmh_v1alpha1.BareMetalHost, error) { bmhSpoke, mutateFn := r.newSpokeBMH(bmh, machine, agent) if result, err := controllerutil.CreateOrUpdate(ctx, spokeClient, bmhSpoke, mutateFn); err != nil { return nil, err } else if result != controllerutil.OperationResultNone { - r.Log.Info("Spoke BareMetalHost created") + log.Info("Spoke BareMetalHost created") } return bmhSpoke, nil } -func (r *BMACReconciler) ensureSpokeMachine(ctx context.Context, spokeClient client.Client, bmh *bmh_v1alpha1.BareMetalHost, clusterDeployment *hivev1.ClusterDeployment) (*machinev1beta1.Machine, error) { +func (r *BMACReconciler) ensureSpokeMachine(ctx context.Context, log logrus.FieldLogger, spokeClient client.Client, bmh *bmh_v1alpha1.BareMetalHost, clusterDeployment *hivev1.ClusterDeployment) (*machinev1beta1.Machine, error) { machineSpoke, mutateFn := r.newSpokeMachine(bmh, clusterDeployment) if result, err := controllerutil.CreateOrUpdate(ctx, spokeClient, machineSpoke, mutateFn); err != nil { return nil, err } else if result != controllerutil.OperationResultNone { - r.Log.Info("Spoke Machine created") + log.Info("Spoke Machine created") } return machineSpoke, nil } -func (r *BMACReconciler) ensureSpokeBMHSecret(ctx context.Context, spokeClient client.Client, bmh *bmh_v1alpha1.BareMetalHost) (*corev1.Secret, error) { +func (r *BMACReconciler) ensureSpokeBMHSecret(ctx context.Context, log logrus.FieldLogger, spokeClient client.Client, bmh *bmh_v1alpha1.BareMetalHost) (*corev1.Secret, error) { secretName := bmh.Spec.BMC.CredentialsName secret := &corev1.Secret{} err := r.Get(ctx, types.NamespacedName{Namespace: bmh.Namespace, Name: secretName}, secret) @@ -793,7 +807,7 @@ func (r *BMACReconciler) ensureSpokeBMHSecret(ctx context.Context, spokeClient c if result, err := controllerutil.CreateOrUpdate(ctx, spokeClient, secretSpoke, mutateFn); err != nil { return nil, err } else if result != controllerutil.OperationResultNone { - r.Log.Info("Spoke BareMetalHost Secret created") + log.Info("Spoke BareMetalHost Secret created") } return secretSpoke, nil } diff --git a/internal/controller/controllers/clusterdeployments_controller.go b/internal/controller/controllers/clusterdeployments_controller.go index d47c7f1571e..13d8655006d 100644 --- a/internal/controller/controllers/clusterdeployments_controller.go +++ b/internal/controller/controllers/clusterdeployments_controller.go @@ -24,6 +24,8 @@ import ( "strings" "time" + logutil "github.com/openshift/assisted-service/pkg/log" + "github.com/go-openapi/strfmt" "github.com/go-openapi/swag" "github.com/google/uuid" @@ -36,6 +38,7 @@ import ( "github.com/openshift/assisted-service/internal/host" "github.com/openshift/assisted-service/internal/manifests" "github.com/openshift/assisted-service/models" + logutil "github.com/openshift/assisted-service/pkg/log" "github.com/openshift/assisted-service/restapi/operations/installer" operations "github.com/openshift/assisted-service/restapi/operations/manifests" hivev1 "github.com/openshift/hive/apis/hive/v1" @@ -86,16 +89,27 @@ type ClusterDeploymentsReconciler struct { // +kubebuilder:rbac:groups=extensions.hive.openshift.io,resources=agentclusterinstalls,verbs=get;list;watch;create;update;patch;delete // +kubebuilder:rbac:groups=extensions.hive.openshift.io,resources=agentclusterinstalls/status,verbs=get;update;patch -func (r *ClusterDeploymentsReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { - r.Log.Infof("Reconcile has been called for ClusterDeployment name=%s namespace=%s", req.Name, req.Namespace) +func (r *ClusterDeploymentsReconciler) Reconcile(origCtx context.Context, req ctrl.Request) (ctrl.Result, error) { + ctx := addRequestIdIfNeeded(origCtx) + log := logutil.FromContext(ctx, r.Log).WithFields( + logrus.Fields{ + "cluster_deployment": req.Name, + "cluster_deployment_namespace": req.Namespace, + }) + + defer func() { + log.Info("ClusterDeployment Reconcile ended") + }() + + log.Info("ClusterDeployment Reconcile started") clusterDeployment := &hivev1.ClusterDeployment{} err := r.Get(ctx, req.NamespacedName, clusterDeployment) if err != nil { if k8serrors.IsNotFound(err) { - return r.deregisterClusterIfNeeded(ctx, req.NamespacedName) + return r.deregisterClusterIfNeeded(ctx, log, req.NamespacedName) } - r.Log.WithError(err).Errorf("Failed to get resource %s", req.NamespacedName) + log.WithError(err).Errorf("Failed to get resource %s", req.NamespacedName) return ctrl.Result{Requeue: true}, nil } @@ -106,7 +120,7 @@ func (r *ClusterDeploymentsReconciler) Reconcile(ctx context.Context, req ctrl.R clusterInstall := &hiveext.AgentClusterInstall{} if clusterDeployment.Spec.ClusterInstallRef == nil { - r.Log.Infof("AgentClusterInstall not set for ClusterDeployment %s", clusterDeployment.Name) + log.Infof("AgentClusterInstall not set for ClusterDeployment %s", clusterDeployment.Name) return ctrl.Result{}, nil } @@ -119,14 +133,14 @@ func (r *ClusterDeploymentsReconciler) Reconcile(ctx context.Context, req ctrl.R clusterInstall) if err != nil { if k8serrors.IsNotFound(err) { - r.Log.WithField("AgentClusterInstall", aciName).Infof("AgentClusterInstall does not exist for ClusterDeployment %s", clusterDeployment.Name) + log.WithField("AgentClusterInstall", aciName).Infof("AgentClusterInstall does not exist for ClusterDeployment %s", clusterDeployment.Name) return ctrl.Result{}, nil } - r.Log.WithError(err).Errorf("Failed to get AgentClusterInstall %s", aciName) + log.WithError(err).Errorf("Failed to get AgentClusterInstall %s", aciName) return ctrl.Result{Requeue: true}, err } - err = r.ensureOwnerRef(ctx, clusterDeployment, clusterInstall) + err = r.ensureOwnerRef(ctx, log, clusterDeployment, clusterInstall) if err != nil { return ctrl.Result{Requeue: true}, err } @@ -134,62 +148,62 @@ func (r *ClusterDeploymentsReconciler) Reconcile(ctx context.Context, req ctrl.R cluster, err := r.Installer.GetClusterByKubeKey(req.NamespacedName) if errors.Is(err, gorm.ErrRecordNotFound) { if !isInstalled(clusterDeployment, clusterInstall) { - return r.createNewCluster(ctx, req.NamespacedName, clusterDeployment, clusterInstall) + return r.createNewCluster(ctx, log, req.NamespacedName, clusterDeployment, clusterInstall) } if !r.isSNO(clusterInstall) { - return r.createNewDay2Cluster(ctx, req.NamespacedName, clusterDeployment, clusterInstall) + return r.createNewDay2Cluster(ctx, log, req.NamespacedName, clusterDeployment, clusterInstall) } // cluster is installed and SNO nothing to do return ctrl.Result{Requeue: false}, nil } if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } // check for updates from user, compare spec and update if needed - err = r.updateIfNeeded(ctx, clusterDeployment, clusterInstall, cluster) + err = r.updateIfNeeded(ctx, log, clusterDeployment, clusterInstall, cluster) if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } // check for install config overrides and update if needed - err = r.updateInstallConfigOverrides(ctx, clusterInstall, cluster) + err = r.updateInstallConfigOverrides(ctx, log, clusterInstall, cluster) if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } // In case the Cluster is a Day 1 cluster and is installed, update the Metadata and create secrets for credentials if *cluster.Status == models.ClusterStatusInstalled && swag.StringValue(cluster.Kind) == models.ClusterKindCluster { if !isInstalled(clusterDeployment, clusterInstall) { // create secrets and update status - err = r.updateClusterMetadata(ctx, clusterDeployment, cluster, clusterInstall) - return r.updateStatus(ctx, clusterInstall, cluster, err) + err = r.updateClusterMetadata(ctx, log, clusterDeployment, cluster, clusterInstall) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } else { // Delete Day1 Cluster err = r.Installer.DeregisterClusterInternal(ctx, installer.DeregisterClusterParams{ ClusterID: *cluster.ID, }) if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } if !r.isSNO(clusterInstall) { //Create Day2 cluster - return r.createNewDay2Cluster(ctx, req.NamespacedName, clusterDeployment, clusterInstall) + return r.createNewDay2Cluster(ctx, log, req.NamespacedName, clusterDeployment, clusterInstall) } - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } } if swag.StringValue(cluster.Kind) == models.ClusterKindCluster { // Day 1 - return r.installDay1(ctx, clusterDeployment, clusterInstall, cluster) + return r.installDay1(ctx, log, clusterDeployment, clusterInstall, cluster) } else if swag.StringValue(cluster.Kind) == models.ClusterKindAddHostsCluster { // Day 2 - return r.installDay2Hosts(ctx, clusterDeployment, clusterInstall, cluster) + return r.installDay2Hosts(ctx, log, clusterDeployment, clusterInstall, cluster) } - return r.updateStatus(ctx, clusterInstall, cluster, nil) + return r.updateStatus(ctx, log, clusterInstall, cluster, nil) } func isInstalled(clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hiveext.AgentClusterInstall) bool { @@ -200,61 +214,62 @@ func isInstalled(clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hi return cond != nil && cond.Reason == InstalledReason } -func (r *ClusterDeploymentsReconciler) installDay1(ctx context.Context, clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hiveext.AgentClusterInstall, cluster *common.Cluster) (ctrl.Result, error) { +func (r *ClusterDeploymentsReconciler) installDay1(ctx context.Context, log logrus.FieldLogger, clusterDeployment *hivev1.ClusterDeployment, + clusterInstall *hiveext.AgentClusterInstall, cluster *common.Cluster) (ctrl.Result, error) { ready, err := r.isReadyForInstallation(ctx, clusterDeployment, clusterInstall, cluster) if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } if ready { // create custom manifests if needed before installation - err = r.addCustomManifests(ctx, clusterInstall, cluster) + err = r.addCustomManifests(ctx, log, clusterInstall, cluster) if err != nil { - _, _ = r.updateStatus(ctx, clusterInstall, cluster, err) + _, _ = r.updateStatus(ctx, log, clusterInstall, cluster, err) // We decided to requeue with one minute timeout in order to give user a chance to fix manifest // this timeout allows us not to run reconcile too much time and // still have a nice feedback when user will fix the error return ctrl.Result{Requeue: true, RequeueAfter: 1 * time.Minute}, nil } - r.Log.Infof("Installing clusterDeployment %s %s", clusterDeployment.Name, clusterDeployment.Namespace) + log.Infof("Installing clusterDeployment %s %s", clusterDeployment.Name, clusterDeployment.Namespace) var ic *common.Cluster ic, err = r.Installer.InstallClusterInternal(ctx, installer.InstallClusterParams{ ClusterID: *cluster.ID, }) if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } - return r.updateStatus(ctx, clusterInstall, ic, err) + return r.updateStatus(ctx, log, clusterInstall, ic, err) } - return r.updateStatus(ctx, clusterInstall, cluster, nil) + return r.updateStatus(ctx, log, clusterInstall, cluster, nil) } -func (r *ClusterDeploymentsReconciler) installDay2Hosts(ctx context.Context, clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hiveext.AgentClusterInstall, cluster *common.Cluster) (ctrl.Result, error) { +func (r *ClusterDeploymentsReconciler) installDay2Hosts(ctx context.Context, log logrus.FieldLogger, clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hiveext.AgentClusterInstall, cluster *common.Cluster) (ctrl.Result, error) { for _, h := range cluster.Hosts { commonh, err := r.Installer.GetCommonHostInternal(ctx, cluster.ID.String(), h.ID.String()) if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } if r.HostApi.IsInstallable(h) && commonh.Approved { - r.Log.Infof("Installing Day2 host %s in %s %s", *h.ID, clusterDeployment.Name, clusterDeployment.Namespace) + log.Infof("Installing Day2 host %s in %s %s", *h.ID, clusterDeployment.Name, clusterDeployment.Namespace) err = r.Installer.InstallSingleDay2HostInternal(ctx, *cluster.ID, *h.ID) if err != nil { - return r.updateStatus(ctx, clusterInstall, cluster, err) + return r.updateStatus(ctx, log, clusterInstall, cluster, err) } } } - return r.updateStatus(ctx, clusterInstall, cluster, nil) + return r.updateStatus(ctx, log, clusterInstall, cluster, nil) } -func (r *ClusterDeploymentsReconciler) updateClusterMetadata(ctx context.Context, cluster *hivev1.ClusterDeployment, c *common.Cluster, clusterInstall *hiveext.AgentClusterInstall) error { +func (r *ClusterDeploymentsReconciler) updateClusterMetadata(ctx context.Context, log logrus.FieldLogger, cluster *hivev1.ClusterDeployment, c *common.Cluster, clusterInstall *hiveext.AgentClusterInstall) error { - s, err := r.ensureAdminPasswordSecret(ctx, cluster, c) + s, err := r.ensureAdminPasswordSecret(ctx, log, cluster, c) if err != nil { return err } - k, err := r.ensureKubeConfigSecret(ctx, cluster, c) + k, err := r.ensureKubeConfigSecret(ctx, log, cluster, c) if err != nil { return err } @@ -271,7 +286,7 @@ func (r *ClusterDeploymentsReconciler) updateClusterMetadata(ctx context.Context return r.Update(ctx, clusterInstall) } -func (r *ClusterDeploymentsReconciler) ensureAdminPasswordSecret(ctx context.Context, cluster *hivev1.ClusterDeployment, c *common.Cluster) (*corev1.Secret, error) { +func (r *ClusterDeploymentsReconciler) ensureAdminPasswordSecret(ctx context.Context, log logrus.FieldLogger, cluster *hivev1.ClusterDeployment, c *common.Cluster) (*corev1.Secret, error) { s := &corev1.Secret{} name := fmt.Sprintf(adminPasswordSecretStringTemplate, cluster.Name) getErr := r.Get(ctx, types.NamespacedName{Namespace: cluster.Namespace, Name: name}, s) @@ -288,10 +303,10 @@ func (r *ClusterDeploymentsReconciler) ensureAdminPasswordSecret(ctx context.Con "username": []byte(cred.Username), "password": []byte(cred.Password), } - return r.createClusterCredentialSecret(ctx, cluster, c, name, data, "kubeadmincreds") + return r.createClusterCredentialSecret(ctx, log, cluster, c, name, data, "kubeadmincreds") } -func (r *ClusterDeploymentsReconciler) ensureKubeConfigSecret(ctx context.Context, cluster *hivev1.ClusterDeployment, c *common.Cluster) (*corev1.Secret, error) { +func (r *ClusterDeploymentsReconciler) ensureKubeConfigSecret(ctx context.Context, log logrus.FieldLogger, cluster *hivev1.ClusterDeployment, c *common.Cluster) (*corev1.Secret, error) { s := &corev1.Secret{} name := fmt.Sprintf(adminKubeConfigStringTemplate, cluster.Name) getErr := r.Get(ctx, types.NamespacedName{Namespace: cluster.Namespace, Name: name}, s) @@ -312,10 +327,10 @@ func (r *ClusterDeploymentsReconciler) ensureKubeConfigSecret(ctx context.Contex "kubeconfig": respBytes, } - return r.createClusterCredentialSecret(ctx, cluster, c, name, data, "kubeconfig") + return r.createClusterCredentialSecret(ctx, log, cluster, c, name, data, "kubeconfig") } -func (r *ClusterDeploymentsReconciler) createClusterCredentialSecret(ctx context.Context, cluster *hivev1.ClusterDeployment, c *common.Cluster, name string, data map[string][]byte, secretType string) (*corev1.Secret, error) { +func (r *ClusterDeploymentsReconciler) createClusterCredentialSecret(ctx context.Context, log logrus.FieldLogger, cluster *hivev1.ClusterDeployment, c *common.Cluster, name string, data map[string][]byte, secretType string) (*corev1.Secret, error) { s := &corev1.Secret{ ObjectMeta: metav1.ObjectMeta{ Name: name, @@ -329,7 +344,7 @@ func (r *ClusterDeploymentsReconciler) createClusterCredentialSecret(ctx context deploymentGVK, err := apiutil.GVKForObject(cluster, r.Scheme) if err != nil { - r.Log.WithError(err).Errorf("error getting GVK for clusterdeployment") + log.WithError(err).Errorf("error getting GVK for clusterdeployment") return nil, err } @@ -382,6 +397,7 @@ func isUserManagedNetwork(clusterInstall *hiveext.AgentClusterInstall) bool { } func (r *ClusterDeploymentsReconciler) updateIfNeeded(ctx context.Context, + log logrus.FieldLogger, clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hiveext.AgentClusterInstall, cluster *common.Cluster) error { @@ -453,15 +469,15 @@ func (r *ClusterDeploymentsReconciler) updateIfNeeded(ctx context.Context, return errors.Wrap(err, fmt.Sprintf("failed to search for infraEnv for clusterDeployment %s", clusterDeployment.Name)) } - r.Log.Infof("Updated clusterDeployment %s/%s", clusterDeployment.Namespace, clusterDeployment.Name) + log.Infof("Updated clusterDeployment %s/%s", clusterDeployment.Namespace, clusterDeployment.Name) if notifyInfraEnv && infraEnv != nil { - r.Log.Infof("Notify that infraEnv %s should re-generate the image for clusterDeployment %s", infraEnv.Name, clusterDeployment.ClusterName) + log.Infof("Notify that infraEnv %s should re-generate the image for clusterDeployment %s", infraEnv.Name, clusterDeployment.ClusterName) r.CRDEventsHandler.NotifyInfraEnvUpdates(infraEnv.Name, infraEnv.Namespace) } return nil } -func (r *ClusterDeploymentsReconciler) updateInstallConfigOverrides(ctx context.Context, clusterInstall *hiveext.AgentClusterInstall, +func (r *ClusterDeploymentsReconciler) updateInstallConfigOverrides(ctx context.Context, log logrus.FieldLogger, clusterInstall *hiveext.AgentClusterInstall, cluster *common.Cluster) error { // handle InstallConfigOverrides update := false @@ -479,18 +495,18 @@ func (r *ClusterDeploymentsReconciler) updateInstallConfigOverrides(ctx context. if err != nil { return err } - r.Log.Infof("Updated InstallConfig overrides on clusterInstall %s/%s", clusterInstall.Namespace, clusterInstall.Name) + log.Infof("Updated InstallConfig overrides on clusterInstall %s/%s", clusterInstall.Namespace, clusterInstall.Name) return nil } return nil } -func (r *ClusterDeploymentsReconciler) syncManifests(ctx context.Context, cluster *common.Cluster, +func (r *ClusterDeploymentsReconciler) syncManifests(ctx context.Context, log logrus.FieldLogger, cluster *common.Cluster, clusterInstall *hiveext.AgentClusterInstall, alreadyCreatedManifests models.ListManifests) error { - r.Log.Debugf("Going to sync list of given with already created manifests") + log.Debugf("Going to sync list of given with already created manifests") - manifestsFromConfigMap, err := r.getClusterDeploymentManifest(ctx, clusterInstall) + manifestsFromConfigMap, err := r.getClusterDeploymentManifest(ctx, log, clusterInstall) if err != nil { return err } @@ -499,7 +515,7 @@ func (r *ClusterDeploymentsReconciler) syncManifests(ctx context.Context, cluste // skip errors for _, manifest := range alreadyCreatedManifests { if _, ok := manifestsFromConfigMap[manifest.FileName]; !ok { - r.Log.Infof("Deleting cluster deployment %s manifest %s", cluster.KubeKeyName, manifest.FileName) + log.Infof("Deleting cluster deployment %s manifest %s", cluster.KubeKeyName, manifest.FileName) _ = r.Manifests.DeleteClusterManifestInternal(ctx, operations.DeleteClusterManifestParams{ ClusterID: *cluster.ID, FileName: manifest.FileName, @@ -510,7 +526,7 @@ func (r *ClusterDeploymentsReconciler) syncManifests(ctx context.Context, cluste // create/update all manifests provided by configmap data for filename, manifest := range manifestsFromConfigMap { - r.Log.Infof("Creating cluster deployment %s manifest %s", cluster.KubeKeyName, filename) + log.Infof("Creating cluster deployment %s manifest %s", cluster.KubeKeyName, filename) _, err := r.Manifests.CreateClusterManifestInternal(ctx, operations.CreateClusterManifestParams{ ClusterID: *cluster.ID, CreateManifestParams: &models.CreateManifestParams{ @@ -519,14 +535,14 @@ func (r *ClusterDeploymentsReconciler) syncManifests(ctx context.Context, cluste Folder: swag.String(models.ManifestFolderOpenshift), }}) if err != nil { - r.Log.WithError(err).Errorf("Failed to create cluster deployment %s manifest %s", cluster.KubeKeyName, filename) + log.WithError(err).Errorf("Failed to create cluster deployment %s manifest %s", cluster.KubeKeyName, filename) return err } } return nil } -func (r *ClusterDeploymentsReconciler) getClusterDeploymentManifest(ctx context.Context, clusterInstall *hiveext.AgentClusterInstall) (map[string]string, error) { +func (r *ClusterDeploymentsReconciler) getClusterDeploymentManifest(ctx context.Context, log logrus.FieldLogger, clusterInstall *hiveext.AgentClusterInstall) (map[string]string, error) { configuredManifests := &corev1.ConfigMap{} configuredManifests.Data = map[string]string{} // get manifests from configmap if we have reference for it @@ -534,7 +550,7 @@ func (r *ClusterDeploymentsReconciler) getClusterDeploymentManifest(ctx context. err := r.Get(ctx, types.NamespacedName{Namespace: clusterInstall.Namespace, Name: clusterInstall.Spec.ManifestsConfigMapRef.Name}, configuredManifests) if err != nil { - r.Log.WithError(err).Errorf("Failed to get configmap %s in %s", + log.WithError(err).Errorf("Failed to get configmap %s in %s", clusterInstall.Spec.ManifestsConfigMapRef.Name, clusterInstall.Namespace) return nil, err } @@ -542,14 +558,14 @@ func (r *ClusterDeploymentsReconciler) getClusterDeploymentManifest(ctx context. return configuredManifests.Data, nil } -func (r *ClusterDeploymentsReconciler) addCustomManifests(ctx context.Context, clusterInstall *hiveext.AgentClusterInstall, - cluster *common.Cluster) error { +func (r *ClusterDeploymentsReconciler) addCustomManifests(ctx context.Context, log logrus.FieldLogger, + clusterInstall *hiveext.AgentClusterInstall, cluster *common.Cluster) error { alreadyCreatedManifests, err := r.Manifests.ListClusterManifestsInternal(ctx, operations.ListClusterManifestsParams{ ClusterID: *cluster.ID, }) if err != nil { - r.Log.WithError(err).Errorf("Failed to list manifests for %q cluster install", clusterInstall.Name) + log.WithError(err).Errorf("Failed to list manifests for %q cluster install", clusterInstall.Name) return err } @@ -557,11 +573,11 @@ func (r *ClusterDeploymentsReconciler) addCustomManifests(ctx context.Context, c // but we already added some in previous reconcile loop, we want to clean them. // if no reference were provided we will delete all manifests that were in the list if clusterInstall.Spec.ManifestsConfigMapRef == nil && len(alreadyCreatedManifests) == 0 { - r.Log.Debugf("Nothing to do, skipping manifest creation") + log.Debugf("Nothing to do, skipping manifest creation") return nil } - return r.syncManifests(ctx, cluster, clusterInstall, alreadyCreatedManifests) + return r.syncManifests(ctx, log, cluster, clusterInstall, alreadyCreatedManifests) } func (r *ClusterDeploymentsReconciler) isSNO(clusterInstall *hiveext.AgentClusterInstall) bool { @@ -571,23 +587,24 @@ func (r *ClusterDeploymentsReconciler) isSNO(clusterInstall *hiveext.AgentCluste func (r *ClusterDeploymentsReconciler) createNewCluster( ctx context.Context, + log logrus.FieldLogger, key types.NamespacedName, clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hiveext.AgentClusterInstall) (ctrl.Result, error) { - r.Log.Infof("Creating a new clusterDeployment %s %s", clusterDeployment.Name, clusterDeployment.Namespace) + log.Infof("Creating a new clusterDeployment %s %s", clusterDeployment.Name, clusterDeployment.Namespace) spec := clusterDeployment.Spec pullSecret, err := getPullSecret(ctx, r.Client, spec.PullSecretRef, key.Namespace) if err != nil { - r.Log.WithError(err).Error("failed to get pull secret") - return r.updateStatus(ctx, clusterInstall, nil, err) + log.WithError(err).Error("failed to get pull secret") + return r.updateStatus(ctx, log, clusterInstall, nil, err) } openshiftVersion, err := r.addOpenshiftVersion(ctx, clusterInstall.Spec, pullSecret) if err != nil { - r.Log.WithError(err).Error("failed to add OCP version") - return r.updateStatus(ctx, clusterInstall, nil, err) + log.WithError(err).Error("failed to add OCP version") + return r.updateStatus(ctx, log, clusterInstall, nil, err) } clusterParams := &models.ClusterCreateParams{ @@ -620,30 +637,31 @@ func (r *ClusterDeploymentsReconciler) createNewCluster( NewClusterParams: clusterParams, }) - return r.updateStatus(ctx, clusterInstall, c, err) + return r.updateStatus(ctx, log, clusterInstall, c, err) } func (r *ClusterDeploymentsReconciler) createNewDay2Cluster( ctx context.Context, + log logrus.FieldLogger, key types.NamespacedName, clusterDeployment *hivev1.ClusterDeployment, clusterInstall *hiveext.AgentClusterInstall) (ctrl.Result, error) { - r.Log.Infof("Creating a new Day2 Cluster %s %s", clusterDeployment.Name, clusterDeployment.Namespace) + log.Infof("Creating a new Day2 Cluster %s %s", clusterDeployment.Name, clusterDeployment.Namespace) spec := clusterDeployment.Spec id := strfmt.UUID(uuid.New().String()) apiVipDnsname := fmt.Sprintf("api.%s.%s", spec.ClusterName, spec.BaseDomain) pullSecret, err := getPullSecret(ctx, r.Client, spec.PullSecretRef, key.Namespace) if err != nil { - r.Log.WithError(err).Error("failed to get pull secret") - return r.updateStatus(ctx, clusterInstall, nil, err) + log.WithError(err).Error("failed to get pull secret") + return r.updateStatus(ctx, log, clusterInstall, nil, err) } openshiftVersion, err := r.addOpenshiftVersion(ctx, clusterInstall.Spec, pullSecret) if err != nil { - r.Log.WithError(err).Error("failed to add OCP version") - return r.updateStatus(ctx, clusterInstall, nil, err) + log.WithError(err).Error("failed to add OCP version") + return r.updateStatus(ctx, log, clusterInstall, nil, err) } clusterParams := &models.AddHostsClusterCreateParams{ @@ -657,7 +675,7 @@ func (r *ClusterDeploymentsReconciler) createNewDay2Cluster( NewAddHostsClusterParams: clusterParams, }) - return r.updateStatus(ctx, clusterInstall, c, err) + return r.updateStatus(ctx, log, clusterInstall, c, err) } func (r *ClusterDeploymentsReconciler) getReleaseImage(ctx context.Context, spec hiveext.AgentClusterInstallSpec) (string, error) { @@ -686,7 +704,7 @@ func (r *ClusterDeploymentsReconciler) addOpenshiftVersion( return openshiftVersion, nil } -func (r *ClusterDeploymentsReconciler) deregisterClusterIfNeeded(ctx context.Context, key types.NamespacedName) (ctrl.Result, error) { +func (r *ClusterDeploymentsReconciler) deregisterClusterIfNeeded(ctx context.Context, log logrus.FieldLogger, key types.NamespacedName) (ctrl.Result, error) { buildReply := func(err error) (ctrl.Result, error) { reply := ctrl.Result{} @@ -695,7 +713,7 @@ func (r *ClusterDeploymentsReconciler) deregisterClusterIfNeeded(ctx context.Con } reply.RequeueAfter = defaultRequeueAfterOnError err = errors.Wrapf(err, "failed to deregister cluster: %s", key.Name) - r.Log.Error(err) + log.Error(err) return reply, err } @@ -716,7 +734,7 @@ func (r *ClusterDeploymentsReconciler) deregisterClusterIfNeeded(ctx context.Con return buildReply(err) } - r.Log.Infof("Cluster resource deleted, Unregistered cluster: %s", c.ID.String()) + log.Infof("Cluster resource deleted, Unregistered cluster: %s", c.ID.String()) return buildReply(nil) } @@ -742,12 +760,17 @@ func (r *ClusterDeploymentsReconciler) SetupWithManager(mgr ctrl.Manager) error // Reconcile the ClusterDeployment referenced by this AgentClusterInstall. mapClusterInstallToClusterDeployment := func(a client.Object) []reconcile.Request { + log := logutil.FromContext(context.Background(), r.Log).WithFields( + logrus.Fields{ + "agent_cluster_install": a.GetName(), + "agent_cluster_install_namespace": a.GetNamespace(), + }) aci, ok := a.(*hiveext.AgentClusterInstall) if !ok { - r.Log.Errorf("%v was not an AgentClusterInstall", a) // shouldn't be possible + log.Errorf("%v was not an AgentClusterInstall", a) // shouldn't be possible return []reconcile.Request{} } - r.Log.Debugf("Map ACI : %s %s CD ref name %s", aci.Namespace, aci.Name, aci.Spec.ClusterDeploymentRef.Name) + log.Debugf("Map ACI : %s %s CD ref name %s", aci.Namespace, aci.Name, aci.Spec.ClusterDeploymentRef.Name) return []reconcile.Request{ { NamespacedName: types.NamespacedName{ @@ -770,7 +793,7 @@ func (r *ClusterDeploymentsReconciler) SetupWithManager(mgr ctrl.Manager) error // updateStatus is updating all the AgentClusterInstall Conditions. // In case that an error has occured when trying to sync the Spec, the error (syncErr) is presented in SpecSyncedCondition. // Internal bool differentiate between backend server error (internal HTTP 5XX) and user input error (HTTP 4XXX) -func (r *ClusterDeploymentsReconciler) updateStatus(ctx context.Context, clusterInstall *hiveext.AgentClusterInstall, c *common.Cluster, syncErr error) (ctrl.Result, error) { +func (r *ClusterDeploymentsReconciler) updateStatus(ctx context.Context, log logrus.FieldLogger, clusterInstall *hiveext.AgentClusterInstall, c *common.Cluster, syncErr error) (ctrl.Result, error) { clusterSpecSynced(clusterInstall, syncErr) if c != nil { clusterInstall.Status.ConnectivityMajorityGroups = c.ConnectivityMajorityGroups @@ -787,7 +810,7 @@ func (r *ClusterDeploymentsReconciler) updateStatus(ctx context.Context, cluster } if updateErr := r.Status().Update(ctx, clusterInstall); updateErr != nil { - r.Log.WithError(updateErr).Error("failed to update ClusterDeployment Status") + log.WithError(updateErr).Error("failed to update ClusterDeployment Status") return ctrl.Result{Requeue: true}, nil } if syncErr != nil && !IsUserError(syncErr) { @@ -1065,10 +1088,10 @@ func FindStatusCondition(conditions []hivev1.ClusterInstallCondition, conditionT } // ensureOwnerRef sets the owner reference of ClusterDeployment on AgentClusterInstall -func (r *ClusterDeploymentsReconciler) ensureOwnerRef(ctx context.Context, cd *hivev1.ClusterDeployment, ci *hiveext.AgentClusterInstall) error { +func (r *ClusterDeploymentsReconciler) ensureOwnerRef(ctx context.Context, log logrus.FieldLogger, cd *hivev1.ClusterDeployment, ci *hiveext.AgentClusterInstall) error { if err := controllerutil.SetOwnerReference(cd, ci, r.Scheme); err != nil { - r.Log.WithError(err).Error("error setting owner reference Agent Cluster Install") + log.WithError(err).Error("error setting owner reference Agent Cluster Install") return err } return r.Update(ctx, ci) diff --git a/internal/controller/controllers/common.go b/internal/controller/controllers/common.go index bfcb9a236fe..7672513a94b 100644 --- a/internal/controller/controllers/common.go +++ b/internal/controller/controllers/common.go @@ -7,6 +7,7 @@ import ( "strings" aiv1beta1 "github.com/openshift/assisted-service/internal/controller/api/v1beta1" + "github.com/openshift/assisted-service/pkg/requestid" hivev1 "github.com/openshift/hive/apis/hive/v1" "github.com/pkg/errors" "github.com/sirupsen/logrus" @@ -124,3 +125,11 @@ func getReleaseImage(ctx context.Context, c client.Client, imageSetName string) return clusterImageSet.Spec.ReleaseImage, nil } + +func addRequestIdIfNeeded(ctx context.Context) context.Context { + ctxWithReqID := ctx + if requestid.FromContext(ctx) == "" { + ctxWithReqID = requestid.ToContext(ctx, requestid.NewID()) + } + return ctxWithReqID +} \ No newline at end of file diff --git a/internal/controller/controllers/infraenv_controller.go b/internal/controller/controllers/infraenv_controller.go index 2559a6db53f..24027e8625a 100644 --- a/internal/controller/controllers/infraenv_controller.go +++ b/internal/controller/controllers/infraenv_controller.go @@ -62,22 +62,32 @@ type InfraEnvReconciler struct { // +kubebuilder:rbac:groups=agent-install.openshift.io,resources=infraenvs,verbs=get;list;watch;create;update;patch;delete // +kubebuilder:rbac:groups=agent-install.openshift.io,resources=infraenvs/status,verbs=get;update;patch -func (r *InfraEnvReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { - r.Log.Infof("Reconcile has been called for InfraEnv name=%s namespace=%s", req.Name, req.Namespace) +func (r *InfraEnvReconciler) Reconcile(origCtx context.Context, req ctrl.Request) (ctrl.Result, error) { + ctx := addRequestIdIfNeeded(origCtx) + log := logutil.FromContext(ctx, r.Log).WithFields( + logrus.Fields{ + "infra_env": req.Name, + "infra_env_namespace": req.Namespace, + }) + + defer func() { + log.Info("InfraEnv Reconcile ended") + }() + + log.Info("InfraEnv Reconcile started") infraEnv := &aiv1beta1.InfraEnv{} if err := r.Get(ctx, req.NamespacedName, infraEnv); err != nil { return ctrl.Result{}, client.IgnoreNotFound(err) } - return r.ensureISO(ctx, infraEnv) + return r.ensureISO(ctx, log, infraEnv) } -func (r *InfraEnvReconciler) updateClusterIfNeeded(ctx context.Context, infraEnv *aiv1beta1.InfraEnv, cluster *common.Cluster) error { +func (r *InfraEnvReconciler) updateClusterIfNeeded(ctx context.Context, log logrus.FieldLogger, infraEnv *aiv1beta1.InfraEnv, cluster *common.Cluster) error { var ( params = &models.ClusterUpdateParams{} update bool - log = logutil.FromContext(ctx, r.Log) ) if infraEnv.Spec.Proxy != nil { @@ -116,11 +126,10 @@ func (r *InfraEnvReconciler) updateClusterIfNeeded(ctx context.Context, infraEnv return nil } -func (r *InfraEnvReconciler) updateClusterDiscoveryIgnitionIfNeeded(ctx context.Context, infraEnv *aiv1beta1.InfraEnv, cluster *common.Cluster) error { +func (r *InfraEnvReconciler) updateClusterDiscoveryIgnitionIfNeeded(ctx context.Context, log logrus.FieldLogger, infraEnv *aiv1beta1.InfraEnv, cluster *common.Cluster) error { var ( discoveryIgnitionParams = &models.DiscoveryIgnitionParams{} updateClusterIgnition bool - log = logutil.FromContext(ctx, r.Log) ) if infraEnv.Spec.IgnitionConfigOverride != "" && cluster.IgnitionConfigOverrides != infraEnv.Spec.IgnitionConfigOverride { discoveryIgnitionParams.Config = *swag.String(infraEnv.Spec.IgnitionConfigOverride) @@ -142,10 +151,10 @@ func (r *InfraEnvReconciler) updateClusterDiscoveryIgnitionIfNeeded(ctx context. return nil } -func (r *InfraEnvReconciler) buildMacInterfaceMap(nmStateConfig aiv1beta1.NMStateConfig) models.MacInterfaceMap { +func (r *InfraEnvReconciler) buildMacInterfaceMap(log logrus.FieldLogger, nmStateConfig aiv1beta1.NMStateConfig) models.MacInterfaceMap { macInterfaceMap := make(models.MacInterfaceMap, 0, len(nmStateConfig.Spec.Interfaces)) for _, cfg := range nmStateConfig.Spec.Interfaces { - r.Log.Debugf("adding MAC interface map to host static network config - Name: %s, MacAddress: %s ,", + log.Debugf("adding MAC interface map to host static network config - Name: %s, MacAddress: %s ,", cfg.Name, cfg.MacAddress) macInterfaceMap = append(macInterfaceMap, &models.MacInterfaceMapItems0{ MacAddress: cfg.MacAddress, @@ -155,7 +164,7 @@ func (r *InfraEnvReconciler) buildMacInterfaceMap(nmStateConfig aiv1beta1.NMStat return macInterfaceMap } -func (r *InfraEnvReconciler) processNMStateConfig(ctx context.Context, infraEnv *aiv1beta1.InfraEnv) ([]*models.HostStaticNetworkConfig, error) { +func (r *InfraEnvReconciler) processNMStateConfig(ctx context.Context, log logrus.FieldLogger, infraEnv *aiv1beta1.InfraEnv) ([]*models.HostStaticNetworkConfig, error) { var staticNetworkConfig []*models.HostStaticNetworkConfig if infraEnv.Spec.NMStateConfigLabelSelector.MatchLabels == nil { @@ -168,9 +177,9 @@ func (r *InfraEnvReconciler) processNMStateConfig(ctx context.Context, infraEnv return staticNetworkConfig, err } for _, nmStateConfig := range nmStateConfigs.Items { - r.Log.Debugf("found nmStateConfig: %s for infraEnv: %s", nmStateConfig.Name, infraEnv.Name) + log.Debugf("found nmStateConfig: %s for infraEnv: %s", nmStateConfig.Name, infraEnv.Name) staticNetworkConfig = append(staticNetworkConfig, &models.HostStaticNetworkConfig{ - MacInterfaceMap: r.buildMacInterfaceMap(nmStateConfig), + MacInterfaceMap: r.buildMacInterfaceMap(log, nmStateConfig), NetworkYaml: string(nmStateConfig.Spec.NetConfig.Raw), }) } @@ -180,7 +189,7 @@ func (r *InfraEnvReconciler) processNMStateConfig(ctx context.Context, infraEnv // ensureISO generates ISO for the cluster if needed and will update the condition Reason and Message accordingly. // It returns a result that includes ISODownloadURL. -func (r *InfraEnvReconciler) ensureISO(ctx context.Context, infraEnv *aiv1beta1.InfraEnv) (ctrl.Result, error) { +func (r *InfraEnvReconciler) ensureISO(ctx context.Context, log logrus.FieldLogger, infraEnv *aiv1beta1.InfraEnv) (ctrl.Result, error) { var inventoryErr error var Requeue bool var updatedCluster *common.Cluster @@ -211,7 +220,7 @@ func (r *InfraEnvReconciler) ensureISO(ctx context.Context, infraEnv *aiv1beta1. Message: aiv1beta1.ImageStateFailedToCreate + ": " + clusterDeploymentRefErr.Error(), }) if updateErr := r.Status().Update(ctx, infraEnv); updateErr != nil { - r.Log.WithError(updateErr).Error("failed to update infraEnv status") + log.WithError(updateErr).Error("failed to update infraEnv status") } return ctrl.Result{Requeue: Requeue}, nil } @@ -237,19 +246,19 @@ func (r *InfraEnvReconciler) ensureISO(ctx context.Context, infraEnv *aiv1beta1. Message: aiv1beta1.ImageStateFailedToCreate + ": " + inventoryErr.Error(), }) if updateErr := r.Status().Update(ctx, infraEnv); updateErr != nil { - r.Log.WithError(updateErr).Error("failed to update infraEnv status") + log.WithError(updateErr).Error("failed to update infraEnv status") } return ctrl.Result{Requeue: Requeue}, nil } // Check for updates from user, compare spec and update the cluster - if err = r.updateClusterIfNeeded(ctx, infraEnv, cluster); err != nil { - return r.handleEnsureISOErrors(ctx, infraEnv, err) + if err = r.updateClusterIfNeeded(ctx, log, infraEnv, cluster); err != nil { + return r.handleEnsureISOErrors(ctx, log, infraEnv, err) } // Check for discovery ignition specific updates from user, compare spec and update the ignition config - if err = r.updateClusterDiscoveryIgnitionIfNeeded(ctx, infraEnv, cluster); err != nil { - return r.handleEnsureISOErrors(ctx, infraEnv, err) + if err = r.updateClusterDiscoveryIgnitionIfNeeded(ctx, log, infraEnv, cluster); err != nil { + return r.handleEnsureISOErrors(ctx, log, infraEnv, err) } isoParams := installer.GenerateClusterISOParams{ @@ -260,9 +269,9 @@ func (r *InfraEnvReconciler) ensureISO(ctx context.Context, infraEnv *aiv1beta1. }, } - staticNetworkConfig, err := r.processNMStateConfig(ctx, infraEnv) + staticNetworkConfig, err := r.processNMStateConfig(ctx, log, infraEnv) if err != nil { - return r.handleEnsureISOErrors(ctx, infraEnv, err) + return r.handleEnsureISOErrors(ctx, log, infraEnv, err) } if len(staticNetworkConfig) > 0 { isoParams.ImageCreateParams.StaticNetworkConfig = staticNetworkConfig @@ -271,21 +280,21 @@ func (r *InfraEnvReconciler) ensureISO(ctx context.Context, infraEnv *aiv1beta1. // Add openshift version to ensure it isn't missing in versions cache _, err = r.Installer.AddOpenshiftVersion(ctx, cluster.OcpReleaseImage, cluster.PullSecret) if err != nil { - return r.handleEnsureISOErrors(ctx, infraEnv, err) + return r.handleEnsureISOErrors(ctx, log, infraEnv, err) } // GenerateClusterISOInternal will generate an ISO only if there it was not generated before, // or something has changed in isoParams. updatedCluster, inventoryErr = r.Installer.GenerateClusterISOInternal(ctx, isoParams) if inventoryErr != nil { - return r.handleEnsureISOErrors(ctx, infraEnv, inventoryErr) + return r.handleEnsureISOErrors(ctx, log, infraEnv, inventoryErr) } // Image successfully generated. Reflect that in infraEnv obj and conditions - return r.updateEnsureISOSuccess(ctx, infraEnv, updatedCluster.ImageInfo) + return r.updateEnsureISOSuccess(ctx, log, infraEnv, updatedCluster.ImageInfo) } func (r *InfraEnvReconciler) updateEnsureISOSuccess( - ctx context.Context, infraEnv *aiv1beta1.InfraEnv, imageInfo *models.ImageInfo) (ctrl.Result, error) { + ctx context.Context, log logrus.FieldLogger, infraEnv *aiv1beta1.InfraEnv, imageInfo *models.ImageInfo) (ctrl.Result, error) { conditionsv1.SetStatusConditionNoHeartbeat(&infraEnv.Status.Conditions, conditionsv1.Condition{ Type: aiv1beta1.ImageCreatedCondition, Status: corev1.ConditionTrue, @@ -294,14 +303,14 @@ func (r *InfraEnvReconciler) updateEnsureISOSuccess( }) infraEnv.Status.ISODownloadURL = imageInfo.DownloadURL if updateErr := r.Status().Update(ctx, infraEnv); updateErr != nil { - r.Log.WithError(updateErr).Error("failed to update infraEnv status") + log.WithError(updateErr).Error("failed to update infraEnv status") return ctrl.Result{Requeue: true}, nil } return ctrl.Result{Requeue: false}, nil } func (r *InfraEnvReconciler) handleEnsureISOErrors( - ctx context.Context, infraEnv *aiv1beta1.InfraEnv, err error) (ctrl.Result, error) { + ctx context.Context, log logrus.FieldLogger, infraEnv *aiv1beta1.InfraEnv, err error) (ctrl.Result, error) { var ( currentReason = "" errMsg string @@ -315,7 +324,7 @@ func (r *InfraEnvReconciler) handleEnsureISOErrors( if imageBeingCreated(err) && currentReason != aiv1beta1.ImageCreationErrorReason { // Not an actual error, just an image generation in progress. err = nil Requeue = false - r.Log.Infof("Image %s being prepared for cluster %s", infraEnv.Name, infraEnv.ClusterName) + log.Infof("Image %s being prepared for cluster %s", infraEnv.Name, infraEnv.ClusterName) conditionsv1.SetStatusConditionNoHeartbeat(&infraEnv.Status.Conditions, conditionsv1.Condition{ Type: aiv1beta1.ImageCreatedCondition, Status: corev1.ConditionTrue, @@ -323,7 +332,7 @@ func (r *InfraEnvReconciler) handleEnsureISOErrors( Message: aiv1beta1.ImageStateCreated, }) } else { // Actual errors - r.Log.WithError(err).Error("infraEnv reconcile failed") + log.WithError(err).Error("infraEnv reconcile failed") if isClientError(err) { Requeue = false errMsg = ": " + err.Error() @@ -341,7 +350,7 @@ func (r *InfraEnvReconciler) handleEnsureISOErrors( infraEnv.Status.ISODownloadURL = "" } if updateErr := r.Status().Update(ctx, infraEnv); updateErr != nil { - r.Log.WithError(updateErr).Error("failed to update infraEnv status") + log.WithError(updateErr).Error("failed to update infraEnv status") } return ctrl.Result{Requeue: Requeue}, err } @@ -352,23 +361,28 @@ func imageBeingCreated(err error) bool { func (r *InfraEnvReconciler) SetupWithManager(mgr ctrl.Manager) error { mapNMStateConfigToInfraEnv := func(a client.Object) []reconcile.Request { + log := logutil.FromContext(context.Background(), r.Log).WithFields( + logrus.Fields{ + "nmstate_config": a.GetName(), + "nmstate_config_namespace": a.GetNamespace(), + }) infraEnvs := &aiv1beta1.InfraEnvList{} if len(a.GetLabels()) == 0 { - r.Log.Debugf("NMState config: %s has no labels", a.GetName()) + log.Debugf("NMState config: %s has no labels", a.GetName()) return []reconcile.Request{} } if err := r.List(context.Background(), infraEnvs, client.InNamespace(a.GetNamespace())); err != nil { - r.Log.Debugf("failed to list InfraEnvs") + log.Debugf("failed to list InfraEnvs") return []reconcile.Request{} } reply := make([]reconcile.Request, 0, len(infraEnvs.Items)) for labelName, labelValue := range a.GetLabels() { - r.Log.Debugf("Detected NMState config with label name: %s with value %s, about to search for a matching InfraEnv", + log.Debugf("Detected NMState config with label name: %s with value %s, about to search for a matching InfraEnv", labelName, labelValue) for _, infraEnv := range infraEnvs.Items { if infraEnv.Spec.NMStateConfigLabelSelector.MatchLabels[labelName] == labelValue { - r.Log.Debugf("Detected NMState config for InfraEnv: %s in namespace: %s", infraEnv.Name, infraEnv.Namespace) + log.Debugf("Detected NMState config for InfraEnv: %s in namespace: %s", infraEnv.Name, infraEnv.Namespace) reply = append(reply, reconcile.Request{NamespacedName: types.NamespacedName{ Namespace: infraEnv.Namespace, Name: infraEnv.Name, @@ -380,9 +394,14 @@ func (r *InfraEnvReconciler) SetupWithManager(mgr ctrl.Manager) error { } mapClusterDeploymentToInfraEnv := func(clusterDeployment client.Object) []reconcile.Request { + log := logutil.FromContext(context.Background(), r.Log).WithFields( + logrus.Fields{ + "cluster_deployment": clusterDeployment.GetName(), + "cluster_deployment_namespace": clusterDeployment.GetNamespace(), + }) infraEnvs := &aiv1beta1.InfraEnvList{} if err := r.List(context.Background(), infraEnvs, client.InNamespace(clusterDeployment.GetNamespace())); err != nil { - r.Log.Debugf("failed to list InfraEnvs") + log.Debugf("failed to list InfraEnvs") return []reconcile.Request{} }