switch to log/slog logging

cmd/root.go

@@ -3,13 +3,13 @@ package cmd
 import (
 	"fmt"
 	"log"
+	"log/slog"
 	"math/rand"
 	"os"
 	"strings"
 	"time"
 
 	"git.bloy.org/mike/hasshelper/web"
-	"github.com/rs/zerolog"
 	"github.com/spf13/cobra"
 	"github.com/spf13/viper"
 )
@@ -22,24 +22,27 @@ var rootCmd = &cobra.Command{
 	Run:   rootCmdRun,
 }
 
+func logLevelVar(str string) slog.Level {
+	levelUpper := strings.ToUpper(str)
+	switch levelUpper {
+	case "DEBUG":
+		return slog.LevelDebug
+	case "INFO":
+		return slog.LevelInfo
+	case "WARN":
+		return slog.LevelWarn
+	case "ERROR":
+		return slog.LevelError
+	default:
+		return slog.LevelInfo
+	}
+}
+
 func rootCmdRun(cmd *cobra.Command, args []string) {
-	logLevel, err := zerolog.ParseLevel(viper.GetString("loglevel"))
+	logLevel := logLevelVar(viper.GetString("loglevel"))
-	zerolog.SetGlobalLevel(logLevel)
+	logger := slog.New(slog.NewTextHandler(os.Stdout,
-	if err != nil {
+		&slog.HandlerOptions{Level: logLevel}))
-		fmt.Fprintln(os.Stderr, err)
+	logger.Info("HASSHelper startup", "version", viper.GetString("version"))
-		os.Exit(1)
-	}
-	var logger zerolog.Logger
-	if viper.GetString("deployment") == "prod" {
-		logger = zerolog.New(os.Stderr)
-	} else {
-		logger = zerolog.New(zerolog.ConsoleWriter{
-			Out:         os.Stdout,
-			FormatLevel: func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("%-6s|", i)) },
-		})
-	}
-	logger = logger.With().Timestamp().Caller().Logger()
-	logger.Info().Str("version", viper.GetString("version")).Msg("HASSHelper startup")
 	exitchan := make(chan bool)
 	web.Run(logger, exitchan)
 	<-exitchan // run the main command until one of the goroutines is done

go.mod

