Logging improvements (#69)

* a more straightforward logging configuration

* improved top-level error messages

* log the config but hide sensitive fields

* improved the logger configuration with structured environment variables and improved feedback

Author: Southclaws

go.mod

@@ -15,6 +15,7 @@ require (
 	github.com/hashicorp/vault/api v1.0.5-0.20200117231345-460d63e36490
 	github.com/hashicorp/vault/sdk v0.1.14-0.20200121232954-73f411823aa0 // indirect
 	github.com/joho/godotenv v1.3.0
+	github.com/kelseyhightower/envconfig v1.4.0
 	github.com/pierrec/lz4 v2.4.1+incompatible // indirect
 	github.com/pkg/errors v0.9.1
 	github.com/robertkrimen/otto v0.0.0-20191219234010-c382bd3c16ff

go.sum

@@ -111,6 +111,8 @@ github.com/jbenet/go-context v0.0.0-20150711004518-d14ea06fba99/go.mod h1:1lJo3i
 github.com/jessevdk/go-flags v1.4.0/go.mod h1:4FA24M0QyGHXBuZZK/XkWh8h0e1EYbRYJSGM75WSRxI=
 github.com/joho/godotenv v1.3.0 h1:Zjp+RcGpHhGlrMbJzXTrZZPrWj+1vfm90La1wgB6Bhc=
 github.com/joho/godotenv v1.3.0/go.mod h1:7hK45KPybAkOC6peb+G5yklZfMxEjkZhHbwpqxOKXbg=
+github.com/kelseyhightower/envconfig v1.4.0 h1:Im6hONhd3pLkfDFsbRgu68RDNkGF1r3dvMUtDTo2cv8=
+github.com/kelseyhightower/envconfig v1.4.0/go.mod h1:cccZRl6mQpaq41TPp5QxidR+Sa3axMbJDNb//FQX6Gg=
 github.com/kevinburke/ssh_config v0.0.0-20190725054713-01f96b0aa0cd h1:Coekwdh0v2wtGp9Gmz1Ze3eVRAWJMLokvN3QjdzCHLY=
 github.com/kevinburke/ssh_config v0.0.0-20190725054713-01f96b0aa0cd/go.mod h1:CT57kijsi8u/K/BOFA39wgDQJ9CxiF4nAY/ojJ6r6mM=
 github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck=

logger/logger.go

@@ -1,32 +1,68 @@
 package logger
 
 import (
+	"fmt"
 	"os"
-	"strconv"
 	"strings"
 
+	"github.com/joho/godotenv"
+	"github.com/kelseyhightower/envconfig"
+	"github.com/pkg/errors"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
 )
 
+type Env string
+
+type cfg struct {
+	Environment Env           `envconfig:"ENVIRONMENT" default:"production"`
+	LogLevel    zapcore.Level `envconfig:"LOG_LEVEL"   default:"info"`
+}
+
+const (
+	EnvironmentProd Env = "production"
+	EnvironmentDev  Env = "development"
+)
+
+func (e *Env) UnmarshalText(text []byte) error {
+	switch strings.ToLower(string(text)) {
+	case string(EnvironmentProd):
+		*e = EnvironmentProd
+	case string(EnvironmentDev):
+		*e = EnvironmentDev
+	default:
+		return errors.Errorf("unknown environment type: '%s'", string(text))
+	}
+	return nil
+}
+
 func init() {
-	// constructs a logger and replaces the default global logger
+	godotenv.Load("../.env", ".env") //nolint:errcheck
+
+	var c cfg
+	envconfig.MustProcess("", &c)
+
 	var config zap.Config
-	if d, e := strconv.ParseBool(os.Getenv("DEVELOPMENT")); d && e == nil || isInTests() {
+	if c.Environment == EnvironmentDev || isInTests() {
 		config = zap.NewDevelopmentConfig()
 	} else {
 		config = zap.NewProductionConfig()
 	}
+
+	config.Level.SetLevel(c.LogLevel)
 	config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder
-	config.DisableStacktrace = true
-	if d, e := strconv.ParseBool(os.Getenv("DEBUG")); d && e == nil || isInTests() {
-		config.Level = zap.NewAtomicLevelAt(zap.DebugLevel)
-	}
+
 	logger, err := config.Build()
 	if err != nil {
-		panic(err)
+		fmt.Println("Error during logging config:", err)
+		os.Exit(1)
 	}
 	zap.ReplaceGlobals(logger)
+
+	zap.L().Info("logger configured",
+		zap.String("level", c.LogLevel.String()),
+		zap.String("env", string(c.Environment)))
+
 }
 
 func isInTests() bool {

main.go

@@ -6,6 +6,7 @@ import (
 	"os"
 	"os/signal"
 	"runtime"
+	"strings"
 	"time"
 
 	_ "github.com/joho/godotenv/autoload"
@@ -57,7 +58,7 @@ this repository has new commits, Pico will automatically reconfigure.`,
 			Action: func(c *cli.Context) (err error) {
 				if !c.Args().Present() {
 					cli.ShowCommandHelp(c, "run")
-					return errors.New("missing argument: target")
+					return errors.New("missing argument: configuration repository URL")
 				}
 
 				ctx, cancel := context.WithCancel(context.Background())
@@ -72,9 +73,7 @@ this repository has new commits, Pico will automatically reconfigure.`,
 					}
 				}
 
-				zap.L().Debug("initialising service")
-
-				svc, err := service.Initialise(service.Config{
+				cfg := service.Config{
 					Target: task.Repo{
 						URL:  c.Args().First(),
 						User: c.String("git-username"),
@@ -90,7 +89,11 @@ this repository has new commits, Pico will automatically reconfigure.`,
 					VaultPath:       c.String("vault-path"),
 					VaultRenewal:    c.Duration("vault-renew-interval"),
 					VaultConfig:     c.String("vault-config-path"),
-				})
+				}
+
+				zap.L().Debug("initialising service", zap.Any("config", cfg))
+
+				svc, err := service.Initialise(cfg)
 				if err != nil {
 					return errors.Wrap(err, "failed to initialise")
 				}
@@ -116,7 +119,7 @@ this repository has new commits, Pico will automatically reconfigure.`,
 		},
 	}
 
-	if os.Getenv("DEBUG") != "" {
+	if strings.ToLower(os.Getenv("LOG_LEVEL")) == "debug" {
 		go func() {
 			sigs := make(chan os.Signal, 1)
 			signal.Notify(sigs, os.Interrupt)

service/service.go

@@ -32,7 +32,7 @@ type Config struct {
 	PassEnvironment bool
 	CheckInterval   time.Duration
 	VaultAddress    string
-	VaultToken      string
+	VaultToken      string `json:"-"`
 	VaultPath       string
 	VaultRenewal    time.Duration
 	VaultConfig     string
@@ -63,7 +63,7 @@ func Initialise(c Config) (app *App, err error) {
 
 		secretStore, err = vault.New(c.VaultAddress, c.VaultPath, c.VaultToken, c.VaultRenewal)
 		if err != nil {
-			return nil, err
+			return nil, errors.Wrap(err, "failed to create vault secret store")
 		}
 	} else {
 		secretStore = &memory.MemorySecrets{
@@ -118,16 +118,25 @@ func (app *App) Start(ctx context.Context) error {
 
 	gw := app.watcher.(*watcher.GitWatcher)
 	go func() {
-		errs <- errors.Wrap(gw.Start(), "git watcher terminated fatally")
+		errs <- errors.Wrap(
+			gw.Start(),
+			"git watcher crashed",
+		)
 	}()
 
 	go func() {
-		errs <- errors.Wrap(app.reconfigurer.Configure(app.watcher), "git watcher terminated fatally")
+		errs <- errors.Wrap(
+			app.reconfigurer.Configure(app.watcher),
+			"reconfigure provider crashed",
+		)
 	}()
 
 	if s, ok := app.secrets.(*vault.VaultSecrets); ok {
 		go func() {
-			errs <- errors.Wrap(retrier.New(retrier.ConstantBackoff(3, 100*time.Millisecond), nil).RunCtx(ctx, s.Renew), "git watcher terminated fatally")
+			errs <- errors.Wrap(
+				retrier.New(retrier.ConstantBackoff(3, 100*time.Millisecond), nil).RunCtx(ctx, s.Renew),
+				"vault token renewal job failed",
+			)
 		}()
 	}
 

task/target.go

@@ -20,7 +20,7 @@ type ExecutionTask struct {
 type Repo struct {
 	URL  string
 	User string
-	Pass string
+	Pass string `json:"-"`
 }
 
 // Targets is just a list of target objects, to implement the Sort interface