feat: integrate zerolog for structured logging and replace fmt with logger

2025-01-21 23:33:14 -06:00
parent 0d8e8acf3a
commit 0ca2a9eeed
6 changed files with 59 additions and 17 deletions
--- a/go.mod
+++ b/go.mod
@@ -4,11 +4,15 @@ go 1.23.0

 require (
 	github.com/docker/go-units v0.5.0
+	github.com/rs/zerolog v1.33.0
 	github.com/spf13/cobra v1.8.1
 	golang.org/x/exp v0.0.0-20250106191152-7588d65b2ba8
 )

 require (
 	github.com/inconshreveable/mousetrap v1.1.0 // indirect
+	github.com/mattn/go-colorable v0.1.13 // indirect
+	github.com/mattn/go-isatty v0.0.19 // indirect
 	github.com/spf13/pflag v1.0.5 // indirect
+	golang.org/x/sys v0.12.0 // indirect
 )
--- a/go.sum
+++ b/go.sum
@@ -1,8 +1,19 @@
+github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 github.com/cpuguy83/go-md2man/v2 v2.0.4/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o=
 github.com/docker/go-units v0.5.0 h1:69rxXcBk27SvSaaxTtLh/8llcHD8vYHT7WSdRZ/jvr4=
 github.com/docker/go-units v0.5.0/go.mod h1:fgPhTUdO+D/Jk86RDLlptpiXQzgHJF7gydDDbaIK4Dk=
+github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
 github.com/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8=
 github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw=
+github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA=
+github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg=
+github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
+github.com/mattn/go-isatty v0.0.19 h1:JITubQf0MOLdlGRuRq+jtsDlekdYPia9ZFsB8h/APPA=
+github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
+github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
+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/spf13/cobra v1.8.1 h1:e5/vxKd/rZsfSJMUX1agtjeTDf+qv1/JdBF8gg5k9ZM=
 github.com/spf13/cobra v1.8.1/go.mod h1:wHxEcudfqmLYa8iTfL+OuZPbBZkmvliBWKIezN3kD9Y=
@@ -10,5 +21,9 @@ github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA=
 github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg=
 golang.org/x/exp v0.0.0-20250106191152-7588d65b2ba8 h1:yqrTHse8TCMW1M1ZCP+VAR/l0kKxwaAIqN/il7x4voA=
 golang.org/x/exp v0.0.0-20250106191152-7588d65b2ba8/go.mod h1:tujkw807nyEEAamNbDrEGzRav+ilXA7PCRAd6xsmwiU=
+golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
+golang.org/x/sys v0.12.0 h1:CM0HF96J0hcLAwsHPJZjfdNzs0gftsLfgKt57wWHJ0o=
+golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
 gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
--- a/steamcache/gc.go
+++ b/steamcache/gc.go
@@ -1,7 +1,7 @@
 package steamcache

 import (
-	"fmt"
+	"s1d3sw1ped/SteamCache2/steamcache/logger"
 	"s1d3sw1ped/SteamCache2/vfs"
 	"s1d3sw1ped/SteamCache2/vfs/cachestate"
 	"time"
@@ -17,7 +17,7 @@ func randomgc(vfss vfs.VFS, stats []*vfs.FileInfo) int64 {
 	err := vfss.Delete(randfile.Name())
 	if err != nil {
 		// If we failed to delete the file, log it and return 0
-		// fmt.Printf("Failed to delete %s: %v", randfile.Name(), err)
+		// logger.Logger.Error().Err(err).Msgf("Failed to delete %s", randfile.Name())
 		return 0
 	}

@@ -39,7 +39,12 @@ func memorygc(vfss vfs.VFS, size int) {
 		}
 	}

-	fmt.Printf("GC of %s took %v to reclaim %s by deleting %d files", vfss.Name(), time.Since(tstart), units.HumanSize(float64(reclaimed)), deletions)
+	logger.Logger.Info().
+		Str("name", vfss.Name()).
+		Str("duration", time.Since(tstart).String()).
+		Str("reclaimed", units.HumanSize(float64(reclaimed))).
+		Int("deletions", deletions).
+		Msgf("GC")
 }

 func diskgc(vfss vfs.VFS, size int) {
@@ -57,7 +62,12 @@ func diskgc(vfss vfs.VFS, size int) {
 		}
 	}

