Skip to content

Commit

Permalink
update structured logging
Browse files Browse the repository at this point in the history 
This automatically adds additional fields like reconcile_id etc.. from the controller context.

before :

2023-05-18T01:53:14+03:00 INFO  controllers.KeystoneAPI Reconciled Service init successfully

after:

2023-10-15T02:22:33+03:00       INFO    Controllers.KeystoneAPI Reconciling Service     {"controller": "k eystoneapi", "controllerGroup": "keystone.openstack.org", "controllerKind": "KeystoneAPI", "KeystoneAPI": {"name":"keystone","namespace":"openstack"}, "namespace": "openstack", "name": "keystone", "reconcileID" : "30b247eb-4538-47d1-89a6-b877816a1103"}

*by using per reconcile function respective logger objects, the intention is to lay the ground for parallel reconciliation in future and avoid race conditions as ctx objects are reconcile run specific.

update structured logging

fix log obj.

update logging naming

update logging naming

update logging in tests

update logging
  • Loading branch information
@pinikomarov
pinikomarov committed Oct 24, 2023
1 parent d73d07c commit 32f5f50
Show file tree
Hide file tree
Showing 5 changed files with 98 additions and 81 deletions.
56 changes: 29 additions & 27 deletions controllers/keystoneapi_controller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -78,8 +78,8 @@ func (r *KeystoneAPIReconciler) GetScheme() *runtime.Scheme {
return r.Scheme
}

