chore: Switch from zerolog to slog (#2068)

Signed-off-by: Dave Henderson <dhenderson@gmail.com>

5 files changed, 103 insertions, 122 deletions

diff --git a/internal/cmd/config.go b/internal/cmd/config.go
index d0c7bff4..62777061 100644
--- a/internal/cmd/config.go
+++ b/internal/cmd/config.go
@@ -3,6 +3,7 @@ package cmd
 import (
 	"context"
 	"fmt"
+	"log/slog"
 	"time"
 
 	"github.com/hairyhenderson/gomplate/v4/conv"
@@ -10,8 +11,6 @@ import (
 	"github.com/hairyhenderson/gomplate/v4/internal/config"
 	"github.com/hairyhenderson/gomplate/v4/internal/datafs"
 
-	"github.com/rs/zerolog"
-
 	"github.com/spf13/cobra"
 )
 
@@ -66,8 +65,6 @@ func pickConfigFile(cmd *cobra.Command) (cfgFile string, required bool) {
 }
 
 func readConfigFile(ctx context.Context, cmd *cobra.Command) (cfg *config.Config, err error) {
-	log := zerolog.Ctx(ctx)
-
 	cfgFile, configRequired := pickConfigFile(cmd)
 
 	// we only support loading configs from the local filesystem for now
@@ -89,7 +86,7 @@ func readConfigFile(ctx context.Context, cmd *cobra.Command) (cfg *config.Config
 		return cfg, fmt.Errorf("parsing config file %q: %w", cfgFile, err)
 	}
 
-	log.Debug().Str("cfgFile", cfgFile).Msg("using config file")
+	slog.DebugContext(ctx, "using config file", "cfgFile", cfgFile)
 
 	return cfg, nil
 }
diff --git a/internal/cmd/logger.go b/internal/cmd/logger.go
index 06c48f66..3231abb2 100644
--- a/internal/cmd/logger.go
+++ b/internal/cmd/logger.go
@@ -1,17 +1,13 @@
 package cmd
 
 import (
-	"context"
-	"fmt"
 	"io"
-	stdlog "log"
+	"log/slog"
 	"os"
 	"runtime"
-	"time"
 
 	"github.com/hairyhenderson/gomplate/v4/env"
-	"github.com/rs/zerolog"
-	zlog "github.com/rs/zerolog/log"
+	"github.com/lmittmann/tint"
 	"golang.org/x/term"
 )
 
@@ -23,78 +19,53 @@ func logFormat(out io.Writer) string {
 	return env.Getenv("GOMPLATE_LOG_FORMAT", defaultFormat)
 }
 
-func fmtField(fname string) func(i interface{}) string {
-	return func(i interface{}) string {
-		if i == nil || i == "" {
-			return ""
-		}
-
-		if s, ok := i.(string); ok {
-			for _, c := range s {
-				if c <= 0x20 || c == '\\' || c == '"' {
-					return fmt.Sprintf("%s=%q", fname, i)
-				}
-			}
-		}
-		return fmt.Sprintf("%s=%s", fname, i)
-	}
-}
-
-func createLogger(format string, out io.Writer) zerolog.Logger {
-	zerolog.MessageFieldName = "msg"
-
-	l := zlog.Logger.Output(out)
-
-	stdlogger := l.With().Bool("stdlog", true).Logger()
-	stdlog.SetFlags(0)
+func createLogHandler(format string, out io.Writer, level slog.Level) slog.Handler {
+	opts := &slog.HandlerOptions{Level: level}
 
+	var handler slog.Handler
 	switch format {
 	case "console":
+		// logFormat() already checks if this is a terminal, but we need to
+		// check again because the format may be overridden with `GOMPLATE_LOG_FORMAT`
 		useColour := false
 		if f, ok := out.(*os.File); ok && term.IsTerminal(int(f.Fd())) && runtime.GOOS != "windows" {
 			useColour = true
 		}
-		l = l.Output(zerolog.ConsoleWriter{
-			Out:        out,
-			NoColor:    !useColour,
+		handler = tint.NewHandler(out, &tint.Options{
+			Level:      level,
 			TimeFormat: "15:04:05",
+			NoColor:    !useColour,
 		})
-		stdlogger = stdlogger.Output(zerolog.ConsoleWriter{
-			Out:         out,
-			NoColor:     !useColour,
-			FormatLevel: func(_ interface{}) string { return "" },
+	case "simple":
+		handler = tint.NewHandler(out, &tint.Options{
+			Level:   level,
+			NoColor: true,
+			ReplaceAttr: func(_ []string, attr slog.Attr) slog.Attr {
+				if attr.Key == "level" {
+					attr.Value = slog.StringValue("")
+				}
+				if attr.Key == "time" {
+					attr.Value = slog.StringValue("")
+				}
+				return attr
+			},
 		})
 	case "logfmt":
-		w := zerolog.ConsoleWriter{
-			Out:             out,
-			NoColor:         true,
-			FormatMessage:   fmtField(zerolog.MessageFieldName),
-			FormatLevel:     fmtField(zerolog.LevelFieldName),
-			FormatTimestamp: fmtField(zerolog.TimestampFieldName),
-		}
-		l = l.Output(w)
-		stdlogger = stdlogger.Output(w)
-	case "simple":
-		w := zerolog.ConsoleWriter{
-			Out:             out,
-			NoColor:         true,
-			FormatLevel:     func(_ interface{}) string { return "" },
-			FormatTimestamp: func(_ interface{}) string { return "" },
-		}
-		l = l.Output(w)
-		stdlogger = stdlogger.Output(w)
+		handler = slog.NewTextHandler(out, opts)
+	default:
+		// json is still default
+		handler = slog.NewJSONHandler(out, opts)
 	}
-	stdlog.SetOutput(stdlogger)
 
-	return l
+	return handler
 }
 
-func initLogger(ctx context.Context, out io.Writer) context.Context {
+func initLogger(out io.Writer, level slog.Level) {
 	// default to warn level
-	zerolog.SetGlobalLevel(zerolog.WarnLevel)
-	zerolog.DurationFieldUnit = time.Second
-
-	l := createLogger(logFormat(out), out)
+	if level == 0 {
+		level = slog.LevelWarn
+	}
 
-	return l.WithContext(ctx)
+	handler := createLogHandler(logFormat(out), out, level)
+	slog.SetDefault(slog.New(handler))
 }
diff --git a/internal/cmd/logger_test.go b/internal/cmd/logger_test.go
index ea595c1e..ca585858 100644
--- a/internal/cmd/logger_test.go
+++ b/internal/cmd/logger_test.go
@@ -2,13 +2,14 @@ package cmd
 
 import (
 	"bytes"
+	"context"
 	"log"
+	"log/slog"
 	"os"
 	"strings"
 	"testing"
+	"time"
 
-	"github.com/rs/zerolog"
-	zlog "github.com/rs/zerolog/log"
 	"github.com/stretchr/testify/assert"
 )
 
@@ -24,41 +25,64 @@ func TestLogFormat(t *testing.T) {
 	assert.Equal(t, "simple", logFormat(&bytes.Buffer{}))
 }
 
-func TestCreateLogger(t *testing.T) {
-	zerolog.SetGlobalLevel(zerolog.WarnLevel)
-	buf := &bytes.Buffer{}
+// a slog handler that strips the 'time' field
+type noTimestampHandler struct {
+	slog.Handler
+}
+
+var _ slog.Handler = (*noTimestampHandler)(nil)
+
+func (h *noTimestampHandler) Handle(ctx context.Context, r slog.Record) error {
+	r.Time = time.Time{}
+
+	return h.Handler.Handle(ctx, r)
+}
 
-	// avoid timestamps
-	zlog.Logger = zerolog.New(buf)
+func TestCreateLogHandler(t *testing.T) {
+	buf := &bytes.Buffer{}
+	h := createLogHandler("", buf, slog.LevelWarn)
+	// strip the 'time' field for easier comparison
+	h = &noTimestampHandler{h}
+	l := slog.New(h)
+	slog.SetDefault(l)
 
-	l := createLogger("", buf)
-	l.Debug().Msg("this won't show up")
-	l.Warn().Msg("hello world")
+	l.Debug("this won't show up")
+	l.Warn("hello world")
 
 	actual := strings.TrimSpace(buf.String())
-	assert.Equal(t, `{"level":"warn","msg":"hello world"}`, actual)
+	assert.JSONEq(t, `{"level":"WARN","msg":"hello world"}`, actual)
 
 	buf.Reset()
-	zerolog.SetGlobalLevel(zerolog.DebugLevel)
-	l = createLogger("simple", buf)
-	l.Debug().Str("field", "a value").Msg("this will show up")
+	h = createLogHandler("simple", buf, slog.LevelDebug)
+	l = slog.New(h)
+	slog.SetDefault(l)
+
+	l.Debug("this will show up", "field", "a value")
 	log.Println("hello world")
 
 	actual = strings.TrimSpace(buf.String())
-	assert.Equal(t, "this will show up field=\"a value\"\nhello world stdlog=true", actual)
+	assert.Equal(t, "this will show up field=\"a value\"\n  hello world", actual)
 
 	buf.Reset()
-	l = createLogger("console", buf)
-	l.Debug().Msg("hello")
+	h = createLogHandler("console", buf, slog.LevelDebug)
+	h = &noTimestampHandler{h}
+	l = slog.New(h)
+	slog.SetDefault(l)
+
+	l.Debug("hello")
 	log.Println("world")
 
 	actual = strings.TrimSpace(buf.String())
-	assert.Equal(t, "<nil> DBG hello\n<nil> world stdlog=true", actual)
+	assert.Equal(t, "DBG hello\nINF world", actual)
 
 	buf.Reset()
-	l = createLogger("logfmt", buf)
-	l.Info().Str("field", "a value").Int("num", 84).Msg("hello\"")
+	h = createLogHandler("logfmt", buf, slog.LevelInfo)
+	h = &noTimestampHandler{h}
+	l = slog.New(h)
+	slog.SetDefault(l)
+
+	l.Info("hello\"", "field", "a value", "num", 84)
 
 	actual = strings.TrimSpace(buf.String())
-	assert.Equal(t, "level=info msg=\"hello\\\"\" field=\"a value\" num=84", actual)
+	assert.Equal(t, "level=INFO msg=\"hello\\\"\" field=\"a value\" num=84", actual)
 }
diff --git a/internal/cmd/main.go b/internal/cmd/main.go
index 0c5596d6..22388521 100644
--- a/internal/cmd/main.go
+++ b/internal/cmd/main.go
@@ -2,7 +2,9 @@ package cmd
 
 import (
 	"context"
+	"fmt"
 	"io"
+	"log/slog"
 	"os"
 	"os/exec"
 	"os/signal"
@@ -12,15 +14,13 @@ import (
 	"github.com/hairyhenderson/gomplate/v4/internal/datafs"
 	"github.com/hairyhenderson/gomplate/v4/version"
 
-	"github.com/rs/zerolog"
 	"github.com/spf13/cobra"
 )
 
 // postRunExec - if templating succeeds, the command following a '--' will be executed
 func postRunExec(ctx context.Context, args []string, stdin io.Reader, stdout, stderr io.Writer) error {
 	if len(args) > 0 {
-		log := zerolog.Ctx(ctx)
-		log.Debug().Strs("args", args).Msg("running post-exec command")
+		slog.DebugContext(ctx, "running post-exec command", "args", args)
 
 		//nolint:govet
 		ctx, cancel := context.WithCancel(ctx)
@@ -69,17 +69,19 @@ func optionalExecArgs(cmd *cobra.Command, args []string) error {
 }
 
 // NewGomplateCmd -
-func NewGomplateCmd() *cobra.Command {
+func NewGomplateCmd(stderr io.Writer) *cobra.Command {
 	rootCmd := &cobra.Command{
 		Use:     "gomplate",
 		Short:   "Process text files with Go templates",
 		Version: version.Version,
 		RunE: func(cmd *cobra.Command, args []string) error {
+			level := slog.LevelWarn
 			if v, _ := cmd.Flags().GetBool("verbose"); v {
-				zerolog.SetGlobalLevel(zerolog.DebugLevel)
+				level = slog.LevelDebug
 			}
+			initLogger(stderr, level)
+
 			ctx := cmd.Context()
-			log := zerolog.Ctx(ctx)
 
 			cfg, err := loadConfig(ctx, cmd, args)
 			if err != nil {
@@ -87,28 +89,26 @@ func NewGomplateCmd() *cobra.Command {
 			}
 
 			if cfg.Experimental {
-				log.UpdateContext(func(c zerolog.Context) zerolog.Context {
-					return c.Bool("experimental", true)
-				})
-				log.Info().Msg("experimental functions and features enabled!")
+				slog.SetDefault(slog.With("experimental", true))
+				slog.InfoContext(ctx, "experimental functions and features enabled!")
 
 				ctx = gomplate.SetExperimental(ctx)
 			}
 
-			log.Debug().Msgf("starting %s", cmd.Name())
-			log.Debug().
-				Str("version", version.Version).
-				Str("build", version.GitCommit).
-				Msgf("config is:\n%v", cfg)
+			slog.DebugContext(ctx, fmt.Sprintf("starting %s", cmd.Name()))
+			slog.DebugContext(ctx, fmt.Sprintf("config is:\n%v", cfg),
+				slog.String("version", version.Version),
+				slog.String("build", version.GitCommit),
+			)
 
 			err = gomplate.Run(ctx, cfg)
 			cmd.SilenceErrors = true
 			cmd.SilenceUsage = true
 
-			log.Debug().Int("templatesRendered", gomplate.Metrics.TemplatesProcessed).
-				Int("errors", gomplate.Metrics.Errors).
-				Dur("duration", gomplate.Metrics.TotalRenderDuration).
-				Msg("completed rendering")
+			slog.DebugContext(ctx, "completed rendering",
+				slog.Int("templatesRendered", gomplate.Metrics.TemplatesProcessed),
+				slog.Int("errors", gomplate.Metrics.Errors),
+				slog.Duration("duration", gomplate.Metrics.TotalRenderDuration))
 
 			if err != nil {
 				return err
@@ -167,15 +167,13 @@ func InitFlags(command *cobra.Command) {
 
 // Main -
 func Main(ctx context.Context, args []string, stdin io.Reader, stdout, stderr io.Writer) error {
-	ctx = initLogger(ctx, stderr)
-
 	// inject default filesystem provider if it hasn't already been provided in
 	// the context
 	if datafs.FSProviderFromContext(ctx) == nil {
 		ctx = datafs.ContextWithFSProvider(ctx, gomplate.DefaultFSProvider)
 	}
 
-	command := NewGomplateCmd()
+	command := NewGomplateCmd(stderr)
 	InitFlags(command)
 	command.SetArgs(args)
 	command.SetIn(stdin)
@@ -184,8 +182,7 @@ func Main(ctx context.Context, args []string, stdin io.Reader, stdout, stderr io
 
 	err := command.ExecuteContext(ctx)
 	if err != nil {
-		log := zerolog.Ctx(ctx)
-		log.Error().Err(err).Send()
+		slog.Error("", slog.Any("err", err))
 	}
 	return err
 }
diff --git a/internal/deprecated/deprecated.go b/internal/deprecated/deprecated.go
index 6f9ef317..ee49088a 100644
--- a/internal/deprecated/deprecated.go
+++ b/internal/deprecated/deprecated.go
@@ -4,18 +4,10 @@ import (
 	"context"
 	"fmt"
 	"log/slog"
-
-	"github.com/rs/zerolog"
 )
 
 // WarnDeprecated - use this to warn about deprecated template functions or
 // datasources
 func WarnDeprecated(ctx context.Context, msg string) {
-	logger := zerolog.Ctx(ctx)
-	if !logger.Warn().Enabled() {
-		// we'll flip to slog soon, but in the meantime if we don't have a
-		// logger in the context, just log it
-		slog.WarnContext(ctx, fmt.Sprintf("Deprecated: %s", msg))
-	}
-	logger.Warn().Msgf("Deprecated: %s", msg)
+	slog.WarnContext(ctx, fmt.Sprintf("Deprecated: %s", msg))
 }