@@ -9,7 +9,6 @@ require (
 	github.com/cortesi/modd v0.8.1
 	github.com/eclipse/paho.mqtt.golang v1.5.0
 	github.com/mdomke/git-semver/v6 v6.9.0
-	github.com/rs/zerolog v1.33.0
 	github.com/spf13/cobra v1.8.1
 	github.com/spf13/viper v1.19.0
 	github.com/stretchr/testify v1.9.0

go.sum

@@ -28,7 +28,6 @@ github.com/bwesterb/go-ristretto v1.2.3/go.mod h1:fUIoIZaG73pV5biE2Blr2xEzDoMj7N
 github.com/cloudflare/circl v1.3.3/go.mod h1:5XYMA4rFBvNIrhs50XuiBJ15vF2pZn4nnUKZrLbUZFA=
 github.com/cloudflare/circl v1.4.0 h1:BV7h5MgrktNzytKmWjpOtdYrf0lkkbF8YMlBGPhJQrY=
 github.com/cloudflare/circl v1.4.0/go.mod h1:PDRU+oXvdD7KCtgKxW95M5Z8BpSCJXQORiZFnBQS5QU=
-github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 github.com/cortesi/devd v0.0.0-20200427000907-c1a3bfba27d8 h1:1vi6SfP/dbmV8Yg4OuuJCSRAZhinuhVnA/YLISA91X0=
 github.com/cortesi/devd v0.0.0-20200427000907-c1a3bfba27d8/go.mod h1:KNI5SyGy0Z2vqxTcYNeuNEWZY1cOSMO6q/W0DgqVcs0=
 github.com/cortesi/modd v0.8.1 h1:0s8e10CJ6pxc6NQHYFrmUZOLP0X6v63ry+3na6Gq2Ow=
@@ -86,7 +85,6 @@ github.com/go-git/go-git/v5 v5.12.0 h1:7Md+ndsjrzZxbddRDZjF14qK+NN56sy6wkqaVrjZt
 github.com/go-git/go-git/v5 v5.12.0/go.mod h1:FTM9VKtnI2m65hNI/TenDDDnUf2Q9FHnXYjuz9i5OEY=
 github.com/go-quicktest/qt v1.101.0 h1:O1K29Txy5P2OK0dGo59b7b0LR6wKfIhttaAhHUyn7eI=
 github.com/go-quicktest/qt v1.101.0/go.mod h1:14Bz/f7NwaXPtdYEgzsx46kqSxVwTbzVZsDC26tQJow=
-github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
 github.com/goji/httpauth v0.0.0-20160601135302-2da839ab0f4d h1:lBXNCxVENCipq4D1Is42JVOP4eQjlB8TQ6H69Yx5J9Q=
 github.com/goji/httpauth v0.0.0-20160601135302-2da839ab0f4d/go.mod h1:nnjvkQ9ptGaCkuDUx6wNykzzlUixGxvkme+H/lnzb+A=
 github.com/golang/groupcache v0.0.0-20210331224755-41bb18bfe9da h1:oI5xCqsCo564l8iNU+DwB5epxmsaqB+rhGL0m5jtYqE=
@@ -137,7 +135,6 @@ github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Ky
 github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94=
 github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
 github.com/mattn/go-isatty v0.0.17/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
-github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
 github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY=
 github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
 github.com/mdomke/git-semver/v6 v6.9.0 h1:pVqzo3LTT0iuiVeicOJwElH1l2CBlbaVHXNncWi08U0=
@@ -169,9 +166,6 @@ github.com/rjeczalik/notify v0.9.3/go.mod h1:gF3zSOrafR9DQEWSE8TjfI9NkooDxbyT4Ug
 github.com/rogpeppe/go-internal v1.9.0/go.mod h1:WtVeX8xhTBvf0smdhujwtBcq4Qrzq/fJaraNFVN+nFs=
 github.com/rogpeppe/go-internal v1.12.0 h1:exVL4IDcn6na9z1rAb56Vxr+CgyK3nn3O+epU5NdKM8=
 github.com/rogpeppe/go-internal v1.12.0/go.mod h1:E+RYuTGaKKdloAfM02xzb0FW3Paa99yedzYV+kq4uf4=
-github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
-github.com/rs/zerolog v1.33.0 h1:1cU2KZkvPxNyfgEmhHAz/1A9Bz+llsdYzklWFzgp0r8=
-github.com/rs/zerolog v1.33.0/go.mod h1:/7mN4D5sKwJLZQ2b/znpjC3/GQWY/xaDXUM0kKWRHss=
 github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM=
 github.com/sagikazarmark/locafero v0.6.0 h1:ON7AQg37yzcRPU69mt7gwhFEBwxI6P9T4Qu3N51bwOk=
 github.com/sagikazarmark/locafero v0.6.0/go.mod h1:77OmuIc6VTraTXKXIs/uvUxKGUXjE1GbemJYHqdNjX0=
@@ -278,7 +272,6 @@ golang.org/x/sys v0.3.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 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.7.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.25.0 h1:r+8e+loiHxRqhXVl6ML1nO3l1+oFoWbnlu2Ehimmi34=
 golang.org/x/sys v0.25.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
 golang.org/x/term v0.0.0-20201117132131-f5c789dd3221/go.mod h1:Nr5EML6q2oocZ2LXRh80K7BxOlk5/8JxuGnuhpl+muw=

web/handlers.go

@@ -18,20 +18,20 @@ func imageHandler() http.Handler {
 
 func chooseRandomFile(ctx context.Context, imageDir string) (filepath string, err error) {
 	validEntries := make([]string, 0)
-	log := config.logger.With().Str("imageDir", imageDir).Logger()
+	log := config.logger.With("imageDir", imageDir)
 	err = fs.WalkDir(
 		os.DirFS(imageDir), ".", func(path string, d fs.DirEntry, err error) error {
 			if err != nil {
-				log.Error().Err(err).Msg("Error walking directory")
+				log.Error("Error walking directory", "err", err)
 				return err
 			}
 			if ctxErr := ctx.Err(); ctxErr != nil {
-				log.Error().Err(ctxErr).Msg("Context closed while walking directory")
+				log.Error("Context closed while walking directory", "err", ctxErr)
 				return ctxErr
 			}
 			if d.Type().IsRegular() {
 				filename := fmt.Sprintf("%s%c%s", imageDir, os.PathSeparator, d.Name())
-				log.Debug().Str("filename", filename).Msg("file scan")
+				log.Debug("file scan", filename, "filename")
 				validEntries = append(validEntries, filename)
 			}
 			return nil
@@ -52,10 +52,10 @@ func randomImageFunc(w http.ResponseWriter, r *http.Request) {
 	log := config.logger
 	path, err := chooseRandomFile(r.Context(), config.imageDir)
 	if err != nil {
-		log.Error().Err(err).Msg("Couldn't choose a random file")
+		log.Error("Couldn't choose a random file", "err", err)
 		w.WriteHeader(http.StatusInternalServerError)
 		return
 	}
-	log.Info().Str("imageFile", path).Msg("random image served")
+	log.Info("random image served", "imagefile", path)
 	http.ServeFile(w, r, path)
 }

web/server.go

@@ -2,14 +2,15 @@ package web
 
 import (
 	"fmt"
+	"log/slog"
 	"net/http"
+	"time"
 
-	"github.com/rs/zerolog"
 	"github.com/spf13/viper"
 )
 
 type configObj struct {
-	logger   zerolog.Logger
+	logger   *slog.Logger
 	port     int
 	imageDir string
 }
@@ -18,8 +19,9 @@ var config = configObj{}
 
 // Run starts up the webserver part of hasshelper. It writes to exitch if
 // the webserver ends unexpectedly. Config values will be read from viper.
-func Run(rootLogger zerolog.Logger, exitch chan bool) {
+func Run(rootLogger *slog.Logger, exitch chan bool) {
-	config.logger = rootLogger.With().Str("name", "web").Logger()
+	rootLogger = rootLogger.With("component", "web")
+	config.logger = rootLogger
 	config.port = viper.GetInt("webserver_port")
 	config.imageDir = viper.GetString("image_dir")
 
@@ -27,17 +29,29 @@ func Run(rootLogger zerolog.Logger, exitch chan bool) {
 	http.HandleFunc("/randimg/", randomImageFunc)
 	var logger = config.logger
 
-	logger.Info().
+	logger.Info("Webserver startup", "port", config.port, "imageDir", config.imageDir)
-		Int("port", config.port).
-		Str("imageDir", config.imageDir).
-		Msg("Webserver startup")
 
 	addr := fmt.Sprintf(":%d", config.port)
 
-	if err := http.ListenAndServe(addr, nil); err != nil {
+	if err := http.ListenAndServe(addr, middleware(http.DefaultServeMux)); err != nil {
-		logger.Error().Err(err).Msg("Webserver fatal error")
+		logger.Error("Webserver fatal error", "err", err)
 	} else {
-		logger.Info().Msg("webserver shutting down")
+		logger.Info("Webserver shutting down")
 	}
 	exitch <- true
 }
+
+func middleware(next http.Handler) http.Handler {
+	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		logger := config.logger.
+			WithGroup("request").
+			With("method", r.Method,
+				"url", r.URL,
+				"remote", r.RemoteAddr)
+		logger.Info("Starting web request")
+		start := time.Now()
+		next.ServeHTTP(w, r)
+		elapsed := time.Now().Sub(start)
+		logger.Info("Web request", "durationMS", elapsed.Milliseconds())
+	})
+}