Added more logging

Added a named logger to GenSource (auto-tls), mostly debug-level for
telling which is the leader and which is the follower.

helper/cert/notify_test.go

@@ -5,6 +5,8 @@ import (
 	"fmt"
 	"testing"
 	"time"
+
+	"github.com/hashicorp/go-hclog"
 )
 
 func TestNotify(t *testing.T) {
@@ -64,6 +66,7 @@ func TestNotifyRace(t *testing.T) {
 		var certSource Source = &GenSource{
 			Name:  "Agent Inject",
 			Hosts: []string{"some", "hosts"},
+			Log:   hclog.Default(),
 		}
 		n := NewNotify(ctx, certCh, certSource)
 

helper/cert/source_gen.go

@@ -18,6 +18,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/vault-k8s/leader"
 	v1 "k8s.io/api/core/v1"
 	"k8s.io/apimachinery/pkg/api/errors"
@@ -59,6 +60,8 @@ type GenSource struct {
 	Namespace     string
 	SecretsCache  informerv1.SecretInformer
 	LeaderElector *leader.LeaderElector
+
+	Log hclog.Logger
 }
 
 // Certificate implements source
@@ -76,8 +79,10 @@ func (s *GenSource) Certificate(ctx context.Context, last *Bundle) (Bundle, erro
 		// and returns that in the result. That will flow through the existing
 		// notify channel structure, testing if it's the same cert as last, etc.
 		if !leaderCheck {
+			s.Log.Debug("Currently a follower")
 			return s.getBundleFromSecret()
 		}
+		s.Log.Debug("Currently the leader")
 	}
 
 	// If we have no CA, generate it for the first time.
@@ -87,6 +92,8 @@ func (s *GenSource) Certificate(ctx context.Context, last *Bundle) (Bundle, erro
 		}
 		// If we had no CA, also ensure the cert is regenerated
 		last = nil
+
+		s.Log.Info("Generated CA")
 	}
 
 	// Set the CA cert

helper/cert/source_gen_test.go

@@ -12,6 +12,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/vault-k8s/leader"
 	"github.com/stretchr/testify/require"
 	v1 "k8s.io/api/core/v1"
@@ -77,6 +78,7 @@ func testGenSource() *GenSource {
 	return &GenSource{
 		Name:  "Test",
 		Hosts: []string{"127.0.0.1", "localhost"},
+		Log:   hclog.Default(),
 	}
 }
 

subcommand/injector/command.go

@@ -105,6 +105,17 @@ func (c *Command) Run(args []string) int {
 		leaderElector = leader.New()
 	}
 
+	level, err := c.logLevel()
+	if err != nil {
+		c.UI.Error(fmt.Sprintf("Error setting log level: %s", err))
+		return 1
+	}
+
+	logger := hclog.New(&hclog.LoggerOptions{
+		Name:       "handler",
+		Level:      level,
+		JSONFormat: (c.flagLogFormat == "json")})
+
 	// Determine where to source the certificates from
 	var certSource cert.Source = &cert.GenSource{
 		Name:          "Agent Inject",
@@ -113,6 +124,7 @@ func (c *Command) Run(args []string) int {
 		Namespace:     namespace,
 		SecretsCache:  secrets,
 		LeaderElector: leaderElector,
+		Log:           logger.Named("auto-tls"),
 	}
 	if c.flagCertFile != "" {
 		certSource = &cert.DiskSource{
@@ -126,18 +138,7 @@ func (c *Command) Run(args []string) int {
 	certCh := make(chan cert.Bundle)
 	certNotify := cert.NewNotify(ctx, certCh, certSource)
 	go certNotify.Run()
-	go c.certWatcher(ctx, certCh, clientset)
-
-	level, err := c.logLevel()
-	if err != nil {
-		c.UI.Error(fmt.Sprintf("Error setting log level: %s", err))
-		return 1
-	}
-
-	logger := hclog.New(&hclog.LoggerOptions{
-		Name:       "handler",
-		Level:      level,
-		JSONFormat: (c.flagLogFormat == "json")})
+	go c.certWatcher(ctx, certCh, clientset, logger.Named("certwatcher"))
 
 	// Build the HTTP handler and server
 	injector := agentInject.Handler{
@@ -224,12 +225,12 @@ func (c *Command) getCertificate(*tls.ClientHelloInfo) (*tls.Certificate, error)
 	return certRaw.(*tls.Certificate), nil
 }
 
-func (c *Command) certWatcher(ctx context.Context, ch <-chan cert.Bundle, clientset *kubernetes.Clientset) {
+func (c *Command) certWatcher(ctx context.Context, ch <-chan cert.Bundle, clientset *kubernetes.Clientset, log hclog.Logger) {
 	var bundle cert.Bundle
 	for {
 		select {
 		case bundle = <-ch:
-			c.UI.Output("Updated certificate bundle received. Updating certs...")
+			log.Info("Updated certificate bundle received. Updating certs...")
 			// Bundle is updated, set it up
 
 		case <-time.After(1 * time.Second):
@@ -245,7 +246,7 @@ func (c *Command) certWatcher(ctx context.Context, ch <-chan cert.Bundle, client
 
 		crt, err := tls.X509KeyPair(bundle.Cert, bundle.Key)
 		if err != nil {
-			c.UI.Error(fmt.Sprintf("Error loading TLS keypair: %s", err))
+			log.Error(fmt.Sprintf("Error loading TLS keypair: %s", err))
 			continue
 		}
 
@@ -256,7 +257,7 @@ func (c *Command) certWatcher(ctx context.Context, ch <-chan cert.Bundle, client
 			le := leader.New()
 			isLeader, err = le.IsLeader()
 			if err != nil {
-				c.UI.Error(fmt.Sprintf("error checking leader: %s", err))
+				log.Error(fmt.Sprintf("error checking leader: %s", err))
 				continue
 			}
 		}