Skip to content

Commit

Permalink
tracing reconciliation log output with an rid (#190)
Browse files Browse the repository at this point in the history 
* adding rid to trace logging by reconciliation

* removing unused line

* adding rid for namespacereservation controller

* Adding rid to ctx

* updated changes with context

* adjustments to logging through context
  • Loading branch information
@maknop
maknop authored Oct 9, 2023
1 parent a57988e commit e7c3af6
Show file tree
Hide file tree
Showing 4 changed files with 48 additions and 34 deletions.
14 changes: 9 additions & 5 deletions controllers/cloud.redhat.com/clowdenvironment_controller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@ import (

clowder "github.com/RedHatInsights/clowder/apis/cloud.redhat.com/v1alpha1"
"github.com/RedHatInsights/ephemeral-namespace-operator/controllers/cloud.redhat.com/helpers"
"github.com/RedHatInsights/rhc-osdk-utils/utils"
"github.com/go-logr/logr"
"github.com/prometheus/client_golang/prometheus"
"k8s.io/apimachinery/pkg/runtime"
Expand All @@ -44,24 +45,27 @@ type ClowdenvironmentReconciler struct {
//+kubebuilder:rbac:groups=cloud.redhat.com,resources=clowdenvironments/status,verbs=get

func (r *ClowdenvironmentReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
log := r.log.WithValues("rid", utils.RandString(5))
ctx = context.WithValue(ctx, helpers.ErrType("log"), &log)

env := clowder.ClowdEnvironment{}
if err := r.client.Get(ctx, req.NamespacedName, &env); err != nil {
r.log.Error(err, "Error retrieving clowdenv", "env-name", env.Name)
log.Error(err, "Error retrieving clowdenv", "env-name", env.Name)
return ctrl.Result{}, err
}

if ready, err := helpers.VerifyClowdEnvReady(env); !ready {
return ctrl.Result{Requeue: true}, err
}

r.log.Info(
log.Info(
"Reconciling clowdenv",
"env-name", env.Name,
"deployments", fmt.Sprintf("%d / %d", env.Status.Deployments.ReadyDeployments, env.Status.Deployments.ManagedDeployments),
)

namespaceName := env.Spec.TargetNamespace
r.log.Info("clowdenvironment ready", "namespace", namespaceName)
log.Info("clowdenvironment ready", "namespace", namespaceName)

if err := helpers.CreateFrontendEnv(ctx, r.client, namespaceName, env); err != nil {
r.log.Error(err, "error encountered with frontend environment", "namespace", namespaceName)
Expand All @@ -70,7 +74,7 @@ func (r *ClowdenvironmentReconciler) Reconcile(ctx context.Context, req ctrl.Req
}
}

r.log.Info("namespace ready", "namespace", namespaceName)
log.Info("namespace ready", "namespace", namespaceName)
if err := helpers.UpdateAnnotations(ctx, r.client, namespaceName, helpers.AnnotationEnvReady.ToMap()); err != nil {
return ctrl.Result{Requeue: true}, fmt.Errorf("error setting annotations: %w", err)
}
Expand All @@ -94,7 +98,7 @@ func (r *ClowdenvironmentReconciler) Reconcile(ctx context.Context, req ctrl.Req

namespace, err = helpers.GetNamespace(ctx, r.client, namespaceName)
if err != nil {
r.log.Error(err, "could not retrieve newly created namespace", "namespace", namespaceName)
log.Error(err, "could not retrieve newly created namespace", "namespace", namespaceName)
}

if err := r.client.Update(ctx, &namespace); err != nil {
Expand Down
2 changes: 2 additions & 0 deletions controllers/cloud.redhat.com/helpers/types.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,3 +41,5 @@ var AnnotationReservedTrue = CustomAnnotation{Annotation: AnnotationReserved, Va
var AnnotationReservedFalse = CustomAnnotation{Annotation: AnnotationReserved, Value: FalseValue}

var LabelOperatorNamespaceTrue = CustomLabel{Label: LabelOperatorNS, Value: TrueValue}

type ErrType string
20 changes: 12 additions & 8 deletions controllers/cloud.redhat.com/namespacepool_controller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@ import (

crd "github.com/RedHatInsights/ephemeral-namespace-operator/apis/cloud.redhat.com/v1alpha1"
"github.com/RedHatInsights/ephemeral-namespace-operator/controllers/cloud.redhat.com/helpers"
"github.com/RedHatInsights/rhc-osdk-utils/utils"
)

// NamespacePoolReconciler reconciles a NamespacePool object
Expand All @@ -46,44 +47,47 @@ type NamespacePoolReconciler struct {
//+kubebuilder:rbac:groups=cloud.redhat.com,resources=namespacepools/finalizers,verbs=update

func (r *NamespacePoolReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
log := r.log.WithValues("rid", utils.RandString(5))
ctx = context.WithValue(ctx, helpers.ErrType("log"), &log)

pool := crd.NamespacePool{}

if err := r.client.Get(ctx, req.NamespacedName, &pool); err != nil {
r.log.Error(err, fmt.Sprintf("cannot retrieve [%s] pool resource", pool.Name))
log.Error(err, fmt.Sprintf("cannot retrieve [%s] pool resource", pool.Name))
return ctrl.Result{Requeue: true}, err
}

errNamespaceList, err := r.getPoolStatus(ctx, &pool)
if err != nil {
r.log.Error(err, "unable to get status of owned namespaces")
log.Error(err, "unable to get status of owned namespaces")
return ctrl.Result{Requeue: true}, err
}

if len(errNamespaceList) > 0 {
r.log.Info(fmt.Sprintf("[%d] namespaces in error state are queued for deletion", len(errNamespaceList)))
log.Info(fmt.Sprintf("[%d] namespaces in error state are queued for deletion", len(errNamespaceList)))
err = r.deleteErrorNamespaces(ctx, errNamespaceList)
if err != nil {
r.log.Error(err, "Unable to delete namespaces in error state")
return ctrl.Result{Requeue: true}, err
}
}

r.log.Info(fmt.Sprintf("[%s] pool status", pool.Name),
log.Info(fmt.Sprintf("[%s] pool status", pool.Name),
"ready", pool.Status.Ready,
"creating", pool.Status.Creating,
"reserved", pool.Status.Reserved)

quantityOfNamespaces := r.getNamespaceQuantityDelta(pool)

if quantityOfNamespaces > 0 {
r.log.Info(fmt.Sprintf("filling [%s] pool with [%d] namespace(s)", pool.Name, quantityOfNamespaces))
log.Info(fmt.Sprintf("filling [%s] pool with [%d] namespace(s)", pool.Name, quantityOfNamespaces))
err := r.increaseReadyNamespacesQueue(ctx, pool, quantityOfNamespaces)
if err != nil {
r.log.Error(err, fmt.Sprintf("unable to create more namespaces for [%s] pool.", pool.Name))
log.Error(err, fmt.Sprintf("unable to create more namespaces for [%s] pool.", pool.Name))
return ctrl.Result{Requeue: true}, err
}
} else if quantityOfNamespaces < 0 {
r.log.Info(fmt.Sprintf("excess number of ready namespaces in [%s] pool detected, removing [%d] namespace(s)", pool.Name, (quantityOfNamespaces * -1)))
log.Info(fmt.Sprintf("excess number of ready namespaces in [%s] pool detected, removing [%d] namespace(s)", pool.Name, (quantityOfNamespaces * -1)))
err := r.decreaseReadyNamespacesQueue(ctx, pool.Name, quantityOfNamespaces)
if err != nil {
r.log.Error(err, fmt.Sprintf("unable to delete excess namespaces for [%s] pool.", pool.Name))
Expand All @@ -92,7 +96,7 @@ func (r *NamespacePoolReconciler) Reconcile(ctx context.Context, req ctrl.Reques
}

if err := r.client.Status().Update(ctx, &pool); err != nil {
r.log.Error(err, fmt.Sprintf("cannot update [%s] pool status", pool.Name))
log.Error(err, fmt.Sprintf("cannot update [%s] pool status", pool.Name))
return ctrl.Result{}, err
}

Expand Down
46 changes: 25 additions & 21 deletions controllers/cloud.redhat.com/namespacereservation_controller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ import (

crd "github.com/RedHatInsights/ephemeral-namespace-operator/apis/cloud.redhat.com/v1alpha1"
"github.com/RedHatInsights/ephemeral-namespace-operator/controllers/cloud.redhat.com/helpers"
"github.com/RedHatInsights/rhc-osdk-utils/utils"
"github.com/go-logr/logr"
core "k8s.io/api/core/v1"
rbac "k8s.io/api/rbac/v1"
Expand Down Expand Up @@ -60,14 +61,17 @@ type NamespaceReservationReconciler struct {
//+kubebuilder:rbac:groups=rbac.authorization.k8s.io,resources=rolebindings;roles,verbs=get;list;watch;create;update;patch;delete

func (r *NamespaceReservationReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) {
log := r.log.WithValues("rid", utils.RandString(5))
ctx = context.WithValue(ctx, helpers.ErrType("log"), &log)

// Fetch the reservation
res := crd.NamespaceReservation{}
if err := r.client.Get(ctx, req.NamespacedName, &res); err != nil {
if k8serr.IsNotFound(err) {
// Must have been deleted
return ctrl.Result{}, nil
}
r.log.Error(err, "Reservation Not Found")
log.Error(err, "Reservation Not Found")
return ctrl.Result{}, err
}

Expand All @@ -81,7 +85,7 @@ func (r *NamespaceReservationReconciler) Reconcile(ctx context.Context, req ctrl

switch res.Status.State {
case "active":
r.log.Info("Reconciling active reservation", "name", res.Name, "namespace", res.Status.Namespace)
log.Info("Reconciling active reservation", "name", res.Name, "namespace", res.Status.Namespace)
expirationTS, err := getExpirationTime(&res)
if err != nil {
r.log.Error(err, "Could not get expiration time for reservation", "name", res.Name)
Expand All @@ -92,7 +96,7 @@ func (r *NamespaceReservationReconciler) Reconcile(ctx context.Context, req ctrl
r.poller.activeReservations[res.Name] = expirationTS

if err := r.client.Status().Update(ctx, &res); err != nil {
r.log.Error(err, "Cannot update reservation status", "name", res.Name)
log.Error(err, "Cannot update reservation status", "name", res.Name)
return ctrl.Result{}, err
}

Expand All @@ -101,48 +105,48 @@ func (r *NamespaceReservationReconciler) Reconcile(ctx context.Context, req ctrl
return ctrl.Result{}, nil

case "waiting":
r.log.Info("Reconciling waiting reservation", "name", res.Name)
log.Info("Reconciling waiting reservation", "name", res.Name)
expirationTS, err := getExpirationTime(&res)
if err != nil {
r.log.Error(err, "Could not get expiration time for reservation", "name", res.Name)
log.Error(err, "Could not get expiration time for reservation", "name", res.Name)
return ctrl.Result{}, err
}
if r.poller.namespaceIsExpired(expirationTS) {
if err := r.client.Delete(ctx, &res); err != nil {
r.log.Error(err, "Unable to delete waiting reservation", "res-name", res.Name)
log.Error(err, "Unable to delete waiting reservation", "res-name", res.Name)
}
return ctrl.Result{}, nil
}
fallthrough // fallthrough to default case to check for ns availability if not expired

default:
// if no, requeue and wait for pool to populate
r.log.Info("Reconciling reservation", "name", res.Name)
r.log.Info(fmt.Sprintf("Checking %s pool for ready namespaces", res.Status.Pool), "name", res.Name)
log.Info("Reconciling reservation", "name", res.Name)
log.Info(fmt.Sprintf("Checking %s pool for ready namespaces", res.Status.Pool), "name", res.Name)

expirationTS, err := getExpirationTime(&res)
if err != nil {
r.log.Error(err, "Could not set expiration time on reservation. Deleting", "res-name", res.Name)
log.Error(err, "Could not set expiration time on reservation. Deleting", "res-name", res.Name)
if err := r.client.Delete(ctx, &res); err != nil {
r.log.Error(err, "cannot delete resource - aborting delete", "name", res.Name)
log.Error(err, "cannot delete resource - aborting delete", "name", res.Name)
}
return ctrl.Result{}, err
}

nsList, err := helpers.GetReadyNamespaces(ctx, r.client, res.Status.Pool)
if err != nil {
r.log.Error(err, fmt.Sprintf("unable to retrieve list of namespaces from '%s' pool", res.Status.Pool), "res-name", res.Name)
log.Error(err, fmt.Sprintf("unable to retrieve list of namespaces from '%s' pool", res.Status.Pool), "res-name", res.Name)
return ctrl.Result{}, err
}

if len(nsList) < 1 {
r.log.Info(fmt.Sprintf("requeue to wait for namespace population from '%s' pool", res.Status.Pool), "name", res.Name)
log.Info(fmt.Sprintf("requeue to wait for namespace population from '%s' pool", res.Status.Pool), "name", res.Name)
if res.Status.State == "" {
res.Status.State = "waiting"
res.Status.Expiration = expirationTS
err := r.client.Status().Update(ctx, &res)
if err != nil {
r.log.Error(err, "cannot update status", "name", res.Name)
log.Error(err, "cannot update status", "name", res.Name)
return ctrl.Result{}, err
}
}
Expand All @@ -151,21 +155,21 @@ func (r *NamespaceReservationReconciler) Reconcile(ctx context.Context, req ctrl

// Check to see if there's an error with the Get
readyNsName := nsList[0].Name
r.log.Info(fmt.Sprintf("Found namespace in '%s' pool; verifying ready status", res.Status.Pool))
log.Info(fmt.Sprintf("Found namespace in '%s' pool; verifying ready status", res.Status.Pool))

// Verify that the ClowdEnv has been set up for the requested namespace
if err := r.verifyClowdEnvForReadyNs(ctx, readyNsName); err != nil {
r.log.Error(err, err.Error(), "namespace", readyNsName)
log.Error(err, err.Error(), "namespace", readyNsName)
if err := helpers.UpdateAnnotations(ctx, r.client, readyNsName, helpers.AnnotationEnvError.ToMap()); err != nil {
r.log.Error(err, fmt.Sprintf("unable to update annotations for unready namespace in '%s' pool", res.Status.Pool), "namespace", readyNsName)
log.Error(err, fmt.Sprintf("unable to update annotations for unready namespace in '%s' pool", res.Status.Pool), "namespace", readyNsName)
return ctrl.Result{Requeue: true}, err
}
return ctrl.Result{Requeue: true}, err
}

// Resolve the requested namespace and remove it from the pool
if err := r.reserveNamespace(ctx, readyNsName, &res); err != nil {
r.log.Error(err, fmt.Sprintf("could not reserve namespace from '%s' pool", res.Status.Pool), "namespace", readyNsName)
log.Error(err, fmt.Sprintf("could not reserve namespace from '%s' pool", res.Status.Pool), "namespace", readyNsName)

totalFailedPoolReservationsCountMetrics.With(prometheus.Labels{"pool": res.Spec.Pool}).Inc()

Expand All @@ -179,22 +183,22 @@ func (r *NamespaceReservationReconciler) Reconcile(ctx context.Context, req ctrl

r.poller.activeReservations[res.Name] = expirationTS

r.log.Info("updating NamespaceReservation status")
r.log.Info("reservation details",
log.Info("updating NamespaceReservation status")
log.Info("reservation details",
"res-name", res.Name,
"res-uuid", res.ObjectMeta.UID,
"created", res.ObjectMeta.CreationTimestamp,
"spec", res.Spec,
"status", res.Status,
)
if err := r.client.Status().Update(ctx, &res); err != nil {
r.log.Error(err, "cannot update status")
log.Error(err, "cannot update status")
return ctrl.Result{}, err
}

duration, err := parseDurationTime(*res.Spec.Duration)
if err != nil {
r.log.Error(err, "cannot parse duration")
log.Error(err, "cannot parse duration")
return ctrl.Result{}, err
}

Expand Down

0 comments on commit e7c3af6

Please sign in to comment.