From 00b37678a06908a7176ec766a4e42fe58a9b64c4 Mon Sep 17 00:00:00 2001 From: Eric Stroczynski Date: Fri, 2 Nov 2018 16:23:32 -0700 Subject: [PATCH 1/6] pkg/logutil: SDK logging package for generated projects pkg/*,example/,test/: use logutil in all code used in generated operators --- commands/operator-sdk/cmd/up/local.go | 4 ++ .../memcached_controller.go.tmpl | 23 +++++----- pkg/ansible/controller/controller.go | 14 +++--- pkg/ansible/controller/reconcile.go | 28 ++++++------ pkg/ansible/controller/status/types.go | 9 ++-- pkg/ansible/events/log_events.go | 43 +++++++++++-------- pkg/ansible/operator/operator.go | 6 +-- pkg/ansible/proxy/kubectl.go | 15 ++++--- pkg/ansible/proxy/proxy.go | 23 +++++----- pkg/ansible/runner/eventapi/eventapi.go | 42 ++++++------------ pkg/ansible/runner/eventapi/types.go | 5 +-- .../runner/internal/inputdir/inputdir.go | 10 +++-- pkg/ansible/runner/runner.go | 29 +++++++------ pkg/leader/leader.go | 32 +++++++------- pkg/scaffold/cmd.go | 41 ++++++++++++------ pkg/scaffold/cmd_test.go | 41 ++++++++++++------ pkg/scaffold/controller_kind.go | 13 +++--- pkg/scaffold/controller_kind_test.go | 11 +++-- pkg/sdk/internal/metrics/metrics.go | 5 ++- pkg/sdk/metrics.go | 12 ++++-- .../cmd/ansible-operator/main.go | 25 ++++++----- 21 files changed, 243 insertions(+), 188 deletions(-) diff --git a/commands/operator-sdk/cmd/up/local.go b/commands/operator-sdk/cmd/up/local.go index 4aa910ed2a9..58cffa380ea 100644 --- a/commands/operator-sdk/cmd/up/local.go +++ b/commands/operator-sdk/cmd/up/local.go @@ -39,6 +39,7 @@ import ( "github.com/spf13/cobra" "sigs.k8s.io/controller-runtime/pkg/client/config" "sigs.k8s.io/controller-runtime/pkg/manager" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) func NewLocalCmd() *cobra.Command { @@ -134,6 +135,9 @@ func upLocal() { func upLocalAnsible() { // Set the kubeconfig that the manager will be able to grab os.Setenv(k8sutil.KubeConfigEnvVar, kubeConfig) + + logf.SetLogger(logf.ZapLogger(false)) + mgr, err := manager.New(config.GetConfigOrDie(), manager.Options{Namespace: namespace}) if err != nil { log.Fatal(err) diff --git a/example/memcached-operator/memcached_controller.go.tmpl b/example/memcached-operator/memcached_controller.go.tmpl index 0d8d8437090..033f8642351 100644 --- a/example/memcached-operator/memcached_controller.go.tmpl +++ b/example/memcached-operator/memcached_controller.go.tmpl @@ -2,7 +2,6 @@ package memcached import ( "context" - "log" "reflect" cachev1alpha1 "github.com/example-inc/memcached-operator/pkg/apis/cache/v1alpha1" @@ -20,9 +19,12 @@ import ( "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/manager" "sigs.k8s.io/controller-runtime/pkg/reconcile" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" "sigs.k8s.io/controller-runtime/pkg/source" ) +var log = logf.Log.WithName("controller_memcached") + /** * USER ACTION REQUIRED: This is a scaffold file intended for the user to modify with their own Controller * business logic. Delete these comments after modifying this file.* @@ -85,7 +87,8 @@ type ReconcileMemcached struct { // The Controller will requeue the Request to be processed again if the returned error is non-nil or // Result.Requeue is true, otherwise upon completion it will remove the work from the queue. func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Result, error) { - log.Printf("Reconciling Memcached %s/%s\n", request.Namespace, request.Name) + reqLogger := log.WithValues("Request.Namespace", request.Namespace, "Requst.Name", request.Name) + reqLogger.Info("Reconciling Memcached") // Fetch the Memcached instance memcached := &cachev1alpha1.Memcached{} @@ -95,11 +98,11 @@ func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Res // Request object not found, could have been deleted after reconcile request. // Owned objects are automatically garbage collected. For additional cleanup logic use finalizers. // Return and don't requeue - log.Printf("Memcached %s/%s not found. Ignoring since object must be deleted\n", request.Namespace, request.Name) + reqLogger.Info("Memcached resource not found. Ignoring since object must be deleted") return reconcile.Result{}, nil } // Error reading the object - requeue the request. - log.Printf("Failed to get Memcached: %v", err) + reqLogger.Error(err, "failed to get Memcached") return reconcile.Result{}, err } @@ -109,16 +112,16 @@ func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Res if err != nil && errors.IsNotFound(err) { // Define a new deployment dep := r.deploymentForMemcached(memcached) - log.Printf("Creating a new Deployment %s/%s\n", dep.Namespace, dep.Name) + reqLogger.Info("Creating a new Deployment", "Deployment.Namespace", dep.Namespace, "Deployment.Name", dep.Name) err = r.client.Create(context.TODO(), dep) if err != nil { - log.Printf("Failed to create new Deployment: %v\n", err) + reqLogger.Error(err, "failed to create new Deployment", "Deployment.Namespace", dep.Namespace, "Deployment.Name", dep.Name) return reconcile.Result{}, err } // Deployment created successfully - return and requeue return reconcile.Result{Requeue: true}, nil } else if err != nil { - log.Printf("Failed to get Deployment: %v\n", err) + reqLogger.Error(err, "failed to get Deployment") return reconcile.Result{}, err } @@ -128,7 +131,7 @@ func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Res found.Spec.Replicas = &size err = r.client.Update(context.TODO(), found) if err != nil { - log.Printf("Failed to update Deployment: %v\n", err) + reqLogger.Error(err, "failed to update Deployment", "Deployment.Namespace", found.Namespace, "Deployment.Name", found.Name) return reconcile.Result{}, err } // Spec updated - return and requeue @@ -142,7 +145,7 @@ func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Res listOps := &client.ListOptions{Namespace: memcached.Namespace, LabelSelector: labelSelector} err = r.client.List(context.TODO(), listOps, podList) if err != nil { - log.Printf("Failed to list pods: %v", err) + reqLogger.Error(err, "failed to list pods", "Memcached.Namespace", memcached.Namespace, "Memcached.Name", memcached.Name) return reconcile.Result{}, err } podNames := getPodNames(podList.Items) @@ -152,7 +155,7 @@ func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Res memcached.Status.Nodes = podNames err := r.client.Update(context.TODO(), memcached) if err != nil { - log.Printf("failed to update memcached status: %v", err) + reqLogger.Error(err, "failed to update Memcached status") return reconcile.Result{}, err } } diff --git a/pkg/ansible/controller/controller.go b/pkg/ansible/controller/controller.go index 262cb41380e..12c98d4ea16 100644 --- a/pkg/ansible/controller/controller.go +++ b/pkg/ansible/controller/controller.go @@ -16,23 +16,25 @@ package controller import ( "fmt" - "log" + "os" "strings" "time" "github.com/operator-framework/operator-sdk/pkg/ansible/events" "github.com/operator-framework/operator-sdk/pkg/ansible/runner" - "github.com/sirupsen/logrus" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime/schema" "sigs.k8s.io/controller-runtime/pkg/controller" crthandler "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/manager" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" "sigs.k8s.io/controller-runtime/pkg/source" ) +var log = logf.Log.WithName("ansible-controller") + // Options - options for your controller type Options struct { EventHandlers []events.EventHandler @@ -44,7 +46,7 @@ type Options struct { // Add - Creates a new ansible operator controller and adds it to the manager func Add(mgr manager.Manager, options Options) { - logrus.Infof("Watching %s/%v, %s", options.GVK.Group, options.GVK.Version, options.GVK.Kind) + log.Info("Watching resource", "Options.Group", options.GVK.Group, "Options.Version", options.GVK.Version, "Options.Kind", options.GVK.Kind) if options.EventHandlers == nil { options.EventHandlers = []events.EventHandler{} } @@ -70,11 +72,13 @@ func Add(mgr manager.Manager, options Options) { Reconciler: aor, }) if err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } u := &unstructured.Unstructured{} u.SetGroupVersionKind(options.GVK) if err := c.Watch(&source.Kind{Type: u}, &crthandler.EnqueueRequestForObject{}); err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } } diff --git a/pkg/ansible/controller/reconcile.go b/pkg/ansible/controller/reconcile.go index f10d684fc9c..431b80f7a3f 100644 --- a/pkg/ansible/controller/reconcile.go +++ b/pkg/ansible/controller/reconcile.go @@ -30,7 +30,6 @@ import ( "github.com/operator-framework/operator-sdk/pkg/ansible/runner" "github.com/operator-framework/operator-sdk/pkg/ansible/runner/eventapi" - "github.com/sirupsen/logrus" "k8s.io/api/core/v1" apierrors "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -38,6 +37,7 @@ import ( "k8s.io/apimachinery/pkg/runtime/schema" "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/reconcile" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) const ( @@ -69,12 +69,11 @@ func (r *AnsibleOperatorReconciler) Reconcile(request reconcile.Request) (reconc } ident := strconv.Itoa(rand.Int()) - logger := logrus.WithFields(logrus.Fields{ - "component": "reconciler", - "job": ident, - "name": u.GetName(), - "namespace": u.GetNamespace(), - }) + logger := logf.Log.WithName("reconciler").WithValues( + "job", ident, + "name", u.GetName(), + "namespace", u.GetNamespace(), + ) reconcileResult := reconcile.Result{RequeueAfter: r.ReconcilePeriod} if ds, ok := u.GetAnnotations()[ReconcilePeriodAnnotation]; ok { @@ -90,7 +89,7 @@ func (r *AnsibleOperatorReconciler) Reconcile(request reconcile.Request) (reconc pendingFinalizers := u.GetFinalizers() // If the resource is being deleted we don't want to add the finalizer again if finalizerExists && !deleted && !contains(pendingFinalizers, finalizer) { - logger.Debugf("Adding finalizer %s to resource", finalizer) + logger.V(1).Info("Adding finalizer to resource", "Finalizer", finalizer) finalizers := append(pendingFinalizers, finalizer) u.SetFinalizers(finalizers) err := r.Client.Update(context.TODO(), u) @@ -106,7 +105,7 @@ func (r *AnsibleOperatorReconciler) Reconcile(request reconcile.Request) (reconc spec := u.Object["spec"] _, ok := spec.(map[string]interface{}) if !ok { - logger.Debugf("spec was not found") + logger.V(1).Info("spec was not found") u.Object["spec"] = map[string]interface{}{} err = r.Client.Update(context.TODO(), u) if err != nil { @@ -180,15 +179,14 @@ func (r *AnsibleOperatorReconciler) Reconcile(request reconcile.Request) (reconc } } if statusEvent.Event == "" { - msg := "did not receive playbook_on_stats event" - logger.Error(msg) + eventErr := errors.New("did not receive playbook_on_stats event") stdout, err := result.Stdout() if err != nil { - logger.Infof("failed to get ansible-runner stdout: %s\n", err.Error()) - } else { - logger.Error(stdout) + logger.Error(err, "failed to get ansible-runner stdout") + return reconcileResult, err } - return reconcileResult, errors.New(msg) + logger.Error(eventErr, stdout) + return reconcileResult, eventErr } // We only want to update the CustomResource once, so we'll track changes and do it at the end diff --git a/pkg/ansible/controller/status/types.go b/pkg/ansible/controller/status/types.go index 8da061710c3..396ac608bd2 100644 --- a/pkg/ansible/controller/status/types.go +++ b/pkg/ansible/controller/status/types.go @@ -18,11 +18,14 @@ import ( "time" "github.com/operator-framework/operator-sdk/pkg/ansible/runner/eventapi" - "github.com/sirupsen/logrus" + "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) +var log = logf.Log.WithName("controller.status") + const ( host = "localhost" ) @@ -128,7 +131,7 @@ func createConditionFromMap(cm map[string]interface{}) Condition { if ok { t, err := time.Parse("2006-01-02T15:04:05Z", ltts) if err != nil { - logrus.Warningf("unable to parse time for status condition: %v", ltts) + log.Info("unable to parse time for status condition", "Time", ltts) } else { ltt = metav1.NewTime(t) } @@ -158,7 +161,7 @@ func CreateFromMap(statusMap map[string]interface{}) Status { for _, ci := range conditionsInterface { cm, ok := ci.(map[string]interface{}) if !ok { - logrus.Warningf("unknown condition, removing condition: %v", ci) + log.Info("unknown condition, removing condition", "ConditionInterface", ci) continue } conditions = append(conditions, createConditionFromMap(cm)) diff --git a/pkg/ansible/events/log_events.go b/pkg/ansible/events/log_events.go index b7cce7066e8..271be8e0d8a 100644 --- a/pkg/ansible/events/log_events.go +++ b/pkg/ansible/events/log_events.go @@ -15,9 +15,12 @@ package events import ( + "errors" + "github.com/operator-framework/operator-sdk/pkg/ansible/runner/eventapi" - "github.com/sirupsen/logrus" + "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) // LogLevel - Levelt for the logging to take place. @@ -44,44 +47,48 @@ type loggingEventHandler struct { } func (l loggingEventHandler) Handle(ident string, u *unstructured.Unstructured, e eventapi.JobEvent) { - log := logrus.WithFields(logrus.Fields{ - "component": "logging_event_handler", - "name": u.GetName(), - "namespace": u.GetNamespace(), - "gvk": u.GroupVersionKind().String(), - "event_type": e.Event, - "job": ident, - }) if l.LogLevel == Nothing { return } - // log only the following for the 'Tasks' LogLevel + + logger := logf.Log.WithName("logging_event_handler").WithValues( + "name", u.GetName(), + "namespace", u.GetNamespace(), + "gvk", u.GroupVersionKind().String(), + "event_type", e.Event, + "job", ident, + ) + + // logger only the following for the 'Tasks' LogLevel t, ok := e.EventData["task"] if ok { setFactAction := e.EventData["task_action"] == eventapi.TaskActionSetFact debugAction := e.EventData["task_action"] == eventapi.TaskActionDebug if e.Event == eventapi.EventPlaybookOnTaskStart && !setFactAction && !debugAction { - log.Infof("[playbook task]: %s", e.EventData["name"]) + logger.Info("[playbook task]", "EventData.Name", e.EventData["name"]) return } if e.Event == eventapi.EventRunnerOnOk && debugAction { - log.Infof("[playbook debug]: %v", e.EventData["task_args"]) + logger.V(1).Info("[playbook debug]", "EventData.TaskArgs", e.EventData["task_args"]) return } if e.Event == eventapi.EventRunnerOnFailed { - log.Errorf("[failed]: [playbook task] '%s' failed with task_args - %v", - t, e.EventData["task_args"]) - taskPath, ok := e.EventData["task_path"] - if ok { - log.Errorf("failed task: %s\n", taskPath) + errKVs := []interface{}{ + "EventData.Task", t, + "EventData.TaskArgs", e.EventData["task_args"], + } + if taskPath, ok := e.EventData["task_path"]; ok { + errKVs = append(errKVs, "EventData.FailedTaskPath", taskPath) } + logger.Error(errors.New("[playbook task failed]"), "", errKVs...) return } } + // log everything else for the 'Everything' LogLevel if l.LogLevel == Everything { - log.Infof("event: %#v", e.EventData) + logger.Info("", "EventData", e.EventData) } } diff --git a/pkg/ansible/operator/operator.go b/pkg/ansible/operator/operator.go index 394bacaf0a1..f828fac382d 100644 --- a/pkg/ansible/operator/operator.go +++ b/pkg/ansible/operator/operator.go @@ -20,10 +20,10 @@ import ( "github.com/operator-framework/operator-sdk/pkg/ansible/controller" "github.com/operator-framework/operator-sdk/pkg/ansible/runner" + "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/sirupsen/logrus" ) // Run - A blocking function which starts a controller-runtime manager @@ -32,7 +32,7 @@ import ( func Run(done chan error, mgr manager.Manager, watchesPath string, reconcilePeriod time.Duration) { watches, err := runner.NewFromWatches(watchesPath) if err != nil { - logrus.Error("Failed to get watches") + logf.Log.WithName("manager").Error(err, "failed to get watches") done <- err return } diff --git a/pkg/ansible/proxy/kubectl.go b/pkg/ansible/proxy/kubectl.go index 3c24243b7e6..bfe3db4ebd4 100644 --- a/pkg/ansible/proxy/kubectl.go +++ b/pkg/ansible/proxy/kubectl.go @@ -22,7 +22,6 @@ package proxy import ( "fmt" - "log" "net" "net/http" "net/url" @@ -36,8 +35,11 @@ import ( k8sproxy "k8s.io/apimachinery/pkg/util/proxy" "k8s.io/client-go/rest" "k8s.io/client-go/transport" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) +var log = logf.Log.WithName("proxy") + const ( // DefaultHostAcceptRE is the default value for which hosts to accept. DefaultHostAcceptRE = "^localhost$,^127\\.0\\.0\\.1$,^\\[::1\\]$" @@ -91,7 +93,8 @@ func MakeRegexpArray(str string) ([]*regexp.Regexp, error) { func MakeRegexpArrayOrDie(str string) []*regexp.Regexp { result, err := MakeRegexpArray(str) if err != nil { - log.Fatalf("error compiling re: %v", err) + log.Error(err, "error compiling re") + os.Exit(1) } return result } @@ -99,7 +102,7 @@ func MakeRegexpArrayOrDie(str string) []*regexp.Regexp { func matchesRegexp(str string, regexps []*regexp.Regexp) bool { for _, re := range regexps { if re.MatchString(str) { - log.Printf("%v matched %s", str, re) + log.Info("matched found", "MatchString", str, "Regexp", re) return true } } @@ -139,11 +142,11 @@ func extractHost(header string) (host string) { func (f *FilterServer) ServeHTTP(rw http.ResponseWriter, req *http.Request) { host := extractHost(req.Host) if f.accept(req.Method, req.URL.Path, host) { - log.Printf("Filter accepting %v %v %v", req.Method, req.URL.Path, host) + log.Info("Filter acception", "Request.Method", req.Method, "Request.URL", req.URL.Path, "Host", host) f.delegate.ServeHTTP(rw, req) return } - log.Printf("Filter rejecting %v %v %v", req.Method, req.URL.Path, host) + log.Info("Filter rejection", "Request.Method", req.Method, "Request.URL", req.URL.Path, "Host", host) rw.WriteHeader(http.StatusForbidden) rw.Write([]byte("

Unauthorized

")) } @@ -156,7 +159,7 @@ type server struct { type responder struct{} func (r *responder) Error(w http.ResponseWriter, req *http.Request, err error) { - log.Printf("Error while proxying request: %v", err) + log.Error(err, "error while proxying request") http.Error(w, err.Error(), http.StatusInternalServerError) } diff --git a/pkg/ansible/proxy/proxy.go b/pkg/ansible/proxy/proxy.go index 0ab87eca3b6..3f519614a04 100644 --- a/pkg/ansible/proxy/proxy.go +++ b/pkg/ansible/proxy/proxy.go @@ -21,11 +21,12 @@ import ( "bytes" "encoding/base64" "encoding/json" + "errors" + "fmt" "io/ioutil" "net/http" "net/http/httputil" - "github.com/sirupsen/logrus" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/client-go/rest" @@ -37,13 +38,13 @@ import ( func InjectOwnerReferenceHandler(h http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) { if req.Method == http.MethodPost { - logrus.Info("injecting owner reference") + log.Info("injecting owner reference") dump, _ := httputil.DumpRequest(req, false) - logrus.Debugf(string(dump)) + log.V(1).Info("dumping request", "RequestDump", string(dump)) user, _, ok := req.BasicAuth() if !ok { - logrus.Error("basic auth header not found") + log.Error(errors.New("basic auth header not found"), "") w.Header().Set("WWW-Authenticate", "Basic realm=\"Operator Proxy\"") http.Error(w, "", http.StatusUnauthorized) return @@ -51,19 +52,19 @@ func InjectOwnerReferenceHandler(h http.Handler) http.Handler { authString, err := base64.StdEncoding.DecodeString(user) if err != nil { m := "could not base64 decode username" - logrus.Errorf("%s", err.Error()) + log.Error(err, m) http.Error(w, m, http.StatusBadRequest) return } owner := metav1.OwnerReference{} json.Unmarshal(authString, &owner) - logrus.Debugf("%#+v", owner) + log.V(1).Info(fmt.Sprintf("%#+v", owner)) body, err := ioutil.ReadAll(req.Body) if err != nil { m := "could not read request body" - logrus.Errorf("%s", err.Error()) + log.Error(err, m) http.Error(w, m, http.StatusInternalServerError) return } @@ -71,7 +72,7 @@ func InjectOwnerReferenceHandler(h http.Handler) http.Handler { err = json.Unmarshal(body, data) if err != nil { m := "could not deserialize request body" - logrus.Errorf("%s", err.Error()) + log.Error(err, m) http.Error(w, m, http.StatusBadRequest) return } @@ -79,11 +80,11 @@ func InjectOwnerReferenceHandler(h http.Handler) http.Handler { newBody, err := json.Marshal(data.Object) if err != nil { m := "could not serialize body" - logrus.Errorf("%s", err.Error()) + log.Error(err, m) http.Error(w, m, http.StatusInternalServerError) return } - logrus.Debugf(string(newBody)) + log.V(1).Info("serialized body", "Body", string(newBody)) req.Body = ioutil.NopCloser(bytes.NewBuffer(newBody)) req.ContentLength = int64(len(newBody)) } @@ -128,7 +129,7 @@ func Run(done chan error, o Options) error { return err } go func() { - logrus.Infof("Starting to serve on %s\n", l.Addr().String()) + log.Info("Starting to serve", "Address", l.Addr().String()) done <- server.ServeOnListener(l) }() return nil diff --git a/pkg/ansible/runner/eventapi/eventapi.go b/pkg/ansible/runner/eventapi/eventapi.go index 10a9b2b2fae..69e12ac6a1f 100644 --- a/pkg/ansible/runner/eventapi/eventapi.go +++ b/pkg/ansible/runner/eventapi/eventapi.go @@ -25,7 +25,8 @@ import ( "sync" "time" - "github.com/sirupsen/logrus" + "github.com/go-logr/logr" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) // EventReceiver serves the event API @@ -58,7 +59,7 @@ type EventReceiver struct { ident string // logger holds a logger that has some fields already set - logger logrus.FieldLogger + logger logr.Logger } func New(ident string, errChan chan<- error) (*EventReceiver, error) { @@ -73,10 +74,7 @@ func New(ident string, errChan chan<- error) (*EventReceiver, error) { SocketPath: sockPath, URLPath: "/events/", ident: ident, - logger: logrus.WithFields(logrus.Fields{ - "component": "eventapi", - "job": ident, - }), + logger: logf.Log.WithName("eventapi").WithValues("job", ident), } mux := http.NewServeMux() @@ -96,7 +94,7 @@ func (e *EventReceiver) Close() { e.mutex.Lock() e.stopped = true e.mutex.Unlock() - e.logger.Debug("event API stopped") + e.logger.V(1).Info("event API stopped") e.server.Close() close(e.Events) } @@ -104,25 +102,19 @@ func (e *EventReceiver) Close() { func (e *EventReceiver) handleEvents(w http.ResponseWriter, r *http.Request) { if r.URL.Path != e.URLPath { http.NotFound(w, r) - e.logger.WithFields(logrus.Fields{ - "code": "404", - }).Infof("path not found: %s\n", r.URL.Path) + e.logger.Info("path not found", "code", "404", "Request.Path", r.URL.Path) return } if r.Method != http.MethodPost { - e.logger.WithFields(logrus.Fields{ - "code": "405", - }).Infof("method %s not allowed", r.Method) + e.logger.Info("method not allowed", "code", "405", "Request.Method", r.Method) w.WriteHeader(http.StatusMethodNotAllowed) return } ct := r.Header.Get("content-type") if strings.Split(ct, ";")[0] != "application/json" { - e.logger.WithFields(logrus.Fields{ - "code": "415", - }).Infof("wrong content type: %s", ct) + e.logger.Info("wrong content type", "code", "415", "Request.Content-Type", ct) w.WriteHeader(http.StatusUnsupportedMediaType) w.Write([]byte("The content-type must be \"application/json\"")) return @@ -130,9 +122,7 @@ func (e *EventReceiver) handleEvents(w http.ResponseWriter, r *http.Request) { body, err := ioutil.ReadAll(r.Body) if err != nil { - e.logger.WithFields(logrus.Fields{ - "code": "500", - }).Errorf("%s", err.Error()) + e.logger.Error(err, "could not read request body", "code", "500") w.WriteHeader(http.StatusInternalServerError) return } @@ -140,9 +130,7 @@ func (e *EventReceiver) handleEvents(w http.ResponseWriter, r *http.Request) { event := JobEvent{} err = json.Unmarshal(body, &event) if err != nil { - e.logger.WithFields(logrus.Fields{ - "code": "400", - }).Infof("could not deserialize body: %s", err.Error()) + e.logger.Info("could not deserialize body.", "code", "400", "Error", err) w.WriteHeader(http.StatusBadRequest) w.Write([]byte("Could not deserialize body as JSON")) return @@ -155,9 +143,7 @@ func (e *EventReceiver) handleEvents(w http.ResponseWriter, r *http.Request) { if e.stopped { e.mutex.RUnlock() w.WriteHeader(http.StatusGone) - e.logger.WithFields(logrus.Fields{ - "code": "410", - }).Info("stopped and not accepting additional events for this job") + e.logger.Info("stopped and not accepting additional events for this job", "code", "410") return } // ansible-runner sends "status events" and "ansible events". The "status @@ -165,16 +151,14 @@ func (e *EventReceiver) handleEvents(w http.ResponseWriter, r *http.Request) { // we're not currently interested in. // https://ansible-runner.readthedocs.io/en/latest/external_interface.html#event-structure if event.UUID == "" { - e.logger.Debug("dropping event that is not a JobEvent") + e.logger.V(1).Info("dropping event that is not a JobEvent") } else { // timeout if the channel blocks for too long timeout := time.NewTimer(10 * time.Second) select { case e.Events <- event: case <-timeout.C: - e.logger.WithFields(logrus.Fields{ - "code": "500", - }).Warn("timed out writing event to channel") + e.logger.Info("timed out writing event to channel", "code", "500") w.WriteHeader(http.StatusInternalServerError) return } diff --git a/pkg/ansible/runner/eventapi/types.go b/pkg/ansible/runner/eventapi/types.go index f360a01121f..3f0492547ec 100644 --- a/pkg/ansible/runner/eventapi/types.go +++ b/pkg/ansible/runner/eventapi/types.go @@ -51,10 +51,7 @@ type EventTime struct { // UnmarshalJSON - override unmarshal json. func (e *EventTime) UnmarshalJSON(b []byte) (err error) { e.Time, err = time.Parse("2006-01-02T15:04:05.999999999", strings.Trim(string(b[:]), "\"\\")) - if err != nil { - return err - } - return nil + return } // MarshalJSON - override the marshal json. diff --git a/pkg/ansible/runner/internal/inputdir/inputdir.go b/pkg/ansible/runner/internal/inputdir/inputdir.go index 07771dd7233..ce2c9915d38 100644 --- a/pkg/ansible/runner/internal/inputdir/inputdir.go +++ b/pkg/ansible/runner/internal/inputdir/inputdir.go @@ -21,9 +21,11 @@ import ( "os" "path/filepath" - "github.com/sirupsen/logrus" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) +var log = logf.Log.WithName("inputdir") + // InputDir represents an input directory for ansible-runner. type InputDir struct { Path string @@ -39,7 +41,7 @@ func (i *InputDir) makeDirs() error { fullPath := filepath.Join(i.Path, path) err := os.MkdirAll(fullPath, os.ModePerm) if err != nil { - logrus.Errorf("unable to create directory %v", fullPath) + log.Error(err, "unable to create directory", "Path", fullPath) return err } } @@ -51,7 +53,7 @@ func (i *InputDir) addFile(path string, content []byte) error { fullPath := filepath.Join(i.Path, path) err := ioutil.WriteFile(fullPath, content, 0644) if err != nil { - logrus.Errorf("unable to write file %v", fullPath) + log.Error(err, "unable to write file", "Path", fullPath) } return err } @@ -112,7 +114,7 @@ func (i *InputDir) Write() error { if i.PlaybookPath != "" { f, err := os.Open(i.PlaybookPath) if err != nil { - logrus.Errorf("failed to open playbook file %v", i.PlaybookPath) + log.Error(err, "failed to open playbook file", "Path", i.PlaybookPath) return err } defer f.Close() diff --git a/pkg/ansible/runner/runner.go b/pkg/ansible/runner/runner.go index a68367a6d14..4caedc20680 100644 --- a/pkg/ansible/runner/runner.go +++ b/pkg/ansible/runner/runner.go @@ -28,12 +28,15 @@ import ( "github.com/operator-framework/operator-sdk/pkg/ansible/paramconv" "github.com/operator-framework/operator-sdk/pkg/ansible/runner/eventapi" "github.com/operator-framework/operator-sdk/pkg/ansible/runner/internal/inputdir" - "github.com/sirupsen/logrus" + yaml "gopkg.in/yaml.v2" "k8s.io/apimachinery/pkg/apis/meta/v1/unstructured" "k8s.io/apimachinery/pkg/runtime/schema" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) +var log = logf.Log.WithName("runner") + // Runner - a runnable that should take the parameters and name and namespace // and run the correct code. type Runner interface { @@ -66,13 +69,13 @@ type Finalizer struct { func NewFromWatches(path string) (map[schema.GroupVersionKind]Runner, error) { b, err := ioutil.ReadFile(path) if err != nil { - logrus.Errorf("failed to get config file %v", err) + log.Error(err, "failed to get config file") return nil, err } watches := []watch{} err = yaml.Unmarshal(b, &watches) if err != nil { - logrus.Errorf("failed to unmarshal config %v", err) + log.Error(err, "failed to unmarshal config") return nil, err } @@ -178,12 +181,12 @@ func (r *runner) Run(ident string, u *unstructured.Unstructured, kubeconfig stri if u.GetDeletionTimestamp() != nil && !r.isFinalizerRun(u) { return nil, errors.New("resource has been deleted, but no finalizer was matched, skipping reconciliation") } - logger := logrus.WithFields(logrus.Fields{ - "component": "runner", - "job": ident, - "name": u.GetName(), - "namespace": u.GetNamespace(), - }) + logger := log.WithValues( + "job", ident, + "name", u.GetName(), + "namespace", u.GetNamespace(), + ) + // start the event receiver. We'll check errChan for an error after // ansible-runner exits. errChan := make(chan error, 1) @@ -219,7 +222,7 @@ func (r *runner) Run(ident string, u *unstructured.Unstructured, kubeconfig stri go func() { var dc *exec.Cmd if r.isFinalizerRun(u) { - logger.Debugf("Resource is marked for deletion, running finalizer %s", r.Finalizer.Name) + logger.V(1).Info("Resource is marked for deletion, running finalizer", "Finalizer", r.Finalizer.Name) dc = r.finalizerCmdFunc(ident, inputDir.Path) } else { dc = r.cmdFunc(ident, inputDir.Path) @@ -227,7 +230,7 @@ func (r *runner) Run(ident string, u *unstructured.Unstructured, kubeconfig stri err := dc.Run() if err != nil { - logger.Errorf("error from ansible-runner: %s", err.Error()) + logger.Error(err, "error from ansible-runner") } else { logger.Info("ansible-runner exited successfully") } @@ -236,7 +239,7 @@ func (r *runner) Run(ident string, u *unstructured.Unstructured, kubeconfig stri err = <-errChan // http.Server returns this in the case of being closed cleanly if err != nil && err != http.ErrServerClosed { - logger.Errorf("error from event api: %s", err.Error()) + logger.Error(err, "error from event api") } }() return &RunResult{ @@ -317,7 +320,7 @@ func (r *runner) makeParameters(u *unstructured.Unstructured) map[string]interfa s := u.Object["spec"] spec, ok := s.(map[string]interface{}) if !ok { - logrus.Warnf("spec was not found for CR:%v - %v in %v", u.GroupVersionKind(), u.GetNamespace(), u.GetName()) + log.Info("spec was not found for CR", "GroupVersionKind", u.GroupVersionKind(), "Namespace", u.GetNamespace(), "Name", u.GetName()) spec = map[string]interface{}{} } parameters := paramconv.MapToSnake(spec) diff --git a/pkg/leader/leader.go b/pkg/leader/leader.go index 14536a4a092..4b977f9c028 100644 --- a/pkg/leader/leader.go +++ b/pkg/leader/leader.go @@ -23,15 +23,17 @@ import ( "strings" "time" - "github.com/sirupsen/logrus" corev1 "k8s.io/api/core/v1" apierrors "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/util/wait" "k8s.io/client-go/rest" crclient "sigs.k8s.io/controller-runtime/pkg/client" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) +var log = logf.Log.WithName("leader") + // errNoNS indicates that a namespace could not be found for the current // environment var errNoNS = errors.New("namespace not found for current environment") @@ -50,12 +52,12 @@ const PodNameEnv = "POD_NAME" // leader. Upon termination of that pod, the garbage collector will delete the // ConfigMap, enabling a different pod to become the leader. func Become(ctx context.Context, lockName string) error { - logrus.Info("trying to become the leader") + log.Info("Trying to become the leader.") ns, err := myNS() if err != nil { if err == errNoNS { - logrus.Info("Skipping leader election; not running in a cluster") + log.Info("Skipping leader election; not running in a cluster.") return nil } return err @@ -90,17 +92,17 @@ func Become(ctx context.Context, lockName string) error { case err == nil: for _, existingOwner := range existing.GetOwnerReferences() { if existingOwner.Name == owner.Name { - logrus.Info("Found existing lock with my name. I was likely restarted.") - logrus.Info("Continuing as the leader.") + log.Info("Found existing lock with my name. I was likely restarted.") + log.Info("Continuing as the leader.") return nil } else { - logrus.Infof("Found existing lock from %s", existingOwner.Name) + log.Info("Found existing lock", "LockOwner", existingOwner.Name) } } case apierrors.IsNotFound(err): - logrus.Info("No pre-existing lock was found.") + log.Info("No pre-existing lock was found.") default: - logrus.Error("unknown error trying to get ConfigMap") + log.Error(err, "unknown error trying to get ConfigMap") return err } @@ -122,10 +124,10 @@ func Become(ctx context.Context, lockName string) error { err := client.Create(ctx, cm) switch { case err == nil: - logrus.Info("Became the leader.") + log.Info("Became the leader.") return nil case apierrors.IsAlreadyExists(err): - logrus.Info("Not the leader. Waiting.") + log.Info("Not the leader. Waiting.") select { case <-time.After(wait.Jitter(backoff, .2)): if backoff < maxBackoffInterval { @@ -136,7 +138,7 @@ func Become(ctx context.Context, lockName string) error { return ctx.Err() } default: - logrus.Errorf("unknown error creating configmap: %v", err) + log.Error(err, "unknown error creating configmap") return err } } @@ -147,13 +149,13 @@ func myNS() (string, error) { nsBytes, err := ioutil.ReadFile("/var/run/secrets/kubernetes.io/serviceaccount/namespace") if err != nil { if os.IsNotExist(err) { - logrus.Debug("current namespace not found") + log.V(1).Info("current namespace not found") return "", errNoNS } return "", err } ns := strings.TrimSpace(string(nsBytes)) - logrus.Debugf("found namespace: %s", ns) + log.V(1).Info("found namespace", "Namespace", ns) return ns, nil } @@ -166,7 +168,7 @@ func myOwnerRef(ctx context.Context, client crclient.Client, ns string) (*metav1 return nil, fmt.Errorf("required env %s not set, please configure downward API", PodNameEnv) } - logrus.Debugf("found podname: %s", podName) + log.V(1).Info("found podname", "Pod.Name", podName) myPod := &corev1.Pod{ TypeMeta: metav1.TypeMeta{ @@ -178,7 +180,7 @@ func myOwnerRef(ctx context.Context, client crclient.Client, ns string) (*metav1 key := crclient.ObjectKey{Namespace: ns, Name: podName} err := client.Get(ctx, key, myPod) if err != nil { - logrus.Errorf("failed to get pod: %v", err) + log.Error(err, "failed to get pod", "Pod.Namespace", ns, "Pod.Name", podName) return nil, err } diff --git a/pkg/scaffold/cmd.go b/pkg/scaffold/cmd.go index 8410d16e3a4..eaee51dfa5a 100644 --- a/pkg/scaffold/cmd.go +++ b/pkg/scaffold/cmd.go @@ -38,7 +38,8 @@ const cmdTmpl = `package main import ( "flag" - "log" + "fmt" + "os" "runtime" "{{ .Repo }}/pkg/apis" @@ -49,51 +50,67 @@ import ( _ "k8s.io/client-go/plugin/pkg/client/auth/gcp" "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" ) func printVersion() { - log.Printf("Go Version: %s", runtime.Version()) - log.Printf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH) - log.Printf("operator-sdk Version: %v", sdkVersion.Version) + logf.Log.Info(fmt.Sprintf("Go Version: %s", runtime.Version())) + logf.Log.Info(fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) + logf.Log.Info(fmt.Sprintf("operator-sdk Version: %v", sdkVersion.Version)) } func main() { printVersion() flag.Parse() + // The logger instantiated here can be changed to any logger + // implementing the logr.Logger interface. This logger will + // be propagated through the whole operator, generating + // uniform and structured logs. + logf.SetLogger(logf.ZapLogger(false)) + log := logf.Log.WithName("cmd") + namespace, err := k8sutil.GetWatchNamespace() if err != nil { - log.Fatalf("failed to get watch namespace: %v", err) + log.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 { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } // Create a new Cmd to provide shared dependencies and start components mgr, err := manager.New(cfg, manager.Options{Namespace: namespace}) if err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } - log.Print("Registering Components.") + log.Info("Registering Components.") // Setup Scheme for all resources if err := apis.AddToScheme(mgr.GetScheme()); err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } // Setup all Controllers if err := controller.AddToManager(mgr); err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } - log.Print("Starting the Cmd.") + log.Info("Starting the Cmd.") // Start the Cmd - log.Fatal(mgr.Start(signals.SetupSignalHandler())) + if err := mgr.Start(signals.SetupSignalHandler()); err != nil { + log.Error(err, "manager exited non-zero") + os.Exit(1) + } } ` diff --git a/pkg/scaffold/cmd_test.go b/pkg/scaffold/cmd_test.go index e9468baac85..5b93f90ed4d 100644 --- a/pkg/scaffold/cmd_test.go +++ b/pkg/scaffold/cmd_test.go @@ -37,7 +37,8 @@ const cmdExp = `package main import ( "flag" - "log" + "fmt" + "os" "runtime" "github.com/example-inc/app-operator/pkg/apis" @@ -47,51 +48,67 @@ import ( _ "k8s.io/client-go/plugin/pkg/client/auth/gcp" "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" ) func printVersion() { - log.Printf("Go Version: %s", runtime.Version()) - log.Printf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH) - log.Printf("operator-sdk Version: %v", sdkVersion.Version) + logf.Log.Info(fmt.Sprintf("Go Version: %s", runtime.Version())) + logf.Log.Info(fmt.Sprintf("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH)) + logf.Log.Info(fmt.Sprintf("operator-sdk Version: %v", sdkVersion.Version)) } func main() { printVersion() flag.Parse() + // The logger instantiated here can be changed to any logger + // implementing the logr.Logger interface. This logger will + // be propagated through the whole operator, generating + // uniform and structured logs. + logf.SetLogger(logf.ZapLogger(false)) + log := logf.Log.WithName("cmd") + namespace, err := k8sutil.GetWatchNamespace() if err != nil { - log.Fatalf("failed to get watch namespace: %v", err) + log.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 { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } // Create a new Cmd to provide shared dependencies and start components mgr, err := manager.New(cfg, manager.Options{Namespace: namespace}) if err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } - log.Print("Registering Components.") + log.Info("Registering Components.") // Setup Scheme for all resources if err := apis.AddToScheme(mgr.GetScheme()); err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } // Setup all Controllers if err := controller.AddToManager(mgr); err != nil { - log.Fatal(err) + log.Error(err, "") + os.Exit(1) } - log.Print("Starting the Cmd.") + log.Info("Starting the Cmd.") // Start the Cmd - log.Fatal(mgr.Start(signals.SetupSignalHandler())) + if err := mgr.Start(signals.SetupSignalHandler()); err != nil { + log.Error(err, "manager exited non-zero") + os.Exit(1) + } } ` diff --git a/pkg/scaffold/controller_kind.go b/pkg/scaffold/controller_kind.go index d831066b0d9..f33fdecc1ed 100644 --- a/pkg/scaffold/controller_kind.go +++ b/pkg/scaffold/controller_kind.go @@ -43,7 +43,6 @@ const controllerKindTemplate = `package {{ .Resource.LowerKind }} import ( "context" - "log" {{ .Resource.Group}}{{ .Resource.Version }} "{{ .Repo }}/pkg/apis/{{ .Resource.Group}}/{{ .Resource.Version }}" @@ -58,9 +57,12 @@ import ( "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/manager" "sigs.k8s.io/controller-runtime/pkg/reconcile" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" "sigs.k8s.io/controller-runtime/pkg/source" ) +var log = logf.Log.WithName("controller_{{ .Resource.LowerKind }}") + /** * USER ACTION REQUIRED: This is a scaffold file intended for the user to modify with their own Controller * business logic. Delete these comments after modifying this file.* @@ -122,7 +124,8 @@ type Reconcile{{ .Resource.Kind }} struct { // The Controller will requeue the Request to be processed again if the returned error is non-nil or // Result.Requeue is true, otherwise upon completion it will remove the work from the queue. func (r *Reconcile{{ .Resource.Kind }}) Reconcile(request reconcile.Request) (reconcile.Result, error) { - log.Printf("Reconciling {{ .Resource.Kind }} %s/%s\n", request.Namespace, request.Name) + reqLogger := reqLogger.WithValues("Request.Namespace", request.Namespace, "Requst.Name", request.Name) + reqLogger.Info("Reconciling {{ .Resource.Kind }}") // Fetch the {{ .Resource.Kind }} instance instance := &{{ .Resource.Group}}{{ .Resource.Version }}.{{ .Resource.Kind }}{} @@ -150,7 +153,7 @@ func (r *Reconcile{{ .Resource.Kind }}) Reconcile(request reconcile.Request) (re found := &corev1.Pod{} err = r.client.Get(context.TODO(), types.NamespacedName{Name: pod.Name, Namespace: pod.Namespace}, found) if err != nil && errors.IsNotFound(err) { - log.Printf("Creating a new Pod %s/%s\n", pod.Namespace, pod.Name) + reqLogger.Info("Creating a new Pod", "Pod.Namespace", pod.Namespace, "Pod.Name", pod.Name) err = r.client.Create(context.TODO(), pod) if err != nil { return reconcile.Result{}, err @@ -163,11 +166,11 @@ func (r *Reconcile{{ .Resource.Kind }}) Reconcile(request reconcile.Request) (re } // Pod already exists - don't requeue - log.Printf("Skip reconcile: Pod %s/%s already exists", found.Namespace, found.Name) + reqLogger.Info("Skip reconcile: Pod already exists", "Pod.Namespace", found.Namespace, "Pod.Name", found.Name) return reconcile.Result{}, nil } -// newPodForCR returns a busybox pod with the same name/namespace as the cr +// newPodForCR returns a busybox pod with the same name/namespace as the cr func newPodForCR(cr *{{ .Resource.Group}}{{ .Resource.Version }}.{{ .Resource.Kind }}) *corev1.Pod { labels := map[string]string{ "app": cr.Name, diff --git a/pkg/scaffold/controller_kind_test.go b/pkg/scaffold/controller_kind_test.go index ad57a76bdaa..565a3d196f5 100644 --- a/pkg/scaffold/controller_kind_test.go +++ b/pkg/scaffold/controller_kind_test.go @@ -41,7 +41,6 @@ const controllerKindExp = `package appservice import ( "context" - "log" appv1alpha1 "github.com/example-inc/app-operator/pkg/apis/app/v1alpha1" corev1 "k8s.io/api/core/v1" @@ -55,9 +54,12 @@ import ( "sigs.k8s.io/controller-runtime/pkg/handler" "sigs.k8s.io/controller-runtime/pkg/manager" "sigs.k8s.io/controller-runtime/pkg/reconcile" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" "sigs.k8s.io/controller-runtime/pkg/source" ) +var log = logf.Log.WithName("controller_appservice") + /** * USER ACTION REQUIRED: This is a scaffold file intended for the user to modify with their own Controller * business logic. Delete these comments after modifying this file.* @@ -119,7 +121,8 @@ type ReconcileAppService struct { // The Controller will requeue the Request to be processed again if the returned error is non-nil or // Result.Requeue is true, otherwise upon completion it will remove the work from the queue. func (r *ReconcileAppService) Reconcile(request reconcile.Request) (reconcile.Result, error) { - log.Printf("Reconciling AppService %s/%s\n", request.Namespace, request.Name) + reqLogger := reqLogger.WithValues("Request.Namespace", request.Namespace, "Requst.Name", request.Name) + reqLogger.Info("Reconciling AppService") // Fetch the AppService instance instance := &appv1alpha1.AppService{} @@ -147,7 +150,7 @@ func (r *ReconcileAppService) Reconcile(request reconcile.Request) (reconcile.Re found := &corev1.Pod{} err = r.client.Get(context.TODO(), types.NamespacedName{Name: pod.Name, Namespace: pod.Namespace}, found) if err != nil && errors.IsNotFound(err) { - log.Printf("Creating a new Pod %s/%s\n", pod.Namespace, pod.Name) + reqLogger.Info("Creating a new Pod", "Pod.Namespace", pod.Namespace, "Pod.Name", pod.Name) err = r.client.Create(context.TODO(), pod) if err != nil { return reconcile.Result{}, err @@ -160,7 +163,7 @@ func (r *ReconcileAppService) Reconcile(request reconcile.Request) (reconcile.Re } // Pod already exists - don't requeue - log.Printf("Skip reconcile: Pod %s/%s already exists", found.Namespace, found.Name) + reqLogger.Info("Skip reconcile: Pod already exists", "Pod.Namespace", found.Namespace, "Pod.Name", found.Name) return reconcile.Result{}, nil } diff --git a/pkg/sdk/internal/metrics/metrics.go b/pkg/sdk/internal/metrics/metrics.go index dacdbfb18d7..b592d854701 100644 --- a/pkg/sdk/internal/metrics/metrics.go +++ b/pkg/sdk/internal/metrics/metrics.go @@ -18,7 +18,7 @@ import ( "sync" prom "github.com/prometheus/client_golang/prometheus" - "github.com/sirupsen/logrus" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) const ( @@ -42,6 +42,7 @@ const ( var ( once sync.Once + log = logf.Log.WithName("metrics") ) // Collector - metric collector for all the metrics the sdk will watch @@ -69,7 +70,7 @@ func RegisterCollector(c *Collector) { once.Do(func() { err := prom.Register(c) if err != nil { - logrus.Errorf("unable to register collector with prometheus: %v", err) + log.Error(err, "unable to register collector with prometheus") } }) } diff --git a/pkg/sdk/metrics.go b/pkg/sdk/metrics.go index 2e603e97355..376a012b39f 100644 --- a/pkg/sdk/metrics.go +++ b/pkg/sdk/metrics.go @@ -20,14 +20,17 @@ import ( "strconv" "github.com/operator-framework/operator-sdk/pkg/k8sutil" + "github.com/prometheus/client_golang/prometheus/promhttp" - "github.com/sirupsen/logrus" v1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/api/errors" "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/client/config" + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" ) +var log = logf.Log.WithName("metrics") + // ExposeMetricsPort generate a Kubernetes Service to expose metrics port func ExposeMetricsPort() *v1.Service { http.Handle("/"+k8sutil.PrometheusMetricsPortName, promhttp.Handler()) @@ -35,7 +38,7 @@ func ExposeMetricsPort() *v1.Service { service, err := k8sutil.InitOperatorService() if err != nil { - logrus.Errorf("failed to initialize service object for operator metrics: %v", err) + log.Error(err, "failed to initialize service object for operator metrics") return nil } kubeconfig, err := config.GetConfig() @@ -48,9 +51,10 @@ func ExposeMetricsPort() *v1.Service { } err = runtimeClient.Create(context.TODO(), service) if err != nil && !errors.IsAlreadyExists(err) { - logrus.Errorf("failed to create service for operator metrics: %v", err) + log.Error(err, "failed to create service for operator metrics") return nil } - logrus.Infof("Metrics service %s created", service.Name) + + log.Info("Metrics service created.", "ServiceName", service.Name) return service } diff --git a/test/ansible-operator/cmd/ansible-operator/main.go b/test/ansible-operator/cmd/ansible-operator/main.go index 38d45eab24e..eb8348dfcb8 100644 --- a/test/ansible-operator/cmd/ansible-operator/main.go +++ b/test/ansible-operator/cmd/ansible-operator/main.go @@ -16,7 +16,6 @@ package main import ( "flag" - "log" "runtime" "time" @@ -24,26 +23,27 @@ import ( proxy "github.com/operator-framework/operator-sdk/pkg/ansible/proxy" "github.com/operator-framework/operator-sdk/pkg/k8sutil" sdkVersion "github.com/operator-framework/operator-sdk/version" + + log "github.com/sirupsen/logrus" "sigs.k8s.io/controller-runtime/pkg/client/config" "sigs.k8s.io/controller-runtime/pkg/manager" logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" - - "github.com/sirupsen/logrus" ) func printVersion() { - logrus.Infof("Go Version: %s", runtime.Version()) - logrus.Infof("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH) - logrus.Infof("operator-sdk Version: %v", sdkVersion.Version) + log.Infof("Go Version: %s", runtime.Version()) + log.Infof("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH) + log.Infof("operator-sdk Version: %v", sdkVersion.Version) } func main() { flag.Parse() - logf.SetLogger(logf.ZapLogger(false)) + + logf.SetLogger(logf.ZapLogger(true)) namespace, err := k8sutil.GetWatchNamespace() if err != nil { - log.Fatalf("failed to get watch namespace: %v", err) + log.Fatalf("failed to get watch namespace: (%v)", err) } mgr, err := manager.New(config.GetConfigOrDie(), manager.Options{ @@ -63,7 +63,7 @@ func main() { KubeConfig: mgr.GetConfig(), }) if err != nil { - logrus.Fatalf("error starting proxy: %v", err) + log.Fatalf("error starting proxy: (%v)", err) } // start the operator @@ -71,9 +71,8 @@ func main() { // wait for either to finish err = <-done - if err == nil { - logrus.Info("Exiting") - } else { - logrus.Fatal(err.Error()) + if err != nil { + log.Fatal(err) } + log.Info("Exiting.") } From 48d8946dca31271ec727638d67a55f4adb7f08ee Mon Sep 17 00:00:00 2001 From: Eric Stroczynski Date: Wed, 7 Nov 2018 12:01:18 -0800 Subject: [PATCH 2/6] Gopkg.lock: dep ensure --- Gopkg.lock | 1 + 1 file changed, 1 insertion(+) diff --git a/Gopkg.lock b/Gopkg.lock index 6057f6111b4..b91e28d31d3 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -791,6 +791,7 @@ input-imports = [ "github.com/coreos/prometheus-operator/pkg/client/monitoring/v1", "github.com/ghodss/yaml", + "github.com/go-logr/logr", "github.com/markbates/inflect", "github.com/prometheus/client_golang/prometheus", "github.com/prometheus/client_golang/prometheus/promhttp", From 9e5ae1c08a05693d19665674bcafc3947cf5cc78 Mon Sep 17 00:00:00 2001 From: Eric Stroczynski Date: Mon, 5 Nov 2018 14:11:08 -0800 Subject: [PATCH 3/6] *: use logrus instead of std log --- commands/operator-sdk/cmd/add/api.go | 5 ++-- commands/operator-sdk/cmd/add/controller.go | 3 +- commands/operator-sdk/cmd/add/crd.go | 12 ++++---- commands/operator-sdk/cmd/build.go | 24 +++++++-------- commands/operator-sdk/cmd/generate/k8s.go | 16 ++++++---- commands/operator-sdk/cmd/new.go | 16 +++++----- commands/operator-sdk/cmd/test/cluster.go | 5 ++-- commands/operator-sdk/cmd/test/local.go | 33 ++++++++++----------- commands/operator-sdk/cmd/up/local.go | 31 ++++++++++--------- internal/util/fileutil/file_util.go | 2 +- internal/util/projutil/project_util.go | 4 +-- pkg/scaffold/role.go | 6 ++-- pkg/scaffold/scaffold.go | 5 ++-- pkg/scaffold/test_setup.go | 5 ++-- pkg/test/context.go | 7 +++-- pkg/test/main_entry.go | 3 +- test/e2e/framework/framework.go | 2 +- test/e2e/framework/main_entry.go | 5 ++-- 18 files changed, 96 insertions(+), 88 deletions(-) diff --git a/commands/operator-sdk/cmd/add/api.go b/commands/operator-sdk/cmd/add/api.go index f5f0db379d4..01b1af8932d 100644 --- a/commands/operator-sdk/cmd/add/api.go +++ b/commands/operator-sdk/cmd/add/api.go @@ -15,13 +15,12 @@ package add import ( - "log" - "github.com/operator-framework/operator-sdk/commands/operator-sdk/cmd/generate" "github.com/operator-framework/operator-sdk/internal/util/projutil" "github.com/operator-framework/operator-sdk/pkg/scaffold" "github.com/operator-framework/operator-sdk/pkg/scaffold/input" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) @@ -95,7 +94,7 @@ func apiRun(cmd *cobra.Command, args []string) { // update deploy/role.yaml for the given resource r. if err := scaffold.UpdateRoleForResource(r, absProjectPath); err != nil { - log.Fatalf("failed to update the RBAC manifest for the resource (%v, %v): %v", r.APIVersion, r.Kind, err) + log.Fatalf("failed to update the RBAC manifest for the resource (%v, %v): (%v)", r.APIVersion, r.Kind, err) } // Run k8s codegen for deepcopy diff --git a/commands/operator-sdk/cmd/add/controller.go b/commands/operator-sdk/cmd/add/controller.go index bc1a3351d8e..8f28d399499 100644 --- a/commands/operator-sdk/cmd/add/controller.go +++ b/commands/operator-sdk/cmd/add/controller.go @@ -15,12 +15,11 @@ package add import ( - "log" - "github.com/operator-framework/operator-sdk/internal/util/projutil" "github.com/operator-framework/operator-sdk/pkg/scaffold" "github.com/operator-framework/operator-sdk/pkg/scaffold/input" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) diff --git a/commands/operator-sdk/cmd/add/crd.go b/commands/operator-sdk/cmd/add/crd.go index e6980bae40d..e433e7fbd96 100644 --- a/commands/operator-sdk/cmd/add/crd.go +++ b/commands/operator-sdk/cmd/add/crd.go @@ -16,7 +16,6 @@ package add import ( "fmt" - "log" "os" "path/filepath" "strings" @@ -25,6 +24,7 @@ import ( "github.com/operator-framework/operator-sdk/pkg/scaffold" "github.com/operator-framework/operator-sdk/pkg/scaffold/input" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) @@ -60,26 +60,26 @@ func crdFunc(cmd *cobra.Command, args []string) { verifyCrdFlags() verifyCrdDeployPath() - fmt.Fprintln(os.Stdout, "Generating custom resource definition (CRD) file") + fmt.Println("Generating custom resource definition (CRD) file") // generate CR/CRD file resource, err := scaffold.NewResource(apiVersion, kind) if err != nil { - log.Fatalf("%v", err) + log.Fatal(err) } + s := scaffold.Scaffold{} err = s.Execute(cfg, &scaffold.Crd{Resource: resource}, &scaffold.Cr{Resource: resource}, ) - if err != nil { log.Fatalf("add scaffold failed: (%v)", err) } // update deploy/role.yaml for the given resource r. if err := scaffold.UpdateRoleForResource(resource, cfg.AbsProjectPath); err != nil { - log.Fatalf("failed to update the RBAC manifest for the resource (%v, %v): %v", resource.APIVersion, resource.Kind, err) + log.Fatalf("failed to update the RBAC manifest for the resource (%v, %v): (%v)", resource.APIVersion, resource.Kind, err) } } @@ -103,7 +103,7 @@ func verifyCrdFlags() { func verifyCrdDeployPath() { wd, err := os.Getwd() if err != nil { - log.Fatalf("failed to determine the full path of the current directory: %v", err) + log.Fatalf("failed to determine the full path of the current directory: (%v)", err) } // check if the deploy sub-directory exist _, err = os.Stat(filepath.Join(wd, scaffold.DeployDir)) diff --git a/commands/operator-sdk/cmd/build.go b/commands/operator-sdk/cmd/build.go index cd638291fcf..1617d7591a0 100644 --- a/commands/operator-sdk/cmd/build.go +++ b/commands/operator-sdk/cmd/build.go @@ -19,7 +19,6 @@ import ( "errors" "fmt" "io/ioutil" - "log" "os" "os/exec" "path/filepath" @@ -30,6 +29,7 @@ import ( "github.com/operator-framework/operator-sdk/pkg/test" "github.com/ghodss/yaml" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) @@ -78,11 +78,11 @@ func verifyDeploymentImage(yamlFile []byte, imageName string) error { yamlMap := make(map[string]interface{}) err := yaml.Unmarshal(yamlSpec, &yamlMap) if err != nil { - log.Fatal("Could not unmarshal yaml namespaced spec") + log.Fatalf("could not unmarshal yaml namespaced spec: (%v)", err) } kind, ok := yamlMap["kind"].(string) if !ok { - log.Fatal("Yaml manifest file contains a 'kind' field that is not a string") + log.Fatal("yaml manifest file contains a 'kind' field that is not a string") } if kind == "Deployment" { // this is ugly and hacky; we should probably make this cleaner @@ -122,13 +122,13 @@ func verifyDeploymentImage(yamlFile []byte, imageName string) error { func verifyTestManifest(image string) { namespacedBytes, err := ioutil.ReadFile(namespacedManBuild) if err != nil { - log.Fatalf("could not read namespaced manifest: %v", err) + log.Fatalf("could not read namespaced manifest: (%v)", err) } err = verifyDeploymentImage(namespacedBytes, image) // the error from verifyDeploymentImage is just a warning, not fatal error if err != nil { - fmt.Printf("%v\n", err) + log.Warn(err) } } @@ -141,7 +141,7 @@ func buildFunc(cmd *cobra.Command, args []string) { goBuildEnv := append(os.Environ(), "GOOS=linux", "GOARCH=amd64", "CGO_ENABLED=0") wd, err := os.Getwd() if err != nil { - log.Fatalf("could not identify current working directory: %v", err) + log.Fatalf("could not identify current working directory: (%v)", err) } // Don't need to build go code if Ansible Operator @@ -154,7 +154,7 @@ func buildFunc(cmd *cobra.Command, args []string) { buildCmd.Stderr = os.Stderr err = buildCmd.Run() if err != nil { - log.Fatalf("failed to build operator binary: %v", err) + log.Fatalf("failed to build operator binary: (%v)", err) } } @@ -169,9 +169,9 @@ func buildFunc(cmd *cobra.Command, args []string) { err = dbcmd.Run() if err != nil { if enableTests { - log.Fatalf("failed to build intermediate image for %s image: %v", image, err) + log.Fatalf("failed to output intermediate image %s: (%v)", image, err) } else { - log.Fatalf("failed to output build image %s: %v", image, err) + log.Fatalf("failed to output build image %s: (%v)", image, err) } } @@ -183,7 +183,7 @@ func buildFunc(cmd *cobra.Command, args []string) { buildTestCmd.Stderr = os.Stderr err = buildTestCmd.Run() if err != nil { - log.Fatalf("failed to build test binary: %v", err) + log.Fatalf("failed to build test binary: (%v)", err) } // if a user is using an older sdk repo as their library, make sure they have required build files testDockerfile := filepath.Join(scaffold.BuildTestDir, scaffold.DockerfileFile) @@ -204,7 +204,7 @@ func buildFunc(cmd *cobra.Command, args []string) { &scaffold.TestPod{Image: image, TestNamespaceEnv: test.TestNamespaceEnv}, ) if err != nil { - log.Fatalf("build scaffold failed: (%v)", err) + log.Fatalf("test scaffold failed: (%v)", err) } } @@ -213,7 +213,7 @@ func buildFunc(cmd *cobra.Command, args []string) { testDbcmd.Stderr = os.Stderr err = testDbcmd.Run() if err != nil { - log.Fatalf("failed to output build image %s: %v", image, err) + log.Fatalf("failed to output test image %s: (%v)", image, err) } // Check image name of deployments in namespaced manifest verifyTestManifest(image) diff --git a/commands/operator-sdk/cmd/generate/k8s.go b/commands/operator-sdk/cmd/generate/k8s.go index 51ae9112777..2c5920dbb23 100644 --- a/commands/operator-sdk/cmd/generate/k8s.go +++ b/commands/operator-sdk/cmd/generate/k8s.go @@ -17,7 +17,6 @@ package generate import ( "fmt" "io/ioutil" - "log" "os" "os/exec" "path/filepath" @@ -25,6 +24,7 @@ import ( "github.com/operator-framework/operator-sdk/internal/util/projutil" "github.com/operator-framework/operator-sdk/pkg/scaffold" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) @@ -41,7 +41,7 @@ to comply with kube-API requirements. func k8sFunc(cmd *cobra.Command, args []string) { if len(args) != 0 { - log.Fatalf("k8s command doesn't accept any arguments.") + log.Fatal("k8s command doesn't accept any arguments") } // Only Go projects can generate k8s deepcopy code. @@ -62,7 +62,7 @@ func K8sCodegen() { log.Fatalf("failed to parse group versions: (%v)", err) } - fmt.Fprintf(os.Stdout, "Running code-generation for custom resource group versions: [%s]\n", groupVersions) + log.Printf("Running code-generation for custom resource group versions: [%s]\n", groupVersions) // TODO: Replace generate-groups.sh by building the vendored generators(deepcopy, lister etc) // and running them directly // TODO: remove dependency on boilerplate.go.txt @@ -73,11 +73,13 @@ func K8sCodegen() { apisPkg, groupVersions, } - out, err := exec.Command(genGroupsCmd, args...).CombinedOutput() + cgCmd := exec.Command(genGroupsCmd, args...) + cgCmd.Stdout = os.Stdout + cgCmd.Stderr = os.Stderr + err = cgCmd.Run() if err != nil { log.Fatalf("failed to perform code-generation: (%v)", err) } - fmt.Fprintln(os.Stdout, string(out)) } // getGroupVersions parses the layout of pkg/apis to return the API groups and versions @@ -108,5 +110,9 @@ func parseGroupVersions() (string, error) { } } + if groupVersions == "" { + return "", fmt.Errorf("no groups or versions found in %s", scaffold.ApisDir) + } + return groupVersions, nil } diff --git a/commands/operator-sdk/cmd/new.go b/commands/operator-sdk/cmd/new.go index b699089d775..99cb90370e1 100644 --- a/commands/operator-sdk/cmd/new.go +++ b/commands/operator-sdk/cmd/new.go @@ -17,7 +17,6 @@ package cmd import ( "fmt" "io/ioutil" - "log" "os" "os/exec" "path/filepath" @@ -28,6 +27,7 @@ import ( "github.com/operator-framework/operator-sdk/pkg/scaffold/ansible" "github.com/operator-framework/operator-sdk/pkg/scaffold/input" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) @@ -150,13 +150,13 @@ func doAnsibleScaffold() { resource, err := scaffold.NewResource(apiVersion, kind) if err != nil { - log.Fatal("Invalid apiVersion and kind.") + log.Fatalf("invalid apiVersion and kind: (%v)", err) } s := &scaffold.Scaffold{} tmpdir, err := ioutil.TempDir("", "osdk") if err != nil { - log.Fatal("unable to get temp directory") + log.Fatalf("unable to get temp directory: (%v)", err) } galaxyInit := &ansible.GalaxyInit{ @@ -196,7 +196,7 @@ func doAnsibleScaffold() { }, ) if err != nil { - log.Fatalf("new scaffold failed: (%v)", err) + log.Fatalf("new playbook scaffold failed: (%v)", err) } } @@ -210,12 +210,12 @@ func doAnsibleScaffold() { // everything. tmpDirectorySlice := strings.Split(os.TempDir(), "/") if err = os.RemoveAll(filepath.Join(galaxyInit.AbsProjectPath, tmpDirectorySlice[1])); err != nil { - log.Fatalf("failed to remove the galaxy init script") + log.Fatalf("failed to remove the galaxy init script: (%v)", err) } // update deploy/role.yaml for the given resource r. if err := scaffold.UpdateRoleForResource(resource, cfg.AbsProjectPath); err != nil { - log.Fatalf("failed to update the RBAC manifest for the resource (%v, %v): %v", resource.APIVersion, resource.Kind, err) + log.Fatalf("failed to update the RBAC manifest for the resource (%v, %v): (%v)", resource.APIVersion, resource.Kind, err) } } @@ -254,14 +254,14 @@ func execCmd(stdout *os.File, cmd string, args ...string) { dc.Stderr = os.Stderr err := dc.Run() if err != nil { - log.Fatalf("failed to exec %s %#v: %v", cmd, args, err) + log.Fatalf("failed to exec %s %#v: (%v)", cmd, args, err) } } func pullDep() { _, err := exec.LookPath(dep) if err != nil { - log.Fatalf("looking for dep in $PATH: %v", err) + log.Fatalf("looking for dep in $PATH: (%v)", err) } fmt.Fprintln(os.Stdout, "Run dep ensure ...") execCmd(os.Stdout, dep, ensureCmd, "-v") diff --git a/commands/operator-sdk/cmd/test/cluster.go b/commands/operator-sdk/cmd/test/cluster.go index 8abebee850d..64535be425d 100644 --- a/commands/operator-sdk/cmd/test/cluster.go +++ b/commands/operator-sdk/cmd/test/cluster.go @@ -24,6 +24,7 @@ import ( "github.com/operator-framework/operator-sdk/pkg/scaffold" "github.com/operator-framework/operator-sdk/pkg/test" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" v1 "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -110,7 +111,7 @@ func testClusterFunc(cmd *cobra.Command, args []string) error { defer func() { err = kubeclient.CoreV1().Pods(tcConfig.namespace).Delete(testPod.Name, &metav1.DeleteOptions{}) if err != nil { - fmt.Printf("Warning: failed to delete test pod") + log.Warn("failed to delete test pod") } }() err = wait.Poll(time.Second*5, time.Second*time.Duration(tcConfig.pendingTimeout), func() (bool, error) { @@ -140,7 +141,7 @@ func testClusterFunc(cmd *cobra.Command, args []string) error { time.Sleep(time.Second * 5) continue } else if testPod.Status.Phase == v1.PodSucceeded { - fmt.Printf("Test Successfully Completed\n") + fmt.Println("Test Successfully Completed") return nil } else if testPod.Status.Phase == v1.PodFailed { req := kubeclient.CoreV1().Pods(tcConfig.namespace).GetLogs(testPod.Name, &v1.PodLogOptions{}) diff --git a/commands/operator-sdk/cmd/test/local.go b/commands/operator-sdk/cmd/test/local.go index 17a8b72a3c9..99850168bff 100644 --- a/commands/operator-sdk/cmd/test/local.go +++ b/commands/operator-sdk/cmd/test/local.go @@ -17,7 +17,6 @@ package cmdtest import ( "fmt" "io/ioutil" - "log" "os" "os/exec" "path/filepath" @@ -28,6 +27,7 @@ import ( "github.com/operator-framework/operator-sdk/pkg/scaffold" "github.com/operator-framework/operator-sdk/pkg/test" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) @@ -60,32 +60,31 @@ func NewTestLocalCmd() *cobra.Command { func testLocalFunc(cmd *cobra.Command, args []string) { if len(args) != 1 { - log.Fatalf("operator-sdk test local requires exactly 1 argument") + log.Fatal("operator-sdk test local requires exactly 1 argument") } // if no namespaced manifest path is given, combine deploy/service_account.yaml, deploy/role.yaml, deploy/role_binding.yaml and deploy/operator.yaml if tlConfig.namespacedManPath == "" { err := os.MkdirAll(deployTestDir, os.FileMode(fileutil.DefaultDirFileMode)) if err != nil { - log.Fatalf("could not create %s: %v", deployTestDir, err) + log.Fatalf("could not create %s: (%v)", deployTestDir, err) } tlConfig.namespacedManPath = filepath.Join(deployTestDir, "namespace-manifests.yaml") - saFile := filepath.Join(scaffold.DeployDir, scaffold.ServiceAccountYamlFile) - sa, err := ioutil.ReadFile(saFile) + sa, err := ioutil.ReadFile(filepath.Join(scaffold.DeployDir, scaffold.ServiceAccountYamlFile)) if err != nil { - log.Printf("WARN: could not find the manifest %s: %v", saFile, err) + log.Warnf("could not find the serviceaccount manifest: (%v)", err) } role, err := ioutil.ReadFile(filepath.Join(scaffold.DeployDir, scaffold.RoleYamlFile)) if err != nil { - log.Printf("WARN: could not find role manifest: %v", err) + log.Warnf("could not find role manifest: (%v)", err) } roleBinding, err := ioutil.ReadFile(filepath.Join(scaffold.DeployDir, scaffold.RoleBindingYamlFile)) if err != nil { - log.Printf("WARN: could not find role_binding manifest: %v", err) + log.Warnf("could not find role_binding manifest: (%v)", err) } operator, err := ioutil.ReadFile(filepath.Join(scaffold.DeployDir, scaffold.OperatorYamlFile)) if err != nil { - log.Fatalf("could not find operator manifest: %v", err) + log.Fatalf("could not find operator manifest: (%v)", err) } combined := []byte{} combined = combineManifests(combined, sa) @@ -94,31 +93,31 @@ func testLocalFunc(cmd *cobra.Command, args []string) { combined = append(combined, operator...) err = ioutil.WriteFile(tlConfig.namespacedManPath, combined, os.FileMode(fileutil.DefaultFileMode)) if err != nil { - log.Fatalf("could not create temporary namespaced manifest file: %v", err) + log.Fatalf("could not create temporary namespaced manifest file: (%v)", err) } defer func() { err := os.Remove(tlConfig.namespacedManPath) if err != nil { - log.Fatalf("could not delete temporary namespace manifest file") + log.Fatalf("could not delete temporary namespace manifest file: (%v)", err) } }() } if tlConfig.globalManPath == "" { err := os.MkdirAll(deployTestDir, os.FileMode(fileutil.DefaultDirFileMode)) if err != nil { - log.Fatalf("could not create %s: %v", deployTestDir, err) + log.Fatalf("could not create %s: (%v)", deployTestDir, err) } tlConfig.globalManPath = filepath.Join(deployTestDir, "global-manifests.yaml") files, err := ioutil.ReadDir(scaffold.CrdsDir) if err != nil { - log.Fatalf("could not read deploy directory: %v", err) + log.Fatalf("could not read deploy directory: (%v)", err) } var combined []byte for _, file := range files { if strings.HasSuffix(file.Name(), "crd.yaml") { fileBytes, err := ioutil.ReadFile(filepath.Join(scaffold.CrdsDir, file.Name())) if err != nil { - log.Fatalf("could not read file %s: %v", filepath.Join(scaffold.CrdsDir, file.Name()), err) + log.Fatalf("could not read file %s: (%v)", filepath.Join(scaffold.CrdsDir, file.Name()), err) } if combined == nil { combined = []byte{} @@ -130,12 +129,12 @@ func testLocalFunc(cmd *cobra.Command, args []string) { } err = ioutil.WriteFile(tlConfig.globalManPath, combined, os.FileMode(fileutil.DefaultFileMode)) if err != nil { - log.Fatalf("could not create temporary global manifest file: %v", err) + log.Fatalf("could not create temporary global manifest file: (%v)", err) } defer func() { err := os.Remove(tlConfig.globalManPath) if err != nil { - log.Fatalf("could not delete global namespace manifest file") + log.Fatalf("could not delete global namespace manifest file: (%v)", err) } }() } @@ -159,7 +158,7 @@ func testLocalFunc(cmd *cobra.Command, args []string) { dc.Stderr = os.Stderr err := dc.Run() if err != nil { - log.Fatalf("failed to exec `go %s`: %v", strings.Join(testArgs, " "), err) + log.Fatalf("failed to exec `go %s`: (%v)", strings.Join(testArgs, " "), err) } } diff --git a/commands/operator-sdk/cmd/up/local.go b/commands/operator-sdk/cmd/up/local.go index 58cffa380ea..6c850542d7c 100644 --- a/commands/operator-sdk/cmd/up/local.go +++ b/commands/operator-sdk/cmd/up/local.go @@ -16,7 +16,6 @@ package up import ( "fmt" - "log" "os" "os/exec" "os/signal" @@ -35,7 +34,7 @@ import ( ansibleScaffold "github.com/operator-framework/operator-sdk/pkg/scaffold/ansible" sdkVersion "github.com/operator-framework/operator-sdk/version" - "github.com/sirupsen/logrus" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" "sigs.k8s.io/controller-runtime/pkg/client/config" "sigs.k8s.io/controller-runtime/pkg/manager" @@ -91,14 +90,14 @@ func mustKubeConfig() { if len(kubeConfig) == 0 { usr, err := user.Current() if err != nil { - log.Fatalf("failed to determine user's home dir: %v", err) + log.Fatalf("failed to determine user's home dir: (%v)", err) } kubeConfig = filepath.Join(usr.HomeDir, defaultConfigPath) } _, err := os.Stat(kubeConfig) if err != nil && os.IsNotExist(err) { - log.Fatalf("failed to find the kubeconfig file (%v): %v", kubeConfig, err) + log.Fatalf("failed to find the kubeconfig file (%v): (%v)", kubeConfig, err) } } @@ -119,16 +118,17 @@ func upLocal() { <-c err := dc.Process.Kill() if err != nil { - log.Fatalf("failed to terminate the operator: %v", err) + log.Fatalf("failed to terminate the operator: (%v)", err) } os.Exit(0) }() dc.Stdout = os.Stdout dc.Stderr = os.Stderr - dc.Env = append(os.Environ(), fmt.Sprintf("%v=%v", k8sutil.KubeConfigEnvVar, kubeConfig), fmt.Sprintf("%v=%v", k8sutil.WatchNamespaceEnvVar, namespace)) + dc.Env = append(os.Environ(), fmt.Sprintf("%v=%v", k8sutil.KubeConfigEnvVar, kubeConfig)) + dc.Env = append(dc.Env, fmt.Sprintf("%v=%v", k8sutil.WatchNamespaceEnvVar, namespace)) err := dc.Run() if err != nil { - log.Fatalf("failed to run operator locally: %v", err) + log.Fatalf("failed to run operator locally: (%v)", err) } } @@ -144,7 +144,7 @@ func upLocalAnsible() { } printVersion() - logrus.Infof("watching namespace: %s", namespace) + log.Infof("watching namespace: %s", namespace) done := make(chan error) // start the proxy @@ -154,7 +154,7 @@ func upLocalAnsible() { KubeConfig: mgr.GetConfig(), }) if err != nil { - logrus.Fatalf("error starting proxy: %v", err) + log.Fatalf("error starting proxy: (%v)", err) } // start the operator @@ -162,15 +162,14 @@ func upLocalAnsible() { // wait for either to finish err = <-done - if err == nil { - logrus.Info("Exiting") - } else { - logrus.Fatal(err.Error()) + if err != nil { + log.Fatal(err) } + log.Info("Ansible operator started succesfully. Exiting.") } func printVersion() { - logrus.Infof("Go Version: %s", runtime.Version()) - logrus.Infof("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH) - logrus.Infof("operator-sdk Version: %v", sdkVersion.Version) + log.Infof("Go Version: %s", runtime.Version()) + log.Infof("Go OS/Arch: %s/%s", runtime.GOOS, runtime.GOARCH) + log.Infof("operator-sdk Version: %v", sdkVersion.Version) } diff --git a/internal/util/fileutil/file_util.go b/internal/util/fileutil/file_util.go index 995edc210f7..de2b36fb755 100644 --- a/internal/util/fileutil/file_util.go +++ b/internal/util/fileutil/file_util.go @@ -19,11 +19,11 @@ package fileutil import ( "fmt" "io" - "log" "os" "path/filepath" "sync" + log "github.com/sirupsen/logrus" "github.com/spf13/afero" ) diff --git a/internal/util/projutil/project_util.go b/internal/util/projutil/project_util.go index 377ddead6fc..68a5490ac33 100644 --- a/internal/util/projutil/project_util.go +++ b/internal/util/projutil/project_util.go @@ -15,11 +15,11 @@ package projutil import ( - "log" "os" "path/filepath" "strings" + log "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) @@ -50,7 +50,7 @@ func MustInProjectRoot() { // we are at the project root. _, err := os.Stat(buildDockerfile) if err != nil && os.IsNotExist(err) { - log.Fatalf("must run command in project root dir: %v", err) + log.Fatalf("must run command in project root dir: (%v)", err) } } diff --git a/pkg/scaffold/role.go b/pkg/scaffold/role.go index 7f76f566ad0..1cf9166761e 100644 --- a/pkg/scaffold/role.go +++ b/pkg/scaffold/role.go @@ -19,12 +19,12 @@ import ( "errors" "fmt" "io/ioutil" - "log" "path/filepath" "github.com/operator-framework/operator-sdk/internal/util/fileutil" "github.com/operator-framework/operator-sdk/pkg/scaffold/input" + log "github.com/sirupsen/logrus" yaml "gopkg.in/yaml.v2" rbacv1 "k8s.io/api/rbac/v1" cgoscheme "k8s.io/client-go/kubernetes/scheme" @@ -70,7 +70,7 @@ func UpdateRoleForResource(r *Resource, absProjectPath string) error { // check if the resource already exists for _, resource := range pr.Resources { if resource == r.Resource { - log.Printf("deploy/role.yaml RBAC rules already up to date for the resource (%v, %v)", r.APIVersion, r.Kind) + log.Infof("deploy/role.yaml RBAC rules already up to date for the resource (%v, %v)", r.APIVersion, r.Kind) return nil } } @@ -112,7 +112,7 @@ func UpdateRoleForResource(r *Resource, absProjectPath string) error { // check if the resource already exists for _, resource := range pr.Resources { if resource == r.Resource { - log.Printf("deploy/role.yaml RBAC rules already up to date for the resource (%v, %v)", r.APIVersion, r.Kind) + log.Infof("deploy/role.yaml RBAC rules already up to date for the resource (%v, %v)", r.APIVersion, r.Kind) return nil } } diff --git a/pkg/scaffold/scaffold.go b/pkg/scaffold/scaffold.go index 18de34a82d2..8bc4a25f50c 100644 --- a/pkg/scaffold/scaffold.go +++ b/pkg/scaffold/scaffold.go @@ -20,7 +20,6 @@ import ( "bytes" "fmt" "io" - "log" "os" "path/filepath" "strings" @@ -28,6 +27,8 @@ import ( "github.com/operator-framework/operator-sdk/internal/util/fileutil" "github.com/operator-framework/operator-sdk/pkg/scaffold/input" + + log "github.com/sirupsen/logrus" "golang.org/x/tools/imports" ) @@ -161,7 +162,7 @@ func (s *Scaffold) doTemplate(i input.Input, e input.File, absPath string) error } _, err = f.Write(b) - fmt.Printf("Create %s\n", i.Path) + log.Infoln("Create", i.Path) return err } diff --git a/pkg/scaffold/test_setup.go b/pkg/scaffold/test_setup.go index 06c91e14d6c..d2fc160b701 100644 --- a/pkg/scaffold/test_setup.go +++ b/pkg/scaffold/test_setup.go @@ -17,11 +17,12 @@ package scaffold import ( "bytes" "io" - "log" "os" "path/filepath" "github.com/operator-framework/operator-sdk/pkg/scaffold/input" + + log "github.com/sirupsen/logrus" ) const ( @@ -43,7 +44,7 @@ var ( func mustGetImportPath() string { wd, err := os.Getwd() if err != nil { - log.Fatal("mustGetImportPath: ", err) + log.Fatalf("mustGetImportPath: (%v)", err) } return filepath.Join(wd, appRepo) } diff --git a/pkg/test/context.go b/pkg/test/context.go index 51c3dd411c3..016486f1230 100644 --- a/pkg/test/context.go +++ b/pkg/test/context.go @@ -15,11 +15,12 @@ package test import ( - "log" "strconv" "strings" "testing" "time" + + log "github.com/sirupsen/logrus" ) type TestCtx struct { @@ -69,7 +70,7 @@ func (ctx *TestCtx) Cleanup() { for i := len(ctx.cleanupFns) - 1; i >= 0; i-- { err := ctx.cleanupFns[i]() if err != nil { - ctx.t.Errorf("a cleanup function failed with error: %v\n", err) + ctx.t.Errorf("a cleanup function failed with error: (%v)\n", err) } } } @@ -82,7 +83,7 @@ func (ctx *TestCtx) CleanupNoT() { err := ctx.cleanupFns[i]() if err != nil { failed = true - log.Printf("a cleanup function failed with error: %v\n", err) + log.Errorf("a cleanup function failed with error: (%v)", err) } } if failed { diff --git a/pkg/test/main_entry.go b/pkg/test/main_entry.go index 25c75b5d634..16f01c7493a 100644 --- a/pkg/test/main_entry.go +++ b/pkg/test/main_entry.go @@ -17,9 +17,10 @@ package test import ( "flag" "io/ioutil" - "log" "os" "testing" + + log "github.com/sirupsen/logrus" ) const ( diff --git a/test/e2e/framework/framework.go b/test/e2e/framework/framework.go index 77c6cfe7e1f..143a1d6102f 100644 --- a/test/e2e/framework/framework.go +++ b/test/e2e/framework/framework.go @@ -18,11 +18,11 @@ import ( goctx "context" "flag" "fmt" - "log" "os" "sync" "time" + log "github.com/sirupsen/logrus" extscheme "k8s.io/apiextensions-apiserver/pkg/client/clientset/clientset/scheme" "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/runtime/serializer" diff --git a/test/e2e/framework/main_entry.go b/test/e2e/framework/main_entry.go index e4098941540..d962757d26b 100644 --- a/test/e2e/framework/main_entry.go +++ b/test/e2e/framework/main_entry.go @@ -15,14 +15,15 @@ package framework import ( - "log" "os" "testing" + + log "github.com/sirupsen/logrus" ) func MainEntry(m *testing.M) { if err := setup(); err != nil { - log.Fatalf("failed to set up framework: %v", err) + log.Fatalf("failed to set up framework: (%v)", err) } os.Exit(m.Run()) From 168df8e1c31315af6f672f69fe1d201d2ab83e48 Mon Sep 17 00:00:00 2001 From: Eric Stroczynski Date: Tue, 6 Nov 2018 14:32:29 -0800 Subject: [PATCH 4/6] commands/operator-sdk/*: add Info statements for SDK steps --- commands/operator-sdk/cmd/add/api.go | 5 +++++ commands/operator-sdk/cmd/add/controller.go | 5 +++++ commands/operator-sdk/cmd/add/crd.go | 5 +++-- commands/operator-sdk/cmd/build.go | 11 ++++++++++- commands/operator-sdk/cmd/generate/k8s.go | 6 ++++-- commands/operator-sdk/cmd/new.go | 18 +++++++++++++----- commands/operator-sdk/cmd/test/cluster.go | 5 ++++- commands/operator-sdk/cmd/test/local.go | 7 ++++++- commands/operator-sdk/cmd/up/local.go | 5 ++++- commands/operator-sdk/main.go | 7 ++----- 10 files changed, 56 insertions(+), 18 deletions(-) diff --git a/commands/operator-sdk/cmd/add/api.go b/commands/operator-sdk/cmd/add/api.go index 01b1af8932d..b19d63e6758 100644 --- a/commands/operator-sdk/cmd/add/api.go +++ b/commands/operator-sdk/cmd/add/api.go @@ -67,6 +67,9 @@ func apiRun(cmd *cobra.Command, args []string) { // Create and validate new resource projutil.MustInProjectRoot() + + log.Infof("Generating api version %s for kind %s.", apiVersion, kind) + r, err := scaffold.NewResource(apiVersion, kind) if err != nil { log.Fatal(err) @@ -99,4 +102,6 @@ func apiRun(cmd *cobra.Command, args []string) { // Run k8s codegen for deepcopy generate.K8sCodegen() + + log.Info("Api generation complete.") } diff --git a/commands/operator-sdk/cmd/add/controller.go b/commands/operator-sdk/cmd/add/controller.go index 8f28d399499..3da37038e83 100644 --- a/commands/operator-sdk/cmd/add/controller.go +++ b/commands/operator-sdk/cmd/add/controller.go @@ -60,6 +60,9 @@ func controllerRun(cmd *cobra.Command, args []string) { projutil.MustGoProjectCmd(cmd) projutil.MustInProjectRoot() + + log.Infof("Generating controller version %s for kind %s.", apiVersion, kind) + // Create and validate new resource r, err := scaffold.NewResource(apiVersion, kind) if err != nil { @@ -79,4 +82,6 @@ func controllerRun(cmd *cobra.Command, args []string) { if err != nil { log.Fatalf("add scaffold failed: (%v)", err) } + + log.Info("Controller generation complete.") } diff --git a/commands/operator-sdk/cmd/add/crd.go b/commands/operator-sdk/cmd/add/crd.go index e433e7fbd96..617d6612ca0 100644 --- a/commands/operator-sdk/cmd/add/crd.go +++ b/commands/operator-sdk/cmd/add/crd.go @@ -15,7 +15,6 @@ package add import ( - "fmt" "os" "path/filepath" "strings" @@ -60,7 +59,7 @@ func crdFunc(cmd *cobra.Command, args []string) { verifyCrdFlags() verifyCrdDeployPath() - fmt.Println("Generating custom resource definition (CRD) file") + log.Infof("Generating Custom Resource Definition (CRD) version %s for kind %s.", apiVersion, kind) // generate CR/CRD file resource, err := scaffold.NewResource(apiVersion, kind) @@ -81,6 +80,8 @@ func crdFunc(cmd *cobra.Command, args []string) { if err := scaffold.UpdateRoleForResource(resource, cfg.AbsProjectPath); err != nil { log.Fatalf("failed to update the RBAC manifest for the resource (%v, %v): (%v)", resource.APIVersion, resource.Kind, err) } + + log.Info("CRD generation complete.") } func verifyCrdFlags() { diff --git a/commands/operator-sdk/cmd/build.go b/commands/operator-sdk/cmd/build.go index 1617d7591a0..d7c4d6de445 100644 --- a/commands/operator-sdk/cmd/build.go +++ b/commands/operator-sdk/cmd/build.go @@ -163,6 +163,9 @@ func buildFunc(cmd *cobra.Command, args []string) { if enableTests { baseImageName += "-intermediate" } + + log.Infof("Building Docker image %s", baseImageName) + dbcmd := exec.Command("docker", "build", ".", "-f", "build/Dockerfile", "-t", baseImageName) dbcmd.Stdout = os.Stdout dbcmd.Stderr = os.Stderr @@ -190,6 +193,8 @@ func buildFunc(cmd *cobra.Command, args []string) { _, err = os.Stat(testDockerfile) if err != nil && os.IsNotExist(err) { + log.Info("Generating build manifests for test-framework.") + absProjectPath := projutil.MustGetwd() cfg := &input.Config{ Repo: projutil.CheckAndGetProjectGoPkg(), @@ -204,10 +209,12 @@ func buildFunc(cmd *cobra.Command, args []string) { &scaffold.TestPod{Image: image, TestNamespaceEnv: test.TestNamespaceEnv}, ) if err != nil { - log.Fatalf("test scaffold failed: (%v)", err) + log.Fatalf("test-framework manifest scaffold failed: (%v)", err) } } + log.Infof("Building test Docker image %s", image) + testDbcmd := exec.Command("docker", "build", ".", "-f", testDockerfile, "-t", image, "--build-arg", "NAMESPACEDMAN="+namespacedManBuild, "--build-arg", "BASEIMAGE="+baseImageName) testDbcmd.Stdout = os.Stdout testDbcmd.Stderr = os.Stderr @@ -218,6 +225,8 @@ func buildFunc(cmd *cobra.Command, args []string) { // Check image name of deployments in namespaced manifest verifyTestManifest(image) } + + log.Info("Operator build complete.") } func mainExists() bool { diff --git a/commands/operator-sdk/cmd/generate/k8s.go b/commands/operator-sdk/cmd/generate/k8s.go index 2c5920dbb23..4b331bbc486 100644 --- a/commands/operator-sdk/cmd/generate/k8s.go +++ b/commands/operator-sdk/cmd/generate/k8s.go @@ -62,10 +62,10 @@ func K8sCodegen() { log.Fatalf("failed to parse group versions: (%v)", err) } - log.Printf("Running code-generation for custom resource group versions: [%s]\n", groupVersions) + log.Infof("Running code-generation for Custom Resource group versions: [%s]\n", groupVersions) + // TODO: Replace generate-groups.sh by building the vendored generators(deepcopy, lister etc) // and running them directly - // TODO: remove dependency on boilerplate.go.txt genGroupsCmd := "vendor/k8s.io/code-generator/generate-groups.sh" args := []string{ "deepcopy", @@ -80,6 +80,8 @@ func K8sCodegen() { if err != nil { log.Fatalf("failed to perform code-generation: (%v)", err) } + + log.Info("Code-generation complete.") } // getGroupVersions parses the layout of pkg/apis to return the API groups and versions diff --git a/commands/operator-sdk/cmd/new.go b/commands/operator-sdk/cmd/new.go index 99cb90370e1..af0b775e24b 100644 --- a/commands/operator-sdk/cmd/new.go +++ b/commands/operator-sdk/cmd/new.go @@ -15,7 +15,6 @@ package cmd import ( - "fmt" "io/ioutil" "os" "os/exec" @@ -80,6 +79,8 @@ func newFunc(cmd *cobra.Command, args []string) { mustBeNewProject() verifyFlags() + log.Infof("Creating new %s operator '%s'.", strings.Title(operatorType), projectName) + switch operatorType { case projutil.OperatorTypeGo: doScaffold() @@ -88,6 +89,8 @@ func newFunc(cmd *cobra.Command, args []string) { doAnsibleScaffold() } initGit() + + log.Info("Project creation complete.") } func parse(args []string) { @@ -190,6 +193,8 @@ func doAnsibleScaffold() { // Decide on playbook. if generatePlaybook { + log.Infof("Generating %s playbook.", strings.Title(operatorType)) + err := s.Execute(cfg, &ansible.Playbook{ Resource: *resource, @@ -200,11 +205,14 @@ func doAnsibleScaffold() { } } + log.Info("Running galaxy-init.") + // Run galaxy init. cmd := exec.Command(filepath.Join(galaxyInit.AbsProjectPath, galaxyInit.Path)) cmd.Stdout = os.Stdout cmd.Stderr = os.Stderr cmd.Run() + // Delete Galxy INIT // Mac OS tmp directory is /var/folders/_c/..... this means we have to make sure that we get the top level directory to remove // everything. @@ -263,18 +271,18 @@ func pullDep() { if err != nil { log.Fatalf("looking for dep in $PATH: (%v)", err) } - fmt.Fprintln(os.Stdout, "Run dep ensure ...") + log.Info("Run dep ensure ...") execCmd(os.Stdout, dep, ensureCmd, "-v") - fmt.Fprintln(os.Stdout, "Run dep ensure done") + log.Info("Run dep ensure done") } func initGit() { if skipGit { return } - fmt.Fprintln(os.Stdout, "Run git init ...") + log.Info("Run git init ...") execCmd(os.Stdout, "git", "init") execCmd(os.Stdout, "git", "add", "--all") execCmd(os.Stdout, "git", "commit", "-q", "-m", "INITIAL COMMIT") - fmt.Fprintln(os.Stdout, "Run git init done") + log.Info("Run git init done") } diff --git a/commands/operator-sdk/cmd/test/cluster.go b/commands/operator-sdk/cmd/test/cluster.go index 64535be425d..3728c03e456 100644 --- a/commands/operator-sdk/cmd/test/cluster.go +++ b/commands/operator-sdk/cmd/test/cluster.go @@ -63,6 +63,9 @@ func testClusterFunc(cmd *cobra.Command, args []string) error { if len(args) != 1 { return fmt.Errorf("operator-sdk test cluster requires exactly 1 argument") } + + log.Info("Testing operator in cluster.") + var pullPolicy v1.PullPolicy if strings.ToLower(tcConfig.imagePullPolicy) == "always" { pullPolicy = v1.PullAlways @@ -141,7 +144,7 @@ func testClusterFunc(cmd *cobra.Command, args []string) error { time.Sleep(time.Second * 5) continue } else if testPod.Status.Phase == v1.PodSucceeded { - fmt.Println("Test Successfully Completed") + log.Info("Cluster test successfully completed.") return nil } else if testPod.Status.Phase == v1.PodFailed { req := kubeclient.CoreV1().Pods(tcConfig.namespace).GetLogs(testPod.Name, &v1.PodLogOptions{}) diff --git a/commands/operator-sdk/cmd/test/local.go b/commands/operator-sdk/cmd/test/local.go index 99850168bff..bbf3f5ed04f 100644 --- a/commands/operator-sdk/cmd/test/local.go +++ b/commands/operator-sdk/cmd/test/local.go @@ -62,6 +62,9 @@ func testLocalFunc(cmd *cobra.Command, args []string) { if len(args) != 1 { log.Fatal("operator-sdk test local requires exactly 1 argument") } + + log.Info("Testing operator locally.") + // if no namespaced manifest path is given, combine deploy/service_account.yaml, deploy/role.yaml, deploy/role_binding.yaml and deploy/operator.yaml if tlConfig.namespacedManPath == "" { err := os.MkdirAll(deployTestDir, os.FileMode(fileutil.DefaultDirFileMode)) @@ -134,7 +137,7 @@ func testLocalFunc(cmd *cobra.Command, args []string) { defer func() { err := os.Remove(tlConfig.globalManPath) if err != nil { - log.Fatalf("could not delete global namespace manifest file: (%v)", err) + log.Fatalf("could not delete global manifest file: (%v)", err) } }() } @@ -160,6 +163,8 @@ func testLocalFunc(cmd *cobra.Command, args []string) { if err != nil { log.Fatalf("failed to exec `go %s`: (%v)", strings.Join(testArgs, " "), err) } + + log.Info("Local operator test successfully completed.") } // combineManifests combines a given manifest with a base manifest and adds yaml diff --git a/commands/operator-sdk/cmd/up/local.go b/commands/operator-sdk/cmd/up/local.go index 6c850542d7c..d5ad9389685 100644 --- a/commands/operator-sdk/cmd/up/local.go +++ b/commands/operator-sdk/cmd/up/local.go @@ -73,6 +73,9 @@ const ( func upLocalFunc(cmd *cobra.Command, args []string) { mustKubeConfig() + + log.Info("Running the operator locally.") + switch projutil.GetOperatorType() { case projutil.OperatorTypeGo: projutil.MustInProjectRoot() @@ -165,7 +168,7 @@ func upLocalAnsible() { if err != nil { log.Fatal(err) } - log.Info("Ansible operator started succesfully. Exiting.") + log.Info("Exiting.") } func printVersion() { diff --git a/commands/operator-sdk/main.go b/commands/operator-sdk/main.go index 0c282e01479..6f8f2135578 100644 --- a/commands/operator-sdk/main.go +++ b/commands/operator-sdk/main.go @@ -15,15 +15,12 @@ package main import ( - "fmt" - "os" - "github.com/operator-framework/operator-sdk/commands/operator-sdk/cmd" + log "github.com/sirupsen/logrus" ) func main() { if err := cmd.NewRootCmd().Execute(); err != nil { - fmt.Fprintln(os.Stderr, err) - os.Exit(-1) + log.Fatal(err) } } From 5eb3e661f94c092a0df8c737607dcff768706031 Mon Sep 17 00:00:00 2001 From: Eric Stroczynski Date: Wed, 7 Nov 2018 12:28:28 -0800 Subject: [PATCH 5/6] hack/check_error_case.sh: check against Error/Fatal --- hack/check_error_case.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/hack/check_error_case.sh b/hack/check_error_case.sh index 6e6ecd05578..070da7bf31d 100755 --- a/hack/check_error_case.sh +++ b/hack/check_error_case.sh @@ -7,7 +7,7 @@ source "hack/lib/test_lib.sh" echo "Checking case of error messages..." allfiles=$(listFiles) -output=$(grep -Rn 'Fatalf("[[:upper:]]\|Errorf("[[:upper:]]\|errors.New("[[:upper:]]' $allfiles) +output=$(grep -ERn 'Fatal(f)?\("[[:upper:]]|Error(f)?\("[[:upper:]]|Error\((err|nil), "[[:upper:]]|errors.New\("[[:upper:]]' $allfiles) if [ -n "${output}" ]; then echo "Error messages in wrong case:" echo "${output}" From 6df28578eca080492c552efd607b47625bfe3b8b Mon Sep 17 00:00:00 2001 From: Eric Stroczynski Date: Tue, 13 Nov 2018 13:58:25 -0800 Subject: [PATCH 6/6] doc/dev/logging.md: discuss how to use logging in SDK operators --- doc/dev/logging.md | 105 ++++++++++++++++++ .../memcached_controller.go.tmpl | 2 +- 2 files changed, 106 insertions(+), 1 deletion(-) create mode 100644 doc/dev/logging.md diff --git a/doc/dev/logging.md b/doc/dev/logging.md new file mode 100644 index 00000000000..054ba84011e --- /dev/null +++ b/doc/dev/logging.md @@ -0,0 +1,105 @@ +# Logging in operators + +Operator SDK-generated operators use the [`logr`][godoc_logr] interface to log. This log interface has several backends such as [`zap`][repo_zapr], which the SDK uses in generated code by default. [`logr.Logger`][godoc_logr_logger] exposes [structured logging][site_struct_logging] methods that help create machine-readable logs and adding a wealth of information to log records. + +## Setting the logger + +Operators set the logger for all operator logging in [`cmd/manager/main.go`][code_set_logger]: + +```Go +import ( + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" +) + +func main() { + logf.SetLogger(logf.ZapLogger(false)) + log := logf.Log.WithName("cmd") + + ... + + log.Info("Starting the Cmd.") + + ... +} +``` + +By using `controller-runtime/pkg/runtime/log`, your logger is propagated through `controller-runtime`. Any logs produced by `controller-runtime` code will be through your logger, and therefore have the same formatting and destination. + +In the above example, `logf.ZapLogger()` takes a boolean flag to set development parameters. Passing in `true` will set the logger to log in development mode; debug log statements will trigger, and error log statements will include stack traces. + +## Creating a structured log statement + +There are two ways to create structured logs with `logr`. You can create new loggers using `log.WithValues(keyValues)` that include `keyValues`, a list of key-value pair `interface{}`'s, in each log record. Alternatively you can include `keyValues` directly in a log statement, as all `logr` log statements take some message and `keyValues`. The signature of `logr.Error()` has an `error`-type parameter, which can be `nil`. + +An example from [`memcached_controller.go`][code_memcached_controller]: + +```Go +package memcached + +import ( + logf "sigs.k8s.io/controller-runtime/pkg/runtime/log" +) + +// Set a global logger for the memcached package. Each log record produced +// by this logger will have an identifier containing "controller_memcached". +// These names are hierarchical; the name attached to memcached log statements +// will be "operator-sdk.controller_memcached" because SDKLog has name +// "operator-sdk". +var log = logf.Log.WithName("controller_memcached") + +func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Result, error) { + // Create a logger for Reconcile() that includes "Request.Namespace" + // and "Request.Name" in each log record from this log statement. + reqLogger := log.WithValues("Request.Namespace", request.Namespace, "Request.Name", request.Name) + reqLogger.Info("Reconciling Memcached.") + + memcached := &cachev1alpha1.Memcached{} + err := r.client.Get(context.TODO(), request.NamespacedName, memcached) + if err != nil { + if errors.IsNotFound(err) { + reqLogger.Info("Memcached resource not found. Ignoring since object must be deleted.") + return reconcile.Result{}, nil + } + return reconcile.Result{}, err + } + + found := &appsv1.Deployment{} + err = r.client.Get(context.TODO(), types.NamespacedName{Name: memcached.Name, Namespace: memcached.Namespace}, found) + if err != nil { + if errors.IsNotFound(err) { + dep := r.deploymentForMemcached(memcached) + // Include "Deployment.Namespace" and "Deployment.Name" in records + // produced by this particular log statement. "Request.Namespace" and + // "Request.Name" will also be included from reqLogger. + reqLogger.Info("Creating a new Deployment", "Deployment.Namespace", dep.Namespace, "Deployment.Name", dep.Name) + err = r.client.Create(context.TODO(), dep) + if err != nil { + // Include the error in records produced by this log statement. + reqLogger.Error(err, "failed to create new Deployment", "Deployment.Namespace", dep.Namespace, "Deployment.Name", dep.Name) + return reconcile.Result{}, err + } + } + return reconcile.Result{}, err + } + + ... +} +``` + +Log records will look like the following (from `reqLogger.Error()` above): + +``` +2018-11-08T00:00:25.700Z ERROR operator-sdk.controller_memcached pkg/controller/memcached/memcached_controller.go:118 failed to create new Deployment {"Request.Namespace", "memcached", "Request.Name", "memcached-operator", "Deployment.Namespace", "memcached", "Deployment.Name", "memcached-operator"} +``` + +## Non-default logging + +If you do not want to use `logr` as your logging tool, you can remove `logr`-specific statements without issue from your operator's code, including the `logr` [setup code][code_set_logger] in `cmd/manager/main.go`, and add your own. Note that removing `logr` setup code will prevent `controller-runtime` from logging. + + +[godoc_logr]:https://godoc.org/github.com/go-logr/logr +[repo_zapr]:https://godoc.org/github.com/go-logr/zapr +[godoc_logr_logger]:https://godoc.org/github.com/go-logr/logr#Logger +[site_struct_logging]:https://www.client9.com/structured-logging-in-golang/ +[code_memcached_controller]:../../example/memcached-operator/memcached_controller.go.tmpl +[code_set_logger]:https://github.com/operator-framework/operator-sdk/blob/948139171fff0e802c9e68f87cb95939941772ef/pkg/scaffold/cmd.go#L68-L72 diff --git a/example/memcached-operator/memcached_controller.go.tmpl b/example/memcached-operator/memcached_controller.go.tmpl index 033f8642351..4f83c41a59c 100644 --- a/example/memcached-operator/memcached_controller.go.tmpl +++ b/example/memcached-operator/memcached_controller.go.tmpl @@ -87,7 +87,7 @@ type ReconcileMemcached struct { // The Controller will requeue the Request to be processed again if the returned error is non-nil or // Result.Requeue is true, otherwise upon completion it will remove the work from the queue. func (r *ReconcileMemcached) Reconcile(request reconcile.Request) (reconcile.Result, error) { - reqLogger := log.WithValues("Request.Namespace", request.Namespace, "Requst.Name", request.Name) + reqLogger := log.WithValues("Request.Namespace", request.Namespace, "Request.Name", request.Name) reqLogger.Info("Reconciling Memcached") // Fetch the Memcached instance