-	fmt.Printf("GC of %s took %v to reclaim %s by deleting %d files", vfss.Name(), time.Since(tstart), units.HumanSize(float64(reclaimed)), deletions)
+	logger.Logger.Info().
+		Str("name", vfss.Name()).
+		Str("duration", time.Since(tstart).String()).
+		Str("reclaimed", units.HumanSize(float64(reclaimed))).
+		Int("deletions", deletions).
+		Msgf("GC")
 }

 func cachehandler(fi *vfs.FileInfo, cs cachestate.CacheState) bool {
--- a/steamcache/logger/logger.go
+++ b/steamcache/logger/logger.go
@@ -0,0 +1,9 @@
+package logger
+
+import (
+	"os"
+
+	"github.com/rs/zerolog"
+)
+
+var Logger = zerolog.New(zerolog.ConsoleWriter{Out: os.Stderr}).With().Timestamp().Logger()
--- a/steamcache/steamcache.go
+++ b/steamcache/steamcache.go
@@ -7,6 +7,7 @@ import (
 	"net/url"
 	"os"
 	"s1d3sw1ped/SteamCache2/steamcache/avgcachestate"
+	"s1d3sw1ped/SteamCache2/steamcache/logger"
 	"s1d3sw1ped/SteamCache2/vfs"
 	"s1d3sw1ped/SteamCache2/vfs/cache"
 	"s1d3sw1ped/SteamCache2/vfs/cachestate"
@@ -80,7 +81,7 @@ func New(address string, memorySize string, memoryMultiplier int, diskSize strin
 }

 func (sc *SteamCache) Run() {
-	fmt.Printf("SteamCache2 running on %s", sc.address)
+	logger.Logger.Info().Str("address", sc.address).Msg("listening")

 	sc.mu.Lock()
 	sc.dirty = true
@@ -96,7 +97,11 @@ func (sc *SteamCache) Run() {

 	err := http.ListenAndServe(sc.address, sc)
 	if err != nil {
-		fmt.Println(err)
+		if err == http.ErrServerClosed {
+			logger.Logger.Info().Msg("shutdown")
+			return
+		}
+		logger.Logger.Error().Err(err).Msg("Failed to start SteamCache2")
 		os.Exit(1)
 	}
 }
@@ -105,12 +110,11 @@ func (sc *SteamCache) LogStats() {
 	sc.mu.Lock()
 	defer sc.mu.Unlock()
 	if sc.dirty {
-		fmt.Printf(
-			"%s: (%d) %s/%s   %s: (%d) %s/%s   Hitrate: %f%%",
-			sc.memory.Name(), len(sc.memory.StatAll()), units.HumanSize(float64(sc.memory.Size())), units.HumanSize(float64(sc.memory.Capacity())),
-			sc.disk.Name(), len(sc.disk.StatAll()), units.HumanSize(float64(sc.disk.Size())), units.HumanSize(float64(sc.disk.Capacity())),
-			sc.hits.Avg()*100,
-		)
+		logger.Logger.Info().
+			Str("memory", fmt.Sprintf("%s/%s", units.HumanSize(float64(sc.memory.Size())), units.HumanSize(float64(sc.memory.Capacity())))).Int("memory-files", len(sc.memory.StatAll())).
+			Str("disk", fmt.Sprintf("%s/%s", units.HumanSize(float64(sc.disk.Size())), units.HumanSize(float64(sc.disk.Capacity())))).Int("disk-files", len(sc.disk.StatAll())).
+			Str("hitrate", fmt.Sprintf("%.2f%%", sc.hits.Avg()*100)).
+			Msg("stats")
 		sc.dirty = false
 	}
 }
@@ -141,7 +145,7 @@ func (sc *SteamCache) ServeHTTP(w http.ResponseWriter, r *http.Request) {

 	// tstart := time.Now()
 	// defer func() {
-	// 	fmt.Printf("%s %s %s took %s", r.Method, r.URL.String(), w.Header().Get("X-LanCache-Status"), time.Since(tstart))
+	// logger.Logger.Info().Str("method", r.Method).Str("url", r.URL.String()).Str("status", w.Header().Get("X-LanCache-Status")).Dur("duration", time.Since(tstart)).Msg("Request")
 	// }()

 	sc.mu.Lock()
--- a/vfs/disk/disk.go
+++ b/vfs/disk/disk.go
@@ -1,9 +1,9 @@
 package disk

 import (
-	"fmt"
 	"os"
 	"path/filepath"
+	"s1d3sw1ped/SteamCache2/steamcache/logger"
 	"s1d3sw1ped/SteamCache2/vfs"
 	"s1d3sw1ped/SteamCache2/vfs/vfserror"
 	"sync"
@@ -53,14 +53,14 @@ func NewSkipInit(root string, capacity int64) *DiskFS {
 }

 func (d *DiskFS) init() {
-	// fmt.Printf("DiskFS(%s, %s) init", d.root, units.HumanSize(float64(d.capacity)))
+	// logger.Logger.Info().Str("name", d.Name()).Str("root", d.root).Str("capacity", units.HumanSize(float64(d.capacity))).Msg("init")

 	tstart := time.Now()

 	d.walk(d.root)
 	d.sg.Wait()

-	fmt.Printf("DiskFS(%s, %s) init took %v", d.root, units.HumanSize(float64(d.capacity)), time.Since(tstart))
+	logger.Logger.Info().Str("name", d.Name()).Str("root", d.root).Str("capacity", units.HumanSize(float64(d.capacity))).Str("duration", time.Since(tstart).String()).Msg("init")
 }

 func (d *DiskFS) walk(path string) {
@@ -86,7 +86,7 @@ func (d *DiskFS) walk(path string) {
 			d.info[k] = vfs.NewFileInfoFromOS(info, k)
 			d.mu.Unlock()

-			// fmt.Printf("DiskFS(%s, %s) init: %s", d.root, units.HumanSize(float64(d.capacity)), npath)
+			// logger.Logger.Debug().Str("name", d.Name()).Str("root", d.root).Str("capacity", units.HumanSize(float64(d.capacity))).Str("path", npath).Msg("init")
 			return nil
 		})
 	}()