use zap for logging, previous log never outputted to kubectl logs

Author: eatwithforks

go.mod

@@ -2,13 +2,15 @@ module github.com/open-policy-agent/cert-controller
 
 go 1.14
 
-require (
-	github.com/onsi/gomega v1.10.1
-	github.com/pkg/errors v0.9.1
-	go.uber.org/atomic v1.4.0
-	go.uber.org/zap v1.10.0
-	k8s.io/api v0.18.6
-	k8s.io/apimachinery v0.18.6
-	k8s.io/client-go v0.18.6
-	sigs.k8s.io/controller-runtime v0.6.3
-)
+ require (
+ 	github.com/go-logr/zapr v0.1.0
+ 	github.com/onsi/gomega v1.10.1
+ 	github.com/open-policy-agent/cert-controller v0.1.0
+ 	github.com/pkg/errors v0.9.1
+ 	go.uber.org/atomic v1.4.0
+ 	go.uber.org/zap v1.10.0
+ 	k8s.io/api v0.18.6
+ 	k8s.io/apimachinery v0.18.6
+ 	k8s.io/client-go v0.18.6
+ 	sigs.k8s.io/controller-runtime v0.6.3
+ )

main.go

@@ -12,6 +12,8 @@ import (
 	"k8s.io/client-go/tools/clientcmd/api"
 	"os"
 	ctrl "sigs.k8s.io/controller-runtime"
+	logf "sigs.k8s.io/controller-runtime/pkg/log"
+	"github.com/go-logr/zapr"
 	"sigs.k8s.io/controller-runtime/pkg/client/apiutil"
 	"time"
 )
@@ -27,6 +29,21 @@ var (
 	webhookName    = flag.String("webhook-name", "", "Your webhook name")
 )
 