// GetLog returns a logger object with a prefix of "conroller.name" and aditional controller context fields
func GetLog(ctx context.Context) logr.Logger {
// GetLog returns a logger object with a logging prefix of "conrollers.name" and aditional controller context fields
func (r *KeystoneAPIReconciler) GetLogger(ctx context.Context) logr.Logger {
return log.FromContext(ctx).WithName("Controllers").WithName("KeystoneAPI")
}

Expand Down Expand Up @@ -115,6 +115,7 @@ type KeystoneAPIReconciler struct {

// Reconcile reconcile keystone API requests
func (r *KeystoneAPIReconciler) Reconcile(ctx context.Context, req ctrl.Request) (result ctrl.Result, _err error) {
Log := r.GetLogger(ctx)
// Fetch the KeystoneAPI instance
instance := &keystonev1.KeystoneAPI{}
err := r.Client.Get(ctx, req.NamespacedName, instance)
Expand All @@ -134,15 +135,15 @@ func (r *KeystoneAPIReconciler) Reconcile(ctx context.Context, req ctrl.Request)
r.Client,
r.Kclient,
r.Scheme,
GetLog(ctx),
Log,
)
if err != nil {
return ctrl.Result{}, err
}

// Always patch the instance status when exiting this function so we can persist any changes.
defer func() {
// update the Ready condition based on the sub conditions
// updatehe Ready condition based on the sub conditions
if instance.Status.Conditions.AllSubConditionIsTrue() {
instance.Status.Conditions.MarkTrue(
condition.ReadyCondition, condition.ReadyMessage)
Expand Down Expand Up @@ -214,8 +215,8 @@ func (r *KeystoneAPIReconciler) Reconcile(ctx context.Context, req ctrl.Request)
}

// SetupWithManager -
func (r *KeystoneAPIReconciler) SetupWithManager(mgr ctrl.Manager) error {
logger := mgr.GetLogger()
func (r *KeystoneAPIReconciler) SetupWithManager(ctx context.Context, mgr ctrl.Manager) error {
Log := r.GetLogger(ctx)

memcachedFn := func(o client.Object) []reconcile.Request {
result := []reconcile.Request{}
Expand All @@ -225,8 +226,8 @@ func (r *KeystoneAPIReconciler) SetupWithManager(mgr ctrl.Manager) error {
listOpts := []client.ListOption{
client.InNamespace(o.GetNamespace()),
}
if err := r.Client.List(context.Background(), keystoneAPIs, listOpts...); err != nil {
logger.Error(err, "Unable to retrieve KeystoneAPI CRs %w")
if err := r.Client.List(ctx, keystoneAPIs, listOpts...); err != nil {
Log.Error(err, "Unable to retrieve KeystoneAPI CRs %w")
return nil
}

Expand All @@ -236,7 +237,7 @@ func (r *KeystoneAPIReconciler) SetupWithManager(mgr ctrl.Manager) error {
Namespace: o.GetNamespace(),
Name: cr.Name,
}
logger.Info(fmt.Sprintf("Memcached %s is used by KeystoneAPI CR %s", o.GetName(), cr.Name))
Log.Info(fmt.Sprintf("Memcached %s is used by KeystoneAPI CR %s", o.GetName(), cr.Name))
result = append(result, reconcile.Request{NamespacedName: name})
}
}
Expand Down Expand Up @@ -265,8 +266,8 @@ func (r *KeystoneAPIReconciler) SetupWithManager(mgr ctrl.Manager) error {
}

func (r *KeystoneAPIReconciler) reconcileDelete(ctx context.Context, instance *keystonev1.KeystoneAPI, helper *helper.Helper) (ctrl.Result, error) {
l := GetLog(ctx)
l.Info("Reconciling Service delete")
Log := r.GetLogger(ctx)
Log.Info("Reconciling Service delete")

// We need to allow all KeystoneEndpoint and KeystoneService processing to finish
// in the case of a delete before we remove the finalizers. For instance, in the
Expand Down Expand Up @@ -314,7 +315,7 @@ func (r *KeystoneAPIReconciler) reconcileDelete(ctx context.Context, instance *k

// Service is deleted so remove the finalizer.
controllerutil.RemoveFinalizer(instance, helper.GetFinalizer())
l.Info("Reconciled Service delete successfully")
Log.Info("Reconciled Service delete successfully")

return ctrl.Result{}, nil
}
Expand All @@ -326,8 +327,8 @@ func (r *KeystoneAPIReconciler) reconcileInit(
serviceLabels map[string]string,
serviceAnnotations map[string]string,
) (ctrl.Result, error) {
l := GetLog(ctx)
l.Info("Reconciling Service init")
Log := r.GetLogger(ctx)
Log.Info("Reconciling Service init")
//
// Service account, role, binding
//
Expand Down Expand Up @@ -445,7 +446,7 @@ func (r *KeystoneAPIReconciler) reconcileInit(
}
if dbSyncjob.HasChanged() {
instance.Status.Hash[keystonev1.DbSyncHash] = dbSyncjob.GetHash()
l.Info(fmt.Sprintf("Job %s hash added - %s", jobDef.Name, instance.Status.Hash[keystonev1.DbSyncHash]))
Log.Info(fmt.Sprintf("Job %s hash added - %s", jobDef.Name, instance.Status.Hash[keystonev1.DbSyncHash]))
}
instance.Status.Conditions.MarkTrue(condition.DBSyncReadyCondition, condition.DBSyncReadyMessage)

Expand Down Expand Up @@ -543,41 +544,41 @@ func (r *KeystoneAPIReconciler) reconcileInit(
}
if bootstrapjob.HasChanged() {
instance.Status.Hash[keystonev1.BootstrapHash] = bootstrapjob.GetHash()
l.Info(fmt.Sprintf("Job %s hash added - %s", jobDef.Name, instance.Status.Hash[keystonev1.BootstrapHash]))
Log.Info(fmt.Sprintf("Job %s hash added - %s", jobDef.Name, instance.Status.Hash[keystonev1.BootstrapHash]))
}
instance.Status.Conditions.MarkTrue(condition.BootstrapReadyCondition, condition.BootstrapReadyMessage)

// run keystone bootstrap - end

l.Info("Reconciled Service init successfully")
Log.Info("Reconciled Service init successfully")
return ctrl.Result{}, nil
}

func (r *KeystoneAPIReconciler) reconcileUpdate(ctx context.Context, instance *keystonev1.KeystoneAPI, helper *helper.Helper) (ctrl.Result, error) {
l := GetLog(ctx)
l.Info("Reconciling Service update")
Log := r.GetLogger(ctx)
Log.Info("Reconciling Service update")

// TODO: should have minor update tasks if required
// - delete dbsync hash from status to rerun it?

l.Info("Reconciled Service update successfully")
Log.Info("Reconciled Service update successfully")
return ctrl.Result{}, nil
}

func (r *KeystoneAPIReconciler) reconcileUpgrade(ctx context.Context, instance *keystonev1.KeystoneAPI, helper *helper.Helper) (ctrl.Result, error) {
l := GetLog(ctx)
l.Info("Reconciling Service upgrade")
Log := r.GetLogger(ctx)
Log.Info("Reconciling Service upgrade")

// TODO: should have major version upgrade tasks
// -delete dbsync hash from status to rerun it?

l.Info("Reconciled Service upgrade successfully")
Log.Info("Reconciled Service upgrade successfully")
return ctrl.Result{}, nil
}

func (r *KeystoneAPIReconciler) reconcileNormal(ctx context.Context, instance *keystonev1.KeystoneAPI, helper *helper.Helper) (ctrl.Result, error) {
l := GetLog(ctx)
l.Info("Reconciling Service")
Log := r.GetLogger(ctx)
Log.Info("Reconciling Service")

// ConfigMap
configMapVars := make(map[string]env.Setter)
Expand Down Expand Up @@ -864,7 +865,7 @@ func (r *KeystoneAPIReconciler) reconcileNormal(ctx context.Context, instance *k
return ctrl.Result{}, err
}

l.Info("Reconciled Service successfully")
Log.Info("Reconciled Service successfully")
return ctrl.Result{}, nil
}

Expand Down Expand Up @@ -1067,6 +1068,7 @@ func (r *KeystoneAPIReconciler) createHashOfInputHashes(
instance *keystonev1.KeystoneAPI,
envVars map[string]env.Setter,
) (string, bool, error) {
Log := r.GetLogger(ctx)
var hashMap map[string]string
changed := false
mergedMapVars := env.MergeEnvs([]corev1.EnvVar{}, envVars)
Expand All @@ -1076,7 +1078,7 @@ func (r *KeystoneAPIReconciler) createHashOfInputHashes(
}
if hashMap, changed = util.SetHash(instance.Status.Hash, common.InputHashName, hash); changed {
instance.Status.Hash = hashMap
GetLog(ctx).Info(fmt.Sprintf("Input maps hash %s - %s", common.InputHashName, hash))
Log.Info(fmt.Sprintf("Input maps hash %s - %s", common.InputHashName, hash))
}
return hash, changed, nil
}
Expand Down
51 changes: 29 additions & 22 deletions controllers/keystoneendpoint_controller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,9 @@ import (
ctrl "sigs.k8s.io/controller-runtime"
"sigs.k8s.io/controller-runtime/pkg/client"
"sigs.k8s.io/controller-runtime/pkg/controller/controllerutil"
"sigs.k8s.io/controller-runtime/pkg/log"

"github.com/go-logr/logr"
keystonev1 "github.com/openstack-k8s-operators/keystone-operator/api/v1beta1"
condition "github.com/openstack-k8s-operators/lib-common/modules/common/condition"
helper "github.com/openstack-k8s-operators/lib-common/modules/common/helper"
Expand All @@ -42,6 +44,11 @@ type KeystoneEndpointReconciler struct {
Scheme *runtime.Scheme
}

// GetLog returns a logger object with a logging prefix of "conrollers.name" and aditional controller context fields
func (r *KeystoneEndpointReconciler) GetLogger(ctx context.Context) logr.Logger {
return log.FromContext(ctx).WithName("Controllers").WithName("KeystoneEndpoint")
}

//+kubebuilder:rbac:groups=keystone.openstack.org,resources=keystoneendpoints,verbs=get;list;watch;create;update;patch;delete
//+kubebuilder:rbac:groups=keystone.openstack.org,resources=keystoneendpoints/status,verbs=get;update;patch
//+kubebuilder:rbac:groups=keystone.openstack.org,resources=keystoneendpoints/finalizers,verbs=update
Expand All @@ -52,7 +59,7 @@ type KeystoneEndpointReconciler struct {

// Reconcile keystone endpoint requests
func (r *KeystoneEndpointReconciler) Reconcile(ctx context.Context, req ctrl.Request) (result ctrl.Result, _err error) {
l := GetLog(ctx)
Log := r.GetLogger(ctx)

// Fetch the KeystoneEndpoint instance
instance := &keystonev1.KeystoneEndpoint{}
Expand All @@ -74,7 +81,7 @@ func (r *KeystoneEndpointReconciler) Reconcile(ctx context.Context, req ctrl.Req
r.Kclient,
r.Scheme,
//TODO remove later, log used here as to not break the helper struct signiture.
l,
Log,
)
if err != nil {
return ctrl.Result{}, err
Expand Down Expand Up @@ -144,7 +151,7 @@ func (r *KeystoneEndpointReconciler) Reconcile(ctx context.Context, req ctrl.Req
condition.SeverityWarning,
keystonev1.KeystoneAPIReadyNotFoundMessage,
))
l.Info("KeystoneAPI not found!")
Log.Info("KeystoneAPI not found!")

return ctrl.Result{RequeueAfter: time.Second * 5}, nil
}
Expand Down Expand Up @@ -185,7 +192,7 @@ func (r *KeystoneEndpointReconciler) Reconcile(ctx context.Context, req ctrl.Req
condition.RequestedReason,
condition.SeverityInfo,
keystonev1.KeystoneAPIReadyWaitingMessage))
l.Info("KeystoneAPI not yet ready!")
Log.Info("KeystoneAPI not yet ready!")

return ctrl.Result{RequeueAfter: time.Second * 5}, nil
}
Expand Down Expand Up @@ -228,7 +235,7 @@ func (r *KeystoneEndpointReconciler) Reconcile(ctx context.Context, req ctrl.Req
}

// SetupWithManager sets up the controller with the Manager.
func (r *KeystoneEndpointReconciler) SetupWithManager(mgr ctrl.Manager) error {
func (r *KeystoneEndpointReconciler) SetupWithManager(ctx context.Context, mgr ctrl.Manager) error {
return ctrl.NewControllerManagedBy(mgr).
For(&keystonev1.KeystoneEndpoint{}).
Complete(r)
Expand All @@ -241,9 +248,9 @@ func (r *KeystoneEndpointReconciler) reconcileDelete(
os *openstack.OpenStack,
keystoneAPI *keystonev1.KeystoneAPI,
) (ctrl.Result, error) {
l := GetLog(ctx)
Log := r.GetLogger(ctx)

l.Info("Reconciling Endpoint delete")
Log.Info("Reconciling Endpoint delete")

// We might not have an OpenStack backend to use in certain situations
if os != nil {
Expand All @@ -257,7 +264,7 @@ func (r *KeystoneEndpointReconciler) reconcileDelete(
}

err = os.DeleteEndpoint(
l,
Log,
openstack.Endpoint{
Name: instance.Spec.ServiceName,
ServiceID: instance.Status.ServiceID,
Expand All @@ -280,7 +287,7 @@ func (r *KeystoneEndpointReconciler) reconcileDelete(
return ctrl.Result{}, err
}
}
} else if ! k8s_errors.IsNotFound(err) {
} else if !k8s_errors.IsNotFound(err) {
return ctrl.Result{}, err
}

Expand All @@ -298,7 +305,7 @@ func (r *KeystoneEndpointReconciler) reconcileDelete(

// Endpoints are deleted so remove the finalizer.
controllerutil.RemoveFinalizer(instance, helper.GetFinalizer())
l.Info("Reconciled Endpoint delete successfully")
Log.Info("Reconciled Endpoint delete successfully")

return ctrl.Result{}, nil
}
Expand All @@ -309,16 +316,16 @@ func (r *KeystoneEndpointReconciler) reconcileNormal(
helper *helper.Helper,
os *openstack.OpenStack,
) (ctrl.Result, error) {
l := GetLog(ctx)
l.Info("Reconciling Endpoint normal")
Log := r.GetLogger(ctx)
Log.Info("Reconciling Endpoint normal")

//
// Wait for KeystoneService is Ready and get the ServiceID from the object
//
ksSvc, err := keystonev1.GetKeystoneServiceWithName(ctx, helper, instance.Spec.ServiceName, instance.Namespace)
if err != nil {
if k8s_errors.IsNotFound(err) {
l.Info("KeystoneService not found", "KeystoneService", instance.Spec.ServiceName)
Log.Info("KeystoneService not found", "KeystoneService", instance.Spec.ServiceName)
return ctrl.Result{RequeueAfter: time.Second * 5}, nil
}

Expand All @@ -332,7 +339,7 @@ func (r *KeystoneEndpointReconciler) reconcileNormal(
}

if !ksSvc.IsReady() {
l.Info("KeystoneService not ready, waiting to create endpoints", "KeystoneService", instance.Spec.ServiceName)
Log.Info("KeystoneService not ready, waiting to create endpoints", "KeystoneService", instance.Spec.ServiceName)

return ctrl.Result{RequeueAfter: 10 * time.Second}, nil
}
Expand Down Expand Up @@ -374,7 +381,7 @@ func (r *KeystoneEndpointReconciler) reconcileNormal(
instance.Spec.Endpoints,
)

l.Info("Reconciled Endpoint normal successfully")
Log.Info("Reconciled Endpoint normal successfully")

return ctrl.Result{}, nil
}
Expand All @@ -385,8 +392,8 @@ func (r *KeystoneEndpointReconciler) reconcileEndpoints(
helper *helper.Helper,
os *openstack.OpenStack,
) error {
l := GetLog(ctx)
l.Info("Reconciling Endpoints")
Log := r.GetLogger(ctx)
Log.Info("Reconciling Endpoints")

// delete endpoint if it does no longer exist in Spec.Endpoints
// but has a reference in Status.EndpointIDs
Expand All @@ -400,7 +407,7 @@ func (r *KeystoneEndpointReconciler) reconcileEndpoints(
}

err = os.DeleteEndpoint(
l,
Log,
openstack.Endpoint{
Name: instance.Spec.ServiceName,
ServiceID: instance.Status.ServiceID,
Expand Down Expand Up @@ -428,7 +435,7 @@ func (r *KeystoneEndpointReconciler) reconcileEndpoints(

// get registered endpoints for the service and endpointType
allEndpoints, err := os.GetEndpoints(
l,
Log,
instance.Status.ServiceID,
endpointType)
if err != nil {
Expand All @@ -439,7 +446,7 @@ func (r *KeystoneEndpointReconciler) reconcileEndpoints(
if len(allEndpoints) == 0 {
// Create the endpoint
endpointID, err = os.CreateEndpoint(
l,
Log,
openstack.Endpoint{
Name: instance.Spec.ServiceName,
ServiceID: instance.Status.ServiceID,
Expand All @@ -455,7 +462,7 @@ func (r *KeystoneEndpointReconciler) reconcileEndpoints(
endpoint := allEndpoints[0]
if endpointURL != endpoint.URL {
endpointID, err = os.UpdateEndpoint(
l,
Log,
openstack.Endpoint{
Name: endpoint.Name,
ServiceID: endpoint.ServiceID,
Expand Down Expand Up @@ -485,7 +492,7 @@ func (r *KeystoneEndpointReconciler) reconcileEndpoints(
}
}

l.Info("Reconciled Endpoints successfully")
Log.Info("Reconciled Endpoints successfully")

return nil
}
Loading

0 comments on commit 32f5f50

Please sign in to comment.