From 661d4e2afeb7c7d5aaa93e3c78e01072ac8b61a2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Mon, 7 Oct 2019 15:19:02 +0200 Subject: [PATCH 01/14] Introduce logging levels of verbosity. --- .../servicebindingrequest/annotations.go | 12 ++--- .../servicebindingrequest/binder.go | 27 ++++++----- .../servicebindingrequest/logging.go | 32 +++++++++++++ .../servicebindingrequest/mapper.go | 5 +- pkg/controller/servicebindingrequest/olm.go | 37 ++++++++------- .../servicebindingrequest/planner.go | 18 +++---- .../servicebindingrequest/reconciler.go | 30 ++++++------ .../servicebindingrequest/retriever.go | 47 +++++++++---------- .../servicebindingrequest/sbrcontroller.go | 30 ++++++------ pkg/controller/servicebindingrequest/watch.go | 7 ++- 10 files changed, 140 insertions(+), 105 deletions(-) create mode 100644 pkg/controller/servicebindingrequest/logging.go diff --git a/pkg/controller/servicebindingrequest/annotations.go b/pkg/controller/servicebindingrequest/annotations.go index 7e82a65303..280d07fd9d 100644 --- a/pkg/controller/servicebindingrequest/annotations.go +++ b/pkg/controller/servicebindingrequest/annotations.go @@ -55,22 +55,22 @@ func GetSBRNamespacedNameFromObject(obj runtime.Object) (types.NamespacedName, e ) if IsNamespacedNameEmpty(sbrNamespacedName) { - logger.Info("SBR information not present in annotations, continue inspecting object") + LogDebug(&logger, "SBR information not present in annotations, continue inspecting object") } else { // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - logger.Info("SBR information found in annotations, returning it") + LogTrace(&logger, "SBR information found in annotations, returning it") return sbrNamespacedName, nil } if u.GroupVersionKind() == v1alpha1.SchemeGroupVersion.WithKind(ServiceBindingRequestKind) { - logger.Info("Object is a SBR, returning its namespaced name") + LogDebug(&logger, "Object is a SBR, returning its namespaced name") sbrNamespacedName.Namespace = u.GetNamespace() sbrNamespacedName.Name = u.GetName() return sbrNamespacedName, nil } // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - logger.Info("Object is not a SBR, returning an empty namespaced name") + LogTrace(&logger, "Object is not a SBR, returning an empty namespaced name") return sbrNamespacedName, nil } @@ -102,10 +102,10 @@ func SetSBRAnnotations( "Resource.Namespace", obj.GetNamespace(), "Resource.Name", obj.GetName(), ) - logger.Info("Updating resource annotations...") + LogDebug(&logger, "Updating resource annotations...") _, err := client.Resource(gvr).Namespace(obj.GetNamespace()).Update(obj, opts) if err != nil { - logger.Error(err, "unable to set/update annotations in object") + LogError(err, &logger, "unable to set/update annotations in object") return err } } diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index 98ef2142cd..8dd4c1bd33 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -85,12 +85,12 @@ func (b *Binder) updateSpecVolumes( volumesPath := []string{"spec", "template", "spec", "volumes"} logger = logger.WithValues("Volumes.NestedPath", volumesPath) - logger.Info("Reading volumes definitions...") + LogDebug(&logger, "Reading volumes definitions...") volumes, _, err := unstructured.NestedSlice(obj.Object, volumesPath...) if err != nil { return nil, err } - logger.WithValues("Volumes", len(volumes)).Info("Amount of volumes in spec.") + LogDebug(&logger, "Amount of volumes in spec.", "Volumes", len(volumes)) volumes, err = b.updateVolumes(logger, volumes) if err != nil { @@ -108,11 +108,11 @@ func (b *Binder) updateSpecVolumes( func (b *Binder) updateVolumes(logger logr.Logger, volumes []interface{}) ([]interface{}, error) { name := b.sbr.GetName() - logger.Info("Checking if binding volume is already defined...") + LogDebug(&logger, "Checking if binding volume is already defined...") for _, v := range volumes { volume := v.(corev1.Volume) if name == volume.Name { - logger.Info("Volume is already defined!") + LogDebug(&logger, "Volume is already defined!") return volumes, nil } } @@ -122,7 +122,7 @@ func (b *Binder) updateVolumes(logger logr.Logger, volumes []interface{}) ([]int items = append(items, corev1.KeyToPath{Key: k, Path: k}) } - logger.WithValues("Items", items).Info("Appending new volume with items.") + LogDebug(&logger, "Appending new volume with items.", "Items", items) bindVolume := corev1.Volume{ Name: name, VolumeSource: corev1.VolumeSource{ @@ -156,7 +156,7 @@ func (b *Binder) updateSpecContainers( if !found { err = fmt.Errorf("unable to find '%#v' in object kind '%s'", containersPath, obj.GetKind()) - logger.Error(err, "is this definition supported by this operator?") + LogError(err, &logger, "is this definition supported by this operator?") return nil, err } @@ -178,11 +178,11 @@ func (b *Binder) updateContainers( for i, container := range containers { logger := logger.WithValues("Obj.Container.Number", i) - logger.Info("Inspecting container...") + LogDebug(&logger, "Inspecting container...") containers[i], err = b.updateContainer(container) if err != nil { - logger.Error(err, "during container update.") + LogError(err, &logger, "during container update.") return nil, err } } @@ -214,15 +214,16 @@ func (b *Binder) appendEnvVar(envList []corev1.EnvVar, envParam string, envValue // appendEnvFrom based on secret name and list of EnvFromSource instances, making sure secret is // part of the list or appended. func (b *Binder) appendEnvFrom(envList []corev1.EnvFromSource, secret string) []corev1.EnvFromSource { + logger := &(b.logger) for _, env := range envList { if env.SecretRef.Name == secret { - b.logger.Info("Directive 'envFrom' is already present!") + LogDebug(logger, "Directive 'envFrom' is already present!") // secret name is already referenced return envList } } - b.logger.Info("Adding 'envFrom' directive...") + LogDebug(logger, "Adding 'envFrom' directive...") return append(envList, corev1.EnvFromSource{ SecretRef: &corev1.SecretEnvSource{ LocalObjectReference: corev1.LocalObjectReference{ @@ -280,7 +281,7 @@ func (b *Binder) update(objs *unstructured.UnstructuredList) ([]*unstructured.Un for _, obj := range objs.Items { name := obj.GetName() logger := b.logger.WithValues("Obj.Name", name, "Obj.Kind", obj.GetKind()) - logger.Info("Inspecting object...") + LogDebug(&logger, "Inspecting object...") updatedObj, err := b.updateSpecContainers(logger, &obj) if err != nil { @@ -294,12 +295,12 @@ func (b *Binder) update(objs *unstructured.UnstructuredList) ([]*unstructured.Un } } - logger.Info("Updating object...") + LogDebug(&logger, "Updating object...") if err := b.client.Update(b.ctx, updatedObj); err != nil { return nil, err } - logger.Info("Reading back updated object...") + LogDebug(&logger, "Reading back updated object...") // reading object back again, to comply with possible modifications namespacedName := types.NamespacedName{ Namespace: updatedObj.GetNamespace(), diff --git a/pkg/controller/servicebindingrequest/logging.go b/pkg/controller/servicebindingrequest/logging.go new file mode 100644 index 0000000000..f1192690d1 --- /dev/null +++ b/pkg/controller/servicebindingrequest/logging.go @@ -0,0 +1,32 @@ +package servicebindingrequest + +import ( + "fmt" + + "github.com/go-logr/logr" +) + +// LogError logs the message using go-logr package on a default level as WARNING +func LogError(err error, logger *logr.Logger, msg string, keysAndValues ...interface{}) { + (*logger).Error(err, msg, keysAndValues...) +} + +// LogWarning logs the message using go-logr package on a default level as WARNING +func LogWarning(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + (*logger).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) +} + +// LogInfo logs the message using go-logr package on a default level as INFO +func LogInfo(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + (*logger).Info(msg, keysAndValues...) +} + +// LogDebug logs the message using go-logr package on a V=1 level as DEBUG +func LogDebug(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + (*logger).V(1).Info(msg, keysAndValues...) +} + +// LogTrace logs the message using go-logr package on a V=2 level as TRACE +func LogTrace(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + (*logger).V(2).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) +} diff --git a/pkg/controller/servicebindingrequest/mapper.go b/pkg/controller/servicebindingrequest/mapper.go index c2cfebb118..65487e3309 100644 --- a/pkg/controller/servicebindingrequest/mapper.go +++ b/pkg/controller/servicebindingrequest/mapper.go @@ -20,11 +20,12 @@ func (m *SBRRequestMapper) Map(obj handler.MapObject) []reconcile.Request { sbrNamespacedName, err := GetSBRNamespacedNameFromObject(obj.Object) if err != nil { - logger.Error(err, "on inspecting object for annotations for SBR object") + LogError(err, &logger, "on inspecting object for annotations for SBR object") return toReconcile } if IsNamespacedNameEmpty(sbrNamespacedName) { - log.Info("not able to extract SBR namespaced-name") + LogWarning(&logger, "not able to extract SBR namespaced-name") + LogWarning(&logger, "not able to extract SBR namespaced-name") return toReconcile } diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index c4590d5da0..5ac86406ec 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -29,11 +29,12 @@ const ( // listCSVs simple list to all CSV objects in the cluster. func (o *OLM) listCSVs() ([]unstructured.Unstructured, error) { + logger := &(o.logger) gvr := olmv1alpha1.SchemeGroupVersion.WithResource(csvResource) resourceClient := o.client.Resource(gvr).Namespace(o.ns) csvs, err := resourceClient.List(metav1.ListOptions{}) if err != nil { - o.logger.Error(err, "during listing CSV objects from cluster") + LogError(err, logger, "during listing CSV objects from cluster") return nil, err } return csvs.Items, nil @@ -50,7 +51,7 @@ func (o *OLM) extractOwnedCRDs( ownedCRDs, exists, err := unstructured.NestedSlice(csv.Object, ownedPath...) if err != nil { - logger.Error(err, "on extracting nested slice") + LogError(err, &logger, "on extracting nested slice") return nil, err } if !exists { @@ -68,9 +69,10 @@ func (o *OLM) extractOwnedCRDs( // ListCSVOwnedCRDs return a unstructured list of CRD objects from "owned" section in CSVs. func (o *OLM) ListCSVOwnedCRDs() ([]unstructured.Unstructured, error) { + logger := &(o.logger) csvs, err := o.listCSVs() if err != nil { - o.logger.Error(err, "on listting CSVs") + LogError(err, logger, "on listting CSVs") return nil, err } return o.extractOwnedCRDs(csvs) @@ -87,16 +89,16 @@ func (o *OLM) loopCRDDescriptions( fn eachCRDDescriptionFn, ) error { for _, u := range crdDescriptions { + logger := &(o.logger) crdDescription := &olmv1alpha1.CRDDescription{} err := runtime.DefaultUnstructuredConverter.FromUnstructured(u.Object, crdDescription) if err != nil { - o.logger.Error(err, "on converting from unstructured to CRD") + LogError(err, logger, "on converting from unstructured to CRD") return err } - logger := o.logger.WithValues("CRDDescription", crdDescription) - logger.Info("Inspecting CRDDescription...") + LogDebug(logger, "Inspecting CRDDescription...", "CRDDescription", crdDescription) if crdDescription.Name == "" { - logger.Info("Skipping empty CRDDescription!") + LogDebug(logger, "Skipping empty CRDDescription!") continue } fn(crdDescription) @@ -109,7 +111,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr logger := o.logger.WithValues("Selector.GVK", gvk) ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - logger.Error(err, "on listing owned CRDs") + LogError(err, &logger, "on listing owned CRDs") return nil, err } @@ -120,7 +122,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr "CRDDescription.Version", crdDescription.Version, "CRDDescription.Kind", crdDescription.Kind, ) - logger.Info("Inspecting CRDDescription object...") + LogDebug(&logger, "Inspecting CRDDescription object...") // checking for suffix since is expected to have object type as prefix if !strings.EqualFold(strings.ToLower(crdDescription.Kind), strings.ToLower(gvk.Kind)) { return @@ -130,7 +132,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr strings.ToLower(gvk.Version) != strings.ToLower(crdDescription.Version) { return } - logger.Info("CRDDescription object matches selector!") + LogDebug(&logger, "CRDDescription object matches selector!") crdDescriptions = append(crdDescriptions, crdDescription) }) if err != nil { @@ -138,7 +140,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr } if len(crdDescriptions) == 0 { - logger.Info("No CRD could be found for GVK.") + LogDebug(&logger, "No CRD could be found for GVK.") return nil, fmt.Errorf("no crd could be found for gvk") } return crdDescriptions[0], nil @@ -148,10 +150,10 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr func (o *OLM) extractGVKs( crdDescriptions []unstructured.Unstructured, ) ([]schema.GroupVersionKind, error) { + logger := &(o.logger) gvks := []schema.GroupVersionKind{} err := o.loopCRDDescriptions(crdDescriptions, func(crdDescription *olmv1alpha1.CRDDescription) { - o.logger.WithValues("CRDDescription.Name", crdDescription.Name). - Info("Extracting GVK from CRDDescription") + LogDebug(logger, "Extracting GVK from CRDDescription", "CRDDescription.Name", crdDescription.Name) _, gv := schema.ParseResourceArg(crdDescription.Name) gvks = append(gvks, schema.GroupVersionKind{ Group: gv.Group, @@ -167,9 +169,10 @@ func (o *OLM) extractGVKs( // ListCSVOwnedCRDsAsGVKs return the list of owned CRDs from all CSV objects as a list of GVKs. func (o *OLM) ListCSVOwnedCRDsAsGVKs() ([]schema.GroupVersionKind, error) { + logger := &(o.logger) ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - o.logger.Error(err, "on listting CSVs") + LogError(err, logger, "on listting CSVs") return nil, err } return o.extractGVKs(ownedCRDs) @@ -180,12 +183,12 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( namespacedName types.NamespacedName, ) ([]schema.GroupVersionKind, error) { logger := o.logger.WithValues("CSV.NamespacedName", namespacedName) - logger.Info("Reading CSV to extract GVKs...") + LogDebug(&logger, "Reading CSV to extract GVKs...") gvr := olmv1alpha1.SchemeGroupVersion.WithResource(csvResource) resourceClient := o.client.Resource(gvr).Namespace(namespacedName.Namespace) u, err := resourceClient.Get(namespacedName.Name, metav1.GetOptions{}) if err != nil { - logger.Error(err, "on reading CSV object") + LogError(err, &logger, "on reading CSV object") return []schema.GroupVersionKind{}, err } @@ -194,7 +197,7 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( ownedCRDs, err := o.extractOwnedCRDs(csvs) if err != nil { - logger.Error(err, "on extracting owned CRDs") + LogError(err, &logger, "on extracting owned CRDs") return []schema.GroupVersionKind{}, err } diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index 36ae4aa08e..02ea3325d8 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -26,11 +26,11 @@ type Planner struct { // Plan outcome, after executing planner. type Plan struct { - Ns string // namespace name - Name string // plan name, same than ServiceBindingRequest - CRDDescription *olmv1alpha1.CRDDescription // custom resource definition description - CR *unstructured.Unstructured // custom resource object - SBR v1alpha1.ServiceBindingRequest // service binding request + Ns string // namespace name + Name string // plan name, same than ServiceBindingRequest + CRDDescription *olmv1alpha1.CRDDescription // custom resource definition description + CR *unstructured.Unstructured // custom resource object + SBR v1alpha1.ServiceBindingRequest // service binding request } // searchCR based on a CustomResourceDefinitionDescription and name, search for the object. @@ -41,15 +41,15 @@ func (p *Planner) searchCR(kind string) (*unstructured.Unstructured, error) { opts := metav1.GetOptions{} logger := p.logger.WithValues("CR.GVK", gvk.String(), "CR.GVR", gvr.String()) - logger.Info("Searching for CR instance...") + LogDebug(&logger, "Searching for CR instance...") cr, err := p.client.Resource(gvr).Namespace(p.sbr.GetNamespace()).Get(bss.ResourceRef, opts) if err != nil { - logger.Error(err, "during reading CR") + LogError(err, &logger, "during reading CR") return nil, err } - logger.WithValues("CR.Name", cr.GetName()).Info("Found target CR!") + LogDebug(&logger, "Found target CR!", "CR.Name", cr.GetName()) return cr, nil } @@ -74,7 +74,7 @@ func (p *Planner) Plan() (*Plan, error) { Name: p.sbr.GetName(), CRDDescription: crdDescription, CR: cr, - SBR: *p.sbr, + SBR: *p.sbr, }, nil } diff --git a/pkg/controller/servicebindingrequest/reconciler.go b/pkg/controller/servicebindingrequest/reconciler.go index a9f7f29816..9873dc8e83 100644 --- a/pkg/controller/servicebindingrequest/reconciler.go +++ b/pkg/controller/servicebindingrequest/reconciler.go @@ -125,13 +125,13 @@ func (r *Reconciler) onError( func checkSBR(sbr *v1alpha1.ServiceBindingRequest, logger logr.Logger) error { // Check if application ResourceRef is present if sbr.Spec.ApplicationSelector.ResourceRef == "" { - logger.Info("Spec.ApplicationSelector.ResourceRef not found") + LogDebug(&logger, "Spec.ApplicationSelector.ResourceRef not found") // Check if MatchLabels is present if sbr.Spec.ApplicationSelector.MatchLabels == nil { err := errors.New("NotFoundError") - logger.Error(err, "Spec.ApplicationSelector.MatchLabels not found") + LogError(err, &logger, "Spec.ApplicationSelector.MatchLabels not found") return err } } @@ -155,17 +155,17 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err "Request.Namespace", request.Namespace, "Request.Name", request.Name, ) - logger.Info("Reconciling ServiceBindingRequest...") + LogInfo(&logger, "Reconciling ServiceBindingRequest...") // fetch the ServiceBindingRequest instance sbr, err := r.getServiceBindingRequest(request.NamespacedName) if err != nil { - logger.Error(err, "On retrieving service-binding-request instance.") + LogError(err, &logger, "On retrieving service-binding-request instance.") return RequeueError(err) } logger = logger.WithValues("ServiceBindingRequest.Name", sbr.Name) - logger.Info("Found service binding request to inspect") + LogDebug(&logger, "Found service binding request to inspect") // splitting instance from it's status sbrStatus := sbr.Status @@ -173,7 +173,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Check Service Binding Request err = checkSBR(sbr, logger) if err != nil { - logger.Error(err, "") + LogError(err, &logger, "") return RequeueError(err) } @@ -181,11 +181,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Planing changes // - logger.Info("Creating a plan based on OLM and CRD.") + LogDebug(&logger, "Creating a plan based on OLM and CRD.") planner := NewPlanner(ctx, r.dynClient, sbr) plan, err := planner.Plan() if err != nil { - logger.Error(err, "On creating a plan to bind applications.") + LogError(err, &logger, "On creating a plan to bind applications.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -196,11 +196,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Retrieving data // - logger.Info("Retrieving data to create intermediate secret.") + LogDebug(&logger, "Retrieving data to create intermediate secret.") retriever := NewRetriever(r.dynClient, plan, sbr.Spec.EnvVarPrefix) retrievedObjects, err := retriever.Retrieve() if err != nil { - logger.Error(err, "On retrieving binding data.") + LogError(err, &logger, "On retrieving binding data.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -213,11 +213,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Updating applications to use intermediary secret // - logger.Info("Binding applications with intermediary secret.") + LogInfo(&logger, "Binding applications with intermediary secret.") binder := NewBinder(ctx, r.client, r.dynClient, sbr, retriever.volumeKeys) updatedObjects, err := binder.Bind() if err != nil { - logger.Error(err, "On binding application.") + LogError(err, &logger, "On binding application.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } @@ -231,16 +231,16 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // if err = SetSBRAnnotations(r.dynClient, request.NamespacedName, objectsToAnnotate); err != nil { - logger.Error(err, "On setting annotations in related objects.") + LogError(err, &logger, "On setting annotations in related objects.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } // updating status of request instance if err = r.updateStatusServiceBindingRequest(sbr, &sbrStatus); err != nil { - logger.Error(err, "On updating status of ServiceBindingRequest.") + LogError(err, &logger, "On updating status of ServiceBindingRequest.") return RequeueError(err) } - logger.Info("All done!") + LogInfo(&logger, "All done!") return Done() } diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index 233a040dca..58d39bd0e8 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -48,7 +48,7 @@ func (r *Retriever) getNestedValue(key string, sectionMap interface{}) (string, } attrs := strings.SplitN(key, ".", 2) newSectionMap, exists := sectionMap.(map[string]interface{})[attrs[0]] - logger.Info("Section maps : ") + LogDebug(&logger, "Section maps : ") if !exists { return "", fmt.Errorf("Can't find '%v' section in CR", attrs), newSectionMap } @@ -60,7 +60,7 @@ func (r *Retriever) getCRKey(section string, key string) (string, interface{}, e obj := r.plan.CR.Object objName := r.plan.CR.GetName() logger := r.logger.WithValues("CR.Name", objName, "CR.section", section, "CR.key", key) - logger.Info("Reading CR attributes...") + LogDebug(&logger, "Reading CR attributes...") sectionMap, exists := obj[section] if !exists { @@ -86,7 +86,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { "CRDDescription.Path", path, "CRDDescription.XDescriptors", xDescriptors, ) - logger.Info("Reading CRDDescription attributes...") + LogDebug(&logger, "Reading CRDDescription attributes...") // holds the secret name and items secrets := make(map[string][]string) @@ -96,7 +96,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { pathValue, _, err := r.getCRKey(place, path) for _, xDescriptor := range xDescriptors { logger = logger.WithValues("CRDDescription.xDescriptor", xDescriptor, "cache", r.cache) - logger.Info("Inspecting xDescriptor...") + LogDebug(&logger, "Inspecting xDescriptor...") if err != nil { return err } @@ -120,7 +120,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { } else if strings.HasPrefix(xDescriptor, attributePrefix) { r.store(path, []byte(pathValue)) } else { - logger.Info("Defaulting....") + LogDebug(&logger, "Defaulting....") } } @@ -177,7 +177,7 @@ func (r *Retriever) readSecret( fromPath string, path string) error { logger := r.logger.WithValues("Secret.Name", name, "Secret.Items", items) - logger.Info("Reading secret items...") + LogDebug(&logger, "Reading secret items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "secrets"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -199,8 +199,8 @@ func (r *Retriever) readSecret( if err != nil { return err } - logger.WithValues("Secret.Key.Name", k, "Secret.Key.Length", len(data)). - Info("Inspecting secret key...") + logger.WithValues("Secret.Key.Name", k, "Secret.Key.Length", len(data)) + LogDebug(&logger, "Inspecting secret key...") r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = string(value) @@ -221,7 +221,7 @@ func (r *Retriever) readConfigMap( fromPath string, path string) error { logger := r.logger.WithValues("ConfigMap.Name", name, "ConfigMap.Items", items) - logger.Info("Reading ConfigMap items...") + LogDebug(&logger, "Reading ConfigMap items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "configmaps"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -237,11 +237,10 @@ func (r *Retriever) readConfigMap( return fmt.Errorf("could not find 'data' in secret") } - logger.Info("Inspecting configMap data...") + LogDebug(&logger, "Inspecting configMap data...") for k, v := range data { value := v.(string) - logger.WithValues("configMap.Key.Name", k, "configMap.Key.Length", len(value)). - Info("Inspecting configMap key...") + LogDebug(&logger, "Inspecting configMap key...", "configMap.Key.Name", k, "configMap.Key.Length", len(value)) r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = value @@ -276,7 +275,7 @@ func (r *Retriever) saveDataOnSecret() error { "Secret.Namespace", r.plan.Ns, "Secret.Name", r.plan.Name, ) - logger.Info("Retrieving intermediary secret...") + LogDebug(&logger, "Retrieving intermediary secret...") secretObj := &corev1.Secret{ TypeMeta: metav1.TypeMeta{ @@ -292,26 +291,26 @@ func (r *Retriever) saveDataOnSecret() error { data, err := runtime.DefaultUnstructuredConverter.ToUnstructured(secretObj) if err != nil { - r.logger.Error(err, "Converting secret to unstructured") + LogError(err, &logger, "Converting secret to unstructured") return err } u := &unstructured.Unstructured{Object: data} u.SetGroupVersionKind(gvk) - logger.Info("Creating intermediary secret...") + LogDebug(&logger, "Creating intermediary secret...") _, err = resourceClient.Create(u, metav1.CreateOptions{}) if err != nil && !errors.IsAlreadyExists(err) { - logger.Error(err, "on creating intermediary secret") + LogError(err, &logger, "on creating intermediary secret") return err } - logger.Info("Secret is already found, updating...") + LogDebug(&logger, "Secret is already found, updating...") _, err = resourceClient.Update(u, metav1.UpdateOptions{}) if err != nil { - logger.Error(err, "on updating intermediary secret") + LogError(err, &logger, "on updating intermediary secret") return err } - logger.Info("Intermediary secret created/updated!") + LogDebug(&logger, "Intermediary secret created/updated!") r.objects = append(r.objects, u) return nil } @@ -320,22 +319,22 @@ func (r *Retriever) saveDataOnSecret() error { // Unstructured refering the objects in use by the Retriever, and error when issues reading fields. func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { var err error - - r.logger.Info("Looking for spec-descriptors in 'spec'...") + logger := &(r.logger) + LogDebug(logger, "Looking for spec-descriptors in 'spec'...") for _, specDescriptor := range r.plan.CRDDescription.SpecDescriptors { if err = r.read("spec", specDescriptor.Path, specDescriptor.XDescriptors); err != nil { return nil, err } } - r.logger.Info("Looking for status-descriptors in 'status'...") + LogDebug(logger, "Looking for status-descriptors in 'status'...") for _, statusDescriptor := range r.plan.CRDDescription.StatusDescriptors { if err = r.read("status", statusDescriptor.Path, statusDescriptor.XDescriptors); err != nil { return nil, err } } - r.logger.WithValues("cache", r.cache).Info("Final cache values...") + LogDebug(logger, "Final cache values...", "cache", r.cache) envParser := NewCustomEnvParser(r.plan.SBR.Spec.CustomEnvVar, r.cache) values, err := envParser.Parse() @@ -346,7 +345,7 @@ func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { r.data[k] = []byte(v.(string)) } - r.logger.Info("Saving data on intermediary secret...") + LogDebug(logger, "Saving data on intermediary secret...") if err = r.saveDataOnSecret(); err != nil { return nil, err } diff --git a/pkg/controller/servicebindingrequest/sbrcontroller.go b/pkg/controller/servicebindingrequest/sbrcontroller.go index 4765c05843..01fce1f69a 100644 --- a/pkg/controller/servicebindingrequest/sbrcontroller.go +++ b/pkg/controller/servicebindingrequest/sbrcontroller.go @@ -75,24 +75,23 @@ func (s *SBRController) getWatchingGVKs() ([]schema.GroupVersionKind, error) { log.Error(err, "On listing owned CSV as GVKs") return nil, err } - log.WithValues("CSVOwnedGVK.Amount", len(olmGVKs)). - Info("Amount of GVK founds in CSV objects.") + LogDebug(&log, "Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) return append(gvks, olmGVKs...), nil } // AddWatchForGVK creates a watch on a given GVK, as long as it's not duplicated. func (s *SBRController) AddWatchForGVK(gvk schema.GroupVersionKind) error { logger := s.logger.WithValues("GVK", gvk) - logger.Info("Adding watch for GVK...") + LogDebug(&logger, "Adding watch for GVK...") if _, exists := s.watchingGVKs[gvk]; exists { - logger.Info("Skipping watch on GVK twice, it's already under watch!") + LogDebug(&logger, "Skipping watch on GVK twice, it's already under watch!") return nil } // saving GVK in cache s.watchingGVKs[gvk] = true - logger.Info("Creating watch on GVK") + LogDebug(&logger, "Creating watch on GVK") source := s.createSourceForGVK(gvk) return s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) } @@ -105,7 +104,7 @@ func (s *SBRController) addCSVWatch() error { if err != nil { return err } - log.WithValues("GVK", csvGVK).Info("Watch added for ClusterServiceVersion") + LogDebug(&log, "Watch added for ClusterServiceVersion", "GVK", csvGVK) return nil } @@ -117,29 +116,29 @@ func (s *SBRController) addSBRWatch() error { source := s.createSourceForGVK(gvk) err := s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) if err != nil { - logger.Error(err, "on creating watch for ServiceBindingRequest") + LogError(err, &logger, "on creating watch for ServiceBindingRequest") return err } - logger.Info("Watch added for ServiceBindingRequest") + LogDebug(&logger, "Watch added for ServiceBindingRequest") return nil } // addWhitelistedGVKWatches create watch on GVKs employed on CSVs. func (s *SBRController) addWhitelistedGVKWatches() error { + logger := &(s.logger) // list of interesting GVKs to watch gvks, err := s.getWatchingGVKs() if err != nil { - s.logger.Error(err, "on retrieving list of GVKs to watch") + LogError(err, logger, "on retrieving list of GVKs to watch") return err } for _, gvk := range gvks { - logger := s.logger.WithValues("GVK", gvk) - logger.Info("Adding watch for whitelisted GVK...") + LogDebug(logger, "Adding watch for whitelisted GVK...", "GVK", gvk) err = s.AddWatchForGVK(gvk) if err != nil { - logger.Error(err, "on creating watch for GVK") + LogError(err, logger, "on creating watch for GVK") return err } } @@ -149,21 +148,22 @@ func (s *SBRController) addWhitelistedGVKWatches() error { // Watch setup "watch" for all GVKs relevant for SBRController. func (s *SBRController) Watch() error { + logger := &(s.logger) err := s.addSBRWatch() if err != nil { - s.logger.Error(err, "on adding watch for ServiceBindingRequest") + LogError(err, logger, "on adding watch for ServiceBindingRequest") return err } err = s.addWhitelistedGVKWatches() if err != nil { - s.logger.Error(err, "on adding watch for whitelisted GVKs") + LogError(err, logger, "on adding watch for whitelisted GVKs") return err } err = s.addCSVWatch() if err != nil { - s.logger.Error(err, "on adding watch for ClusterServiceVersion") + LogError(err, logger, "on adding watch for ClusterServiceVersion") return err } diff --git a/pkg/controller/servicebindingrequest/watch.go b/pkg/controller/servicebindingrequest/watch.go index c73be3815d..c875c3ab7c 100644 --- a/pkg/controller/servicebindingrequest/watch.go +++ b/pkg/controller/servicebindingrequest/watch.go @@ -25,16 +25,15 @@ func (c *CSVToWatcherMapper) Map(obj handler.MapObject) []reconcile.Request { gvks, err := olm.ListGVKsFromCSVNamespacedName(namespacedName) if err != nil { - logger.Error(err, "Failed on listing GVK with namespaced-name!") + LogError(err, &logger, "Failed on listing GVK with namespaced-name!") return []reconcile.Request{} } for _, gvk := range gvks { - logger = logger.WithValues("GVK", gvk) - logger.Info("Adding watch for GVK") + LogDebug(&logger, "Adding watch for GVK", "GVK", gvk) err = c.controller.AddWatchForGVK(gvk) if err != nil { - logger.Error(err, "Failed to create a watch") + LogError(err, &logger, "Failed to create a watch") } } From f28ceb9753a21125dfec41eada9f74196ad0433b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Wed, 9 Oct 2019 15:19:18 +0200 Subject: [PATCH 02/14] Unify the logging throughout the operator's code --- cmd/manager/main.go | 43 ++++++------ .../servicebindingrequest/annotations.go | 21 +++--- .../servicebindingrequest/binder.go | 59 ++++++++-------- .../servicebindingrequest/common.go | 5 -- .../servicebindingrequest/logging.go | 32 --------- .../servicebindingrequest/mapper.go | 12 ++-- pkg/controller/servicebindingrequest/olm.go | 56 ++++++++------- .../servicebindingrequest/planner.go | 16 +++-- .../servicebindingrequest/reconciler.go | 44 ++++++------ .../servicebindingrequest/retriever.go | 68 ++++++++++--------- .../servicebindingrequest/sbrcontroller.go | 43 ++++++------ pkg/controller/servicebindingrequest/watch.go | 13 ++-- pkg/logging/logging.go | 51 ++++++++++++++ 13 files changed, 256 insertions(+), 207 deletions(-) delete mode 100644 pkg/controller/servicebindingrequest/logging.go create mode 100644 pkg/logging/logging.go diff --git a/cmd/manager/main.go b/cmd/manager/main.go index 10820b1f19..4abedc9b16 100644 --- a/cmd/manager/main.go +++ b/cmd/manager/main.go @@ -23,11 +23,12 @@ import ( "k8s.io/client-go/rest" "sigs.k8s.io/controller-runtime/pkg/client/config" "sigs.k8s.io/controller-runtime/pkg/manager" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" + "sigs.k8s.io/controller-runtime/pkg/runtime/signals" "github.com/redhat-developer/service-binding-operator/pkg/apis" "github.com/redhat-developer/service-binding-operator/pkg/controller" + "github.com/redhat-developer/service-binding-operator/pkg/logging" ) // Change below variables to serve metrics on different host or port. @@ -35,13 +36,13 @@ var ( metricsHost = "0.0.0.0" metricsPort int32 = 8383 operatorMetricsPort int32 = 8686 + mainLogger = logging.Logger("main") ) -var log = logf.Log.WithName("cmd") func printVersion() { - log.Info(fmt.Sprintf("Go Version: %s", runtime.Version())) - log.Info(fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) - log.Info(fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) + logging.LogInfo(&mainLogger, fmt.Sprintf("Go Version: %s", runtime.Version())) + logging.LogInfo(&mainLogger, fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) + logging.LogInfo(&mainLogger, fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) } // getOperatorName based on environment variable OPERATOR_NAME, or returns the default name for @@ -63,20 +64,20 @@ func main() { pflag.CommandLine.AddFlagSet(zap.FlagSet()) pflag.CommandLine.AddGoFlagSet(flag.CommandLine) pflag.Parse() - logf.SetLogger(zap.Logger()) + logging.SetLogger(zap.Logger()) printVersion() namespace, err := k8sutil.GetWatchNamespace() if err != nil { - log.Error(err, "Failed to get watch namespace") + logging.LogError(err, &mainLogger, "Failed to get watch namespace") os.Exit(1) } // Get a config to talk to the apiserver cfg, err := config.GetConfig() if err != nil { - log.Error(err, "Failed to acquire a configuration to talk to the API server") + logging.LogError(err, &mainLogger, "Failed to acquire a configuration to talk to the API server") os.Exit(1) } @@ -87,11 +88,11 @@ func main() { // Become the leader before proceeding err = leader.Become(ctx, fmt.Sprintf("%s-lock", getOperatorName())) if err != nil { - log.Error(err, "Failed to become the leader") + logging.LogError(err, &mainLogger, "Failed to become the leader") os.Exit(1) } } else { - log.Info("Warning: Leader election is disabled") + logging.LogWarning(&mainLogger, "Leader election is disabled") } // Create a new Cmd to provide shared dependencies and start components @@ -101,31 +102,31 @@ func main() { MetricsBindAddress: fmt.Sprintf("%s:%d", metricsHost, metricsPort), }) if err != nil { - log.Error(err, "Error on creating a new manager instance") + logging.LogError(err, &mainLogger, "Error on creating a new manager instance") os.Exit(1) } - log.Info("Registering Components.") + logging.LogInfo(&mainLogger, "Registering Components.") // Setup Scheme for all resources if err := apis.AddToScheme(mgr.GetScheme()); err != nil { - log.Error(err, "Error adding local operator scheme") + logging.LogError(err, &mainLogger, "Error adding local operator scheme") os.Exit(1) } if err := osappsv1.AddToScheme(mgr.GetScheme()); err != nil { - log.Error(err, "Error on adding OS APIs to scheme") + logging.LogError(err, &mainLogger, "Error on adding OS APIs to scheme") os.Exit(1) } // Setup all Controllers if err := controller.AddToManager(mgr); err != nil { - log.Error(err, "Failed to setup the controller manager") + logging.LogError(err, &mainLogger, "Failed to setup the controller manager") os.Exit(1) } if err = serveCRMetrics(cfg); err != nil { - log.Info("Could not generate and serve custom resource metrics", "error", err.Error()) + logging.LogInfo(&mainLogger, "Could not generate and serve custom resource metrics", "error", err.Error()) } // Add to the below struct any other metrics ports you want to expose. @@ -136,7 +137,7 @@ func main() { // Create Service object to expose the metrics port(s). service, err := metrics.CreateMetricsService(ctx, cfg, servicePorts) if err != nil { - log.Info("Could not create metrics Service", "error", err.Error()) + logging.LogInfo(&mainLogger, "Could not create metrics Service", "error", err.Error()) } // CreateServiceMonitors will automatically create the prometheus-operator ServiceMonitor resources @@ -144,19 +145,19 @@ func main() { services := []*v1.Service{service} _, err = metrics.CreateServiceMonitors(cfg, namespace, services) if err != nil { - log.Info("Could not create ServiceMonitor object", "error", err.Error()) + logging.LogInfo(&mainLogger, "Could not create ServiceMonitor object", "error", err.Error()) // If this operator is deployed to a cluster without the prometheus-operator running, it will return // ErrServiceMonitorNotPresent, which can be used to safely skip ServiceMonitor creation. if err == metrics.ErrServiceMonitorNotPresent { - log.Info("Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) + logging.LogInfo(&mainLogger, "Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) } } - log.Info("Starting the Cmd.") + logging.LogInfo(&mainLogger, "Starting the Cmd.") // Start the Cmd if err := mgr.Start(signals.SetupSignalHandler()); err != nil { - log.Error(err, "Manager exited non-zero") + logging.LogError(err, &mainLogger, "Manager exited non-zero") os.Exit(1) } } diff --git a/pkg/controller/servicebindingrequest/annotations.go b/pkg/controller/servicebindingrequest/annotations.go index 280d07fd9d..ef3ec43d47 100644 --- a/pkg/controller/servicebindingrequest/annotations.go +++ b/pkg/controller/servicebindingrequest/annotations.go @@ -9,6 +9,7 @@ import ( "k8s.io/client-go/dynamic" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" + "github.com/redhat-developer/service-binding-operator/pkg/logging" ) const ( @@ -16,6 +17,10 @@ const ( sbrNameAnnotation = "service-binding-operator.apps.openshift.io/binding-name" ) +var ( + annotationsLogger = logging.Logger("annotations") +) + // extractSBRNamespacedName returns a types.NamespacedName if the required service binding request keys // are present in the given data func extractSBRNamespacedName(data map[string]string) types.NamespacedName { @@ -47,7 +52,7 @@ func GetSBRNamespacedNameFromObject(obj runtime.Object) (types.NamespacedName, e u := &unstructured.Unstructured{Object: data} sbrNamespacedName = extractSBRNamespacedName(u.GetAnnotations()) - logger := log.WithValues( + log := annotationsLogger.WithValues( "Resource.GVK", u.GroupVersionKind(), "Resource.Namespace", u.GetNamespace(), "Resource.Name", u.GetName(), @@ -55,22 +60,22 @@ func GetSBRNamespacedNameFromObject(obj runtime.Object) (types.NamespacedName, e ) if IsNamespacedNameEmpty(sbrNamespacedName) { - LogDebug(&logger, "SBR information not present in annotations, continue inspecting object") + logging.LogDebug(&log, "SBR information not present in annotations, continue inspecting object") } else { // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - LogTrace(&logger, "SBR information found in annotations, returning it") + logging.LogTrace(&log, "SBR information found in annotations, returning it") return sbrNamespacedName, nil } if u.GroupVersionKind() == v1alpha1.SchemeGroupVersion.WithKind(ServiceBindingRequestKind) { - LogDebug(&logger, "Object is a SBR, returning its namespaced name") + logging.LogDebug(&log, "Object is a SBR, returning its namespaced name") sbrNamespacedName.Namespace = u.GetNamespace() sbrNamespacedName.Name = u.GetName() return sbrNamespacedName, nil } // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - LogTrace(&logger, "Object is not a SBR, returning an empty namespaced name") + logging.LogTrace(&log, "Object is not a SBR, returning an empty namespaced name") return sbrNamespacedName, nil } @@ -95,17 +100,17 @@ func SetSBRAnnotations( gvr, _ := meta.UnsafeGuessKindToResource(gvk) opts := metav1.UpdateOptions{} - logger := log.WithValues( + log := annotationsLogger.WithValues( "SBR.Namespace", namespacedName.Namespace, "SBR.Name", namespacedName.Name, "Resource.GVK", gvk, "Resource.Namespace", obj.GetNamespace(), "Resource.Name", obj.GetName(), ) - LogDebug(&logger, "Updating resource annotations...") + logging.LogDebug(&log, "Updating resource annotations...") _, err := client.Resource(gvr).Namespace(obj.GetNamespace()).Update(obj, opts) if err != nil { - LogError(err, &logger, "unable to set/update annotations in object") + logging.LogError(err, &log, "unable to set/update annotations in object") return err } } diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index 8dd4c1bd33..420dd7e29b 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -17,15 +17,19 @@ import ( "k8s.io/apimachinery/pkg/types" "k8s.io/client-go/dynamic" "sigs.k8s.io/controller-runtime/pkg/client" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" + "github.com/redhat-developer/service-binding-operator/pkg/logging" ) const ( lastboundparam = "lastbound" ) +var ( + binderLogger = logging.Logger("binder") +) + // Binder executes the "binding" act of updating different application kinds to use intermediary // secret. Those secrets should be offered as environment variables. type Binder struct { @@ -79,20 +83,19 @@ func (b *Binder) search() (*unstructured.UnstructuredList, error) { // updateSpecVolumes execute the inspection and update "volumes" entries in informed spec. func (b *Binder) updateSpecVolumes( - logger logr.Logger, obj *unstructured.Unstructured, ) (*unstructured.Unstructured, error) { volumesPath := []string{"spec", "template", "spec", "volumes"} - logger = logger.WithValues("Volumes.NestedPath", volumesPath) + log := b.logger.WithValues("Volumes.NestedPath", volumesPath) - LogDebug(&logger, "Reading volumes definitions...") + logging.LogDebug(&log, "Reading volumes definitions...") volumes, _, err := unstructured.NestedSlice(obj.Object, volumesPath...) if err != nil { return nil, err } - LogDebug(&logger, "Amount of volumes in spec.", "Volumes", len(volumes)) + logging.LogDebug(&log, "Amount of volumes in spec.", "Volumes", len(volumes)) - volumes, err = b.updateVolumes(logger, volumes) + volumes, err = b.updateVolumes(volumes) if err != nil { return nil, err } @@ -105,14 +108,14 @@ func (b *Binder) updateSpecVolumes( // updateVolumes inspect informed list assuming as []corev1.Volume, and if binding volume is already // defined just return the same list, otherwise, appending the binding volume. -func (b *Binder) updateVolumes(logger logr.Logger, volumes []interface{}) ([]interface{}, error) { +func (b *Binder) updateVolumes(volumes []interface{}) ([]interface{}, error) { name := b.sbr.GetName() - - LogDebug(&logger, "Checking if binding volume is already defined...") + log := &(b.logger) + logging.LogDebug(log, "Checking if binding volume is already defined...") for _, v := range volumes { volume := v.(corev1.Volume) if name == volume.Name { - LogDebug(&logger, "Volume is already defined!") + logging.LogDebug(&binderLogger, "Volume is already defined!") return volumes, nil } } @@ -122,7 +125,7 @@ func (b *Binder) updateVolumes(logger logr.Logger, volumes []interface{}) ([]int items = append(items, corev1.KeyToPath{Key: k, Path: k}) } - LogDebug(&logger, "Appending new volume with items.", "Items", items) + logging.LogDebug(log, "Appending new volume with items.", "Items", items) bindVolume := corev1.Volume{ Name: name, VolumeSource: corev1.VolumeSource{ @@ -143,11 +146,10 @@ func (b *Binder) updateVolumes(logger logr.Logger, volumes []interface{}) ([]int // updateSpecContainers extract containers from object, and trigger update. func (b *Binder) updateSpecContainers( - logger logr.Logger, obj *unstructured.Unstructured, ) (*unstructured.Unstructured, error) { containersPath := []string{"spec", "template", "spec", "containers"} - logger = logger.WithValues("Containers.NestedPath", containersPath) + log := b.logger.WithValues("Containers.NestedPath", containersPath) containers, found, err := unstructured.NestedSlice(obj.Object, containersPath...) if err != nil { @@ -156,11 +158,11 @@ func (b *Binder) updateSpecContainers( if !found { err = fmt.Errorf("unable to find '%#v' in object kind '%s'", containersPath, obj.GetKind()) - LogError(err, &logger, "is this definition supported by this operator?") + logging.LogError(err, &log, "is this definition supported by this operator?") return nil, err } - if containers, err = b.updateContainers(logger, containers); err != nil { + if containers, err = b.updateContainers(containers); err != nil { return nil, err } if err = unstructured.SetNestedSlice(obj.Object, containers, containersPath...); err != nil { @@ -171,18 +173,17 @@ func (b *Binder) updateSpecContainers( // updateContainers execute the update command per container found. func (b *Binder) updateContainers( - logger logr.Logger, containers []interface{}, ) ([]interface{}, error) { var err error for i, container := range containers { - logger := logger.WithValues("Obj.Container.Number", i) - LogDebug(&logger, "Inspecting container...") + log := b.logger.WithValues("Obj.Container.Number", i) + logging.LogDebug(&log, "Inspecting container...") containers[i], err = b.updateContainer(container) if err != nil { - LogError(err, &logger, "during container update.") + logging.LogError(err, &log, "during container update.") return nil, err } } @@ -214,16 +215,16 @@ func (b *Binder) appendEnvVar(envList []corev1.EnvVar, envParam string, envValue // appendEnvFrom based on secret name and list of EnvFromSource instances, making sure secret is // part of the list or appended. func (b *Binder) appendEnvFrom(envList []corev1.EnvFromSource, secret string) []corev1.EnvFromSource { - logger := &(b.logger) + log := &(b.logger) for _, env := range envList { if env.SecretRef.Name == secret { - LogDebug(logger, "Directive 'envFrom' is already present!") + logging.LogDebug(log, "Directive 'envFrom' is already present!") // secret name is already referenced return envList } } - LogDebug(logger, "Adding 'envFrom' directive...") + logging.LogDebug(log, "Adding 'envFrom' directive...") return append(envList, corev1.EnvFromSource{ SecretRef: &corev1.SecretEnvSource{ LocalObjectReference: corev1.LocalObjectReference{ @@ -280,27 +281,27 @@ func (b *Binder) update(objs *unstructured.UnstructuredList) ([]*unstructured.Un for _, obj := range objs.Items { name := obj.GetName() - logger := b.logger.WithValues("Obj.Name", name, "Obj.Kind", obj.GetKind()) - LogDebug(&logger, "Inspecting object...") + log := b.logger.WithValues("Obj.Name", name, "Obj.Kind", obj.GetKind()) + logging.LogDebug(&log, "Inspecting object...") - updatedObj, err := b.updateSpecContainers(logger, &obj) + updatedObj, err := b.updateSpecContainers(&obj) if err != nil { return nil, err } if len(b.volumeKeys) > 0 { - updatedObj, err = b.updateSpecVolumes(logger, &obj) + updatedObj, err = b.updateSpecVolumes(&obj) if err != nil { return nil, err } } - LogDebug(&logger, "Updating object...") + logging.LogDebug(&log, "Updating object...") if err := b.client.Update(b.ctx, updatedObj); err != nil { return nil, err } - LogDebug(&logger, "Reading back updated object...") + logging.LogDebug(&log, "Reading back updated object...") // reading object back again, to comply with possible modifications namespacedName := types.NamespacedName{ Namespace: updatedObj.GetNamespace(), @@ -340,6 +341,6 @@ func NewBinder( dynClient: dynClient, sbr: sbr, volumeKeys: volumeKeys, - logger: logf.Log.WithName("binder"), + logger: binderLogger, } } diff --git a/pkg/controller/servicebindingrequest/common.go b/pkg/controller/servicebindingrequest/common.go index 1a6cf9e327..4e94dcf05f 100644 --- a/pkg/controller/servicebindingrequest/common.go +++ b/pkg/controller/servicebindingrequest/common.go @@ -5,11 +5,6 @@ import ( "k8s.io/apimachinery/pkg/api/errors" "sigs.k8s.io/controller-runtime/pkg/reconcile" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" -) - -var ( - log = logf.ZapLogger(true).WithName("servicebindingrequest") ) // ServiceBindingRequestResource the name of ServiceBindingRequest resource. diff --git a/pkg/controller/servicebindingrequest/logging.go b/pkg/controller/servicebindingrequest/logging.go deleted file mode 100644 index f1192690d1..0000000000 --- a/pkg/controller/servicebindingrequest/logging.go +++ /dev/null @@ -1,32 +0,0 @@ -package servicebindingrequest - -import ( - "fmt" - - "github.com/go-logr/logr" -) - -// LogError logs the message using go-logr package on a default level as WARNING -func LogError(err error, logger *logr.Logger, msg string, keysAndValues ...interface{}) { - (*logger).Error(err, msg, keysAndValues...) -} - -// LogWarning logs the message using go-logr package on a default level as WARNING -func LogWarning(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - (*logger).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) -} - -// LogInfo logs the message using go-logr package on a default level as INFO -func LogInfo(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - (*logger).Info(msg, keysAndValues...) -} - -// LogDebug logs the message using go-logr package on a V=1 level as DEBUG -func LogDebug(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - (*logger).V(1).Info(msg, keysAndValues...) -} - -// LogTrace logs the message using go-logr package on a V=2 level as TRACE -func LogTrace(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - (*logger).V(2).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) -} diff --git a/pkg/controller/servicebindingrequest/mapper.go b/pkg/controller/servicebindingrequest/mapper.go index 65487e3309..684332650d 100644 --- a/pkg/controller/servicebindingrequest/mapper.go +++ b/pkg/controller/servicebindingrequest/mapper.go @@ -1,10 +1,15 @@ package servicebindingrequest import ( + "github.com/redhat-developer/service-binding-operator/pkg/logging" "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) +var ( + mapperLogger = logging.Logger("mapper") +) + // SBRRequestMapper is the handler.Mapper interface implementation. It should influence the // enqueue process considering the resources informed. type SBRRequestMapper struct{} @@ -12,7 +17,7 @@ type SBRRequestMapper struct{} // Map execute the mapping of a resource with the requests it would produce. Here we inspect the // given object trying to identify if this object is part of a SBR, or a actual SBR resource. func (m *SBRRequestMapper) Map(obj handler.MapObject) []reconcile.Request { - logger := log.WithValues( + log := mapperLogger.WithValues( "Object.Namespace", obj.Meta.GetNamespace(), "Object.Name", obj.Meta.GetName(), ) @@ -20,12 +25,11 @@ func (m *SBRRequestMapper) Map(obj handler.MapObject) []reconcile.Request { sbrNamespacedName, err := GetSBRNamespacedNameFromObject(obj.Object) if err != nil { - LogError(err, &logger, "on inspecting object for annotations for SBR object") + logging.LogError(err, &log, "on inspecting object for annotations for SBR object") return toReconcile } if IsNamespacedNameEmpty(sbrNamespacedName) { - LogWarning(&logger, "not able to extract SBR namespaced-name") - LogWarning(&logger, "not able to extract SBR namespaced-name") + logging.LogDebug(&log, "not able to extract SBR namespaced-name") return toReconcile } diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index 5ac86406ec..d71e64e737 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -6,13 +6,13 @@ import ( "github.com/go-logr/logr" olmv1alpha1 "github.com/operator-framework/operator-lifecycle-manager/pkg/api/apis/operators/v1alpha1" + "github.com/redhat-developer/service-binding-operator/pkg/logging" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/runtime/schema" "k8s.io/apimachinery/pkg/types" "k8s.io/client-go/dynamic" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) // OLM represents the actions this operator needs to take upon Operator-Lifecycle-Manager resources, @@ -27,14 +27,18 @@ const ( csvResource = "clusterserviceversions" ) +var ( + olmLogger = logging.Logger("olm") +) + // listCSVs simple list to all CSV objects in the cluster. func (o *OLM) listCSVs() ([]unstructured.Unstructured, error) { - logger := &(o.logger) + log := &(o.logger) gvr := olmv1alpha1.SchemeGroupVersion.WithResource(csvResource) resourceClient := o.client.Resource(gvr).Namespace(o.ns) csvs, err := resourceClient.List(metav1.ListOptions{}) if err != nil { - LogError(err, logger, "during listing CSV objects from cluster") + logging.LogError(err, log, "during listing CSV objects from cluster") return nil, err } return csvs.Items, nil @@ -47,11 +51,11 @@ func (o *OLM) extractOwnedCRDs( crds := []unstructured.Unstructured{} for _, csv := range csvs { ownedPath := []string{"spec", "customresourcedefinitions", "owned"} - logger := o.logger.WithValues("OwnedPath", ownedPath, "CSV.Name", csv.GetName()) + log := o.logger.WithValues("OwnedPath", ownedPath, "CSV.Name", csv.GetName()) ownedCRDs, exists, err := unstructured.NestedSlice(csv.Object, ownedPath...) if err != nil { - LogError(err, &logger, "on extracting nested slice") + logging.LogError(err, &log, "on extracting nested slice") return nil, err } if !exists { @@ -69,10 +73,10 @@ func (o *OLM) extractOwnedCRDs( // ListCSVOwnedCRDs return a unstructured list of CRD objects from "owned" section in CSVs. func (o *OLM) ListCSVOwnedCRDs() ([]unstructured.Unstructured, error) { - logger := &(o.logger) + log := &(o.logger) csvs, err := o.listCSVs() if err != nil { - LogError(err, logger, "on listting CSVs") + logging.LogError(err, log, "on listting CSVs") return nil, err } return o.extractOwnedCRDs(csvs) @@ -89,16 +93,16 @@ func (o *OLM) loopCRDDescriptions( fn eachCRDDescriptionFn, ) error { for _, u := range crdDescriptions { - logger := &(o.logger) + log := &(o.logger) crdDescription := &olmv1alpha1.CRDDescription{} err := runtime.DefaultUnstructuredConverter.FromUnstructured(u.Object, crdDescription) if err != nil { - LogError(err, logger, "on converting from unstructured to CRD") + logging.LogError(err, log, "on converting from unstructured to CRD") return err } - LogDebug(logger, "Inspecting CRDDescription...", "CRDDescription", crdDescription) + logging.LogDebug(log, "Inspecting CRDDescription...", "CRDDescription", crdDescription) if crdDescription.Name == "" { - LogDebug(logger, "Skipping empty CRDDescription!") + logging.LogDebug(log, "Skipping empty CRDDescription!") continue } fn(crdDescription) @@ -108,21 +112,21 @@ func (o *OLM) loopCRDDescriptions( // SelectCRDByGVK return a single CRD based on a given GVK. func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescription, error) { - logger := o.logger.WithValues("Selector.GVK", gvk) + log := o.logger.WithValues("Selector.GVK", gvk) ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - LogError(err, &logger, "on listing owned CRDs") + logging.LogError(err, &log, "on listing owned CRDs") return nil, err } crdDescriptions := []*olmv1alpha1.CRDDescription{} err = o.loopCRDDescriptions(ownedCRDs, func(crdDescription *olmv1alpha1.CRDDescription) { - logger = logger.WithValues( + log = o.logger.WithValues( "CRDDescription.Name", crdDescription.Name, "CRDDescription.Version", crdDescription.Version, "CRDDescription.Kind", crdDescription.Kind, ) - LogDebug(&logger, "Inspecting CRDDescription object...") + logging.LogDebug(&log, "Inspecting CRDDescription object...") // checking for suffix since is expected to have object type as prefix if !strings.EqualFold(strings.ToLower(crdDescription.Kind), strings.ToLower(gvk.Kind)) { return @@ -132,7 +136,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr strings.ToLower(gvk.Version) != strings.ToLower(crdDescription.Version) { return } - LogDebug(&logger, "CRDDescription object matches selector!") + logging.LogDebug(&log, "CRDDescription object matches selector!") crdDescriptions = append(crdDescriptions, crdDescription) }) if err != nil { @@ -140,7 +144,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr } if len(crdDescriptions) == 0 { - LogDebug(&logger, "No CRD could be found for GVK.") + logging.LogDebug(&log, "No CRD could be found for GVK.") return nil, fmt.Errorf("no crd could be found for gvk") } return crdDescriptions[0], nil @@ -150,10 +154,10 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr func (o *OLM) extractGVKs( crdDescriptions []unstructured.Unstructured, ) ([]schema.GroupVersionKind, error) { - logger := &(o.logger) + log := &(o.logger) gvks := []schema.GroupVersionKind{} err := o.loopCRDDescriptions(crdDescriptions, func(crdDescription *olmv1alpha1.CRDDescription) { - LogDebug(logger, "Extracting GVK from CRDDescription", "CRDDescription.Name", crdDescription.Name) + logging.LogDebug(log, "Extracting GVK from CRDDescription", "CRDDescription.Name", crdDescription.Name) _, gv := schema.ParseResourceArg(crdDescription.Name) gvks = append(gvks, schema.GroupVersionKind{ Group: gv.Group, @@ -169,10 +173,10 @@ func (o *OLM) extractGVKs( // ListCSVOwnedCRDsAsGVKs return the list of owned CRDs from all CSV objects as a list of GVKs. func (o *OLM) ListCSVOwnedCRDsAsGVKs() ([]schema.GroupVersionKind, error) { - logger := &(o.logger) + log := &(o.logger) ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - LogError(err, logger, "on listting CSVs") + logging.LogError(err, log, "on listting CSVs") return nil, err } return o.extractGVKs(ownedCRDs) @@ -182,13 +186,13 @@ func (o *OLM) ListCSVOwnedCRDsAsGVKs() ([]schema.GroupVersionKind, error) { func (o *OLM) ListGVKsFromCSVNamespacedName( namespacedName types.NamespacedName, ) ([]schema.GroupVersionKind, error) { - logger := o.logger.WithValues("CSV.NamespacedName", namespacedName) - LogDebug(&logger, "Reading CSV to extract GVKs...") + log := o.logger.WithValues("CSV.NamespacedName", namespacedName) + logging.LogDebug(&log, "Reading CSV to extract GVKs...") gvr := olmv1alpha1.SchemeGroupVersion.WithResource(csvResource) resourceClient := o.client.Resource(gvr).Namespace(namespacedName.Namespace) u, err := resourceClient.Get(namespacedName.Name, metav1.GetOptions{}) if err != nil { - LogError(err, &logger, "on reading CSV object") + logging.LogError(err, &log, "on reading CSV object") return []schema.GroupVersionKind{}, err } @@ -197,7 +201,7 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( ownedCRDs, err := o.extractOwnedCRDs(csvs) if err != nil { - LogError(err, &logger, "on extracting owned CRDs") + logging.LogError(err, &log, "on extracting owned CRDs") return []schema.GroupVersionKind{}, err } @@ -209,6 +213,6 @@ func NewOLM(client dynamic.Interface, ns string) *OLM { return &OLM{ client: client, ns: ns, - logger: logf.Log.WithName("olm"), + logger: olmLogger, } } diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index 02ea3325d8..d6aa6dba0b 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -10,9 +10,13 @@ import ( "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime/schema" "k8s.io/client-go/dynamic" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" v1alpha1 "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" + "github.com/redhat-developer/service-binding-operator/pkg/logging" +) + +var ( + plannerLogger = logging.Logger("planner") ) // Planner plans resources needed to bind a given backend service, using OperatorLifecycleManager @@ -40,16 +44,16 @@ func (p *Planner) searchCR(kind string) (*unstructured.Unstructured, error) { gvr, _ := meta.UnsafeGuessKindToResource(gvk) opts := metav1.GetOptions{} - logger := p.logger.WithValues("CR.GVK", gvk.String(), "CR.GVR", gvr.String()) - LogDebug(&logger, "Searching for CR instance...") + log := p.logger.WithValues("CR.GVK", gvk.String(), "CR.GVR", gvr.String()) + logging.LogDebug(&log, "Searching for CR instance...") cr, err := p.client.Resource(gvr).Namespace(p.sbr.GetNamespace()).Get(bss.ResourceRef, opts) if err != nil { - LogError(err, &logger, "during reading CR") + logging.LogError(err, &log, "during reading CR") return nil, err } - LogDebug(&logger, "Found target CR!", "CR.Name", cr.GetName()) + logging.LogDebug(&log, "Found target CR!", "CR.Name", cr.GetName()) return cr, nil } @@ -88,6 +92,6 @@ func NewPlanner( ctx: ctx, client: client, sbr: sbr, - logger: logf.Log.WithName("plan"), + logger: plannerLogger, } } diff --git a/pkg/controller/servicebindingrequest/reconciler.go b/pkg/controller/servicebindingrequest/reconciler.go index 9873dc8e83..d7e989fd73 100644 --- a/pkg/controller/servicebindingrequest/reconciler.go +++ b/pkg/controller/servicebindingrequest/reconciler.go @@ -12,10 +12,10 @@ import ( "k8s.io/client-go/dynamic" "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/reconcile" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" "github.com/go-logr/logr" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" + "github.com/redhat-developer/service-binding-operator/pkg/logging" ) // Reconciler reconciles a ServiceBindingRequest object @@ -36,6 +36,10 @@ const ( requeueAfter int64 = 45 ) +var ( + reconcilerLogger = logging.Logger("reconciler") +) + // setSecretName update the CR status field to "in progress", and setting secret name. func (r *Reconciler) setSecretName(sbrStatus *v1alpha1.ServiceBindingRequestStatus, name string) { sbrStatus.BindingStatus = bindingInProgress @@ -122,16 +126,16 @@ func (r *Reconciler) onError( } // checkSBR checks the Service Binding Request -func checkSBR(sbr *v1alpha1.ServiceBindingRequest, logger logr.Logger) error { +func checkSBR(sbr *v1alpha1.ServiceBindingRequest, log logr.Logger) error { // Check if application ResourceRef is present if sbr.Spec.ApplicationSelector.ResourceRef == "" { - LogDebug(&logger, "Spec.ApplicationSelector.ResourceRef not found") + logging.LogDebug(&log, "Spec.ApplicationSelector.ResourceRef not found") // Check if MatchLabels is present if sbr.Spec.ApplicationSelector.MatchLabels == nil { err := errors.New("NotFoundError") - LogError(err, &logger, "Spec.ApplicationSelector.MatchLabels not found") + logging.LogError(err, &log, "Spec.ApplicationSelector.MatchLabels not found") return err } } @@ -151,29 +155,29 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err ctx := context.TODO() objectsToAnnotate := []*unstructured.Unstructured{} - logger := logf.Log.WithValues( + log := reconcilerLogger.WithValues( "Request.Namespace", request.Namespace, "Request.Name", request.Name, ) - LogInfo(&logger, "Reconciling ServiceBindingRequest...") + logging.LogInfo(&log, "Reconciling ServiceBindingRequest...") // fetch the ServiceBindingRequest instance sbr, err := r.getServiceBindingRequest(request.NamespacedName) if err != nil { - LogError(err, &logger, "On retrieving service-binding-request instance.") + logging.LogError(err, &log, "On retrieving service-binding-request instance.") return RequeueError(err) } - logger = logger.WithValues("ServiceBindingRequest.Name", sbr.Name) - LogDebug(&logger, "Found service binding request to inspect") + log = log.WithValues("ServiceBindingRequest.Name", sbr.Name) + logging.LogDebug(&log, "Found service binding request to inspect") // splitting instance from it's status sbrStatus := sbr.Status // Check Service Binding Request - err = checkSBR(sbr, logger) + err = checkSBR(sbr, log) if err != nil { - LogError(err, &logger, "") + logging.LogError(err, &log, "") return RequeueError(err) } @@ -181,11 +185,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Planing changes // - LogDebug(&logger, "Creating a plan based on OLM and CRD.") + logging.LogDebug(&log, "Creating a plan based on OLM and CRD.") planner := NewPlanner(ctx, r.dynClient, sbr) plan, err := planner.Plan() if err != nil { - LogError(err, &logger, "On creating a plan to bind applications.") + logging.LogError(err, &log, "On creating a plan to bind applications.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -196,11 +200,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Retrieving data // - LogDebug(&logger, "Retrieving data to create intermediate secret.") + logging.LogDebug(&log, "Retrieving data to create intermediate secret.") retriever := NewRetriever(r.dynClient, plan, sbr.Spec.EnvVarPrefix) retrievedObjects, err := retriever.Retrieve() if err != nil { - LogError(err, &logger, "On retrieving binding data.") + logging.LogError(err, &log, "On retrieving binding data.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -213,11 +217,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Updating applications to use intermediary secret // - LogInfo(&logger, "Binding applications with intermediary secret.") + logging.LogInfo(&log, "Binding applications with intermediary secret.") binder := NewBinder(ctx, r.client, r.dynClient, sbr, retriever.volumeKeys) updatedObjects, err := binder.Bind() if err != nil { - LogError(err, &logger, "On binding application.") + logging.LogError(err, &log, "On binding application.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } @@ -231,16 +235,16 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // if err = SetSBRAnnotations(r.dynClient, request.NamespacedName, objectsToAnnotate); err != nil { - LogError(err, &logger, "On setting annotations in related objects.") + logging.LogError(err, &log, "On setting annotations in related objects.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } // updating status of request instance if err = r.updateStatusServiceBindingRequest(sbr, &sbrStatus); err != nil { - LogError(err, &logger, "On updating status of ServiceBindingRequest.") + logging.LogError(err, &log, "On updating status of ServiceBindingRequest.") return RequeueError(err) } - LogInfo(&logger, "All done!") + logging.LogInfo(&log, "All done!") return Done() } diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index 58d39bd0e8..b17c37efaf 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -6,6 +6,7 @@ import ( "strings" "github.com/go-logr/logr" + "github.com/redhat-developer/service-binding-operator/pkg/logging" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -13,7 +14,6 @@ import ( "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/runtime/schema" "k8s.io/client-go/dynamic" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) // Retriever reads all data referred in plan instance, and store in a secret. @@ -36,9 +36,13 @@ const ( volumeMountSecretPrefix = "binding:volumemount:secret" ) +var ( + retrieverLogger = logging.Logger("retriever") +) + // getNestedValue retrieve value from dotted key path func (r *Retriever) getNestedValue(key string, sectionMap interface{}) (string, error, interface{}) { - logger := r.logger.WithValues("Key", key, "SectionMap", sectionMap) + log := r.logger.WithValues("Key", key, "SectionMap", sectionMap) if !strings.Contains(key, ".") { value, exists := sectionMap.(map[string]interface{})[key] if !exists { @@ -48,7 +52,7 @@ func (r *Retriever) getNestedValue(key string, sectionMap interface{}) (string, } attrs := strings.SplitN(key, ".", 2) newSectionMap, exists := sectionMap.(map[string]interface{})[attrs[0]] - LogDebug(&logger, "Section maps : ") + logging.LogDebug(&log, "Section maps : ") if !exists { return "", fmt.Errorf("Can't find '%v' section in CR", attrs), newSectionMap } @@ -59,8 +63,8 @@ func (r *Retriever) getNestedValue(key string, sectionMap interface{}) (string, func (r *Retriever) getCRKey(section string, key string) (string, interface{}, error) { obj := r.plan.CR.Object objName := r.plan.CR.GetName() - logger := r.logger.WithValues("CR.Name", objName, "CR.section", section, "CR.key", key) - LogDebug(&logger, "Reading CR attributes...") + log := r.logger.WithValues("CR.Name", objName, "CR.section", section, "CR.key", key) + logging.LogDebug(&log, "Reading CR attributes...") sectionMap, exists := obj[section] if !exists { @@ -81,12 +85,12 @@ func (r *Retriever) getCRKey(section string, key string) (string, interface{}, e // value, and parsing x-descriptors in order to either directly read CR data, or read items from // a secret. func (r *Retriever) read(place, path string, xDescriptors []string) error { - logger := r.logger.WithValues( + log := r.logger.WithValues( "CR.Section", place, "CRDDescription.Path", path, "CRDDescription.XDescriptors", xDescriptors, ) - LogDebug(&logger, "Reading CRDDescription attributes...") + logging.LogDebug(&log, "Reading CRDDescription attributes...") // holds the secret name and items secrets := make(map[string][]string) @@ -95,8 +99,8 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { configMaps := make(map[string][]string) pathValue, _, err := r.getCRKey(place, path) for _, xDescriptor := range xDescriptors { - logger = logger.WithValues("CRDDescription.xDescriptor", xDescriptor, "cache", r.cache) - LogDebug(&logger, "Inspecting xDescriptor...") + log = log.WithValues("CRDDescription.xDescriptor", xDescriptor, "cache", r.cache) + logging.LogDebug(&log, "Inspecting xDescriptor...") if err != nil { return err } @@ -120,7 +124,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { } else if strings.HasPrefix(xDescriptor, attributePrefix) { r.store(path, []byte(pathValue)) } else { - LogDebug(&logger, "Defaulting....") + logging.LogDebug(&log, "Defaulting....") } } @@ -176,8 +180,8 @@ func (r *Retriever) readSecret( items []string, fromPath string, path string) error { - logger := r.logger.WithValues("Secret.Name", name, "Secret.Items", items) - LogDebug(&logger, "Reading secret items...") + log := r.logger.WithValues("Secret.Name", name, "Secret.Items", items) + logging.LogDebug(&log, "Reading secret items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "secrets"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -199,8 +203,8 @@ func (r *Retriever) readSecret( if err != nil { return err } - logger.WithValues("Secret.Key.Name", k, "Secret.Key.Length", len(data)) - LogDebug(&logger, "Inspecting secret key...") + log = log.WithValues("Secret.Key.Name", k, "Secret.Key.Length", len(data)) + logging.LogDebug(&log, "Inspecting secret key...") r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = string(value) @@ -220,8 +224,8 @@ func (r *Retriever) readConfigMap( items []string, fromPath string, path string) error { - logger := r.logger.WithValues("ConfigMap.Name", name, "ConfigMap.Items", items) - LogDebug(&logger, "Reading ConfigMap items...") + log := r.logger.WithValues("ConfigMap.Name", name, "ConfigMap.Items", items) + logging.LogDebug(&log, "Reading ConfigMap items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "configmaps"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -237,10 +241,10 @@ func (r *Retriever) readConfigMap( return fmt.Errorf("could not find 'data' in secret") } - LogDebug(&logger, "Inspecting configMap data...") + logging.LogDebug(&log, "Inspecting configMap data...") for k, v := range data { value := v.(string) - LogDebug(&logger, "Inspecting configMap key...", "configMap.Key.Name", k, "configMap.Key.Length", len(value)) + logging.LogDebug(&log, "Inspecting configMap key...", "configMap.Key.Name", k, "configMap.Key.Length", len(value)) r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = value @@ -270,12 +274,12 @@ func (r *Retriever) saveDataOnSecret() error { gvk := schema.GroupVersion{Group: "", Version: "v1"}.WithKind("Secret") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "secrets"} resourceClient := r.client.Resource(gvr).Namespace(r.plan.Ns) - logger := r.logger.WithValues( + log := r.logger.WithValues( "Secret.GVK", gvk.String(), "Secret.Namespace", r.plan.Ns, "Secret.Name", r.plan.Name, ) - LogDebug(&logger, "Retrieving intermediary secret...") + logging.LogDebug(&log, "Retrieving intermediary secret...") secretObj := &corev1.Secret{ TypeMeta: metav1.TypeMeta{ @@ -291,26 +295,26 @@ func (r *Retriever) saveDataOnSecret() error { data, err := runtime.DefaultUnstructuredConverter.ToUnstructured(secretObj) if err != nil { - LogError(err, &logger, "Converting secret to unstructured") + logging.LogError(err, &log, "Converting secret to unstructured") return err } u := &unstructured.Unstructured{Object: data} u.SetGroupVersionKind(gvk) - LogDebug(&logger, "Creating intermediary secret...") + logging.LogDebug(&log, "Creating intermediary secret...") _, err = resourceClient.Create(u, metav1.CreateOptions{}) if err != nil && !errors.IsAlreadyExists(err) { - LogError(err, &logger, "on creating intermediary secret") + logging.LogError(err, &log, "on creating intermediary secret") return err } - LogDebug(&logger, "Secret is already found, updating...") + logging.LogDebug(&log, "Secret is already found, updating...") _, err = resourceClient.Update(u, metav1.UpdateOptions{}) if err != nil { - LogError(err, &logger, "on updating intermediary secret") + logging.LogError(err, &log, "on updating intermediary secret") return err } - LogDebug(&logger, "Intermediary secret created/updated!") + logging.LogDebug(&log, "Intermediary secret created/updated!") r.objects = append(r.objects, u) return nil } @@ -319,22 +323,22 @@ func (r *Retriever) saveDataOnSecret() error { // Unstructured refering the objects in use by the Retriever, and error when issues reading fields. func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { var err error - logger := &(r.logger) - LogDebug(logger, "Looking for spec-descriptors in 'spec'...") + log := &(r.logger) + logging.LogDebug(log, "Looking for spec-descriptors in 'spec'...") for _, specDescriptor := range r.plan.CRDDescription.SpecDescriptors { if err = r.read("spec", specDescriptor.Path, specDescriptor.XDescriptors); err != nil { return nil, err } } - LogDebug(logger, "Looking for status-descriptors in 'status'...") + logging.LogDebug(log, "Looking for status-descriptors in 'status'...") for _, statusDescriptor := range r.plan.CRDDescription.StatusDescriptors { if err = r.read("status", statusDescriptor.Path, statusDescriptor.XDescriptors); err != nil { return nil, err } } - LogDebug(logger, "Final cache values...", "cache", r.cache) + logging.LogDebug(log, "Final cache values...", "cache", r.cache) envParser := NewCustomEnvParser(r.plan.SBR.Spec.CustomEnvVar, r.cache) values, err := envParser.Parse() @@ -345,7 +349,7 @@ func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { r.data[k] = []byte(v.(string)) } - LogDebug(logger, "Saving data on intermediary secret...") + logging.LogDebug(log, "Saving data on intermediary secret...") if err = r.saveDataOnSecret(); err != nil { return nil, err } @@ -355,7 +359,7 @@ func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { // NewRetriever instantiate a new retriever instance. func NewRetriever(client dynamic.Interface, plan *Plan, bindingPrefix string) *Retriever { return &Retriever{ - logger: logf.Log.WithName("retriever"), + logger: retrieverLogger, data: make(map[string][]byte), objects: []*unstructured.Unstructured{}, client: client, diff --git a/pkg/controller/servicebindingrequest/sbrcontroller.go b/pkg/controller/servicebindingrequest/sbrcontroller.go index 01fce1f69a..ba9d6fac55 100644 --- a/pkg/controller/servicebindingrequest/sbrcontroller.go +++ b/pkg/controller/servicebindingrequest/sbrcontroller.go @@ -13,10 +13,10 @@ import ( "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/manager" "sigs.k8s.io/controller-runtime/pkg/predicate" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" "sigs.k8s.io/controller-runtime/pkg/source" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" + "github.com/redhat-developer/service-binding-operator/pkg/logging" ) // SBRController hold the controller instance and methods for a ServiceBindingRequest. @@ -41,6 +41,7 @@ var ( return !e.DeleteStateUnknown }, } + sbrControllerLogger = logging.Logger("sbrcontroller") ) // newEnqueueRequestsForSBR returns a handler.EventHandler configured to map any incoming object to a @@ -63,6 +64,7 @@ func (s *SBRController) createUnstructuredWithGVK(gvk schema.GroupVersionKind) * // getWatchingGVKs return a list of GVKs that this controller is interested in watching. func (s *SBRController) getWatchingGVKs() ([]schema.GroupVersionKind, error) { + log := &(s.logger) // standard resources types gvks := []schema.GroupVersionKind{ {Group: "", Version: "v1", Kind: "Secret"}, @@ -72,39 +74,40 @@ func (s *SBRController) getWatchingGVKs() ([]schema.GroupVersionKind, error) { olm := NewOLM(s.Client, os.Getenv("WATCH_NAMESPACE")) olmGVKs, err := olm.ListCSVOwnedCRDsAsGVKs() if err != nil { - log.Error(err, "On listing owned CSV as GVKs") + logging.LogError(err, log, "On listing owned CSV as GVKs") return nil, err } - LogDebug(&log, "Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) + logging.LogDebug(log, "Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) return append(gvks, olmGVKs...), nil } // AddWatchForGVK creates a watch on a given GVK, as long as it's not duplicated. func (s *SBRController) AddWatchForGVK(gvk schema.GroupVersionKind) error { - logger := s.logger.WithValues("GVK", gvk) - LogDebug(&logger, "Adding watch for GVK...") + log := s.logger.WithValues("GVK", gvk) + logging.LogDebug(&log, "Adding watch for GVK...") if _, exists := s.watchingGVKs[gvk]; exists { - LogDebug(&logger, "Skipping watch on GVK twice, it's already under watch!") + logging.LogDebug(&log, "Skipping watch on GVK twice, it's already under watch!") return nil } // saving GVK in cache s.watchingGVKs[gvk] = true - LogDebug(&logger, "Creating watch on GVK") + logging.LogDebug(&log, "Creating watch on GVK") source := s.createSourceForGVK(gvk) return s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) } // addCSVWatch creates a watch on ClusterServiceVersion. func (s *SBRController) addCSVWatch() error { + log := &(s.logger) csvGVK := olmv1alpha1.SchemeGroupVersion.WithKind(ClusterServiceVersionKind) source := s.createSourceForGVK(csvGVK) err := s.Controller.Watch(source, NewCreateWatchEventHandler(s), defaultPredicate) if err != nil { return err } - LogDebug(&log, "Watch added for ClusterServiceVersion", "GVK", csvGVK) + logging.LogDebug(log, "Watch added for ClusterServiceVersion", "GVK", csvGVK) return nil } @@ -112,33 +115,33 @@ func (s *SBRController) addCSVWatch() error { // addSBRWatch creates a watchon ServiceBindingRequest GVK. func (s *SBRController) addSBRWatch() error { gvk := v1alpha1.SchemeGroupVersion.WithKind(ServiceBindingRequestKind) - logger := s.logger.WithValues("GKV", gvk) + log := s.logger.WithValues("GKV", gvk) source := s.createSourceForGVK(gvk) err := s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) if err != nil { - LogError(err, &logger, "on creating watch for ServiceBindingRequest") + logging.LogError(err, &log, "on creating watch for ServiceBindingRequest") return err } - LogDebug(&logger, "Watch added for ServiceBindingRequest") + logging.LogDebug(&log, "Watch added for ServiceBindingRequest") return nil } // addWhitelistedGVKWatches create watch on GVKs employed on CSVs. func (s *SBRController) addWhitelistedGVKWatches() error { - logger := &(s.logger) + log := &(s.logger) // list of interesting GVKs to watch gvks, err := s.getWatchingGVKs() if err != nil { - LogError(err, logger, "on retrieving list of GVKs to watch") + logging.LogError(err, log, "on retrieving list of GVKs to watch") return err } for _, gvk := range gvks { - LogDebug(logger, "Adding watch for whitelisted GVK...", "GVK", gvk) + logging.LogDebug(log, "Adding watch for whitelisted GVK...", "GVK", gvk) err = s.AddWatchForGVK(gvk) if err != nil { - LogError(err, logger, "on creating watch for GVK") + logging.LogError(err, log, "on creating watch for GVK") return err } } @@ -148,22 +151,22 @@ func (s *SBRController) addWhitelistedGVKWatches() error { // Watch setup "watch" for all GVKs relevant for SBRController. func (s *SBRController) Watch() error { - logger := &(s.logger) + log := &(s.logger) err := s.addSBRWatch() if err != nil { - LogError(err, logger, "on adding watch for ServiceBindingRequest") + logging.LogError(err, log, "on adding watch for ServiceBindingRequest") return err } err = s.addWhitelistedGVKWatches() if err != nil { - LogError(err, logger, "on adding watch for whitelisted GVKs") + logging.LogError(err, log, "on adding watch for whitelisted GVKs") return err } err = s.addCSVWatch() if err != nil { - LogError(err, logger, "on adding watch for ClusterServiceVersion") + logging.LogError(err, log, "on adding watch for ClusterServiceVersion") return err } @@ -186,6 +189,6 @@ func NewSBRController( Controller: c, Client: client, watchingGVKs: make(map[schema.GroupVersionKind]bool), - logger: logf.Log.WithName("sbrcontroller"), + logger: sbrControllerLogger, }, nil } diff --git a/pkg/controller/servicebindingrequest/watch.go b/pkg/controller/servicebindingrequest/watch.go index c875c3ab7c..cbb9d5ce84 100644 --- a/pkg/controller/servicebindingrequest/watch.go +++ b/pkg/controller/servicebindingrequest/watch.go @@ -1,11 +1,16 @@ package servicebindingrequest import ( + "github.com/redhat-developer/service-binding-operator/pkg/logging" "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) +var ( + watchLogger = logging.Logger("watch") +) + // CSVToWatcherMapper creates a EventHandler interface to map ClusterServiceVersion objects back to // controller and add given GVK to watch list. type CSVToWatcherMapper struct { @@ -21,19 +26,19 @@ func (c *CSVToWatcherMapper) Map(obj handler.MapObject) []reconcile.Request { Name: obj.Meta.GetName(), } - logger := log.WithName("CSVToWatcherMapper").WithValues("Obj.NamespacedName", namespacedName) + log := watchLogger.WithName("CSVToWatcherMapper").WithValues("Obj.NamespacedName", namespacedName) gvks, err := olm.ListGVKsFromCSVNamespacedName(namespacedName) if err != nil { - LogError(err, &logger, "Failed on listing GVK with namespaced-name!") + logging.LogError(err, &log, "Failed on listing GVK with namespaced-name!") return []reconcile.Request{} } for _, gvk := range gvks { - LogDebug(&logger, "Adding watch for GVK", "GVK", gvk) + logging.LogDebug(&log, "Adding watch for GVK", "GVK", gvk) err = c.controller.AddWatchForGVK(gvk) if err != nil { - LogError(err, &logger, "Failed to create a watch") + logging.LogError(err, &log, "Failed to create a watch") } } diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go new file mode 100644 index 0000000000..08035ce0d3 --- /dev/null +++ b/pkg/logging/logging.go @@ -0,0 +1,51 @@ +package logging + +import ( + "fmt" + + "github.com/go-logr/logr" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" +) + +// LogError logs the message using go-logr package on a default level as ERROR +func LogError(err error, logger *logr.Logger, msg string, keysAndValues ...interface{}) { + (*logger).Error(err, msg, keysAndValues...) +} + +// LogWarning logs the message using go-logr package on a default level as WARNING +func LogWarning(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + if (*logger).V(0).Enabled() { + (*logger).V(0).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) + } +} + +// LogInfo logs the message using go-logr package on a default level as INFO +func LogInfo(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + if (*logger).V(0).Enabled() { + (*logger).V(0).Info(msg, keysAndValues...) + } +} + +// LogDebug logs the message using go-logr package on a V=1 level as DEBUG +func LogDebug(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + if (*logger).V(1).Enabled() { + (*logger).V(1).Info(fmt.Sprintf("DEBUG: %s", msg), keysAndValues...) + } +} + +// LogTrace logs the message using go-logr package on a V=1 level as TRACE +func LogTrace(logger *logr.Logger, msg string, keysAndValues ...interface{}) { + if (*logger).V(2).Enabled() { + (*logger).V(1).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) + } +} + +// Logger returns an instance of a logger +func Logger(name string, keysAndValues ...interface{}) logr.Logger { + return logf.Log.WithName(name).WithValues(keysAndValues...) +} + +// SetLogger sets a concrete logging implementation for all deferred Loggers. +func SetLogger(logger logr.Logger) { + logf.SetLogger(logger) +} From 6994682f089224cf66523fcacd60b3b68c12e3b3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Wed, 9 Oct 2019 15:25:04 +0200 Subject: [PATCH 03/14] Remove 'Log' prefix from logging function names to reduce boilerplate code. --- cmd/manager/main.go | 20 +++++------ .../servicebindingrequest/annotations.go | 10 +++--- .../servicebindingrequest/binder.go | 22 ++++++------ .../servicebindingrequest/mapper.go | 2 +- pkg/controller/servicebindingrequest/olm.go | 14 ++++---- .../servicebindingrequest/planner.go | 4 +-- .../servicebindingrequest/reconciler.go | 14 ++++---- .../servicebindingrequest/retriever.go | 36 +++++++++---------- .../servicebindingrequest/sbrcontroller.go | 14 ++++---- pkg/controller/servicebindingrequest/watch.go | 2 +- pkg/logging/logging.go | 16 ++++----- 11 files changed, 77 insertions(+), 77 deletions(-) diff --git a/cmd/manager/main.go b/cmd/manager/main.go index 4abedc9b16..754a203233 100644 --- a/cmd/manager/main.go +++ b/cmd/manager/main.go @@ -40,9 +40,9 @@ var ( ) func printVersion() { - logging.LogInfo(&mainLogger, fmt.Sprintf("Go Version: %s", runtime.Version())) - logging.LogInfo(&mainLogger, fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) - logging.LogInfo(&mainLogger, fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) + logging.Info(&mainLogger, fmt.Sprintf("Go Version: %s", runtime.Version())) + logging.Info(&mainLogger, fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) + logging.Info(&mainLogger, fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) } // getOperatorName based on environment variable OPERATOR_NAME, or returns the default name for @@ -92,7 +92,7 @@ func main() { os.Exit(1) } } else { - logging.LogWarning(&mainLogger, "Leader election is disabled") + logging.Warning(&mainLogger, "Leader election is disabled") } // Create a new Cmd to provide shared dependencies and start components @@ -106,7 +106,7 @@ func main() { os.Exit(1) } - logging.LogInfo(&mainLogger, "Registering Components.") + logging.Info(&mainLogger, "Registering Components.") // Setup Scheme for all resources if err := apis.AddToScheme(mgr.GetScheme()); err != nil { @@ -126,7 +126,7 @@ func main() { } if err = serveCRMetrics(cfg); err != nil { - logging.LogInfo(&mainLogger, "Could not generate and serve custom resource metrics", "error", err.Error()) + logging.Info(&mainLogger, "Could not generate and serve custom resource metrics", "error", err.Error()) } // Add to the below struct any other metrics ports you want to expose. @@ -137,7 +137,7 @@ func main() { // Create Service object to expose the metrics port(s). service, err := metrics.CreateMetricsService(ctx, cfg, servicePorts) if err != nil { - logging.LogInfo(&mainLogger, "Could not create metrics Service", "error", err.Error()) + logging.Info(&mainLogger, "Could not create metrics Service", "error", err.Error()) } // CreateServiceMonitors will automatically create the prometheus-operator ServiceMonitor resources @@ -145,15 +145,15 @@ func main() { services := []*v1.Service{service} _, err = metrics.CreateServiceMonitors(cfg, namespace, services) if err != nil { - logging.LogInfo(&mainLogger, "Could not create ServiceMonitor object", "error", err.Error()) + logging.Info(&mainLogger, "Could not create ServiceMonitor object", "error", err.Error()) // If this operator is deployed to a cluster without the prometheus-operator running, it will return // ErrServiceMonitorNotPresent, which can be used to safely skip ServiceMonitor creation. if err == metrics.ErrServiceMonitorNotPresent { - logging.LogInfo(&mainLogger, "Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) + logging.Info(&mainLogger, "Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) } } - logging.LogInfo(&mainLogger, "Starting the Cmd.") + logging.Info(&mainLogger, "Starting the Cmd.") // Start the Cmd if err := mgr.Start(signals.SetupSignalHandler()); err != nil { diff --git a/pkg/controller/servicebindingrequest/annotations.go b/pkg/controller/servicebindingrequest/annotations.go index ef3ec43d47..25a2631739 100644 --- a/pkg/controller/servicebindingrequest/annotations.go +++ b/pkg/controller/servicebindingrequest/annotations.go @@ -60,22 +60,22 @@ func GetSBRNamespacedNameFromObject(obj runtime.Object) (types.NamespacedName, e ) if IsNamespacedNameEmpty(sbrNamespacedName) { - logging.LogDebug(&log, "SBR information not present in annotations, continue inspecting object") + logging.Debug(&log, "SBR information not present in annotations, continue inspecting object") } else { // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - logging.LogTrace(&log, "SBR information found in annotations, returning it") + logging.Trace(&log, "SBR information found in annotations, returning it") return sbrNamespacedName, nil } if u.GroupVersionKind() == v1alpha1.SchemeGroupVersion.WithKind(ServiceBindingRequestKind) { - logging.LogDebug(&log, "Object is a SBR, returning its namespaced name") + logging.Debug(&log, "Object is a SBR, returning its namespaced name") sbrNamespacedName.Namespace = u.GetNamespace() sbrNamespacedName.Name = u.GetName() return sbrNamespacedName, nil } // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - logging.LogTrace(&log, "Object is not a SBR, returning an empty namespaced name") + logging.Trace(&log, "Object is not a SBR, returning an empty namespaced name") return sbrNamespacedName, nil } @@ -107,7 +107,7 @@ func SetSBRAnnotations( "Resource.Namespace", obj.GetNamespace(), "Resource.Name", obj.GetName(), ) - logging.LogDebug(&log, "Updating resource annotations...") + logging.Debug(&log, "Updating resource annotations...") _, err := client.Resource(gvr).Namespace(obj.GetNamespace()).Update(obj, opts) if err != nil { logging.LogError(err, &log, "unable to set/update annotations in object") diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index 420dd7e29b..2e250247d1 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -88,12 +88,12 @@ func (b *Binder) updateSpecVolumes( volumesPath := []string{"spec", "template", "spec", "volumes"} log := b.logger.WithValues("Volumes.NestedPath", volumesPath) - logging.LogDebug(&log, "Reading volumes definitions...") + logging.Debug(&log, "Reading volumes definitions...") volumes, _, err := unstructured.NestedSlice(obj.Object, volumesPath...) if err != nil { return nil, err } - logging.LogDebug(&log, "Amount of volumes in spec.", "Volumes", len(volumes)) + logging.Debug(&log, "Amount of volumes in spec.", "Volumes", len(volumes)) volumes, err = b.updateVolumes(volumes) if err != nil { @@ -111,11 +111,11 @@ func (b *Binder) updateSpecVolumes( func (b *Binder) updateVolumes(volumes []interface{}) ([]interface{}, error) { name := b.sbr.GetName() log := &(b.logger) - logging.LogDebug(log, "Checking if binding volume is already defined...") + logging.Debug(log, "Checking if binding volume is already defined...") for _, v := range volumes { volume := v.(corev1.Volume) if name == volume.Name { - logging.LogDebug(&binderLogger, "Volume is already defined!") + logging.Debug(&binderLogger, "Volume is already defined!") return volumes, nil } } @@ -125,7 +125,7 @@ func (b *Binder) updateVolumes(volumes []interface{}) ([]interface{}, error) { items = append(items, corev1.KeyToPath{Key: k, Path: k}) } - logging.LogDebug(log, "Appending new volume with items.", "Items", items) + logging.Debug(log, "Appending new volume with items.", "Items", items) bindVolume := corev1.Volume{ Name: name, VolumeSource: corev1.VolumeSource{ @@ -179,7 +179,7 @@ func (b *Binder) updateContainers( for i, container := range containers { log := b.logger.WithValues("Obj.Container.Number", i) - logging.LogDebug(&log, "Inspecting container...") + logging.Debug(&log, "Inspecting container...") containers[i], err = b.updateContainer(container) if err != nil { @@ -218,13 +218,13 @@ func (b *Binder) appendEnvFrom(envList []corev1.EnvFromSource, secret string) [] log := &(b.logger) for _, env := range envList { if env.SecretRef.Name == secret { - logging.LogDebug(log, "Directive 'envFrom' is already present!") + logging.Debug(log, "Directive 'envFrom' is already present!") // secret name is already referenced return envList } } - logging.LogDebug(log, "Adding 'envFrom' directive...") + logging.Debug(log, "Adding 'envFrom' directive...") return append(envList, corev1.EnvFromSource{ SecretRef: &corev1.SecretEnvSource{ LocalObjectReference: corev1.LocalObjectReference{ @@ -282,7 +282,7 @@ func (b *Binder) update(objs *unstructured.UnstructuredList) ([]*unstructured.Un for _, obj := range objs.Items { name := obj.GetName() log := b.logger.WithValues("Obj.Name", name, "Obj.Kind", obj.GetKind()) - logging.LogDebug(&log, "Inspecting object...") + logging.Debug(&log, "Inspecting object...") updatedObj, err := b.updateSpecContainers(&obj) if err != nil { @@ -296,12 +296,12 @@ func (b *Binder) update(objs *unstructured.UnstructuredList) ([]*unstructured.Un } } - logging.LogDebug(&log, "Updating object...") + logging.Debug(&log, "Updating object...") if err := b.client.Update(b.ctx, updatedObj); err != nil { return nil, err } - logging.LogDebug(&log, "Reading back updated object...") + logging.Debug(&log, "Reading back updated object...") // reading object back again, to comply with possible modifications namespacedName := types.NamespacedName{ Namespace: updatedObj.GetNamespace(), diff --git a/pkg/controller/servicebindingrequest/mapper.go b/pkg/controller/servicebindingrequest/mapper.go index 684332650d..2530de1daa 100644 --- a/pkg/controller/servicebindingrequest/mapper.go +++ b/pkg/controller/servicebindingrequest/mapper.go @@ -29,7 +29,7 @@ func (m *SBRRequestMapper) Map(obj handler.MapObject) []reconcile.Request { return toReconcile } if IsNamespacedNameEmpty(sbrNamespacedName) { - logging.LogDebug(&log, "not able to extract SBR namespaced-name") + logging.Debug(&log, "not able to extract SBR namespaced-name") return toReconcile } diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index d71e64e737..550729e2e3 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -100,9 +100,9 @@ func (o *OLM) loopCRDDescriptions( logging.LogError(err, log, "on converting from unstructured to CRD") return err } - logging.LogDebug(log, "Inspecting CRDDescription...", "CRDDescription", crdDescription) + logging.Debug(log, "Inspecting CRDDescription...", "CRDDescription", crdDescription) if crdDescription.Name == "" { - logging.LogDebug(log, "Skipping empty CRDDescription!") + logging.Debug(log, "Skipping empty CRDDescription!") continue } fn(crdDescription) @@ -126,7 +126,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr "CRDDescription.Version", crdDescription.Version, "CRDDescription.Kind", crdDescription.Kind, ) - logging.LogDebug(&log, "Inspecting CRDDescription object...") + logging.Debug(&log, "Inspecting CRDDescription object...") // checking for suffix since is expected to have object type as prefix if !strings.EqualFold(strings.ToLower(crdDescription.Kind), strings.ToLower(gvk.Kind)) { return @@ -136,7 +136,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr strings.ToLower(gvk.Version) != strings.ToLower(crdDescription.Version) { return } - logging.LogDebug(&log, "CRDDescription object matches selector!") + logging.Debug(&log, "CRDDescription object matches selector!") crdDescriptions = append(crdDescriptions, crdDescription) }) if err != nil { @@ -144,7 +144,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr } if len(crdDescriptions) == 0 { - logging.LogDebug(&log, "No CRD could be found for GVK.") + logging.Debug(&log, "No CRD could be found for GVK.") return nil, fmt.Errorf("no crd could be found for gvk") } return crdDescriptions[0], nil @@ -157,7 +157,7 @@ func (o *OLM) extractGVKs( log := &(o.logger) gvks := []schema.GroupVersionKind{} err := o.loopCRDDescriptions(crdDescriptions, func(crdDescription *olmv1alpha1.CRDDescription) { - logging.LogDebug(log, "Extracting GVK from CRDDescription", "CRDDescription.Name", crdDescription.Name) + logging.Debug(log, "Extracting GVK from CRDDescription", "CRDDescription.Name", crdDescription.Name) _, gv := schema.ParseResourceArg(crdDescription.Name) gvks = append(gvks, schema.GroupVersionKind{ Group: gv.Group, @@ -187,7 +187,7 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( namespacedName types.NamespacedName, ) ([]schema.GroupVersionKind, error) { log := o.logger.WithValues("CSV.NamespacedName", namespacedName) - logging.LogDebug(&log, "Reading CSV to extract GVKs...") + logging.Debug(&log, "Reading CSV to extract GVKs...") gvr := olmv1alpha1.SchemeGroupVersion.WithResource(csvResource) resourceClient := o.client.Resource(gvr).Namespace(namespacedName.Namespace) u, err := resourceClient.Get(namespacedName.Name, metav1.GetOptions{}) diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index d6aa6dba0b..001364c058 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -45,7 +45,7 @@ func (p *Planner) searchCR(kind string) (*unstructured.Unstructured, error) { opts := metav1.GetOptions{} log := p.logger.WithValues("CR.GVK", gvk.String(), "CR.GVR", gvr.String()) - logging.LogDebug(&log, "Searching for CR instance...") + logging.Debug(&log, "Searching for CR instance...") cr, err := p.client.Resource(gvr).Namespace(p.sbr.GetNamespace()).Get(bss.ResourceRef, opts) if err != nil { @@ -53,7 +53,7 @@ func (p *Planner) searchCR(kind string) (*unstructured.Unstructured, error) { return nil, err } - logging.LogDebug(&log, "Found target CR!", "CR.Name", cr.GetName()) + logging.Debug(&log, "Found target CR!", "CR.Name", cr.GetName()) return cr, nil } diff --git a/pkg/controller/servicebindingrequest/reconciler.go b/pkg/controller/servicebindingrequest/reconciler.go index d7e989fd73..45ff8dcb4a 100644 --- a/pkg/controller/servicebindingrequest/reconciler.go +++ b/pkg/controller/servicebindingrequest/reconciler.go @@ -129,7 +129,7 @@ func (r *Reconciler) onError( func checkSBR(sbr *v1alpha1.ServiceBindingRequest, log logr.Logger) error { // Check if application ResourceRef is present if sbr.Spec.ApplicationSelector.ResourceRef == "" { - logging.LogDebug(&log, "Spec.ApplicationSelector.ResourceRef not found") + logging.Debug(&log, "Spec.ApplicationSelector.ResourceRef not found") // Check if MatchLabels is present if sbr.Spec.ApplicationSelector.MatchLabels == nil { @@ -159,7 +159,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err "Request.Namespace", request.Namespace, "Request.Name", request.Name, ) - logging.LogInfo(&log, "Reconciling ServiceBindingRequest...") + logging.Info(&log, "Reconciling ServiceBindingRequest...") // fetch the ServiceBindingRequest instance sbr, err := r.getServiceBindingRequest(request.NamespacedName) @@ -169,7 +169,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err } log = log.WithValues("ServiceBindingRequest.Name", sbr.Name) - logging.LogDebug(&log, "Found service binding request to inspect") + logging.Debug(&log, "Found service binding request to inspect") // splitting instance from it's status sbrStatus := sbr.Status @@ -185,7 +185,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Planing changes // - logging.LogDebug(&log, "Creating a plan based on OLM and CRD.") + logging.Debug(&log, "Creating a plan based on OLM and CRD.") planner := NewPlanner(ctx, r.dynClient, sbr) plan, err := planner.Plan() if err != nil { @@ -200,7 +200,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Retrieving data // - logging.LogDebug(&log, "Retrieving data to create intermediate secret.") + logging.Debug(&log, "Retrieving data to create intermediate secret.") retriever := NewRetriever(r.dynClient, plan, sbr.Spec.EnvVarPrefix) retrievedObjects, err := retriever.Retrieve() if err != nil { @@ -217,7 +217,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Updating applications to use intermediary secret // - logging.LogInfo(&log, "Binding applications with intermediary secret.") + logging.Info(&log, "Binding applications with intermediary secret.") binder := NewBinder(ctx, r.client, r.dynClient, sbr, retriever.volumeKeys) updatedObjects, err := binder.Bind() if err != nil { @@ -245,6 +245,6 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err return RequeueError(err) } - logging.LogInfo(&log, "All done!") + logging.Info(&log, "All done!") return Done() } diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index b17c37efaf..6c9b7c50d0 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -52,7 +52,7 @@ func (r *Retriever) getNestedValue(key string, sectionMap interface{}) (string, } attrs := strings.SplitN(key, ".", 2) newSectionMap, exists := sectionMap.(map[string]interface{})[attrs[0]] - logging.LogDebug(&log, "Section maps : ") + logging.Debug(&log, "Section maps : ") if !exists { return "", fmt.Errorf("Can't find '%v' section in CR", attrs), newSectionMap } @@ -64,7 +64,7 @@ func (r *Retriever) getCRKey(section string, key string) (string, interface{}, e obj := r.plan.CR.Object objName := r.plan.CR.GetName() log := r.logger.WithValues("CR.Name", objName, "CR.section", section, "CR.key", key) - logging.LogDebug(&log, "Reading CR attributes...") + logging.Debug(&log, "Reading CR attributes...") sectionMap, exists := obj[section] if !exists { @@ -90,7 +90,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { "CRDDescription.Path", path, "CRDDescription.XDescriptors", xDescriptors, ) - logging.LogDebug(&log, "Reading CRDDescription attributes...") + logging.Debug(&log, "Reading CRDDescription attributes...") // holds the secret name and items secrets := make(map[string][]string) @@ -100,7 +100,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { pathValue, _, err := r.getCRKey(place, path) for _, xDescriptor := range xDescriptors { log = log.WithValues("CRDDescription.xDescriptor", xDescriptor, "cache", r.cache) - logging.LogDebug(&log, "Inspecting xDescriptor...") + logging.Debug(&log, "Inspecting xDescriptor...") if err != nil { return err } @@ -124,7 +124,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { } else if strings.HasPrefix(xDescriptor, attributePrefix) { r.store(path, []byte(pathValue)) } else { - logging.LogDebug(&log, "Defaulting....") + logging.Debug(&log, "Defaulting....") } } @@ -181,7 +181,7 @@ func (r *Retriever) readSecret( fromPath string, path string) error { log := r.logger.WithValues("Secret.Name", name, "Secret.Items", items) - logging.LogDebug(&log, "Reading secret items...") + logging.Debug(&log, "Reading secret items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "secrets"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -204,7 +204,7 @@ func (r *Retriever) readSecret( return err } log = log.WithValues("Secret.Key.Name", k, "Secret.Key.Length", len(data)) - logging.LogDebug(&log, "Inspecting secret key...") + logging.Debug(&log, "Inspecting secret key...") r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = string(value) @@ -225,7 +225,7 @@ func (r *Retriever) readConfigMap( fromPath string, path string) error { log := r.logger.WithValues("ConfigMap.Name", name, "ConfigMap.Items", items) - logging.LogDebug(&log, "Reading ConfigMap items...") + logging.Debug(&log, "Reading ConfigMap items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "configmaps"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -241,10 +241,10 @@ func (r *Retriever) readConfigMap( return fmt.Errorf("could not find 'data' in secret") } - logging.LogDebug(&log, "Inspecting configMap data...") + logging.Debug(&log, "Inspecting configMap data...") for k, v := range data { value := v.(string) - logging.LogDebug(&log, "Inspecting configMap key...", "configMap.Key.Name", k, "configMap.Key.Length", len(value)) + logging.Debug(&log, "Inspecting configMap key...", "configMap.Key.Name", k, "configMap.Key.Length", len(value)) r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = value @@ -279,7 +279,7 @@ func (r *Retriever) saveDataOnSecret() error { "Secret.Namespace", r.plan.Ns, "Secret.Name", r.plan.Name, ) - logging.LogDebug(&log, "Retrieving intermediary secret...") + logging.Debug(&log, "Retrieving intermediary secret...") secretObj := &corev1.Secret{ TypeMeta: metav1.TypeMeta{ @@ -301,20 +301,20 @@ func (r *Retriever) saveDataOnSecret() error { u := &unstructured.Unstructured{Object: data} u.SetGroupVersionKind(gvk) - logging.LogDebug(&log, "Creating intermediary secret...") + logging.Debug(&log, "Creating intermediary secret...") _, err = resourceClient.Create(u, metav1.CreateOptions{}) if err != nil && !errors.IsAlreadyExists(err) { logging.LogError(err, &log, "on creating intermediary secret") return err } - logging.LogDebug(&log, "Secret is already found, updating...") + logging.Debug(&log, "Secret is already found, updating...") _, err = resourceClient.Update(u, metav1.UpdateOptions{}) if err != nil { logging.LogError(err, &log, "on updating intermediary secret") return err } - logging.LogDebug(&log, "Intermediary secret created/updated!") + logging.Debug(&log, "Intermediary secret created/updated!") r.objects = append(r.objects, u) return nil } @@ -324,21 +324,21 @@ func (r *Retriever) saveDataOnSecret() error { func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { var err error log := &(r.logger) - logging.LogDebug(log, "Looking for spec-descriptors in 'spec'...") + logging.Debug(log, "Looking for spec-descriptors in 'spec'...") for _, specDescriptor := range r.plan.CRDDescription.SpecDescriptors { if err = r.read("spec", specDescriptor.Path, specDescriptor.XDescriptors); err != nil { return nil, err } } - logging.LogDebug(log, "Looking for status-descriptors in 'status'...") + logging.Debug(log, "Looking for status-descriptors in 'status'...") for _, statusDescriptor := range r.plan.CRDDescription.StatusDescriptors { if err = r.read("status", statusDescriptor.Path, statusDescriptor.XDescriptors); err != nil { return nil, err } } - logging.LogDebug(log, "Final cache values...", "cache", r.cache) + logging.Debug(log, "Final cache values...", "cache", r.cache) envParser := NewCustomEnvParser(r.plan.SBR.Spec.CustomEnvVar, r.cache) values, err := envParser.Parse() @@ -349,7 +349,7 @@ func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { r.data[k] = []byte(v.(string)) } - logging.LogDebug(log, "Saving data on intermediary secret...") + logging.Debug(log, "Saving data on intermediary secret...") if err = r.saveDataOnSecret(); err != nil { return nil, err } diff --git a/pkg/controller/servicebindingrequest/sbrcontroller.go b/pkg/controller/servicebindingrequest/sbrcontroller.go index ba9d6fac55..8f1555e410 100644 --- a/pkg/controller/servicebindingrequest/sbrcontroller.go +++ b/pkg/controller/servicebindingrequest/sbrcontroller.go @@ -77,23 +77,23 @@ func (s *SBRController) getWatchingGVKs() ([]schema.GroupVersionKind, error) { logging.LogError(err, log, "On listing owned CSV as GVKs") return nil, err } - logging.LogDebug(log, "Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) + logging.Debug(log, "Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) return append(gvks, olmGVKs...), nil } // AddWatchForGVK creates a watch on a given GVK, as long as it's not duplicated. func (s *SBRController) AddWatchForGVK(gvk schema.GroupVersionKind) error { log := s.logger.WithValues("GVK", gvk) - logging.LogDebug(&log, "Adding watch for GVK...") + logging.Debug(&log, "Adding watch for GVK...") if _, exists := s.watchingGVKs[gvk]; exists { - logging.LogDebug(&log, "Skipping watch on GVK twice, it's already under watch!") + logging.Debug(&log, "Skipping watch on GVK twice, it's already under watch!") return nil } // saving GVK in cache s.watchingGVKs[gvk] = true - logging.LogDebug(&log, "Creating watch on GVK") + logging.Debug(&log, "Creating watch on GVK") source := s.createSourceForGVK(gvk) return s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) } @@ -107,7 +107,7 @@ func (s *SBRController) addCSVWatch() error { if err != nil { return err } - logging.LogDebug(log, "Watch added for ClusterServiceVersion", "GVK", csvGVK) + logging.Debug(log, "Watch added for ClusterServiceVersion", "GVK", csvGVK) return nil } @@ -122,7 +122,7 @@ func (s *SBRController) addSBRWatch() error { logging.LogError(err, &log, "on creating watch for ServiceBindingRequest") return err } - logging.LogDebug(&log, "Watch added for ServiceBindingRequest") + logging.Debug(&log, "Watch added for ServiceBindingRequest") return nil } @@ -138,7 +138,7 @@ func (s *SBRController) addWhitelistedGVKWatches() error { } for _, gvk := range gvks { - logging.LogDebug(log, "Adding watch for whitelisted GVK...", "GVK", gvk) + logging.Debug(log, "Adding watch for whitelisted GVK...", "GVK", gvk) err = s.AddWatchForGVK(gvk) if err != nil { logging.LogError(err, log, "on creating watch for GVK") diff --git a/pkg/controller/servicebindingrequest/watch.go b/pkg/controller/servicebindingrequest/watch.go index cbb9d5ce84..c6fb8fe441 100644 --- a/pkg/controller/servicebindingrequest/watch.go +++ b/pkg/controller/servicebindingrequest/watch.go @@ -35,7 +35,7 @@ func (c *CSVToWatcherMapper) Map(obj handler.MapObject) []reconcile.Request { } for _, gvk := range gvks { - logging.LogDebug(&log, "Adding watch for GVK", "GVK", gvk) + logging.Debug(&log, "Adding watch for GVK", "GVK", gvk) err = c.controller.AddWatchForGVK(gvk) if err != nil { logging.LogError(err, &log, "Failed to create a watch") diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go index 08035ce0d3..b9b2909b07 100644 --- a/pkg/logging/logging.go +++ b/pkg/logging/logging.go @@ -12,29 +12,29 @@ func LogError(err error, logger *logr.Logger, msg string, keysAndValues ...inter (*logger).Error(err, msg, keysAndValues...) } -// LogWarning logs the message using go-logr package on a default level as WARNING -func LogWarning(logger *logr.Logger, msg string, keysAndValues ...interface{}) { +// Warning logs the message using go-logr package on a default level as WARNING +func Warning(logger *logr.Logger, msg string, keysAndValues ...interface{}) { if (*logger).V(0).Enabled() { (*logger).V(0).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) } } -// LogInfo logs the message using go-logr package on a default level as INFO -func LogInfo(logger *logr.Logger, msg string, keysAndValues ...interface{}) { +// Info logs the message using go-logr package on a default level as INFO +func Info(logger *logr.Logger, msg string, keysAndValues ...interface{}) { if (*logger).V(0).Enabled() { (*logger).V(0).Info(msg, keysAndValues...) } } -// LogDebug logs the message using go-logr package on a V=1 level as DEBUG -func LogDebug(logger *logr.Logger, msg string, keysAndValues ...interface{}) { +// Debug logs the message using go-logr package on a V=1 level as DEBUG +func Debug(logger *logr.Logger, msg string, keysAndValues ...interface{}) { if (*logger).V(1).Enabled() { (*logger).V(1).Info(fmt.Sprintf("DEBUG: %s", msg), keysAndValues...) } } -// LogTrace logs the message using go-logr package on a V=1 level as TRACE -func LogTrace(logger *logr.Logger, msg string, keysAndValues ...interface{}) { +// Trace logs the message using go-logr package on a V=1 level as TRACE +func Trace(logger *logr.Logger, msg string, keysAndValues ...interface{}) { if (*logger).V(2).Enabled() { (*logger).V(1).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) } From 7344506becc537bdb8cab6698aa1d1a0a6a28545 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Wed, 9 Oct 2019 15:28:08 +0200 Subject: [PATCH 04/14] Remove 'Log' prefix from Error logging function name to reduce boilerplate code. --- cmd/manager/main.go | 16 ++++++++-------- .../servicebindingrequest/annotations.go | 2 +- pkg/controller/servicebindingrequest/binder.go | 4 ++-- pkg/controller/servicebindingrequest/mapper.go | 2 +- pkg/controller/servicebindingrequest/olm.go | 16 ++++++++-------- pkg/controller/servicebindingrequest/planner.go | 2 +- .../servicebindingrequest/reconciler.go | 16 ++++++++-------- .../servicebindingrequest/retriever.go | 6 +++--- .../servicebindingrequest/sbrcontroller.go | 14 +++++++------- pkg/controller/servicebindingrequest/watch.go | 4 ++-- pkg/logging/logging.go | 4 ++-- 11 files changed, 43 insertions(+), 43 deletions(-) diff --git a/cmd/manager/main.go b/cmd/manager/main.go index 754a203233..cd6843c320 100644 --- a/cmd/manager/main.go +++ b/cmd/manager/main.go @@ -70,14 +70,14 @@ func main() { namespace, err := k8sutil.GetWatchNamespace() if err != nil { - logging.LogError(err, &mainLogger, "Failed to get watch namespace") + logging.Error(err, &mainLogger, "Failed to get watch namespace") os.Exit(1) } // Get a config to talk to the apiserver cfg, err := config.GetConfig() if err != nil { - logging.LogError(err, &mainLogger, "Failed to acquire a configuration to talk to the API server") + logging.Error(err, &mainLogger, "Failed to acquire a configuration to talk to the API server") os.Exit(1) } @@ -88,7 +88,7 @@ func main() { // Become the leader before proceeding err = leader.Become(ctx, fmt.Sprintf("%s-lock", getOperatorName())) if err != nil { - logging.LogError(err, &mainLogger, "Failed to become the leader") + logging.Error(err, &mainLogger, "Failed to become the leader") os.Exit(1) } } else { @@ -102,7 +102,7 @@ func main() { MetricsBindAddress: fmt.Sprintf("%s:%d", metricsHost, metricsPort), }) if err != nil { - logging.LogError(err, &mainLogger, "Error on creating a new manager instance") + logging.Error(err, &mainLogger, "Error on creating a new manager instance") os.Exit(1) } @@ -110,18 +110,18 @@ func main() { // Setup Scheme for all resources if err := apis.AddToScheme(mgr.GetScheme()); err != nil { - logging.LogError(err, &mainLogger, "Error adding local operator scheme") + logging.Error(err, &mainLogger, "Error adding local operator scheme") os.Exit(1) } if err := osappsv1.AddToScheme(mgr.GetScheme()); err != nil { - logging.LogError(err, &mainLogger, "Error on adding OS APIs to scheme") + logging.Error(err, &mainLogger, "Error on adding OS APIs to scheme") os.Exit(1) } // Setup all Controllers if err := controller.AddToManager(mgr); err != nil { - logging.LogError(err, &mainLogger, "Failed to setup the controller manager") + logging.Error(err, &mainLogger, "Failed to setup the controller manager") os.Exit(1) } @@ -157,7 +157,7 @@ func main() { // Start the Cmd if err := mgr.Start(signals.SetupSignalHandler()); err != nil { - logging.LogError(err, &mainLogger, "Manager exited non-zero") + logging.Error(err, &mainLogger, "Manager exited non-zero") os.Exit(1) } } diff --git a/pkg/controller/servicebindingrequest/annotations.go b/pkg/controller/servicebindingrequest/annotations.go index 25a2631739..4d9290dabc 100644 --- a/pkg/controller/servicebindingrequest/annotations.go +++ b/pkg/controller/servicebindingrequest/annotations.go @@ -110,7 +110,7 @@ func SetSBRAnnotations( logging.Debug(&log, "Updating resource annotations...") _, err := client.Resource(gvr).Namespace(obj.GetNamespace()).Update(obj, opts) if err != nil { - logging.LogError(err, &log, "unable to set/update annotations in object") + logging.Error(err, &log, "unable to set/update annotations in object") return err } } diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index 2e250247d1..3fb0706203 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -158,7 +158,7 @@ func (b *Binder) updateSpecContainers( if !found { err = fmt.Errorf("unable to find '%#v' in object kind '%s'", containersPath, obj.GetKind()) - logging.LogError(err, &log, "is this definition supported by this operator?") + logging.Error(err, &log, "is this definition supported by this operator?") return nil, err } @@ -183,7 +183,7 @@ func (b *Binder) updateContainers( containers[i], err = b.updateContainer(container) if err != nil { - logging.LogError(err, &log, "during container update.") + logging.Error(err, &log, "during container update.") return nil, err } } diff --git a/pkg/controller/servicebindingrequest/mapper.go b/pkg/controller/servicebindingrequest/mapper.go index 2530de1daa..69ebd215d0 100644 --- a/pkg/controller/servicebindingrequest/mapper.go +++ b/pkg/controller/servicebindingrequest/mapper.go @@ -25,7 +25,7 @@ func (m *SBRRequestMapper) Map(obj handler.MapObject) []reconcile.Request { sbrNamespacedName, err := GetSBRNamespacedNameFromObject(obj.Object) if err != nil { - logging.LogError(err, &log, "on inspecting object for annotations for SBR object") + logging.Error(err, &log, "on inspecting object for annotations for SBR object") return toReconcile } if IsNamespacedNameEmpty(sbrNamespacedName) { diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index 550729e2e3..020dacdebc 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -38,7 +38,7 @@ func (o *OLM) listCSVs() ([]unstructured.Unstructured, error) { resourceClient := o.client.Resource(gvr).Namespace(o.ns) csvs, err := resourceClient.List(metav1.ListOptions{}) if err != nil { - logging.LogError(err, log, "during listing CSV objects from cluster") + logging.Error(err, log, "during listing CSV objects from cluster") return nil, err } return csvs.Items, nil @@ -55,7 +55,7 @@ func (o *OLM) extractOwnedCRDs( ownedCRDs, exists, err := unstructured.NestedSlice(csv.Object, ownedPath...) if err != nil { - logging.LogError(err, &log, "on extracting nested slice") + logging.Error(err, &log, "on extracting nested slice") return nil, err } if !exists { @@ -76,7 +76,7 @@ func (o *OLM) ListCSVOwnedCRDs() ([]unstructured.Unstructured, error) { log := &(o.logger) csvs, err := o.listCSVs() if err != nil { - logging.LogError(err, log, "on listting CSVs") + logging.Error(err, log, "on listting CSVs") return nil, err } return o.extractOwnedCRDs(csvs) @@ -97,7 +97,7 @@ func (o *OLM) loopCRDDescriptions( crdDescription := &olmv1alpha1.CRDDescription{} err := runtime.DefaultUnstructuredConverter.FromUnstructured(u.Object, crdDescription) if err != nil { - logging.LogError(err, log, "on converting from unstructured to CRD") + logging.Error(err, log, "on converting from unstructured to CRD") return err } logging.Debug(log, "Inspecting CRDDescription...", "CRDDescription", crdDescription) @@ -115,7 +115,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr log := o.logger.WithValues("Selector.GVK", gvk) ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - logging.LogError(err, &log, "on listing owned CRDs") + logging.Error(err, &log, "on listing owned CRDs") return nil, err } @@ -176,7 +176,7 @@ func (o *OLM) ListCSVOwnedCRDsAsGVKs() ([]schema.GroupVersionKind, error) { log := &(o.logger) ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - logging.LogError(err, log, "on listting CSVs") + logging.Error(err, log, "on listting CSVs") return nil, err } return o.extractGVKs(ownedCRDs) @@ -192,7 +192,7 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( resourceClient := o.client.Resource(gvr).Namespace(namespacedName.Namespace) u, err := resourceClient.Get(namespacedName.Name, metav1.GetOptions{}) if err != nil { - logging.LogError(err, &log, "on reading CSV object") + logging.Error(err, &log, "on reading CSV object") return []schema.GroupVersionKind{}, err } @@ -201,7 +201,7 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( ownedCRDs, err := o.extractOwnedCRDs(csvs) if err != nil { - logging.LogError(err, &log, "on extracting owned CRDs") + logging.Error(err, &log, "on extracting owned CRDs") return []schema.GroupVersionKind{}, err } diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index 001364c058..d99dee1995 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -49,7 +49,7 @@ func (p *Planner) searchCR(kind string) (*unstructured.Unstructured, error) { cr, err := p.client.Resource(gvr).Namespace(p.sbr.GetNamespace()).Get(bss.ResourceRef, opts) if err != nil { - logging.LogError(err, &log, "during reading CR") + logging.Error(err, &log, "during reading CR") return nil, err } diff --git a/pkg/controller/servicebindingrequest/reconciler.go b/pkg/controller/servicebindingrequest/reconciler.go index 45ff8dcb4a..069e5dbecb 100644 --- a/pkg/controller/servicebindingrequest/reconciler.go +++ b/pkg/controller/servicebindingrequest/reconciler.go @@ -135,7 +135,7 @@ func checkSBR(sbr *v1alpha1.ServiceBindingRequest, log logr.Logger) error { if sbr.Spec.ApplicationSelector.MatchLabels == nil { err := errors.New("NotFoundError") - logging.LogError(err, &log, "Spec.ApplicationSelector.MatchLabels not found") + logging.Error(err, &log, "Spec.ApplicationSelector.MatchLabels not found") return err } } @@ -164,7 +164,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // fetch the ServiceBindingRequest instance sbr, err := r.getServiceBindingRequest(request.NamespacedName) if err != nil { - logging.LogError(err, &log, "On retrieving service-binding-request instance.") + logging.Error(err, &log, "On retrieving service-binding-request instance.") return RequeueError(err) } @@ -177,7 +177,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Check Service Binding Request err = checkSBR(sbr, log) if err != nil { - logging.LogError(err, &log, "") + logging.Error(err, &log, "") return RequeueError(err) } @@ -189,7 +189,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err planner := NewPlanner(ctx, r.dynClient, sbr) plan, err := planner.Plan() if err != nil { - logging.LogError(err, &log, "On creating a plan to bind applications.") + logging.Error(err, &log, "On creating a plan to bind applications.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -204,7 +204,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err retriever := NewRetriever(r.dynClient, plan, sbr.Spec.EnvVarPrefix) retrievedObjects, err := retriever.Retrieve() if err != nil { - logging.LogError(err, &log, "On retrieving binding data.") + logging.Error(err, &log, "On retrieving binding data.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -221,7 +221,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err binder := NewBinder(ctx, r.client, r.dynClient, sbr, retriever.volumeKeys) updatedObjects, err := binder.Bind() if err != nil { - logging.LogError(err, &log, "On binding application.") + logging.Error(err, &log, "On binding application.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } @@ -235,13 +235,13 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // if err = SetSBRAnnotations(r.dynClient, request.NamespacedName, objectsToAnnotate); err != nil { - logging.LogError(err, &log, "On setting annotations in related objects.") + logging.Error(err, &log, "On setting annotations in related objects.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } // updating status of request instance if err = r.updateStatusServiceBindingRequest(sbr, &sbrStatus); err != nil { - logging.LogError(err, &log, "On updating status of ServiceBindingRequest.") + logging.Error(err, &log, "On updating status of ServiceBindingRequest.") return RequeueError(err) } diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index 6c9b7c50d0..db1a2e24dc 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -295,7 +295,7 @@ func (r *Retriever) saveDataOnSecret() error { data, err := runtime.DefaultUnstructuredConverter.ToUnstructured(secretObj) if err != nil { - logging.LogError(err, &log, "Converting secret to unstructured") + logging.Error(err, &log, "Converting secret to unstructured") return err } u := &unstructured.Unstructured{Object: data} @@ -304,13 +304,13 @@ func (r *Retriever) saveDataOnSecret() error { logging.Debug(&log, "Creating intermediary secret...") _, err = resourceClient.Create(u, metav1.CreateOptions{}) if err != nil && !errors.IsAlreadyExists(err) { - logging.LogError(err, &log, "on creating intermediary secret") + logging.Error(err, &log, "on creating intermediary secret") return err } logging.Debug(&log, "Secret is already found, updating...") _, err = resourceClient.Update(u, metav1.UpdateOptions{}) if err != nil { - logging.LogError(err, &log, "on updating intermediary secret") + logging.Error(err, &log, "on updating intermediary secret") return err } diff --git a/pkg/controller/servicebindingrequest/sbrcontroller.go b/pkg/controller/servicebindingrequest/sbrcontroller.go index 8f1555e410..4a22b8b94b 100644 --- a/pkg/controller/servicebindingrequest/sbrcontroller.go +++ b/pkg/controller/servicebindingrequest/sbrcontroller.go @@ -74,7 +74,7 @@ func (s *SBRController) getWatchingGVKs() ([]schema.GroupVersionKind, error) { olm := NewOLM(s.Client, os.Getenv("WATCH_NAMESPACE")) olmGVKs, err := olm.ListCSVOwnedCRDsAsGVKs() if err != nil { - logging.LogError(err, log, "On listing owned CSV as GVKs") + logging.Error(err, log, "On listing owned CSV as GVKs") return nil, err } logging.Debug(log, "Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) @@ -119,7 +119,7 @@ func (s *SBRController) addSBRWatch() error { source := s.createSourceForGVK(gvk) err := s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) if err != nil { - logging.LogError(err, &log, "on creating watch for ServiceBindingRequest") + logging.Error(err, &log, "on creating watch for ServiceBindingRequest") return err } logging.Debug(&log, "Watch added for ServiceBindingRequest") @@ -133,7 +133,7 @@ func (s *SBRController) addWhitelistedGVKWatches() error { // list of interesting GVKs to watch gvks, err := s.getWatchingGVKs() if err != nil { - logging.LogError(err, log, "on retrieving list of GVKs to watch") + logging.Error(err, log, "on retrieving list of GVKs to watch") return err } @@ -141,7 +141,7 @@ func (s *SBRController) addWhitelistedGVKWatches() error { logging.Debug(log, "Adding watch for whitelisted GVK...", "GVK", gvk) err = s.AddWatchForGVK(gvk) if err != nil { - logging.LogError(err, log, "on creating watch for GVK") + logging.Error(err, log, "on creating watch for GVK") return err } } @@ -154,19 +154,19 @@ func (s *SBRController) Watch() error { log := &(s.logger) err := s.addSBRWatch() if err != nil { - logging.LogError(err, log, "on adding watch for ServiceBindingRequest") + logging.Error(err, log, "on adding watch for ServiceBindingRequest") return err } err = s.addWhitelistedGVKWatches() if err != nil { - logging.LogError(err, log, "on adding watch for whitelisted GVKs") + logging.Error(err, log, "on adding watch for whitelisted GVKs") return err } err = s.addCSVWatch() if err != nil { - logging.LogError(err, log, "on adding watch for ClusterServiceVersion") + logging.Error(err, log, "on adding watch for ClusterServiceVersion") return err } diff --git a/pkg/controller/servicebindingrequest/watch.go b/pkg/controller/servicebindingrequest/watch.go index c6fb8fe441..c9d3991cb4 100644 --- a/pkg/controller/servicebindingrequest/watch.go +++ b/pkg/controller/servicebindingrequest/watch.go @@ -30,7 +30,7 @@ func (c *CSVToWatcherMapper) Map(obj handler.MapObject) []reconcile.Request { gvks, err := olm.ListGVKsFromCSVNamespacedName(namespacedName) if err != nil { - logging.LogError(err, &log, "Failed on listing GVK with namespaced-name!") + logging.Error(err, &log, "Failed on listing GVK with namespaced-name!") return []reconcile.Request{} } @@ -38,7 +38,7 @@ func (c *CSVToWatcherMapper) Map(obj handler.MapObject) []reconcile.Request { logging.Debug(&log, "Adding watch for GVK", "GVK", gvk) err = c.controller.AddWatchForGVK(gvk) if err != nil { - logging.LogError(err, &log, "Failed to create a watch") + logging.Error(err, &log, "Failed to create a watch") } } diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go index b9b2909b07..3ddff46178 100644 --- a/pkg/logging/logging.go +++ b/pkg/logging/logging.go @@ -7,8 +7,8 @@ import ( logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) -// LogError logs the message using go-logr package on a default level as ERROR -func LogError(err error, logger *logr.Logger, msg string, keysAndValues ...interface{}) { +// Error logs the message using go-logr package on a default level as ERROR +func Error(err error, logger *logr.Logger, msg string, keysAndValues ...interface{}) { (*logger).Error(err, msg, keysAndValues...) } From 6616fcbde78d74ca10d9e99c732ada8c4f50163d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Wed, 9 Oct 2019 15:37:24 +0200 Subject: [PATCH 05/14] Use proper logger pointer. --- pkg/controller/servicebindingrequest/binder.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index 3fb0706203..5ad281a45d 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -115,7 +115,7 @@ func (b *Binder) updateVolumes(volumes []interface{}) ([]interface{}, error) { for _, v := range volumes { volume := v.(corev1.Volume) if name == volume.Name { - logging.Debug(&binderLogger, "Volume is already defined!") + logging.Debug(log, "Volume is already defined!") return volumes, nil } } From 7c07a9c3060f480a2be9512f163630bd62067bf7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Wed, 9 Oct 2019 16:46:29 +0200 Subject: [PATCH 06/14] Encapulate logging methods under Log type to reduce boilerplate code. --- cmd/manager/main.go | 36 +++++------ .../servicebindingrequest/annotations.go | 12 ++-- .../servicebindingrequest/binder.go | 33 +++++----- .../servicebindingrequest/mapper.go | 4 +- pkg/controller/servicebindingrequest/olm.go | 43 ++++++------- .../servicebindingrequest/planner.go | 9 ++- .../servicebindingrequest/reconciler.go | 33 +++++----- .../servicebindingrequest/retriever.go | 47 +++++++------- .../servicebindingrequest/sbrcontroller.go | 39 ++++++----- pkg/controller/servicebindingrequest/watch.go | 6 +- pkg/logging/logging.go | 64 ++++++++++++++----- 11 files changed, 176 insertions(+), 150 deletions(-) diff --git a/cmd/manager/main.go b/cmd/manager/main.go index cd6843c320..9149407e87 100644 --- a/cmd/manager/main.go +++ b/cmd/manager/main.go @@ -40,9 +40,9 @@ var ( ) func printVersion() { - logging.Info(&mainLogger, fmt.Sprintf("Go Version: %s", runtime.Version())) - logging.Info(&mainLogger, fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) - logging.Info(&mainLogger, fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) + mainLogger.Info(fmt.Sprintf("Go Version: %s", runtime.Version())) + mainLogger.Info(fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) + mainLogger.Info(fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) } // getOperatorName based on environment variable OPERATOR_NAME, or returns the default name for @@ -70,14 +70,14 @@ func main() { namespace, err := k8sutil.GetWatchNamespace() if err != nil { - logging.Error(err, &mainLogger, "Failed to get watch namespace") + mainLogger.Error(err, "Failed to get watch namespace") os.Exit(1) } // Get a config to talk to the apiserver cfg, err := config.GetConfig() if err != nil { - logging.Error(err, &mainLogger, "Failed to acquire a configuration to talk to the API server") + mainLogger.Error(err, "Failed to acquire a configuration to talk to the API server") os.Exit(1) } @@ -88,11 +88,11 @@ func main() { // Become the leader before proceeding err = leader.Become(ctx, fmt.Sprintf("%s-lock", getOperatorName())) if err != nil { - logging.Error(err, &mainLogger, "Failed to become the leader") + mainLogger.Error(err, "Failed to become the leader") os.Exit(1) } } else { - logging.Warning(&mainLogger, "Leader election is disabled") + mainLogger.Warning("Leader election is disabled") } // Create a new Cmd to provide shared dependencies and start components @@ -102,31 +102,31 @@ func main() { MetricsBindAddress: fmt.Sprintf("%s:%d", metricsHost, metricsPort), }) if err != nil { - logging.Error(err, &mainLogger, "Error on creating a new manager instance") + mainLogger.Error(err, "Error on creating a new manager instance") os.Exit(1) } - logging.Info(&mainLogger, "Registering Components.") + mainLogger.Info("Registering Components.") // Setup Scheme for all resources if err := apis.AddToScheme(mgr.GetScheme()); err != nil { - logging.Error(err, &mainLogger, "Error adding local operator scheme") + mainLogger.Error(err, "Error adding local operator scheme") os.Exit(1) } if err := osappsv1.AddToScheme(mgr.GetScheme()); err != nil { - logging.Error(err, &mainLogger, "Error on adding OS APIs to scheme") + mainLogger.Error(err, "Error on adding OS APIs to scheme") os.Exit(1) } // Setup all Controllers if err := controller.AddToManager(mgr); err != nil { - logging.Error(err, &mainLogger, "Failed to setup the controller manager") + mainLogger.Error(err, "Failed to setup the controller manager") os.Exit(1) } if err = serveCRMetrics(cfg); err != nil { - logging.Info(&mainLogger, "Could not generate and serve custom resource metrics", "error", err.Error()) + mainLogger.Info("Could not generate and serve custom resource metrics", "error", err.Error()) } // Add to the below struct any other metrics ports you want to expose. @@ -137,7 +137,7 @@ func main() { // Create Service object to expose the metrics port(s). service, err := metrics.CreateMetricsService(ctx, cfg, servicePorts) if err != nil { - logging.Info(&mainLogger, "Could not create metrics Service", "error", err.Error()) + mainLogger.Info("Could not create metrics Service", "error", err.Error()) } // CreateServiceMonitors will automatically create the prometheus-operator ServiceMonitor resources @@ -145,19 +145,19 @@ func main() { services := []*v1.Service{service} _, err = metrics.CreateServiceMonitors(cfg, namespace, services) if err != nil { - logging.Info(&mainLogger, "Could not create ServiceMonitor object", "error", err.Error()) + mainLogger.Info("Could not create ServiceMonitor object", "error", err.Error()) // If this operator is deployed to a cluster without the prometheus-operator running, it will return // ErrServiceMonitorNotPresent, which can be used to safely skip ServiceMonitor creation. if err == metrics.ErrServiceMonitorNotPresent { - logging.Info(&mainLogger, "Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) + mainLogger.Info("Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) } } - logging.Info(&mainLogger, "Starting the Cmd.") + mainLogger.Info("Starting the Cmd.") // Start the Cmd if err := mgr.Start(signals.SetupSignalHandler()); err != nil { - logging.Error(err, &mainLogger, "Manager exited non-zero") + mainLogger.Error(err, "Manager exited non-zero") os.Exit(1) } } diff --git a/pkg/controller/servicebindingrequest/annotations.go b/pkg/controller/servicebindingrequest/annotations.go index 4d9290dabc..0353ba6302 100644 --- a/pkg/controller/servicebindingrequest/annotations.go +++ b/pkg/controller/servicebindingrequest/annotations.go @@ -60,22 +60,22 @@ func GetSBRNamespacedNameFromObject(obj runtime.Object) (types.NamespacedName, e ) if IsNamespacedNameEmpty(sbrNamespacedName) { - logging.Debug(&log, "SBR information not present in annotations, continue inspecting object") + log.Debug("SBR information not present in annotations, continue inspecting object") } else { // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - logging.Trace(&log, "SBR information found in annotations, returning it") + log.Trace("SBR information found in annotations, returning it") return sbrNamespacedName, nil } if u.GroupVersionKind() == v1alpha1.SchemeGroupVersion.WithKind(ServiceBindingRequestKind) { - logging.Debug(&log, "Object is a SBR, returning its namespaced name") + log.Debug("Object is a SBR, returning its namespaced name") sbrNamespacedName.Namespace = u.GetNamespace() sbrNamespacedName.Name = u.GetName() return sbrNamespacedName, nil } // FIXME: Increase V level for tracing info to avoid flooding logs with this information. - logging.Trace(&log, "Object is not a SBR, returning an empty namespaced name") + log.Trace("Object is not a SBR, returning an empty namespaced name") return sbrNamespacedName, nil } @@ -107,10 +107,10 @@ func SetSBRAnnotations( "Resource.Namespace", obj.GetNamespace(), "Resource.Name", obj.GetName(), ) - logging.Debug(&log, "Updating resource annotations...") + log.Debug("Updating resource annotations...") _, err := client.Resource(gvr).Namespace(obj.GetNamespace()).Update(obj, opts) if err != nil { - logging.Error(err, &log, "unable to set/update annotations in object") + log.Error(err, "unable to set/update annotations in object") return err } } diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index 5ad281a45d..c5399f2206 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -5,7 +5,6 @@ import ( "fmt" "time" - "github.com/go-logr/logr" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -38,7 +37,7 @@ type Binder struct { dynClient dynamic.Interface // kubernetes dynamic api client sbr *v1alpha1.ServiceBindingRequest // instantiated service binding request volumeKeys []string // list of key names used in volume mounts - logger logr.Logger // logger instance + logger *logging.Log // logger instance } // search objects based in Kind/APIVersion, which contain the labels defined in ApplicationSelector. @@ -88,12 +87,12 @@ func (b *Binder) updateSpecVolumes( volumesPath := []string{"spec", "template", "spec", "volumes"} log := b.logger.WithValues("Volumes.NestedPath", volumesPath) - logging.Debug(&log, "Reading volumes definitions...") + log.Debug("Reading volumes definitions...") volumes, _, err := unstructured.NestedSlice(obj.Object, volumesPath...) if err != nil { return nil, err } - logging.Debug(&log, "Amount of volumes in spec.", "Volumes", len(volumes)) + log.Debug("Amount of volumes in spec.", "Volumes", len(volumes)) volumes, err = b.updateVolumes(volumes) if err != nil { @@ -110,12 +109,12 @@ func (b *Binder) updateSpecVolumes( // defined just return the same list, otherwise, appending the binding volume. func (b *Binder) updateVolumes(volumes []interface{}) ([]interface{}, error) { name := b.sbr.GetName() - log := &(b.logger) - logging.Debug(log, "Checking if binding volume is already defined...") + log := b.logger + log.Debug("Checking if binding volume is already defined...") for _, v := range volumes { volume := v.(corev1.Volume) if name == volume.Name { - logging.Debug(log, "Volume is already defined!") + log.Debug("Volume is already defined!") return volumes, nil } } @@ -125,7 +124,7 @@ func (b *Binder) updateVolumes(volumes []interface{}) ([]interface{}, error) { items = append(items, corev1.KeyToPath{Key: k, Path: k}) } - logging.Debug(log, "Appending new volume with items.", "Items", items) + log.Debug("Appending new volume with items.", "Items", items) bindVolume := corev1.Volume{ Name: name, VolumeSource: corev1.VolumeSource{ @@ -158,7 +157,7 @@ func (b *Binder) updateSpecContainers( if !found { err = fmt.Errorf("unable to find '%#v' in object kind '%s'", containersPath, obj.GetKind()) - logging.Error(err, &log, "is this definition supported by this operator?") + log.Error(err, "is this definition supported by this operator?") return nil, err } @@ -179,11 +178,11 @@ func (b *Binder) updateContainers( for i, container := range containers { log := b.logger.WithValues("Obj.Container.Number", i) - logging.Debug(&log, "Inspecting container...") + log.Debug("Inspecting container...") containers[i], err = b.updateContainer(container) if err != nil { - logging.Error(err, &log, "during container update.") + log.Error(err, "during container update.") return nil, err } } @@ -215,16 +214,16 @@ func (b *Binder) appendEnvVar(envList []corev1.EnvVar, envParam string, envValue // appendEnvFrom based on secret name and list of EnvFromSource instances, making sure secret is // part of the list or appended. func (b *Binder) appendEnvFrom(envList []corev1.EnvFromSource, secret string) []corev1.EnvFromSource { - log := &(b.logger) + log := b.logger for _, env := range envList { if env.SecretRef.Name == secret { - logging.Debug(log, "Directive 'envFrom' is already present!") + log.Debug("Directive 'envFrom' is already present!") // secret name is already referenced return envList } } - logging.Debug(log, "Adding 'envFrom' directive...") + log.Debug("Adding 'envFrom' directive...") return append(envList, corev1.EnvFromSource{ SecretRef: &corev1.SecretEnvSource{ LocalObjectReference: corev1.LocalObjectReference{ @@ -282,7 +281,7 @@ func (b *Binder) update(objs *unstructured.UnstructuredList) ([]*unstructured.Un for _, obj := range objs.Items { name := obj.GetName() log := b.logger.WithValues("Obj.Name", name, "Obj.Kind", obj.GetKind()) - logging.Debug(&log, "Inspecting object...") + log.Debug("Inspecting object...") updatedObj, err := b.updateSpecContainers(&obj) if err != nil { @@ -296,12 +295,12 @@ func (b *Binder) update(objs *unstructured.UnstructuredList) ([]*unstructured.Un } } - logging.Debug(&log, "Updating object...") + log.Debug("Updating object...") if err := b.client.Update(b.ctx, updatedObj); err != nil { return nil, err } - logging.Debug(&log, "Reading back updated object...") + log.Debug("Reading back updated object...") // reading object back again, to comply with possible modifications namespacedName := types.NamespacedName{ Namespace: updatedObj.GetNamespace(), diff --git a/pkg/controller/servicebindingrequest/mapper.go b/pkg/controller/servicebindingrequest/mapper.go index 69ebd215d0..108a3c2a7f 100644 --- a/pkg/controller/servicebindingrequest/mapper.go +++ b/pkg/controller/servicebindingrequest/mapper.go @@ -25,11 +25,11 @@ func (m *SBRRequestMapper) Map(obj handler.MapObject) []reconcile.Request { sbrNamespacedName, err := GetSBRNamespacedNameFromObject(obj.Object) if err != nil { - logging.Error(err, &log, "on inspecting object for annotations for SBR object") + log.Error(err, "on inspecting object for annotations for SBR object") return toReconcile } if IsNamespacedNameEmpty(sbrNamespacedName) { - logging.Debug(&log, "not able to extract SBR namespaced-name") + log.Debug("not able to extract SBR namespaced-name") return toReconcile } diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index 020dacdebc..badcb54312 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -4,7 +4,6 @@ import ( "fmt" "strings" - "github.com/go-logr/logr" olmv1alpha1 "github.com/operator-framework/operator-lifecycle-manager/pkg/api/apis/operators/v1alpha1" "github.com/redhat-developer/service-binding-operator/pkg/logging" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -20,7 +19,7 @@ import ( type OLM struct { client dynamic.Interface // kubernetes dynamic client ns string // namespace - logger logr.Logger // logger instance + logger *logging.Log // logger instance } const ( @@ -33,12 +32,12 @@ var ( // listCSVs simple list to all CSV objects in the cluster. func (o *OLM) listCSVs() ([]unstructured.Unstructured, error) { - log := &(o.logger) + log := o.logger gvr := olmv1alpha1.SchemeGroupVersion.WithResource(csvResource) resourceClient := o.client.Resource(gvr).Namespace(o.ns) csvs, err := resourceClient.List(metav1.ListOptions{}) if err != nil { - logging.Error(err, log, "during listing CSV objects from cluster") + log.Error(err, "during listing CSV objects from cluster") return nil, err } return csvs.Items, nil @@ -55,7 +54,7 @@ func (o *OLM) extractOwnedCRDs( ownedCRDs, exists, err := unstructured.NestedSlice(csv.Object, ownedPath...) if err != nil { - logging.Error(err, &log, "on extracting nested slice") + log.Error(err, "on extracting nested slice") return nil, err } if !exists { @@ -73,10 +72,10 @@ func (o *OLM) extractOwnedCRDs( // ListCSVOwnedCRDs return a unstructured list of CRD objects from "owned" section in CSVs. func (o *OLM) ListCSVOwnedCRDs() ([]unstructured.Unstructured, error) { - log := &(o.logger) + log := o.logger csvs, err := o.listCSVs() if err != nil { - logging.Error(err, log, "on listting CSVs") + log.Error(err, "on listting CSVs") return nil, err } return o.extractOwnedCRDs(csvs) @@ -93,16 +92,16 @@ func (o *OLM) loopCRDDescriptions( fn eachCRDDescriptionFn, ) error { for _, u := range crdDescriptions { - log := &(o.logger) + log := o.logger crdDescription := &olmv1alpha1.CRDDescription{} err := runtime.DefaultUnstructuredConverter.FromUnstructured(u.Object, crdDescription) if err != nil { - logging.Error(err, log, "on converting from unstructured to CRD") + log.Error(err, "on converting from unstructured to CRD") return err } - logging.Debug(log, "Inspecting CRDDescription...", "CRDDescription", crdDescription) + log.Debug("Inspecting CRDDescription...", "CRDDescription", crdDescription) if crdDescription.Name == "" { - logging.Debug(log, "Skipping empty CRDDescription!") + log.Debug("Skipping empty CRDDescription!") continue } fn(crdDescription) @@ -115,7 +114,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr log := o.logger.WithValues("Selector.GVK", gvk) ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - logging.Error(err, &log, "on listing owned CRDs") + log.Error(err, "on listing owned CRDs") return nil, err } @@ -126,7 +125,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr "CRDDescription.Version", crdDescription.Version, "CRDDescription.Kind", crdDescription.Kind, ) - logging.Debug(&log, "Inspecting CRDDescription object...") + log.Debug("Inspecting CRDDescription object...") // checking for suffix since is expected to have object type as prefix if !strings.EqualFold(strings.ToLower(crdDescription.Kind), strings.ToLower(gvk.Kind)) { return @@ -136,7 +135,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr strings.ToLower(gvk.Version) != strings.ToLower(crdDescription.Version) { return } - logging.Debug(&log, "CRDDescription object matches selector!") + log.Debug("CRDDescription object matches selector!") crdDescriptions = append(crdDescriptions, crdDescription) }) if err != nil { @@ -144,7 +143,7 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr } if len(crdDescriptions) == 0 { - logging.Debug(&log, "No CRD could be found for GVK.") + log.Debug("No CRD could be found for GVK.") return nil, fmt.Errorf("no crd could be found for gvk") } return crdDescriptions[0], nil @@ -154,10 +153,10 @@ func (o *OLM) SelectCRDByGVK(gvk schema.GroupVersionKind) (*olmv1alpha1.CRDDescr func (o *OLM) extractGVKs( crdDescriptions []unstructured.Unstructured, ) ([]schema.GroupVersionKind, error) { - log := &(o.logger) + log := o.logger gvks := []schema.GroupVersionKind{} err := o.loopCRDDescriptions(crdDescriptions, func(crdDescription *olmv1alpha1.CRDDescription) { - logging.Debug(log, "Extracting GVK from CRDDescription", "CRDDescription.Name", crdDescription.Name) + log.Debug("Extracting GVK from CRDDescription", "CRDDescription.Name", crdDescription.Name) _, gv := schema.ParseResourceArg(crdDescription.Name) gvks = append(gvks, schema.GroupVersionKind{ Group: gv.Group, @@ -173,10 +172,10 @@ func (o *OLM) extractGVKs( // ListCSVOwnedCRDsAsGVKs return the list of owned CRDs from all CSV objects as a list of GVKs. func (o *OLM) ListCSVOwnedCRDsAsGVKs() ([]schema.GroupVersionKind, error) { - log := &(o.logger) + log := o.logger ownedCRDs, err := o.ListCSVOwnedCRDs() if err != nil { - logging.Error(err, log, "on listting CSVs") + log.Error(err, "on listting CSVs") return nil, err } return o.extractGVKs(ownedCRDs) @@ -187,12 +186,12 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( namespacedName types.NamespacedName, ) ([]schema.GroupVersionKind, error) { log := o.logger.WithValues("CSV.NamespacedName", namespacedName) - logging.Debug(&log, "Reading CSV to extract GVKs...") + log.Debug("Reading CSV to extract GVKs...") gvr := olmv1alpha1.SchemeGroupVersion.WithResource(csvResource) resourceClient := o.client.Resource(gvr).Namespace(namespacedName.Namespace) u, err := resourceClient.Get(namespacedName.Name, metav1.GetOptions{}) if err != nil { - logging.Error(err, &log, "on reading CSV object") + log.Error(err, "on reading CSV object") return []schema.GroupVersionKind{}, err } @@ -201,7 +200,7 @@ func (o *OLM) ListGVKsFromCSVNamespacedName( ownedCRDs, err := o.extractOwnedCRDs(csvs) if err != nil { - logging.Error(err, &log, "on extracting owned CRDs") + log.Error(err, "on extracting owned CRDs") return []schema.GroupVersionKind{}, err } diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index d99dee1995..e4084b3ab9 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -3,7 +3,6 @@ package servicebindingrequest import ( "context" - "github.com/go-logr/logr" olmv1alpha1 "github.com/operator-framework/operator-lifecycle-manager/pkg/api/apis/operators/v1alpha1" "k8s.io/apimachinery/pkg/api/meta" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -25,7 +24,7 @@ type Planner struct { ctx context.Context // request context client dynamic.Interface // kubernetes dynamic api client sbr *v1alpha1.ServiceBindingRequest // instantiated service binding request - logger logr.Logger // logger instance + logger *logging.Log // logger instance } // Plan outcome, after executing planner. @@ -45,15 +44,15 @@ func (p *Planner) searchCR(kind string) (*unstructured.Unstructured, error) { opts := metav1.GetOptions{} log := p.logger.WithValues("CR.GVK", gvk.String(), "CR.GVR", gvr.String()) - logging.Debug(&log, "Searching for CR instance...") + log.Debug("Searching for CR instance...") cr, err := p.client.Resource(gvr).Namespace(p.sbr.GetNamespace()).Get(bss.ResourceRef, opts) if err != nil { - logging.Error(err, &log, "during reading CR") + log.Error(err, "during reading CR") return nil, err } - logging.Debug(&log, "Found target CR!", "CR.Name", cr.GetName()) + log.Debug("Found target CR!", "CR.Name", cr.GetName()) return cr, nil } diff --git a/pkg/controller/servicebindingrequest/reconciler.go b/pkg/controller/servicebindingrequest/reconciler.go index 069e5dbecb..70d3b4838b 100644 --- a/pkg/controller/servicebindingrequest/reconciler.go +++ b/pkg/controller/servicebindingrequest/reconciler.go @@ -13,7 +13,6 @@ import ( "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/reconcile" - "github.com/go-logr/logr" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" "github.com/redhat-developer/service-binding-operator/pkg/logging" ) @@ -126,16 +125,16 @@ func (r *Reconciler) onError( } // checkSBR checks the Service Binding Request -func checkSBR(sbr *v1alpha1.ServiceBindingRequest, log logr.Logger) error { +func checkSBR(sbr *v1alpha1.ServiceBindingRequest, log *logging.Log) error { // Check if application ResourceRef is present if sbr.Spec.ApplicationSelector.ResourceRef == "" { - logging.Debug(&log, "Spec.ApplicationSelector.ResourceRef not found") + log.Debug("Spec.ApplicationSelector.ResourceRef not found") // Check if MatchLabels is present if sbr.Spec.ApplicationSelector.MatchLabels == nil { err := errors.New("NotFoundError") - logging.Error(err, &log, "Spec.ApplicationSelector.MatchLabels not found") + log.Error(err, "Spec.ApplicationSelector.MatchLabels not found") return err } } @@ -159,17 +158,17 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err "Request.Namespace", request.Namespace, "Request.Name", request.Name, ) - logging.Info(&log, "Reconciling ServiceBindingRequest...") + log.Info("Reconciling ServiceBindingRequest...") // fetch the ServiceBindingRequest instance sbr, err := r.getServiceBindingRequest(request.NamespacedName) if err != nil { - logging.Error(err, &log, "On retrieving service-binding-request instance.") + log.Error(err, "On retrieving service-binding-request instance.") return RequeueError(err) } log = log.WithValues("ServiceBindingRequest.Name", sbr.Name) - logging.Debug(&log, "Found service binding request to inspect") + log.Debug("Found service binding request to inspect") // splitting instance from it's status sbrStatus := sbr.Status @@ -177,7 +176,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Check Service Binding Request err = checkSBR(sbr, log) if err != nil { - logging.Error(err, &log, "") + log.Error(err, "") return RequeueError(err) } @@ -185,11 +184,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Planing changes // - logging.Debug(&log, "Creating a plan based on OLM and CRD.") + log.Debug("Creating a plan based on OLM and CRD.") planner := NewPlanner(ctx, r.dynClient, sbr) plan, err := planner.Plan() if err != nil { - logging.Error(err, &log, "On creating a plan to bind applications.") + log.Error(err, "On creating a plan to bind applications.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -200,11 +199,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Retrieving data // - logging.Debug(&log, "Retrieving data to create intermediate secret.") + log.Debug("Retrieving data to create intermediate secret.") retriever := NewRetriever(r.dynClient, plan, sbr.Spec.EnvVarPrefix) retrievedObjects, err := retriever.Retrieve() if err != nil { - logging.Error(err, &log, "On retrieving binding data.") + log.Error(err, "On retrieving binding data.") return r.onError(err, sbr, &sbrStatus, nil) } @@ -217,11 +216,11 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // Updating applications to use intermediary secret // - logging.Info(&log, "Binding applications with intermediary secret.") + log.Info("Binding applications with intermediary secret.") binder := NewBinder(ctx, r.client, r.dynClient, sbr, retriever.volumeKeys) updatedObjects, err := binder.Bind() if err != nil { - logging.Error(err, &log, "On binding application.") + log.Error(err, "On binding application.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } @@ -235,16 +234,16 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err // if err = SetSBRAnnotations(r.dynClient, request.NamespacedName, objectsToAnnotate); err != nil { - logging.Error(err, &log, "On setting annotations in related objects.") + log.Error(err, "On setting annotations in related objects.") return r.onError(err, sbr, &sbrStatus, updatedObjects) } // updating status of request instance if err = r.updateStatusServiceBindingRequest(sbr, &sbrStatus); err != nil { - logging.Error(err, &log, "On updating status of ServiceBindingRequest.") + log.Error(err, "On updating status of ServiceBindingRequest.") return RequeueError(err) } - logging.Info(&log, "All done!") + log.Info("All done!") return Done() } diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index db1a2e24dc..867a307d0b 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -5,7 +5,6 @@ import ( "fmt" "strings" - "github.com/go-logr/logr" "github.com/redhat-developer/service-binding-operator/pkg/logging" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" @@ -18,7 +17,7 @@ import ( // Retriever reads all data referred in plan instance, and store in a secret. type Retriever struct { - logger logr.Logger // logger instance + logger *logging.Log // logger instance data map[string][]byte // data retrieved objects []*unstructured.Unstructured // list of objects employed client dynamic.Interface // Kubernetes API client @@ -52,7 +51,7 @@ func (r *Retriever) getNestedValue(key string, sectionMap interface{}) (string, } attrs := strings.SplitN(key, ".", 2) newSectionMap, exists := sectionMap.(map[string]interface{})[attrs[0]] - logging.Debug(&log, "Section maps : ") + log.Debug("Section maps : ") if !exists { return "", fmt.Errorf("Can't find '%v' section in CR", attrs), newSectionMap } @@ -64,7 +63,7 @@ func (r *Retriever) getCRKey(section string, key string) (string, interface{}, e obj := r.plan.CR.Object objName := r.plan.CR.GetName() log := r.logger.WithValues("CR.Name", objName, "CR.section", section, "CR.key", key) - logging.Debug(&log, "Reading CR attributes...") + log.Debug("Reading CR attributes...") sectionMap, exists := obj[section] if !exists { @@ -90,7 +89,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { "CRDDescription.Path", path, "CRDDescription.XDescriptors", xDescriptors, ) - logging.Debug(&log, "Reading CRDDescription attributes...") + log.Debug("Reading CRDDescription attributes...") // holds the secret name and items secrets := make(map[string][]string) @@ -100,7 +99,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { pathValue, _, err := r.getCRKey(place, path) for _, xDescriptor := range xDescriptors { log = log.WithValues("CRDDescription.xDescriptor", xDescriptor, "cache", r.cache) - logging.Debug(&log, "Inspecting xDescriptor...") + log.Debug("Inspecting xDescriptor...") if err != nil { return err } @@ -124,7 +123,7 @@ func (r *Retriever) read(place, path string, xDescriptors []string) error { } else if strings.HasPrefix(xDescriptor, attributePrefix) { r.store(path, []byte(pathValue)) } else { - logging.Debug(&log, "Defaulting....") + log.Debug("Defaulting....") } } @@ -181,7 +180,7 @@ func (r *Retriever) readSecret( fromPath string, path string) error { log := r.logger.WithValues("Secret.Name", name, "Secret.Items", items) - logging.Debug(&log, "Reading secret items...") + log.Debug("Reading secret items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "secrets"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -204,7 +203,7 @@ func (r *Retriever) readSecret( return err } log = log.WithValues("Secret.Key.Name", k, "Secret.Key.Length", len(data)) - logging.Debug(&log, "Inspecting secret key...") + log.Debug("Inspecting secret key...") r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = string(value) @@ -225,7 +224,7 @@ func (r *Retriever) readConfigMap( fromPath string, path string) error { log := r.logger.WithValues("ConfigMap.Name", name, "ConfigMap.Items", items) - logging.Debug(&log, "Reading ConfigMap items...") + log.Debug("Reading ConfigMap items...") gvr := schema.GroupVersionResource{Group: "", Version: "v1", Resource: "configmaps"} u, err := r.client.Resource(gvr).Namespace(r.plan.Ns).Get(name, metav1.GetOptions{}) @@ -241,10 +240,10 @@ func (r *Retriever) readConfigMap( return fmt.Errorf("could not find 'data' in secret") } - logging.Debug(&log, "Inspecting configMap data...") + log.Debug("Inspecting configMap data...") for k, v := range data { value := v.(string) - logging.Debug(&log, "Inspecting configMap key...", "configMap.Key.Name", k, "configMap.Key.Length", len(value)) + log.Debug("Inspecting configMap key...", "configMap.Key.Name", k, "configMap.Key.Length", len(value)) r.markVisitedPaths(path, k, fromPath) // update cache after reading configmap/secret in cache r.cache[fromPath].(map[string]interface{})[path].(map[string]interface{})[k] = value @@ -279,7 +278,7 @@ func (r *Retriever) saveDataOnSecret() error { "Secret.Namespace", r.plan.Ns, "Secret.Name", r.plan.Name, ) - logging.Debug(&log, "Retrieving intermediary secret...") + log.Debug("Retrieving intermediary secret...") secretObj := &corev1.Secret{ TypeMeta: metav1.TypeMeta{ @@ -295,26 +294,26 @@ func (r *Retriever) saveDataOnSecret() error { data, err := runtime.DefaultUnstructuredConverter.ToUnstructured(secretObj) if err != nil { - logging.Error(err, &log, "Converting secret to unstructured") + log.Error(err, "Converting secret to unstructured") return err } u := &unstructured.Unstructured{Object: data} u.SetGroupVersionKind(gvk) - logging.Debug(&log, "Creating intermediary secret...") + log.Debug("Creating intermediary secret...") _, err = resourceClient.Create(u, metav1.CreateOptions{}) if err != nil && !errors.IsAlreadyExists(err) { - logging.Error(err, &log, "on creating intermediary secret") + log.Error(err, "on creating intermediary secret") return err } - logging.Debug(&log, "Secret is already found, updating...") + log.Debug("Secret is already found, updating...") _, err = resourceClient.Update(u, metav1.UpdateOptions{}) if err != nil { - logging.Error(err, &log, "on updating intermediary secret") + log.Error(err, "on updating intermediary secret") return err } - logging.Debug(&log, "Intermediary secret created/updated!") + log.Debug("Intermediary secret created/updated!") r.objects = append(r.objects, u) return nil } @@ -323,22 +322,22 @@ func (r *Retriever) saveDataOnSecret() error { // Unstructured refering the objects in use by the Retriever, and error when issues reading fields. func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { var err error - log := &(r.logger) - logging.Debug(log, "Looking for spec-descriptors in 'spec'...") + log := r.logger + log.Debug("Looking for spec-descriptors in 'spec'...") for _, specDescriptor := range r.plan.CRDDescription.SpecDescriptors { if err = r.read("spec", specDescriptor.Path, specDescriptor.XDescriptors); err != nil { return nil, err } } - logging.Debug(log, "Looking for status-descriptors in 'status'...") + log.Debug("Looking for status-descriptors in 'status'...") for _, statusDescriptor := range r.plan.CRDDescription.StatusDescriptors { if err = r.read("status", statusDescriptor.Path, statusDescriptor.XDescriptors); err != nil { return nil, err } } - logging.Debug(log, "Final cache values...", "cache", r.cache) + log.Debug("Final cache values...", "cache", r.cache) envParser := NewCustomEnvParser(r.plan.SBR.Spec.CustomEnvVar, r.cache) values, err := envParser.Parse() @@ -349,7 +348,7 @@ func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { r.data[k] = []byte(v.(string)) } - logging.Debug(log, "Saving data on intermediary secret...") + log.Debug("Saving data on intermediary secret...") if err = r.saveDataOnSecret(); err != nil { return nil, err } diff --git a/pkg/controller/servicebindingrequest/sbrcontroller.go b/pkg/controller/servicebindingrequest/sbrcontroller.go index 4a22b8b94b..6ae9885dfc 100644 --- a/pkg/controller/servicebindingrequest/sbrcontroller.go +++ b/pkg/controller/servicebindingrequest/sbrcontroller.go @@ -3,7 +3,6 @@ package servicebindingrequest import ( "os" - "github.com/go-logr/logr" olmv1alpha1 "github.com/operator-framework/operator-lifecycle-manager/pkg/api/apis/operators/v1alpha1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime/schema" @@ -24,7 +23,7 @@ type SBRController struct { Controller controller.Controller // controller-runtime instance Client dynamic.Interface // kubernetes dynamic api client watchingGVKs map[schema.GroupVersionKind]bool // cache to identify GVKs on watch - logger logr.Logger // logger instance + logger *logging.Log // logger instance } var ( @@ -64,7 +63,7 @@ func (s *SBRController) createUnstructuredWithGVK(gvk schema.GroupVersionKind) * // getWatchingGVKs return a list of GVKs that this controller is interested in watching. func (s *SBRController) getWatchingGVKs() ([]schema.GroupVersionKind, error) { - log := &(s.logger) + log := s.logger // standard resources types gvks := []schema.GroupVersionKind{ {Group: "", Version: "v1", Kind: "Secret"}, @@ -74,40 +73,40 @@ func (s *SBRController) getWatchingGVKs() ([]schema.GroupVersionKind, error) { olm := NewOLM(s.Client, os.Getenv("WATCH_NAMESPACE")) olmGVKs, err := olm.ListCSVOwnedCRDsAsGVKs() if err != nil { - logging.Error(err, log, "On listing owned CSV as GVKs") + log.Error(err, "On listing owned CSV as GVKs") return nil, err } - logging.Debug(log, "Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) + log.Debug("Amount of GVK founds in CSV objects.", "CSVOwnedGVK.Amount", len(olmGVKs)) return append(gvks, olmGVKs...), nil } // AddWatchForGVK creates a watch on a given GVK, as long as it's not duplicated. func (s *SBRController) AddWatchForGVK(gvk schema.GroupVersionKind) error { log := s.logger.WithValues("GVK", gvk) - logging.Debug(&log, "Adding watch for GVK...") + log.Debug("Adding watch for GVK...") if _, exists := s.watchingGVKs[gvk]; exists { - logging.Debug(&log, "Skipping watch on GVK twice, it's already under watch!") + log.Debug("Skipping watch on GVK twice, it's already under watch!") return nil } // saving GVK in cache s.watchingGVKs[gvk] = true - logging.Debug(&log, "Creating watch on GVK") + log.Debug("Creating watch on GVK") source := s.createSourceForGVK(gvk) return s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) } // addCSVWatch creates a watch on ClusterServiceVersion. func (s *SBRController) addCSVWatch() error { - log := &(s.logger) + log := s.logger csvGVK := olmv1alpha1.SchemeGroupVersion.WithKind(ClusterServiceVersionKind) source := s.createSourceForGVK(csvGVK) err := s.Controller.Watch(source, NewCreateWatchEventHandler(s), defaultPredicate) if err != nil { return err } - logging.Debug(log, "Watch added for ClusterServiceVersion", "GVK", csvGVK) + log.Debug("Watch added for ClusterServiceVersion", "GVK", csvGVK) return nil } @@ -119,29 +118,29 @@ func (s *SBRController) addSBRWatch() error { source := s.createSourceForGVK(gvk) err := s.Controller.Watch(source, s.newEnqueueRequestsForSBR(), defaultPredicate) if err != nil { - logging.Error(err, &log, "on creating watch for ServiceBindingRequest") + log.Error(err, "on creating watch for ServiceBindingRequest") return err } - logging.Debug(&log, "Watch added for ServiceBindingRequest") + log.Debug("Watch added for ServiceBindingRequest") return nil } // addWhitelistedGVKWatches create watch on GVKs employed on CSVs. func (s *SBRController) addWhitelistedGVKWatches() error { - log := &(s.logger) + log := s.logger // list of interesting GVKs to watch gvks, err := s.getWatchingGVKs() if err != nil { - logging.Error(err, log, "on retrieving list of GVKs to watch") + log.Error(err, "on retrieving list of GVKs to watch") return err } for _, gvk := range gvks { - logging.Debug(log, "Adding watch for whitelisted GVK...", "GVK", gvk) + log.Debug("Adding watch for whitelisted GVK...", "GVK", gvk) err = s.AddWatchForGVK(gvk) if err != nil { - logging.Error(err, log, "on creating watch for GVK") + log.Error(err, "on creating watch for GVK") return err } } @@ -151,22 +150,22 @@ func (s *SBRController) addWhitelistedGVKWatches() error { // Watch setup "watch" for all GVKs relevant for SBRController. func (s *SBRController) Watch() error { - log := &(s.logger) + log := s.logger err := s.addSBRWatch() if err != nil { - logging.Error(err, log, "on adding watch for ServiceBindingRequest") + log.Error(err, "on adding watch for ServiceBindingRequest") return err } err = s.addWhitelistedGVKWatches() if err != nil { - logging.Error(err, log, "on adding watch for whitelisted GVKs") + log.Error(err, "on adding watch for whitelisted GVKs") return err } err = s.addCSVWatch() if err != nil { - logging.Error(err, log, "on adding watch for ClusterServiceVersion") + log.Error(err, "on adding watch for ClusterServiceVersion") return err } diff --git a/pkg/controller/servicebindingrequest/watch.go b/pkg/controller/servicebindingrequest/watch.go index c9d3991cb4..65d90fa0f0 100644 --- a/pkg/controller/servicebindingrequest/watch.go +++ b/pkg/controller/servicebindingrequest/watch.go @@ -30,15 +30,15 @@ func (c *CSVToWatcherMapper) Map(obj handler.MapObject) []reconcile.Request { gvks, err := olm.ListGVKsFromCSVNamespacedName(namespacedName) if err != nil { - logging.Error(err, &log, "Failed on listing GVK with namespaced-name!") + log.Error(err, "Failed on listing GVK with namespaced-name!") return []reconcile.Request{} } for _, gvk := range gvks { - logging.Debug(&log, "Adding watch for GVK", "GVK", gvk) + log.Debug("Adding watch for GVK", "GVK", gvk) err = c.controller.AddWatchForGVK(gvk) if err != nil { - logging.Error(err, &log, "Failed to create a watch") + log.Error(err, "Failed to create a watch") } } diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go index 3ddff46178..bf6e59348d 100644 --- a/pkg/logging/logging.go +++ b/pkg/logging/logging.go @@ -7,45 +7,77 @@ import ( logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) +// Log logs messages to various levels +type Log struct { + logger *logr.Logger //logger instance +} + // Error logs the message using go-logr package on a default level as ERROR -func Error(err error, logger *logr.Logger, msg string, keysAndValues ...interface{}) { - (*logger).Error(err, msg, keysAndValues...) +func (l *Log) Error(err error, msg string, keysAndValues ...interface{}) { + (*l.logger).Error(err, msg, keysAndValues...) } // Warning logs the message using go-logr package on a default level as WARNING -func Warning(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - if (*logger).V(0).Enabled() { - (*logger).V(0).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) +func (l *Log) Warning(msg string, keysAndValues ...interface{}) { + if (*l.logger).V(0).Enabled() { + (*l.logger).V(0).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) } } // Info logs the message using go-logr package on a default level as INFO -func Info(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - if (*logger).V(0).Enabled() { - (*logger).V(0).Info(msg, keysAndValues...) +func (l *Log) Info(msg string, keysAndValues ...interface{}) { + if (*l.logger).V(0).Enabled() { + (*l.logger).V(0).Info(msg, keysAndValues...) } } // Debug logs the message using go-logr package on a V=1 level as DEBUG -func Debug(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - if (*logger).V(1).Enabled() { - (*logger).V(1).Info(fmt.Sprintf("DEBUG: %s", msg), keysAndValues...) +func (l *Log) Debug(msg string, keysAndValues ...interface{}) { + if (*l.logger).V(1).Enabled() { + (*l.logger).V(1).Info(fmt.Sprintf("DEBUG: %s", msg), keysAndValues...) } } // Trace logs the message using go-logr package on a V=1 level as TRACE -func Trace(logger *logr.Logger, msg string, keysAndValues ...interface{}) { - if (*logger).V(2).Enabled() { - (*logger).V(1).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) +func (l *Log) Trace(msg string, keysAndValues ...interface{}) { + if (*l.logger).V(2).Enabled() { + (*l.logger).V(1).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) } } // Logger returns an instance of a logger -func Logger(name string, keysAndValues ...interface{}) logr.Logger { - return logf.Log.WithName(name).WithValues(keysAndValues...) +func Logger(name string, keysAndValues ...interface{}) *Log { + logger := logf.Log.WithName(name).WithValues(keysAndValues...) + l := &Log{ + logger: &logger, + } + return l } // SetLogger sets a concrete logging implementation for all deferred Loggers. func SetLogger(logger logr.Logger) { logf.SetLogger(logger) } + +// WithValues adds some key-value pairs of context to a logger. +// See Info for documentation on how key/value pairs work. +func (l *Log) WithValues(keysAndValues ...interface{}) *Log { + lgr := ((*l.logger).WithValues(keysAndValues...)) + log := &Log{ + logger: &lgr, + } + return log +} + +// WithName adds a new element to the logger's name. +// Successive calls with WithName continue to append +// suffixes to the logger's name. It's strongly reccomended +// that name segments contain only letters, digits, and hyphens +// (see the package documentation for more information). +func (l *Log) WithName(name string) *Log { + lgr := ((*l.logger).WithName(name)) + log := &Log{ + logger: &lgr, + } + return log +} From 46dd29acf641357c29d40d390b4a5084e0a0d801 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Wed, 9 Oct 2019 17:04:12 +0200 Subject: [PATCH 07/14] Add docs comments to Log type. --- pkg/logging/logging.go | 17 ++++++++++++++++- 1 file changed, 16 insertions(+), 1 deletion(-) diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go index bf6e59348d..c91dad49e1 100644 --- a/pkg/logging/logging.go +++ b/pkg/logging/logging.go @@ -7,7 +7,21 @@ import ( logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) -// Log logs messages to various levels +/* +Log logs messages to various levels. + +Based on the go-logr package. + +The Log type enables various verbosity levels to be logged based on to the --zap-level argument to the operator. + +To create an instance of the logger: + + log := logging.Logger("main") + +When --zap-level is not provided, the logging defaults to INFO level where log.Warning() and log.Info() are logged, +if --zap-level is set to 1 then the logging goes to the DEBUG level where log.Debug() is logged, while the +--zap-level set to 2 is reserved for more finer DEBUG-level logging provided by the log.Trace() function. +*/ type Log struct { logger *logr.Logger //logger instance } @@ -41,6 +55,7 @@ func (l *Log) Debug(msg string, keysAndValues ...interface{}) { // Trace logs the message using go-logr package on a V=1 level as TRACE func (l *Log) Trace(msg string, keysAndValues ...interface{}) { if (*l.logger).V(2).Enabled() { + // The V(1) level here is intentional: TRACE = finer DEBUG logging but is only enabled by setting V=2 (*l.logger).V(1).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) } } From 7120f85725a60aeada206069db0245e0590b26c5 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Wed, 9 Oct 2019 17:21:45 +0200 Subject: [PATCH 08/14] Introduce the ZAP_LEVEL_FLAG variable (based on VERBOSE) and update local make target to pass it to the operator. --- Makefile | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/Makefile b/Makefile index b36af4b874..29a08b7b1e 100644 --- a/Makefile +++ b/Makefile @@ -20,6 +20,7 @@ QUIET_FLAG = --quiet V_FLAG = S_FLAG = -s X_FLAG = +ZAP_LEVEL_FLAG = ifeq ($(VERBOSE),1) Q = endif @@ -30,6 +31,10 @@ ifeq ($(VERBOSE),2) S_FLAG = V_FLAG = -v X_FLAG = -x + ZAP_LEVEL_FLAG = --zap-level 1 +endif +ifeq ($(VERBOSE),3) + ZAP_LEVEL_FLAG = --zap-level 2 endif # Create output directory for artifacts and test results. ./out is supposed to @@ -292,7 +297,7 @@ push-image: build-image .PHONY: local ## Local: Run operator locally local: deploy-clean deploy-rbac deploy-crds - $(Q)operator-sdk --verbose up local + $(Q)operator-sdk --verbose up local --operator-flags "$(ZAP_LEVEL_FLAG)" .PHONY: deploy-rbac ## Deploy-RBAC: Setup service account and deploy RBAC From c41fc5898a38cf540826cec2e6bba6e91cc5834b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Thu, 10 Oct 2019 15:18:48 +0200 Subject: [PATCH 09/14] Fix VERBOSE=3 condition in Makefile. --- Makefile | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/Makefile b/Makefile index f5e247d80f..d8ab0e3503 100644 --- a/Makefile +++ b/Makefile @@ -34,6 +34,11 @@ ifeq ($(VERBOSE),2) ZAP_LEVEL_FLAG = --zap-level 1 endif ifeq ($(VERBOSE),3) + Q_FLAG = + QUIET_FLAG = + S_FLAG = + V_FLAG = -v + X_FLAG = -x ZAP_LEVEL_FLAG = --zap-level 2 endif From 79130574e6bec4bbcc4e2eeb832c941745d8ec23 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Thu, 10 Oct 2019 19:00:09 +0200 Subject: [PATCH 10/14] Set the proper logging level for the e2e tests. --- Makefile | 2 ++ 1 file changed, 2 insertions(+) diff --git a/Makefile b/Makefile index d8ab0e3503..fcc6c2934a 100644 --- a/Makefile +++ b/Makefile @@ -201,6 +201,7 @@ test-e2e: e2e-setup --namespace $(TEST_NAMESPACE) \ --up-local \ --go-test-flags "-timeout=15m" \ + --local-operator-flags "$(ZAP_LEVEL_FLAG)" \ $(OPERATOR_SDK_EXTRA_ARGS) .PHONY: test-unit @@ -236,6 +237,7 @@ test-e2e-olm-ci: $(Q)operator-sdk --verbose test local ./test/e2e \ --no-setup \ --go-test-flags "-timeout=15m" \ + --local-operator-flags "$(ZAP_LEVEL_FLAG)" \ $(OPERATOR_SDK_EXTRA_ARGS) ## -- Build Go binary and OCI image targets -- From 9fefaa8a4618fb5ee0f7a8221e76efad5f7a0162 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Fri, 11 Oct 2019 14:13:20 +0200 Subject: [PATCH 11/14] Update for the PR comments. --- Makefile | 9 +- cmd/manager/main.go | 42 ++++---- .../servicebindingrequest/annotations.go | 8 +- .../servicebindingrequest/binder.go | 8 +- .../servicebindingrequest/mapper.go | 6 +- pkg/controller/servicebindingrequest/olm.go | 8 +- .../servicebindingrequest/planner.go | 8 +- .../servicebindingrequest/reconciler.go | 8 +- .../servicebindingrequest/retriever.go | 8 +- .../servicebindingrequest/sbrcontroller.go | 8 +- pkg/controller/servicebindingrequest/watch.go | 6 +- pkg/log/log.go | 101 ++++++++++++++++++ pkg/logging/logging.go | 98 ----------------- 13 files changed, 162 insertions(+), 156 deletions(-) create mode 100644 pkg/log/log.go delete mode 100644 pkg/logging/logging.go diff --git a/Makefile b/Makefile index fcc6c2934a..fe4ef0265b 100644 --- a/Makefile +++ b/Makefile @@ -20,6 +20,7 @@ QUIET_FLAG = --quiet V_FLAG = S_FLAG = -s X_FLAG = +ZAP_ENCODER_FLAG = --zap-encoder=console ZAP_LEVEL_FLAG = ifeq ($(VERBOSE),1) Q = @@ -42,6 +43,8 @@ ifeq ($(VERBOSE),3) ZAP_LEVEL_FLAG = --zap-level 2 endif +ZAP_FLAGS = $(ZAP_ENCODER_FLAG) $(ZAP_LEVEL_FLAG) + # Create output directory for artifacts and test results. ./out is supposed to # be a safe place for all targets to write to while knowing that all content # inside of ./out is wiped once "make clean" is run. @@ -201,7 +204,7 @@ test-e2e: e2e-setup --namespace $(TEST_NAMESPACE) \ --up-local \ --go-test-flags "-timeout=15m" \ - --local-operator-flags "$(ZAP_LEVEL_FLAG)" \ + --local-operator-flags "$(ZAP_FLAGS)" \ $(OPERATOR_SDK_EXTRA_ARGS) .PHONY: test-unit @@ -237,7 +240,7 @@ test-e2e-olm-ci: $(Q)operator-sdk --verbose test local ./test/e2e \ --no-setup \ --go-test-flags "-timeout=15m" \ - --local-operator-flags "$(ZAP_LEVEL_FLAG)" \ + --local-operator-flags "$(ZAP_FLAGS)" \ $(OPERATOR_SDK_EXTRA_ARGS) ## -- Build Go binary and OCI image targets -- @@ -304,7 +307,7 @@ push-image: build-image .PHONY: local ## Local: Run operator locally local: deploy-clean deploy-rbac deploy-crds - $(Q)operator-sdk --verbose up local --operator-flags "$(ZAP_LEVEL_FLAG)" + $(Q)operator-sdk --verbose up local --operator-flags "$(ZAP_FLAGS)" .PHONY: deploy-rbac ## Deploy-RBAC: Setup service account and deploy RBAC diff --git a/cmd/manager/main.go b/cmd/manager/main.go index 9149407e87..c63c535e06 100644 --- a/cmd/manager/main.go +++ b/cmd/manager/main.go @@ -28,7 +28,7 @@ import ( "github.com/redhat-developer/service-binding-operator/pkg/apis" "github.com/redhat-developer/service-binding-operator/pkg/controller" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" ) // Change below variables to serve metrics on different host or port. @@ -36,13 +36,13 @@ var ( metricsHost = "0.0.0.0" metricsPort int32 = 8383 operatorMetricsPort int32 = 8686 - mainLogger = logging.Logger("main") + mainLog = log.NewLog("main") ) func printVersion() { - mainLogger.Info(fmt.Sprintf("Go Version: %s", runtime.Version())) - mainLogger.Info(fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) - mainLogger.Info(fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) + mainLog.Info(fmt.Sprintf("Go Version: %s", runtime.Version())) + mainLog.Info(fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) + mainLog.Info(fmt.Sprintf("Version of operator-sdk: %v", sdkVersion.Version)) } // getOperatorName based on environment variable OPERATOR_NAME, or returns the default name for @@ -64,20 +64,20 @@ func main() { pflag.CommandLine.AddFlagSet(zap.FlagSet()) pflag.CommandLine.AddGoFlagSet(flag.CommandLine) pflag.Parse() - logging.SetLogger(zap.Logger()) + log.SetLog(zap.Logger()) printVersion() namespace, err := k8sutil.GetWatchNamespace() if err != nil { - mainLogger.Error(err, "Failed to get watch namespace") + mainLog.Error(err, "Failed to get watch namespace") os.Exit(1) } // Get a config to talk to the apiserver cfg, err := config.GetConfig() if err != nil { - mainLogger.Error(err, "Failed to acquire a configuration to talk to the API server") + mainLog.Error(err, "Failed to acquire a configuration to talk to the API server") os.Exit(1) } @@ -88,11 +88,11 @@ func main() { // Become the leader before proceeding err = leader.Become(ctx, fmt.Sprintf("%s-lock", getOperatorName())) if err != nil { - mainLogger.Error(err, "Failed to become the leader") + mainLog.Error(err, "Failed to become the leader") os.Exit(1) } } else { - mainLogger.Warning("Leader election is disabled") + mainLog.Warning("Leader election is disabled") } // Create a new Cmd to provide shared dependencies and start components @@ -102,31 +102,31 @@ func main() { MetricsBindAddress: fmt.Sprintf("%s:%d", metricsHost, metricsPort), }) if err != nil { - mainLogger.Error(err, "Error on creating a new manager instance") + mainLog.Error(err, "Error on creating a new manager instance") os.Exit(1) } - mainLogger.Info("Registering Components.") + mainLog.Info("Registering Components.") // Setup Scheme for all resources if err := apis.AddToScheme(mgr.GetScheme()); err != nil { - mainLogger.Error(err, "Error adding local operator scheme") + mainLog.Error(err, "Error adding local operator scheme") os.Exit(1) } if err := osappsv1.AddToScheme(mgr.GetScheme()); err != nil { - mainLogger.Error(err, "Error on adding OS APIs to scheme") + mainLog.Error(err, "Error on adding OS APIs to scheme") os.Exit(1) } // Setup all Controllers if err := controller.AddToManager(mgr); err != nil { - mainLogger.Error(err, "Failed to setup the controller manager") + mainLog.Error(err, "Failed to setup the controller manager") os.Exit(1) } if err = serveCRMetrics(cfg); err != nil { - mainLogger.Info("Could not generate and serve custom resource metrics", "error", err.Error()) + mainLog.Info("Could not generate and serve custom resource metrics", "error", err.Error()) } // Add to the below struct any other metrics ports you want to expose. @@ -137,7 +137,7 @@ func main() { // Create Service object to expose the metrics port(s). service, err := metrics.CreateMetricsService(ctx, cfg, servicePorts) if err != nil { - mainLogger.Info("Could not create metrics Service", "error", err.Error()) + mainLog.Info("Could not create metrics Service", "error", err.Error()) } // CreateServiceMonitors will automatically create the prometheus-operator ServiceMonitor resources @@ -145,19 +145,19 @@ func main() { services := []*v1.Service{service} _, err = metrics.CreateServiceMonitors(cfg, namespace, services) if err != nil { - mainLogger.Info("Could not create ServiceMonitor object", "error", err.Error()) + mainLog.Info("Could not create ServiceMonitor object", "error", err.Error()) // If this operator is deployed to a cluster without the prometheus-operator running, it will return // ErrServiceMonitorNotPresent, which can be used to safely skip ServiceMonitor creation. if err == metrics.ErrServiceMonitorNotPresent { - mainLogger.Info("Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) + mainLog.Info("Install prometheus-operator in your cluster to create ServiceMonitor objects", "error", err.Error()) } } - mainLogger.Info("Starting the Cmd.") + mainLog.Info("Starting the Cmd.") // Start the Cmd if err := mgr.Start(signals.SetupSignalHandler()); err != nil { - mainLogger.Error(err, "Manager exited non-zero") + mainLog.Error(err, "Manager exited non-zero") os.Exit(1) } } diff --git a/pkg/controller/servicebindingrequest/annotations.go b/pkg/controller/servicebindingrequest/annotations.go index 0353ba6302..209fae702e 100644 --- a/pkg/controller/servicebindingrequest/annotations.go +++ b/pkg/controller/servicebindingrequest/annotations.go @@ -9,7 +9,7 @@ import ( "k8s.io/client-go/dynamic" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" ) const ( @@ -18,7 +18,7 @@ const ( ) var ( - annotationsLogger = logging.Logger("annotations") + annotationsLog = log.NewLog("annotations") ) // extractSBRNamespacedName returns a types.NamespacedName if the required service binding request keys @@ -52,7 +52,7 @@ func GetSBRNamespacedNameFromObject(obj runtime.Object) (types.NamespacedName, e u := &unstructured.Unstructured{Object: data} sbrNamespacedName = extractSBRNamespacedName(u.GetAnnotations()) - log := annotationsLogger.WithValues( + log := annotationsLog.WithValues( "Resource.GVK", u.GroupVersionKind(), "Resource.Namespace", u.GetNamespace(), "Resource.Name", u.GetName(), @@ -100,7 +100,7 @@ func SetSBRAnnotations( gvr, _ := meta.UnsafeGuessKindToResource(gvk) opts := metav1.UpdateOptions{} - log := annotationsLogger.WithValues( + log := annotationsLog.WithValues( "SBR.Namespace", namespacedName.Namespace, "SBR.Name", namespacedName.Name, "Resource.GVK", gvk, diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index c5399f2206..76393599f9 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -18,7 +18,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/client" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" ) const ( @@ -26,7 +26,7 @@ const ( ) var ( - binderLogger = logging.Logger("binder") + binderLog = log.NewLog("binder") ) // Binder executes the "binding" act of updating different application kinds to use intermediary @@ -37,7 +37,7 @@ type Binder struct { dynClient dynamic.Interface // kubernetes dynamic api client sbr *v1alpha1.ServiceBindingRequest // instantiated service binding request volumeKeys []string // list of key names used in volume mounts - logger *logging.Log // logger instance + logger *log.Log // logger instance } // search objects based in Kind/APIVersion, which contain the labels defined in ApplicationSelector. @@ -340,6 +340,6 @@ func NewBinder( dynClient: dynClient, sbr: sbr, volumeKeys: volumeKeys, - logger: binderLogger, + logger: binderLog, } } diff --git a/pkg/controller/servicebindingrequest/mapper.go b/pkg/controller/servicebindingrequest/mapper.go index 108a3c2a7f..a8c3873420 100644 --- a/pkg/controller/servicebindingrequest/mapper.go +++ b/pkg/controller/servicebindingrequest/mapper.go @@ -1,13 +1,13 @@ package servicebindingrequest import ( - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) var ( - mapperLogger = logging.Logger("mapper") + mapperLog = log.NewLog("mapper") ) // SBRRequestMapper is the handler.Mapper interface implementation. It should influence the @@ -17,7 +17,7 @@ type SBRRequestMapper struct{} // Map execute the mapping of a resource with the requests it would produce. Here we inspect the // given object trying to identify if this object is part of a SBR, or a actual SBR resource. func (m *SBRRequestMapper) Map(obj handler.MapObject) []reconcile.Request { - log := mapperLogger.WithValues( + log := mapperLog.WithValues( "Object.Namespace", obj.Meta.GetNamespace(), "Object.Name", obj.Meta.GetName(), ) diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index badcb54312..7272a8c035 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -5,7 +5,7 @@ import ( "strings" olmv1alpha1 "github.com/operator-framework/operator-lifecycle-manager/pkg/api/apis/operators/v1alpha1" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime" @@ -19,7 +19,7 @@ import ( type OLM struct { client dynamic.Interface // kubernetes dynamic client ns string // namespace - logger *logging.Log // logger instance + logger *log.Log // logger instance } const ( @@ -27,7 +27,7 @@ const ( ) var ( - olmLogger = logging.Logger("olm") + olmLog = log.NewLog("olm") ) // listCSVs simple list to all CSV objects in the cluster. @@ -212,6 +212,6 @@ func NewOLM(client dynamic.Interface, ns string) *OLM { return &OLM{ client: client, ns: ns, - logger: olmLogger, + logger: olmLog, } } diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index e4084b3ab9..c3fc6cb623 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -11,11 +11,11 @@ import ( "k8s.io/client-go/dynamic" v1alpha1 "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" ) var ( - plannerLogger = logging.Logger("planner") + plannerLog = log.NewLog("planner") ) // Planner plans resources needed to bind a given backend service, using OperatorLifecycleManager @@ -24,7 +24,7 @@ type Planner struct { ctx context.Context // request context client dynamic.Interface // kubernetes dynamic api client sbr *v1alpha1.ServiceBindingRequest // instantiated service binding request - logger *logging.Log // logger instance + logger *log.Log // logger instance } // Plan outcome, after executing planner. @@ -91,6 +91,6 @@ func NewPlanner( ctx: ctx, client: client, sbr: sbr, - logger: plannerLogger, + logger: plannerLog, } } diff --git a/pkg/controller/servicebindingrequest/reconciler.go b/pkg/controller/servicebindingrequest/reconciler.go index 70d3b4838b..8e7c7aa223 100644 --- a/pkg/controller/servicebindingrequest/reconciler.go +++ b/pkg/controller/servicebindingrequest/reconciler.go @@ -14,7 +14,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/reconcile" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" ) // Reconciler reconciles a ServiceBindingRequest object @@ -36,7 +36,7 @@ const ( ) var ( - reconcilerLogger = logging.Logger("reconciler") + reconcilerLog = log.NewLog("reconciler") ) // setSecretName update the CR status field to "in progress", and setting secret name. @@ -125,7 +125,7 @@ func (r *Reconciler) onError( } // checkSBR checks the Service Binding Request -func checkSBR(sbr *v1alpha1.ServiceBindingRequest, log *logging.Log) error { +func checkSBR(sbr *v1alpha1.ServiceBindingRequest, log *log.Log) error { // Check if application ResourceRef is present if sbr.Spec.ApplicationSelector.ResourceRef == "" { log.Debug("Spec.ApplicationSelector.ResourceRef not found") @@ -154,7 +154,7 @@ func (r *Reconciler) Reconcile(request reconcile.Request) (reconcile.Result, err ctx := context.TODO() objectsToAnnotate := []*unstructured.Unstructured{} - log := reconcilerLogger.WithValues( + log := reconcilerLog.WithValues( "Request.Namespace", request.Namespace, "Request.Name", request.Name, ) diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index 867a307d0b..b1480e03e4 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -5,7 +5,7 @@ import ( "fmt" "strings" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -17,7 +17,7 @@ import ( // Retriever reads all data referred in plan instance, and store in a secret. type Retriever struct { - logger *logging.Log // logger instance + logger *log.Log // logger instance data map[string][]byte // data retrieved objects []*unstructured.Unstructured // list of objects employed client dynamic.Interface // Kubernetes API client @@ -36,7 +36,7 @@ const ( ) var ( - retrieverLogger = logging.Logger("retriever") + retrieverLog = log.NewLog("retriever") ) // getNestedValue retrieve value from dotted key path @@ -358,7 +358,7 @@ func (r *Retriever) Retrieve() ([]*unstructured.Unstructured, error) { // NewRetriever instantiate a new retriever instance. func NewRetriever(client dynamic.Interface, plan *Plan, bindingPrefix string) *Retriever { return &Retriever{ - logger: retrieverLogger, + logger: retrieverLog, data: make(map[string][]byte), objects: []*unstructured.Unstructured{}, client: client, diff --git a/pkg/controller/servicebindingrequest/sbrcontroller.go b/pkg/controller/servicebindingrequest/sbrcontroller.go index 6ae9885dfc..6c5f5f748c 100644 --- a/pkg/controller/servicebindingrequest/sbrcontroller.go +++ b/pkg/controller/servicebindingrequest/sbrcontroller.go @@ -15,7 +15,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/source" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" ) // SBRController hold the controller instance and methods for a ServiceBindingRequest. @@ -23,7 +23,7 @@ type SBRController struct { Controller controller.Controller // controller-runtime instance Client dynamic.Interface // kubernetes dynamic api client watchingGVKs map[schema.GroupVersionKind]bool // cache to identify GVKs on watch - logger *logging.Log // logger instance + logger *log.Log // logger instance } var ( @@ -40,7 +40,7 @@ var ( return !e.DeleteStateUnknown }, } - sbrControllerLogger = logging.Logger("sbrcontroller") + sbrControllerLog = log.NewLog("sbrcontroller") ) // newEnqueueRequestsForSBR returns a handler.EventHandler configured to map any incoming object to a @@ -188,6 +188,6 @@ func NewSBRController( Controller: c, Client: client, watchingGVKs: make(map[schema.GroupVersionKind]bool), - logger: sbrControllerLogger, + logger: sbrControllerLog, }, nil } diff --git a/pkg/controller/servicebindingrequest/watch.go b/pkg/controller/servicebindingrequest/watch.go index 65d90fa0f0..544b695378 100644 --- a/pkg/controller/servicebindingrequest/watch.go +++ b/pkg/controller/servicebindingrequest/watch.go @@ -1,14 +1,14 @@ package servicebindingrequest import ( - "github.com/redhat-developer/service-binding-operator/pkg/logging" + log "github.com/redhat-developer/service-binding-operator/pkg/log" "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) var ( - watchLogger = logging.Logger("watch") + watchLog = log.NewLog("watch") ) // CSVToWatcherMapper creates a EventHandler interface to map ClusterServiceVersion objects back to @@ -26,7 +26,7 @@ func (c *CSVToWatcherMapper) Map(obj handler.MapObject) []reconcile.Request { Name: obj.Meta.GetName(), } - log := watchLogger.WithName("CSVToWatcherMapper").WithValues("Obj.NamespacedName", namespacedName) + log := watchLog.WithName("CSVToWatcherMapper").WithValues("Obj.NamespacedName", namespacedName) gvks, err := olm.ListGVKsFromCSVNamespacedName(namespacedName) if err != nil { diff --git a/pkg/log/log.go b/pkg/log/log.go new file mode 100644 index 0000000000..812d8bcaf9 --- /dev/null +++ b/pkg/log/log.go @@ -0,0 +1,101 @@ +package logging + +import ( + "fmt" + + "github.com/go-logr/logr" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" +) + +// Log logs messages to various levels. +// +// Based on the go-logr package. +// +// The Log type enables various verbosity levels to be logged +// based on to the --zap-level argument to the operator. +// +// To create an instance of the log named "main": +// +// log := log.NewLog("main") +// +// When --zap-level is not provided +// then the logging defaults to INFO level where log.Warning() and log.Info() are logged, +// +// if --zap-level is set to 1 +// then the logging goes to the DEBUG level where log.Debug() is logged, +// +// while the --zap-level set to 2 is reserved for a finer DEBUG-level logging +// provided by the log.Trace() function. +type Log struct { + log *logr.Logger //log instance +} + +// Error logs the message using go-logr package on a default level as ERROR +func (l *Log) Error(err error, msg string, keysAndValues ...interface{}) { + (*l.log).Error(err, msg, keysAndValues...) +} + +// Warning logs the message using go-logr package on a default level as WARNING +func (l *Log) Warning(msg string, keysAndValues ...interface{}) { + if (*l.log).V(0).Enabled() { + (*l.log).V(0).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) + } +} + +// Info logs the message using go-logr package on a default level as INFO +func (l *Log) Info(msg string, keysAndValues ...interface{}) { + if (*l.log).V(0).Enabled() { + (*l.log).V(0).Info(msg, keysAndValues...) + } +} + +// Debug logs the message using go-logr package on a V=1 level as DEBUG +func (l *Log) Debug(msg string, keysAndValues ...interface{}) { + if (*l.log).V(1).Enabled() { + (*l.log).V(1).Info(fmt.Sprintf("DEBUG: %s", msg), keysAndValues...) + } +} + +// Trace logs the message using go-logr package on a V=1 level as TRACE +func (l *Log) Trace(msg string, keysAndValues ...interface{}) { + if (*l.log).V(2).Enabled() { + // The V(1) level here is intentional: + // sTRACE = finer DEBUG logging but is only enabled by setting V=2 + (*l.log).V(1).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) + } +} + +// NewLog returns an instance of a Log +func NewLog(name string, keysAndValues ...interface{}) *Log { + log := logf.Log.WithName(name).WithValues(keysAndValues...) + l := &Log{ + log: &log, + } + return l +} + +// SetLog sets a concrete logging implementation for all deferred Loggers. +func SetLog(log logr.Logger) { + logf.SetLogger(log) +} + +// WithValues adds some key-value pairs of context to a log. +// See Info for documentation on how key/value pairs work. +func (l *Log) WithValues(keysAndValues ...interface{}) *Log { + lgr := ((*l.log).WithValues(keysAndValues...)) + log := &Log{ + log: &lgr, + } + return log +} + +// WithName adds a new element to the log's name. Successive calls with WithName continue to append +// suffixes to the log's name. It's strongly reccomended that name segments contain only letters, +// digits, and hyphens (see the package documentation for more information). +func (l *Log) WithName(name string) *Log { + lgr := ((*l.log).WithName(name)) + log := &Log{ + log: &lgr, + } + return log +} diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go deleted file mode 100644 index c91dad49e1..0000000000 --- a/pkg/logging/logging.go +++ /dev/null @@ -1,98 +0,0 @@ -package logging - -import ( - "fmt" - - "github.com/go-logr/logr" - logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" -) - -/* -Log logs messages to various levels. - -Based on the go-logr package. - -The Log type enables various verbosity levels to be logged based on to the --zap-level argument to the operator. - -To create an instance of the logger: - - log := logging.Logger("main") - -When --zap-level is not provided, the logging defaults to INFO level where log.Warning() and log.Info() are logged, -if --zap-level is set to 1 then the logging goes to the DEBUG level where log.Debug() is logged, while the ---zap-level set to 2 is reserved for more finer DEBUG-level logging provided by the log.Trace() function. -*/ -type Log struct { - logger *logr.Logger //logger instance -} - -// Error logs the message using go-logr package on a default level as ERROR -func (l *Log) Error(err error, msg string, keysAndValues ...interface{}) { - (*l.logger).Error(err, msg, keysAndValues...) -} - -// Warning logs the message using go-logr package on a default level as WARNING -func (l *Log) Warning(msg string, keysAndValues ...interface{}) { - if (*l.logger).V(0).Enabled() { - (*l.logger).V(0).Info(fmt.Sprintf("WARNING: %s", msg), keysAndValues...) - } -} - -// Info logs the message using go-logr package on a default level as INFO -func (l *Log) Info(msg string, keysAndValues ...interface{}) { - if (*l.logger).V(0).Enabled() { - (*l.logger).V(0).Info(msg, keysAndValues...) - } -} - -// Debug logs the message using go-logr package on a V=1 level as DEBUG -func (l *Log) Debug(msg string, keysAndValues ...interface{}) { - if (*l.logger).V(1).Enabled() { - (*l.logger).V(1).Info(fmt.Sprintf("DEBUG: %s", msg), keysAndValues...) - } -} - -// Trace logs the message using go-logr package on a V=1 level as TRACE -func (l *Log) Trace(msg string, keysAndValues ...interface{}) { - if (*l.logger).V(2).Enabled() { - // The V(1) level here is intentional: TRACE = finer DEBUG logging but is only enabled by setting V=2 - (*l.logger).V(1).Info(fmt.Sprintf("TRACE: %s", msg), keysAndValues...) - } -} - -// Logger returns an instance of a logger -func Logger(name string, keysAndValues ...interface{}) *Log { - logger := logf.Log.WithName(name).WithValues(keysAndValues...) - l := &Log{ - logger: &logger, - } - return l -} - -// SetLogger sets a concrete logging implementation for all deferred Loggers. -func SetLogger(logger logr.Logger) { - logf.SetLogger(logger) -} - -// WithValues adds some key-value pairs of context to a logger. -// See Info for documentation on how key/value pairs work. -func (l *Log) WithValues(keysAndValues ...interface{}) *Log { - lgr := ((*l.logger).WithValues(keysAndValues...)) - log := &Log{ - logger: &lgr, - } - return log -} - -// WithName adds a new element to the logger's name. -// Successive calls with WithName continue to append -// suffixes to the logger's name. It's strongly reccomended -// that name segments contain only letters, digits, and hyphens -// (see the package documentation for more information). -func (l *Log) WithName(name string) *Log { - lgr := ((*l.logger).WithName(name)) - log := &Log{ - logger: &lgr, - } - return log -} From 51a11f3431f5d73ce55c6de6bea907bb38d88c0f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Fri, 11 Oct 2019 15:04:22 +0200 Subject: [PATCH 12/14] Remove the 'DEBUG:' prefix from the default debug-level lines. --- pkg/log/log.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/log/log.go b/pkg/log/log.go index 812d8bcaf9..44cc35e8ea 100644 --- a/pkg/log/log.go +++ b/pkg/log/log.go @@ -52,7 +52,7 @@ func (l *Log) Info(msg string, keysAndValues ...interface{}) { // Debug logs the message using go-logr package on a V=1 level as DEBUG func (l *Log) Debug(msg string, keysAndValues ...interface{}) { if (*l.log).V(1).Enabled() { - (*l.log).V(1).Info(fmt.Sprintf("DEBUG: %s", msg), keysAndValues...) + (*l.log).V(1).Info(msg, keysAndValues...) } } @@ -90,7 +90,7 @@ func (l *Log) WithValues(keysAndValues ...interface{}) *Log { } // WithName adds a new element to the log's name. Successive calls with WithName continue to append -// suffixes to the log's name. It's strongly reccomended that name segments contain only letters, +// suffixes to the log's name. It's strongly reccomended that name segments contain only letters, // digits, and hyphens (see the package documentation for more information). func (l *Log) WithName(name string) *Log { lgr := ((*l.log).WithName(name)) From 8a2faed9a1a4fdd8658be0214546f1e7e91dd5fb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Fri, 11 Oct 2019 15:17:40 +0200 Subject: [PATCH 13/14] Fix log package and comment formatting. --- pkg/controller/servicebindingrequest/binder.go | 2 +- pkg/controller/servicebindingrequest/olm.go | 2 +- pkg/controller/servicebindingrequest/planner.go | 2 +- pkg/controller/servicebindingrequest/retriever.go | 2 +- pkg/log/log.go | 2 +- 5 files changed, 5 insertions(+), 5 deletions(-) diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index 76393599f9..aa3cf0670c 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -37,7 +37,7 @@ type Binder struct { dynClient dynamic.Interface // kubernetes dynamic api client sbr *v1alpha1.ServiceBindingRequest // instantiated service binding request volumeKeys []string // list of key names used in volume mounts - logger *log.Log // logger instance + logger *log.Log // logger instance } // search objects based in Kind/APIVersion, which contain the labels defined in ApplicationSelector. diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index 7272a8c035..25928c6d87 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -19,7 +19,7 @@ import ( type OLM struct { client dynamic.Interface // kubernetes dynamic client ns string // namespace - logger *log.Log // logger instance + logger *log.Log // logger instance } const ( diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index c3fc6cb623..18a88b7245 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -24,7 +24,7 @@ type Planner struct { ctx context.Context // request context client dynamic.Interface // kubernetes dynamic api client sbr *v1alpha1.ServiceBindingRequest // instantiated service binding request - logger *log.Log // logger instance + logger *log.Log // logger instance } // Plan outcome, after executing planner. diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index b1480e03e4..4723a9392d 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -17,7 +17,7 @@ import ( // Retriever reads all data referred in plan instance, and store in a secret. type Retriever struct { - logger *log.Log // logger instance + logger *log.Log // logger instance data map[string][]byte // data retrieved objects []*unstructured.Unstructured // list of objects employed client dynamic.Interface // Kubernetes API client diff --git a/pkg/log/log.go b/pkg/log/log.go index 44cc35e8ea..54f73d11cf 100644 --- a/pkg/log/log.go +++ b/pkg/log/log.go @@ -1,4 +1,4 @@ -package logging +package log import ( "fmt" From 9030102bfcb7d81a8e398f61384c5d5fee6d72d8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pavel=20Mac=C3=ADk?= Date: Fri, 11 Oct 2019 15:23:10 +0200 Subject: [PATCH 14/14] Shorter the log package imports. --- cmd/manager/main.go | 2 +- pkg/controller/servicebindingrequest/annotations.go | 2 +- pkg/controller/servicebindingrequest/binder.go | 2 +- pkg/controller/servicebindingrequest/mapper.go | 2 +- pkg/controller/servicebindingrequest/olm.go | 2 +- pkg/controller/servicebindingrequest/planner.go | 2 +- pkg/controller/servicebindingrequest/reconciler.go | 2 +- pkg/controller/servicebindingrequest/retriever.go | 2 +- pkg/controller/servicebindingrequest/sbrcontroller.go | 2 +- pkg/controller/servicebindingrequest/watch.go | 2 +- 10 files changed, 10 insertions(+), 10 deletions(-) diff --git a/cmd/manager/main.go b/cmd/manager/main.go index c63c535e06..f2109de770 100644 --- a/cmd/manager/main.go +++ b/cmd/manager/main.go @@ -28,7 +28,7 @@ import ( "github.com/redhat-developer/service-binding-operator/pkg/apis" "github.com/redhat-developer/service-binding-operator/pkg/controller" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" ) // Change below variables to serve metrics on different host or port. diff --git a/pkg/controller/servicebindingrequest/annotations.go b/pkg/controller/servicebindingrequest/annotations.go index 209fae702e..569c445e98 100644 --- a/pkg/controller/servicebindingrequest/annotations.go +++ b/pkg/controller/servicebindingrequest/annotations.go @@ -9,7 +9,7 @@ import ( "k8s.io/client-go/dynamic" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" ) const ( diff --git a/pkg/controller/servicebindingrequest/binder.go b/pkg/controller/servicebindingrequest/binder.go index aa3cf0670c..1e8924ed59 100644 --- a/pkg/controller/servicebindingrequest/binder.go +++ b/pkg/controller/servicebindingrequest/binder.go @@ -18,7 +18,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/client" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" ) const ( diff --git a/pkg/controller/servicebindingrequest/mapper.go b/pkg/controller/servicebindingrequest/mapper.go index a8c3873420..d1b70b705f 100644 --- a/pkg/controller/servicebindingrequest/mapper.go +++ b/pkg/controller/servicebindingrequest/mapper.go @@ -1,7 +1,7 @@ package servicebindingrequest import ( - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) diff --git a/pkg/controller/servicebindingrequest/olm.go b/pkg/controller/servicebindingrequest/olm.go index 25928c6d87..8bff5b435d 100644 --- a/pkg/controller/servicebindingrequest/olm.go +++ b/pkg/controller/servicebindingrequest/olm.go @@ -5,7 +5,7 @@ import ( "strings" olmv1alpha1 "github.com/operator-framework/operator-lifecycle-manager/pkg/api/apis/operators/v1alpha1" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime" diff --git a/pkg/controller/servicebindingrequest/planner.go b/pkg/controller/servicebindingrequest/planner.go index 18a88b7245..84023c3f32 100644 --- a/pkg/controller/servicebindingrequest/planner.go +++ b/pkg/controller/servicebindingrequest/planner.go @@ -11,7 +11,7 @@ import ( "k8s.io/client-go/dynamic" v1alpha1 "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" ) var ( diff --git a/pkg/controller/servicebindingrequest/reconciler.go b/pkg/controller/servicebindingrequest/reconciler.go index 8e7c7aa223..1e5e4f8906 100644 --- a/pkg/controller/servicebindingrequest/reconciler.go +++ b/pkg/controller/servicebindingrequest/reconciler.go @@ -14,7 +14,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/reconcile" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" ) // Reconciler reconciles a ServiceBindingRequest object diff --git a/pkg/controller/servicebindingrequest/retriever.go b/pkg/controller/servicebindingrequest/retriever.go index 4723a9392d..7604da548e 100644 --- a/pkg/controller/servicebindingrequest/retriever.go +++ b/pkg/controller/servicebindingrequest/retriever.go @@ -5,7 +5,7 @@ import ( "fmt" "strings" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" diff --git a/pkg/controller/servicebindingrequest/sbrcontroller.go b/pkg/controller/servicebindingrequest/sbrcontroller.go index 6c5f5f748c..565f0996e1 100644 --- a/pkg/controller/servicebindingrequest/sbrcontroller.go +++ b/pkg/controller/servicebindingrequest/sbrcontroller.go @@ -15,7 +15,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/source" "github.com/redhat-developer/service-binding-operator/pkg/apis/apps/v1alpha1" - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" ) // SBRController hold the controller instance and methods for a ServiceBindingRequest. diff --git a/pkg/controller/servicebindingrequest/watch.go b/pkg/controller/servicebindingrequest/watch.go index 544b695378..ffcc8f9f87 100644 --- a/pkg/controller/servicebindingrequest/watch.go +++ b/pkg/controller/servicebindingrequest/watch.go @@ -1,7 +1,7 @@ package servicebindingrequest import ( - log "github.com/redhat-developer/service-binding-operator/pkg/log" + "github.com/redhat-developer/service-binding-operator/pkg/log" "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/reconcile"