+func buildLogger() (*zap.Logger, error) {
+	// build a logger:
+	// - without timestamps because docker already logs with timestamps
+	// - use "message" instead of "msg" for consistency with other services / datadog parsing
+	// - remove caller since it points to shared methods most of the time anyway
+	loggerConfig := zap.NewProductionConfig()
+	loggerConfig.EncoderConfig.TimeKey = ""
+	loggerConfig.EncoderConfig.MessageKey = "message"
+	loggerConfig.DisableCaller = true
+	if os.Getenv("DEBUG") == "1" {
+		loggerConfig.Level.SetLevel(zap.DebugLevel)
+	}
+	return loggerConfig.Build()
+}
+
 func main() {
 	flag.Parse()
 
@@ -38,7 +55,9 @@ func main() {
 	}
 
 	// configure logging.
-	logger, _ := zap.NewDevelopment()
+	logger, _ := buildLogger()
+	defer logger.Sync() // flush buffer
+	logf.SetLogger(zapr.NewLogger(logger)) // Set logger for cert-controller or it sends to /dev/null
 
 	logger.Info("sleeping to demonstrate restart behavior")
 	time.Sleep(5 * time.Second)
@@ -63,6 +82,7 @@ func main() {
 	}
 
 	// Make sure certs are generated and valid if cert rotation is enabled.
+	setupFinished := make(chan struct{})
 	if err := rotator.AddRotator(mgr, &rotator.CertRotator{
 		SecretKey: types.NamespacedName{
 			Namespace: *nameSpace,
@@ -72,10 +92,10 @@ func main() {
 		CAName:         *caName,
 		CAOrganization: *caOrganization,
 		DNSName:        *dnsName,
+		IsReady:        setupFinished,
 		Webhooks:       webhooks,
 	}); err != nil {
 		logger.Error("unable to set up cert rotation", zap.Error(err))
-
 		os.Exit(1)
 	}
 

pkg/rotator/rotator.go

@@ -41,6 +41,7 @@ const (
 	caCertName             = "ca.crt"
 	caKeyName              = "ca.key"
 	rotationCheckFrequency = 12 * time.Hour
+	certValidityDuration   = 10 * 365 * 24 * time.Hour
 	lookaheadInterval      = 90 * 24 * time.Hour
 )
 
@@ -62,9 +63,6 @@ var _ manager.Runnable = &CertRotator{}
 
 var restartOnSecretRefresh = false
 
-var certValidityDuration = flag.Duration("cert-validity-duration", 10 * 365 * 24 * time.Hour, "Sets how long the cert is valid for, defaults to 10 years")
-
-
 //WebhookInfo is used by the rotator to receive info about resources to be updated with certificates
 type WebhookInfo struct {
 	//Name is the name of the webhook for a validating or mutating webhook, or the CRD name in case of a CRD conversion webhook
@@ -73,7 +71,7 @@ type WebhookInfo struct {
 }
 
 func init() {
-	flag.BoolVar(&restartOnSecretRefresh, "cert-restart-on-secret-refresh", true, "Kills the process when secrets are refreshed so that the pod can be restarted (secrets take up to 60s to be updated by running pods)")
+	flag.BoolVar(&restartOnSecretRefresh, "cert-restart-on-secret-refresh", false, "Kills the process when secrets are refreshed so that the pod can be restarted (secrets take up to 60s to be updated by running pods)")
 }
 
 func (w WebhookInfo) gvk() schema.GroupVersionKind {
@@ -148,7 +146,7 @@ func addNamespacedCache(mgr manager.Manager, namespace string) (cache.Cache, err
 // SyncingSource is a reader that needs syncing prior to being usable.
 type SyncingReader interface {
 	client.Reader
-	WaitForCacheSync(stop <-chan struct{}) bool
+	WaitForCacheSync(ctx context.Context) bool
 }
 
 // CertRotator contains cert artifacts and a channel to close when the certs are ready.
@@ -169,11 +167,11 @@ type CertRotator struct {
 }
 
 // Start starts the CertRotator runnable to rotate certs and ensure the certs are ready.
-func (cr *CertRotator) Start(stop <-chan struct{}) error {
+func (cr *CertRotator) Start(ctx context.Context) error {
 	if cr.reader == nil {
 		return errors.New("nil reader")
 	}
-	if !cr.reader.WaitForCacheSync(stop) {
+	if !cr.reader.WaitForCacheSync(ctx) {
 		return errors.New("failed waiting for reader to sync")
 	}
 
@@ -199,7 +197,7 @@ tickerLoop:
 			if err := cr.refreshCertIfNeeded(); err != nil {
 				crLog.Error(err, "error rotating certs")
 			}
-		case <-stop:
+		case <-ctx.Done():
 			break tickerLoop
 		case <-cr.certsNotMounted:
 			return errors.New("could not mount certs")
@@ -264,7 +262,7 @@ func (cr *CertRotator) refreshCerts(refreshCA bool, secret *corev1.Secret) error
 	var caArtifacts *KeyPairArtifacts
 	now := time.Now()
 	begin := now.Add(-1 * time.Hour)
-	end := now.Add(*certValidityDuration)
+	end := now.Add(certValidityDuration)
 	if refreshCA {
 		var err error
 		caArtifacts, err = cr.CreateCACert(begin, end)
@@ -539,43 +537,17 @@ func ValidCert(caCert, cert, key []byte, dnsName string, at time.Time) (bool, er
 	return true, nil
 }
 
-// controller code for making sure the CA cert on the
-// webhooks don't get clobbered
-
-var _ handler.Mapper = &crdMapper{}
-
-type crdMapper struct {
-	secretKey types.NamespacedName
-	crdNames  []string
-}
-
-func (m *crdMapper) Map(object handler.MapObject) []reconcile.Request {
-	if object.Meta.GetNamespace() != "" {
-		return nil
-	}
-	for _, crdName := range m.crdNames {
-		if object.Meta.GetName() == crdName {
-			return []reconcile.Request{{NamespacedName: m.secretKey}}
+func reconcileSecretAndWebhookMapFunc(webhook WebhookInfo, r *ReconcileWH) func(object client.Object) []reconcile.Request {
+	return func(object client.Object) []reconcile.Request {
+		whKey := types.NamespacedName{Name: webhook.Name}
+		if object.GetNamespace() != whKey.Namespace {
+			return nil
 		}
+		if object.GetName() != whKey.Name {
+			return nil
+		}
+		return []reconcile.Request{{NamespacedName: r.secretKey}}
 	}
-	return nil
-}
-
-var _ handler.Mapper = &mapper{}
-
-type mapper struct {
-	secretKey types.NamespacedName
-	whKey     types.NamespacedName
-}
-
-func (m *mapper) Map(object handler.MapObject) []reconcile.Request {
-	if object.Meta.GetNamespace() != m.whKey.Namespace {
-		return nil
-	}
-	if object.Meta.GetName() != m.whKey.Name {
-		return nil
-	}
-	return []reconcile.Request{{NamespacedName: m.secretKey}}
 }
 
 // add adds a new Controller to mgr with r as the reconcile.Reconciler
@@ -599,10 +571,7 @@ func addController(mgr manager.Manager, r *ReconcileWH) error {
 		wh.SetGroupVersionKind(webhook.gvk())
 		err = c.Watch(
 			source.NewKindWithCache(wh, r.cache),
-			&handler.EnqueueRequestsFromMapFunc{ToRequests: &mapper{
-				secretKey: r.secretKey,
-				whKey:     types.NamespacedName{Name: webhook.Name},
-			}},
+			handler.EnqueueRequestsFromMapFunc(reconcileSecretAndWebhookMapFunc(webhook, r)),
 		)
 		if err != nil {
 			return fmt.Errorf("watching webhook %s: %w", webhook.Name, err)
@@ -628,13 +597,12 @@ type ReconcileWH struct {
 
 // Reconcile reads that state of the cluster for a validatingwebhookconfiguration
 // object and makes sure the most recent CA cert is included
-func (r *ReconcileWH) Reconcile(request reconcile.Request) (reconcile.Result, error) {
+func (r *ReconcileWH) Reconcile(ctx context.Context, request reconcile.Request) (reconcile.Result, error) {
 	if request.NamespacedName != r.secretKey {
 		return reconcile.Result{}, nil
 	}
 
-	stop := make(<-chan struct{})
-	if !r.cache.WaitForCacheSync(stop) {
+	if !r.cache.WaitForCacheSync(ctx) {
 		return reconcile.Result{}, errors.New("cache not ready")
 	}
 
@@ -657,11 +625,9 @@ func (r *ReconcileWH) Reconcile(request reconcile.Request) (reconcile.Result, er
 		}
 
 		// Ensure certs on webhooks
-		fmt.Println("Starting cert injection")
 		if err := r.ensureCerts(artifacts.CertPEM); err != nil {
 			return reconcile.Result{}, err
 		}
-		fmt.Println("Finished cert injection")
 
 		// Set CAInjected if the reconciler has not exited early.
 		r.wasCAInjected.Store(true)
@@ -690,32 +656,25 @@ func (r *ReconcileWH) ensureCerts(certPem []byte) error {
 		updatedResource.SetGroupVersionKind(gvk)
 		if err := r.cache.Get(r.ctx, types.NamespacedName{Name: webhook.Name}, updatedResource); err != nil {
 			if k8sErrors.IsNotFound(err) {
-				fmt.Println("Webhook not found. Unable to update certificate.", err)
 				log.Error(err, "Webhook not found. Unable to update certificate.")
 				continue
 			}
 			anyError = err
 			log.Error(err, "Error getting webhook for certificate update.")
-			fmt.Println("Error getting webhook for certificate update.", err)
-
 			continue
 		}
 		if !updatedResource.GetDeletionTimestamp().IsZero() {
-			fmt.Println("Webhook is being deleted. Unable to update certificate")
 			log.Info("Webhook is being deleted. Unable to update certificate")
 			continue
 		}
 
 		log.Info("Ensuring CA cert", "name", webhook.Name, "gvk", gvk)
 		if err := injectCert(updatedResource, certPem, webhook.Type); err != nil {
-			fmt.Println("Unable to inject cert to webhook.:", err)
 			log.Error(err, "Unable to inject cert to webhook.")
 			anyError = err
 			continue
 		}
 		if err := r.writer.Update(r.ctx, updatedResource); err != nil {
-			fmt.Println("Error updating webhook with certificate:", err)
-
 			log.Error(err, "Error updating webhook with certificate")
 			anyError = err
 			continue
@@ -766,4 +725,4 @@ func (cr *CertRotator) ensureReady() {
 	}
 	crLog.Info("CA certs are injected to webhooks")
 	close(cr.IsReady)
-}
+}

test.yaml

@@ -18,29 +18,40 @@ spec:
         foo: bar4
     spec:
       containers:
-      - name: busybox
-        image: busybox
-        command: ["sh", "-c", "watch ls /certs"]
-        volumeMounts:
-        - name: certs
-          mountPath: "/certs"
-          readOnly: true
-      - name: cert-controller
-        args:
-          - -cert-dir=/certs
-          - -ca-name=foocaname
-          - -secret-name=vpa-admission-controller-secret
-          - -service-name=fooservice
-          - -ca-organization=fooorg
-          - -namespace=default
-          - -dns-name=foo.bar.svc
-          - -webhook-name=vpa-webhook-config
-        imagePullPolicy: Never
-        image: cert-controller
+        - name: busybox
+          image: busybox
+          command: ["sh", "-c", "watch ls /certs"]
+          volumeMounts:
+            - name: certs
+              mountPath: "/certs"
+              readOnly: true
+        - name: cert-controller
+          args:
+            - -cert-dir=/certs
+            - -ca-name=foocaname
+            - -secret-name=vpa-admission-controller-secret
+            - -service-name=fooservice
+            - -ca-organization=fooorg
+            - -namespace=default
+            - -dns-name=foo.bar.svc
+            - -webhook-name=vpa-webhook-config
+          imagePullPolicy: Never
+          image: cert-controller
+          resources:
+            limits:
+              cpu: 200m
+              memory: 500Mi
+            requests:
+              cpu: 50m
+              memory: 200Mi
+          volumeMounts:
+            - name: certs
+              mountPath: "/certs"
+              readOnly: true
       volumes:
-      - name: certs
-        secret:
-          secretName: vpa-admission-controller-secret
+        - name: certs
+          secret:
+            secretName: vpa-admission-controller-secret
 ---
 apiVersion: admissionregistration.k8s.io/v1
 kind: MutatingWebhookConfiguration
@@ -54,21 +65,21 @@ metadata:
   annotations:
     samson/server_side_apply: 'true'
 webhooks:
-- name: vpa.k8s.io
-  failurePolicy: Ignore
-  admissionReviewVersions: ["v1beta1"]
-  rules:
-  - apiGroups:   [""]
-    apiVersions: ["v1"]
-    operations:  ["CREATE"]
-    resources:   ["pods"]
-  clientConfig:
-    caBundle: Cg==
-    service:
-      namespace: default
-      name: vpa-webhook
-  sideEffects: None
-  timeoutSeconds: 30
+  - name: vpa.k8s.io
+    failurePolicy: Ignore
+    admissionReviewVersions: ["v1beta1"]
+    rules:
+      - apiGroups:   [""]
+        apiVersions: ["v1"]
+        operations:  ["CREATE"]
+        resources:   ["pods"]
+    clientConfig:
+      caBundle: Cg==
+      service:
+        namespace: default
+        name: vpa-webhook
+    sideEffects: None
+    timeoutSeconds: 30
 
 # We need to create a bogus secret for the updater to fill
 ---