Implement feedback

Signed-off-by: Maartje Eyskens <maartje@eyskens.me>

cmd/cainjector/app/start.go

@@ -17,7 +17,6 @@ limitations under the License.
 package app
 
 import (
-	"context"
 	"fmt"
 	"io"
 	"os"
@@ -85,11 +84,9 @@ servers and webhook servers.`,
 
 		// TODO: Refactor this function from this package
 		Run: func(cmd *cobra.Command, args []string) {
-			ctx, cancel := context.WithCancel(context.Background())
-			defer cancel()
-			o.log = logf.FromContext(ctx).WithValues("ca-injector")
+			o.log = logf.Log.WithName("ca-injector")
 
-			logf.V(logf.InfoLevel).Infof("starting ca-injector %s (revision %s)", util.AppVersion, util.AppGitCommit)
+			logf.V(logf.InfoLevel).InfoS("starting", "version", util.AppVersion, "revision", util.AppGitCommit)
 			o.RunInjectorController(stopCh)
 		},
 	}

cmd/cainjector/main.go

@@ -39,7 +39,7 @@ func main() {
 
 	flag.CommandLine.Parse([]string{})
 	if err := cmd.Execute(); err != nil {
-		logf.Log.Error(err, "")
+		logf.Log.Error(err, "error executing command")
 		os.Exit(1)
 	}
 }

cmd/controller/app/controller.go

@@ -95,7 +95,7 @@ func Run(opts *options.ControllerOptions, stopCh <-chan struct{}) {
 			}
 			go func(n string, fn controller.Interface) {
 				defer wg.Done()
-				log.V(logf.DebugLevel).Info("starting controller")
+				log.V(logf.InfoLevel).Info("starting controller")
 
 				workers := 5
 				err := fn.Run(workers, stopCh)

cmd/controller/main.go

@@ -35,7 +35,7 @@ func main() {
 
 	flag.CommandLine.Parse([]string{})
 	if err := cmd.Execute(); err != nil {
-		logf.Log.Error(err, "")
+		logf.Log.Error(err, "error executing command")
 		os.Exit(1)
 	}
 }

cmd/webhook/app/webhook.go

@@ -66,7 +66,7 @@ func NewServerWithOptions(log logr.Logger, opts options.WebhookOptions) (*server
 			Log: log,
 		}
 	default:
-		log.V(logf.WarnLevel).Info("warning: serving insecurely as tls certificate data not provided")
+		log.V(logf.WarnLevel).Info("serving insecurely as tls certificate data not provided")
 	}
 
 	return &server.Server{

cmd/webhook/main.go

@@ -35,7 +35,7 @@ func main() {
 
 	flag.CommandLine.Parse([]string{})
 	if err := cmd.Execute(); err != nil {
-		logf.Log.Error(err, "")
+		logf.Log.Error(err, "error executing command")
 		os.Exit(1)
 	}
 }

go.mod

@@ -56,7 +56,6 @@ require (
 	k8s.io/client-go v0.18.5
 	k8s.io/code-generator v0.18.5
 	k8s.io/component-base v0.18.5
-	k8s.io/klog v1.0.0
 	k8s.io/klog/v2 v2.3.0
 	k8s.io/kube-aggregator v0.18.5
 	k8s.io/kube-openapi v0.0.0-20200410145947-bcb3869e6f29

pkg/acme/client/middleware/logger.go

@@ -47,7 +47,7 @@ type Logger struct {
 var _ client.Interface = &Logger{}
 
 func (l *Logger) AuthorizeOrder(ctx context.Context, id []acme.AuthzID, opt ...acme.OrderOption) (*acme.Order, error) {
-	l.log.V(logf.InfoLevel).Info("Calling CreateOrder")
+	l.log.V(logf.TraceLevel).Info("Calling AuthorizeOrder")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -56,7 +56,7 @@ func (l *Logger) AuthorizeOrder(ctx context.Context, id []acme.AuthzID, opt ...a
 }
 
 func (l *Logger) GetOrder(ctx context.Context, url string) (*acme.Order, error) {
-	l.log.V(logf.InfoLevel).Info("Calling GetOrder")
+	l.log.V(logf.TraceLevel).Info("Calling GetOrder")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -65,7 +65,7 @@ func (l *Logger) GetOrder(ctx context.Context, url string) (*acme.Order, error)
 }
 
 func (l *Logger) FetchCert(ctx context.Context, url string, bundle bool) ([][]byte, error) {
-	l.log.V(logf.InfoLevel).Info("Calling GetCertificate")
+	l.log.V(logf.TraceLevel).Info("Calling FetchCert")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -74,7 +74,7 @@ func (l *Logger) FetchCert(ctx context.Context, url string, bundle bool) ([][]by
 }
 
 func (l *Logger) WaitOrder(ctx context.Context, url string) (*acme.Order, error) {
-	l.log.V(logf.InfoLevel).Info("Calling WaitOrder")
+	l.log.V(logf.TraceLevel).Info("Calling WaitOrder")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -83,7 +83,7 @@ func (l *Logger) WaitOrder(ctx context.Context, url string) (*acme.Order, error)
 }
 
 func (l *Logger) CreateOrderCert(ctx context.Context, finalizeURL string, csr []byte, bundle bool) (der [][]byte, certURL string, err error) {
-	l.log.V(logf.InfoLevel).Info("Calling FinalizeOrder")
+	l.log.V(logf.TraceLevel).Info("Calling CreateOrderCert")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -92,7 +92,7 @@ func (l *Logger) CreateOrderCert(ctx context.Context, finalizeURL string, csr []
 }
 
 func (l *Logger) Accept(ctx context.Context, chal *acme.Challenge) (*acme.Challenge, error) {
-	l.log.V(logf.InfoLevel).Info("Calling AcceptChallenge")
+	l.log.V(logf.TraceLevel).Info("Calling Accept")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -101,7 +101,7 @@ func (l *Logger) Accept(ctx context.Context, chal *acme.Challenge) (*acme.Challe
 }
 
 func (l *Logger) GetChallenge(ctx context.Context, url string) (*acme.Challenge, error) {
-	l.log.V(logf.InfoLevel).Info("Calling GetChallenge")
+	l.log.V(logf.TraceLevel).Info("Calling GetChallenge")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -110,7 +110,7 @@ func (l *Logger) GetChallenge(ctx context.Context, url string) (*acme.Challenge,
 }
 
 func (l *Logger) GetAuthorization(ctx context.Context, url string) (*acme.Authorization, error) {
-	l.log.V(logf.InfoLevel).Info("Calling GetAuthorization")
+	l.log.V(logf.TraceLevel).Info("Calling GetAuthorization")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -119,7 +119,7 @@ func (l *Logger) GetAuthorization(ctx context.Context, url string) (*acme.Author
 }
 
 func (l *Logger) WaitAuthorization(ctx context.Context, url string) (*acme.Authorization, error) {
-	l.log.V(logf.InfoLevel).Info("Calling WaitAuthorization")
+	l.log.V(logf.TraceLevel).Info("Calling WaitAuthorization")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -128,7 +128,7 @@ func (l *Logger) WaitAuthorization(ctx context.Context, url string) (*acme.Autho
 }
 
 func (l *Logger) Register(ctx context.Context, a *acme.Account, prompt func(tosURL string) bool) (*acme.Account, error) {
-	l.log.V(logf.InfoLevel).Info("Calling CreateAccount")
+	l.log.V(logf.TraceLevel).Info("Calling Register")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -137,7 +137,7 @@ func (l *Logger) Register(ctx context.Context, a *acme.Account, prompt func(tosU
 }
 
 func (l *Logger) GetReg(ctx context.Context, url string) (*acme.Account, error) {
-	l.log.V(logf.InfoLevel).Info("Calling GetAccount")
+	l.log.V(logf.TraceLevel).Info("Calling GetReg")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -146,17 +146,17 @@ func (l *Logger) GetReg(ctx context.Context, url string) (*acme.Account, error)
 }
 
 func (l *Logger) HTTP01ChallengeResponse(token string) (string, error) {
-	l.log.V(logf.InfoLevel).Info("Calling HTTP01ChallengeResponse")
+	l.log.V(logf.TraceLevel).Info("Calling HTTP01ChallengeResponse")
 	return l.baseCl.HTTP01ChallengeResponse(token)
 }
 
 func (l *Logger) DNS01ChallengeRecord(token string) (string, error) {
-	l.log.V(logf.InfoLevel).Info("Calling DNS01ChallengeRecord")
+	l.log.V(logf.TraceLevel).Info("Calling DNS01ChallengeRecord")
 	return l.baseCl.DNS01ChallengeRecord(token)
 }
 
 func (l *Logger) Discover(ctx context.Context) (acme.Directory, error) {
-	l.log.V(logf.InfoLevel).Info("Calling Discover")
+	l.log.V(logf.TraceLevel).Info("Calling Discover")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()
@@ -165,7 +165,7 @@ func (l *Logger) Discover(ctx context.Context) (acme.Directory, error) {
 }
 
 func (l *Logger) UpdateReg(ctx context.Context, a *acme.Account) (*acme.Account, error) {
-	l.log.V(logf.InfoLevel).Info("Calling UpdateAccount")
+	l.log.V(logf.TraceLevel).Info("Calling UpdateReg")
 
 	ctx, cancel := context.WithTimeout(ctx, timeout)
 	defer cancel()

pkg/acme/webhook/cmd/cmd.go

@@ -42,7 +42,7 @@ func RunWebhookServer(groupName string, hooks ...webhook.Solver) {
 	cmd := server.NewCommandStartWebhookServer(os.Stdout, os.Stderr, stopCh, groupName, hooks...)
 	cmd.Flags().AddGoFlagSet(flag.CommandLine)
 	if err := cmd.Execute(); err != nil {
-		logf.Log.Error(err, "")
+		logf.Log.Error(err, "error executing command")
 		os.Exit(1)
 	}
 }

pkg/controller/acmeorders/sync.go

@@ -146,7 +146,7 @@ func (c *controller) Sync(ctx context.Context, o *cmacme.Order) (err error) {
 		// TODO (@munnerz): instead of waiting for the ACME server to mark this
 		//  Order as failed, we could just mark the Order as failed as there is
 		//  no way that we will attempt and continue the order anyway.
-		log.V(logf.InfoLevel).Info("Update Order status as at least one Challenge has failed")
+		log.V(logf.DebugLevel).Info("Update Order status as at least one Challenge has failed")
 		_, err := c.updateOrderStatus(ctx, cl, o)
 		if acmeErr, ok := err.(*acmeapi.Error); ok {
 			if acmeErr.StatusCode >= 400 && acmeErr.StatusCode < 500 {
@@ -432,7 +432,7 @@ func (c *controller) finalizeOrder(ctx context.Context, cl acmecl.Interface, o *
 	var derBytes []byte
 	block, _ := pem.Decode(o.Spec.CSR)
 	if block == nil {
-		log.V(logf.DebugLevel).Info("failed to parse CSR as PEM data, attempting to treat CSR as DER encoded for compatibility reasons")
+		log.V(logf.WarnLevel).Info("failed to parse CSR as PEM data, attempting to treat CSR as DER encoded for compatibility reasons")
 		derBytes = o.Spec.CSR
 	} else {
 		derBytes = block.Bytes

pkg/controller/cainjector/controller.go

@@ -147,7 +147,7 @@ func (r *genericInjectReconciler) Reconcile(req ctrl.Request) (ctrl.Result, erro
 
 	dataSource, err := r.caDataSourceFor(log, metaObj)
 	if err != nil {
-		log.V(logf.WarnLevel).Info("failed to determine ca data source for injectable")
+		log.V(logf.DebugLevel).Info("failed to determine ca data source for injectable")
 		return ctrl.Result{}, nil
 	}
 
@@ -157,7 +157,7 @@ func (r *genericInjectReconciler) Reconcile(req ctrl.Request) (ctrl.Result, erro
 		return ctrl.Result{}, err
 	}
 	if caData == nil {
-		log.V(logf.WarnLevel).Info("could not find any ca data in data source for target")
+		log.V(logf.InfoLevel).Info("could not find any ca data in data source for target")
 		return ctrl.Result{}, nil
 	}
 

pkg/controller/certificates/informers.go

@@ -41,7 +41,7 @@ func EnqueueCertificatesForResourceUsingPredicates(log logr.Logger, queue workqu
 	return func(obj interface{}) {
 		s, ok := obj.(metav1.Object)
 		if !ok {
-			log.V(logf.DebugLevel).Info("Non-Object type resource passed to EnqueueCertificatesForSecretUsingPredicates")
+			log.V(logf.ErrorLevel).Info("Non-Object type resource passed to EnqueueCertificatesForSecretUsingPredicates")
 			return
 		}
 

pkg/controller/certificates/requestmanager/requestmanager_controller.go

@@ -266,7 +266,7 @@ func (c *controller) deleteRequestsNotMatchingSpec(ctx context.Context, crt *cma
 			continue
 		}
 		if len(violations) > 0 {
-			log.V(logf.DebugLevel).Info("CertificateRequest does not match requirements on certificate.spec, deleting CertificateRequest", "violations", violations)
+			log.V(logf.InfoLevel).WithValues("violations", violations).Info("CertificateRequest does not match requirements on certificate.spec, deleting CertificateRequest", "violations", violations)
 			if err := c.client.CertmanagerV1alpha2().CertificateRequests(req.Namespace).Delete(ctx, req.Name, metav1.DeleteOptions{}); err != nil {
 				return nil, err
 			}

pkg/controller/certificates/trigger/trigger_controller.go

@@ -159,7 +159,7 @@ func (c *controller) ProcessItem(ctx context.Context, key string) error {
 		now := c.clock.Now()
 		retryAfter := crt.Status.LastFailureTime.Add(retryAfterLastFailure)
 		if now.Before(retryAfter) {
-			log.V(logf.DebugLevel).Info("Not re-issuing certificate as an attempt has been made in the last hour", "retry_after", retryAfter)
+			log.V(logf.InfoLevel).Info("Not re-issuing certificate as an attempt has been made in the last hour", "retry_after", retryAfter)
 			c.scheduleRecheckOfCertificateIfRequired(log, key, retryAfter.Sub(now))
 			return nil
 		}

pkg/issuer/acme/dns/akamai/akamai.go

@@ -29,11 +29,11 @@ import (
 	"time"
 
 	"github.com/go-logr/logr"
-	logf "github.com/jetstack/cert-manager/pkg/logs"
+	"github.com/pkg/errors"
 
 	"github.com/jetstack/cert-manager/pkg/issuer/acme/dns/util"
+	logf "github.com/jetstack/cert-manager/pkg/logs"
 	pkgutil "github.com/jetstack/cert-manager/pkg/util"
-	"github.com/pkg/errors"
 )
 
 // DNSProvider is an implementation of the acme.ChallengeProvider interface

pkg/issuer/acme/dns/azuredns/azuredns.go

@@ -16,14 +16,15 @@ import (
 	"strings"
 
 	"github.com/go-logr/logr"
-	logf "github.com/jetstack/cert-manager/pkg/logs"
 
 	"github.com/Azure/azure-sdk-for-go/services/dns/mgmt/2017-10-01/dns"
 	"github.com/Azure/go-autorest/autorest"
 	"github.com/Azure/go-autorest/autorest/adal"
 	"github.com/Azure/go-autorest/autorest/azure"
 	"github.com/Azure/go-autorest/autorest/to"
+
 	"github.com/jetstack/cert-manager/pkg/issuer/acme/dns/util"
+	logf "github.com/jetstack/cert-manager/pkg/logs"
 )
 
 // DNSProvider implements the util.ChallengeProvider interface
@@ -107,7 +108,7 @@ func (c *DNSProvider) Present(domain, fqdn, value string) error {
 func (c *DNSProvider) CleanUp(domain, fqdn, value string) error {
 	z, err := c.getHostedZoneName(fqdn)
 	if err != nil {
-		c.log.V(logf.WarnLevel).Info("Error getting hosted zone name for:", fqdn, err)
+		c.log.Error(err, "Error getting hosted zone name for:", fqdn)
 		return err
 	}
 
@@ -136,7 +137,7 @@ func (c *DNSProvider) createRecord(fqdn, value string, ttl int) error {
 
 	z, err := c.getHostedZoneName(fqdn)
 	if err != nil {
-		c.log.V(logf.WarnLevel).Info("Error getting hosted zone name for:", fqdn, err)
+		c.log.Error(err, "Error getting hosted zone name for:", fqdn)
 		return err
 	}
 
@@ -149,7 +150,7 @@ func (c *DNSProvider) createRecord(fqdn, value string, ttl int) error {
 		*rparams, "", "")
 
 	if err != nil {
-		c.log.V(logf.WarnLevel).Info("Error creating TXT:", z, err)
+		c.log.Error(err, "Error creating TXT:", z)
 		return err
 	}
 	return nil

pkg/issuer/acme/dns/route53/route53.go

@@ -89,7 +89,7 @@ func (d *sessionProvider) GetSession() (*session.Session, error) {
 	}
 
 	if d.Role != "" {
-		d.log.V(logf.DebugLevel).Info("assuming role:", d.Role)
+		d.log.V(logf.DebugLevel).WithValues("role", d.Role).Info("assuming role")
 		stsSvc := d.StsProvider(sess)
 		result, err := stsSvc.AssumeRole(&sts.AssumeRoleInput{
 			RoleArn:         aws.String(d.Role),
@@ -199,7 +199,7 @@ func (r *DNSProvider) changeRecord(action, fqdn, value string, ttl int) error {
 	if err != nil {
 		if awserr, ok := err.(awserr.Error); ok {
 			if action == route53.ChangeActionDelete && awserr.Code() == route53.ErrCodeInvalidChangeBatch {
-				r.log.V(logf.DebugLevel).Info("ignoring InvalidChangeBatch error:", err)
+				r.log.V(logf.DebugLevel).WithValues("error", err).Info("ignoring InvalidChangeBatch error")
 				// If we try to delete something and get a 'InvalidChangeBatch' that
 				// means it's already deleted, no need to consider it an error.
 				return nil

pkg/issuer/acme/dns/webhook/webhook.go

@@ -60,7 +60,7 @@ func (r *Webhook) Present(ch *v1alpha1.ChallengeRequest) error {
 	}
 
 	if respPayload.Response.Success && resErr == nil {
-		logf.Log.V(logf.InfoLevel).Info("Present call succeeded")
+		logf.Log.V(logf.DebugLevel).Info("Present call succeeded")
 		return nil
 	}
 
@@ -96,7 +96,7 @@ func (r *Webhook) CleanUp(ch *v1alpha1.ChallengeRequest) error {
 	}
 
 	if respPayload.Response.Success && resErr == nil {
-		logf.Log.V(logf.InfoLevel).Info("CleanUp call succeeded")
+		logf.Log.V(logf.DebugLevel).Info("CleanUp call succeeded")
 		return nil
 	}
 

pkg/issuer/vault/setup.go

@@ -101,21 +101,21 @@ func (v *Vault) Setup(ctx context.Context) error {
 	client, err := vaultinternal.New(v.resourceNamespace, v.secretsLister, v.issuer)
 	if err != nil {
 		s := messageVaultClientInitFailed + err.Error()
-		logf.V(logf.DebugLevel).Infof("%s: %s", v.issuer.GetObjectMeta().Name, s)
+		logf.V(logf.WarnLevel).Infof("%s: %s", v.issuer.GetObjectMeta().Name, s)
 		apiutil.SetIssuerCondition(v.issuer, v1alpha2.IssuerConditionReady, cmmeta.ConditionFalse, errorVault, s)
 		return err
 	}
 
 	health, err := client.Sys().Health()
 	if err != nil {
 		s := messageVaultHealthCheckFailed + err.Error()
-		logf.V(logf.DebugLevel).Infof("%s: %s", v.issuer.GetObjectMeta().Name, s)
+		logf.V(logf.WarnLevel).Infof("%s: %s", v.issuer.GetObjectMeta().Name, s)
 		apiutil.SetIssuerCondition(v.issuer, v1alpha2.IssuerConditionReady, cmmeta.ConditionFalse, errorVault, s)
 		return err
 	}
 
 	if !health.Initialized || health.Sealed {
-		logf.V(logf.DebugLevel).Infof("%s: %s: health: %v", v.issuer.GetObjectMeta().Name, messageVaultStatusVerificationFailed, health)
+		logf.V(logf.WarnLevel).Infof("%s: %s: health: %v", v.issuer.GetObjectMeta().Name, messageVaultStatusVerificationFailed, health)
 		apiutil.SetIssuerCondition(v.issuer, v1alpha2.IssuerConditionReady, cmmeta.ConditionFalse, errorVault, messageVaultStatusVerificationFailed)
 		return fmt.Errorf(messageVaultStatusVerificationFailed)
 	}