refactor(logging)!: switch to slog for logging

config.go

@@ -2,6 +2,8 @@ package main
 
 import (
 	"fmt"
+	"log/slog"
+	"os"
 )
 
 type Config struct {
@@ -10,6 +12,30 @@ type Config struct {
 	Region      string
 }
 
+// NewFromEnv creates a new Config from environment variables and defaults
+func NewFromEnv() *Config {
+	cfg := &Config{
+		Service:     os.Getenv("SERVICE_NAME"),
+		Environment: os.Getenv("SERVICE_ENV"),
+		Region:      os.Getenv("AWS_REGION"),
+	}
+
+	if cfg.Service == "" {
+		slog.Warn("SERVICE_NAME is not set, will not load service values")
+	}
+
+	if cfg.Environment == "" {
+		slog.Warn("SERVICE_ENV is not set, defaulting to dev")
+		cfg.Environment = "dev"
+	}
+
+	if cfg.Region == "" {
+		cfg.Region = "us-east-1"
+	}
+
+	return cfg
+}
+
 // ConsulPaths returns the paths from Consul to load
 func (c *Config) ConsulPaths() []string {
 	paths := []string{

go.mod

@@ -9,7 +9,6 @@ require (
 	github.com/hashicorp/vault/api v1.12.0
 	github.com/hashicorp/vault/api/auth/aws v0.6.0
 	github.com/hashicorp/vault/api/auth/kubernetes v0.6.0
-	github.com/rs/zerolog v1.32.0
 	github.com/samber/lo v1.39.0
 	github.com/stretchr/testify v1.8.4
 )

go.sum

@@ -49,7 +49,6 @@ github.com/cenkalti/backoff/v3 v3.0.0/go.mod h1:cIeZDE3IrqwwJl6VUwCN6trj1oXrTS4r
 github.com/cespare/xxhash/v2 v2.1.1/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs=
 github.com/circonus-labs/circonus-gometrics v2.3.1+incompatible/go.mod h1:nmEj6Dob7S7YxXgwXpfOuvO54S+tGdZdw9fuRZt25Ag=
 github.com/circonus-labs/circonusllhist v0.1.3/go.mod h1:kMXHVDlOchFAehlya5ePtbp5jckzBHf4XRpQvBOLI+I=
-github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
@@ -70,7 +69,6 @@ github.com/go-sql-driver/mysql v1.5.0/go.mod h1:DCzpHaOWr8IXmIStZouvnhqoel9Qv2LB
 github.com/go-stack/stack v1.8.0/go.mod h1:v0f6uXyyMGvRgIKkXu+yp6POWl0qKG85gN/melR3HDY=
 github.com/go-test/deep v1.0.2 h1:onZX1rnHT3Wv6cqNgYyFOOlgVKJrksuCMCRvJStbMYw=
 github.com/go-test/deep v1.0.2/go.mod h1:wGDj63lr65AM2AQyKZd/NYHGb0R+1RLqB8NKt3aSFNA=
-github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
 github.com/gogo/protobuf v1.1.1/go.mod h1:r8qH/GZQm5c6nD/R0oafs1akxWv10x8SbQlK7atdtwQ=
 github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
 github.com/golang/protobuf v1.3.1/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
@@ -226,9 +224,6 @@ github.com/prometheus/procfs v0.0.2/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsT
 github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A=
 github.com/rogpeppe/go-internal v1.6.1 h1:/FiVV8dS/e+YqF2JvO3yXRFbBLTIuSDkuC7aBOAvL+k=
 github.com/rogpeppe/go-internal v1.6.1/go.mod h1:xXDCJY+GAPziupqXw64V24skbSoqbTEfhy4qGm1nDQc=
-github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
-github.com/rs/zerolog v1.32.0 h1:keLypqrlIjaFsbmJOBdB/qvyF8KEtCWHwobLp5l/mQ0=
-github.com/rs/zerolog v1.32.0/go.mod h1:/7mN4D5sKwJLZQ2b/znpjC3/GQWY/xaDXUM0kKWRHss=
 github.com/ryanuber/columnize v0.0.0-20160712163229-9b3edd62028f/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts=
 github.com/ryanuber/columnize v2.1.0+incompatible/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts=
 github.com/ryanuber/go-glob v1.0.0 h1:iQh3xXAumdQ+4Ufa5b25cRpC5TYKlno6hsv6Cb3pkBk=
@@ -318,7 +313,6 @@ golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBc
 golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.8.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.13.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.15.0 h1:h48lPFYpsTvQJZF4EKyI4aLHaev3CxivZmv7yZig9pc=
 golang.org/x/sys v0.15.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=

logger.go

@@ -0,0 +1,40 @@
+package main
+
+import "log/slog"
+
+// structuredError is an error that can be logged with additional data
+type structuredError struct {
+	err  error
+	args []any
+}
+
+// NewStructuredError returns a new structure error that will be logged with additional data
+func serror(err error, args ...any) *structuredError {
+	return &structuredError{err: err, args: args}
+}
+
+func (e *structuredError) Error() string {
+	return e.err.Error()
+}
+
+func (e *structuredError) Unwrap() error {
+	return e.err
+}
+
+// LogValue returns a structured log value for use with slog
+func (e structuredError) LogValue() slog.Value {
+	args := make([]slog.Attr, 0, (len(e.args)/2)+1)
+	args = append(args, slog.String(slog.MessageKey, e.Error()))
+
+	var c interface{}
+	for _, a := range e.args {
+		if c == nil {
+			c = a
+			continue
+		}
+		args = append(args, slog.Any(c.(string), a))
+		c = nil
+	}
+
+	return slog.GroupValue(args...)
+}

logger_test.go

@@ -0,0 +1,37 @@
+package main
+
+import (
+	"bytes"
+	"fmt"
+	"log/slog"
+	"os"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestStructuredError(t *testing.T) {
+	wrapped := fmt.Errorf("test error: %w", os.ErrNotExist)
+	err := serror(wrapped, "foo", "bar")
+
+	require.ErrorContains(t, err, "test error")
+	require.ErrorIs(t, err, os.ErrNotExist)
+
+	l, log := testLogger()
+	l.Error("test", "error", err)
+	assert.Contains(t, log.String(), `"error":{"msg":"test error: file does not exist","foo":"bar"}`)
+}
+
+func testLogger() (*slog.Logger, *bytes.Buffer) {
+	log := &bytes.Buffer{}
+	return slog.New(slog.NewJSONHandler(log, &slog.HandlerOptions{
+		Level: slog.LevelDebug,
+		ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr {
+			if a.Key == "time" {
+				a.Value = slog.StringValue("test-time")
+			}
+			return a
+		},
+	})), log
+}

main.go

@@ -3,106 +3,97 @@ package main
 import (
 	"context"
 	"errors"
+	"fmt"
+	"log/slog"
 	"os"
 	"os/exec"
 	"runtime"
 	"strconv"
 	"strings"
-
-	"github.com/rs/zerolog"
-	"github.com/rs/zerolog/log"
 )
 
+var logLevel = new(slog.LevelVar)
+
 func main() {
 	ctx := context.Background()
 
-	zerolog.SetGlobalLevel(zerolog.InfoLevel)
+	logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: logLevel}))
+	slog.SetDefault(logger)
 	if v, ok := os.LookupEnv("DEBUG_BOOTSTRAP"); ok && v != "false" {
-		zerolog.SetGlobalLevel(zerolog.DebugLevel)
-	}
-
-	cfg := &Config{
-		Service:     os.Getenv("SERVICE_NAME"),
-		Environment: os.Getenv("SERVICE_ENV"),
-		Region:      os.Getenv("AWS_REGION"),
+		logLevel.Set(slog.LevelDebug)
 	}
 
-	if cfg.Service == "" {
-		log.Warn().Msg("SERVICE_NAME is not set, will not load service values")
-	}
-
-	if cfg.Environment == "" {
-		log.Warn().Msg("SERVICE_ENV is not set, defaulting to dev")
-		cfg.Environment = "dev"
-	}
-
-	if cfg.Region == "" {
-		cfg.Region = "us-east-1"
-	}
-
-	logger := log.With().
-		Str("env", cfg.Environment).
-		Str("service", cfg.Service).
-		Str("region", cfg.Region).
-		Logger()
+	cfg := NewFromEnv()
+	logger = logger.With("env", cfg.Environment, "service", cfg.Service, "region", cfg.Region)
+	slog.SetDefault(logger)
 
 	if len(os.Args) < 2 {
-		logger.Fatal().Msg("Missing command")
+		logger.ErrorContext(ctx, "Missing command")
+		os.Exit(1)
 	}
 
 	env := NewEnvMap()
-
 	if addr := os.Getenv("CONSUL_ADDR"); addr != "" {
-		env.Merge(loadConsul(addr, cfg, logger))
+		c, err := loadConsul(ctx, addr, cfg, logger)
+		if err != nil {
+			logger.ErrorContext(ctx, "Could not load values from Consul", "error", err)
+			os.Exit(1)
+		}
+		env.Merge(c)
 	} else {
-		logger.Warn().Msg("Not loading values from Consul. CONSUL_ADDR is not set")
+		logger.WarnContext(ctx, "Not loading values from Consul. CONSUL_ADDR is not set")
 	}
 
 	if addr := os.Getenv("VAULT_ADDR"); addr != "" {
-		env.Merge(loadVault(ctx, addr, cfg, logger))
+		v, err := loadVault(ctx, addr, cfg, logger)
+		if err != nil {
+			logger.ErrorContext(ctx, "Could not load values from Vault", "error", err)
+			os.Exit(1)
+		}
+		env.Merge(v)
 	} else {
-		logger.Warn().Msg("Not loading values from Vault. VAULT_ADDR is not set")
+		logger.WarnContext(ctx, "Not loading values from Vault. VAULT_ADDR is not set")
 	}
 
 	pwd, err := os.Getwd()
 	if err != nil {
-		logger.Warn().Err(err).Msg("Cannot determine PWD")
+		logger.WarnContext(ctx, "Cannot determine PWD", "error", err)
 	}
 	env.Add("PWD", pwd)
 	env.Add("AWS_REGION", cfg.Region)
 	env.Add("SERVICE_ENV", cfg.Environment)
 	env.Add("PROCESSOR_COUNT", strconv.Itoa(runtime.NumCPU()))
 
-	os.Exit(run(os.Args[1], os.Args[2:], env.Environ(), logger))
+	os.Exit(run(ctx, os.Args[1], os.Args[2:], env.Environ(), logger))
 }
 
-func loadConsul(addr string, c *Config, l zerolog.Logger) Dict {
-	l.Debug().Msg("Loading values from Consul")
+func loadConsul(ctx context.Context, addr string, c *Config, l *slog.Logger) (Dict, error) {
+	l.Debug("Loading values from Consul")
 
 	client, err := NewConsul(addr)
 	if err != nil {
-		l.Fatal().Err(err).Str("addr", addr).Msg("Could not connect to Consul")
+		return nil, serror(fmt.Errorf("Could not connect to Consul: %w", err), "addr", addr)
 	}
 
 	paths := c.ConsulPaths()
 	if p := os.Getenv("CONSUL_PATHS"); p != "" {
 		paths = append(paths, strings.Split(p, ",")...)
 	}
 
-	return loadValues(client, l, paths)
+	return loadValues(ctx, client, l, paths)
 }
 
-func loadVault(ctx context.Context, addr string, c *Config, l zerolog.Logger) Dict {
-	l.Debug().Msg("Loading values from Vault")
+func loadVault(ctx context.Context, addr string, c *Config, l *slog.Logger) (Dict, error) {
+	l.DebugContext(ctx, "Loading values from Vault")
 
 	client, err := NewVault(addr, c.Region)
 	if err != nil {
-		l.Fatal().Err(err).Str("addr", addr).Msg("Could not connect to Vault")
+		return nil, serror(fmt.Errorf("Could not connect to Vault: %w", err), "addr", addr)
 	}
 
 	token, err := vaultToken(ctx)
 	if err != nil {
-		l.Fatal().Err(err).Msg("Could not get Vault token")
+		return nil, fmt.Errorf("Could not get Vault token: %w", err)
 	}
 
 	role := os.Getenv("VAULT_ROLE")
@@ -112,41 +103,43 @@ func loadVault(ctx context.Context, addr string, c *Config, l zerolog.Logger) Di
 
 	auth, err := client.Authenticate(ctx, token, role)
 	if err != nil {
-		l.Fatal().Err(err).Msg("Could not authenticate Vault")
+		return nil, fmt.Errorf("Could not authenticate Vault: %w", err)
 	}
 
 	if auth == "" {
-		l.Warn().Msg("Not loading values from Vault. Unable to authenticate Vault")
-		return make(Dict)
+		l.WarnContext(ctx, "Not loading values from Vault. Unable to authenticate Vault")
+		return make(Dict), nil
 	}
 
 	paths := c.VaultPaths()
 	if p := os.Getenv("VAULT_PATHS"); p != "" {
 		paths = append(paths, strings.Split(p, ",")...)
 	}
 
-	values := loadValues(client, l, paths)
+	values, err := loadValues(ctx, client, l, paths)
 	values["VAULT_TOKEN"] = auth
-	return values
+	return values, err
 }
 
-func run(name string, args, env []string, l zerolog.Logger) int {
-	cmd := exec.Command(name, args...) //nolint:gosec
+func run(ctx context.Context, name string, args, env []string, l *slog.Logger) int {
+	cmd := exec.CommandContext(ctx, name, args...) //nolint:gosec
 	cmd.Env = append(os.Environ(), env...)
 	cmd.Stdin = os.Stdin
 	cmd.Stderr = os.Stderr
 	cmd.Stdout = os.Stdout
 
 	if err := cmd.Start(); err != nil {
-		l.Fatal().Err(err).Str("cmd", cmd.String()).Msg("Could not start command")
+		l.ErrorContext(ctx, "Could not start command", "error", err, "cmd", cmd.String())
+		return 1
 	}
 
 	if err := cmd.Wait(); err != nil {
 		var exit *exec.ExitError
 		if errors.As(err, &exit) {
 			return exit.ExitCode()
 		}
-		l.Fatal().Err(err).Str("cmd", cmd.String()).Msg("Unknown error while running command")
+		l.ErrorContext(ctx, "Unknown error while running command", "error", err, "cmd", cmd.String())
+		return 1
 	}
 
 	return 0

utils.go

@@ -1,6 +1,10 @@
 package main
 
-import "github.com/rs/zerolog"
+import (
+	"context"
+	"fmt"
+	"log/slog"
+)
 
 type (
 	Dict map[string]string
@@ -11,19 +15,19 @@ type (
 	}
 )
 
-func loadValues(c Client, l zerolog.Logger, paths []string) Dict {
+func loadValues(ctx context.Context, c Client, l *slog.Logger, paths []string) (Dict, error) {
 	values := map[string]string{}
 	for _, path := range paths {
-		l.Debug().Str("path", path).Msg("Loading values")
+		l.DebugContext(ctx, "Loading values", "path", path)
 
 		kv, err := c.Load(path)
 		if err != nil {
-			l.Fatal().Err(err).Str("path", path).Msg("Could not load values")
+			return values, serror(fmt.Errorf("Could not load values: %w", err), "path", path)
 		}
 
 		for k, v := range kv {
 			values[k] = v
 		}
 	}
-	return values
+	return values, nil
 }