From 93d04410bfd691b2da607a681f1ebcd15d5de4e4 Mon Sep 17 00:00:00 2001 From: Justin Harms Date: Tue, 21 Jan 2025 23:33:14 -0600 Subject: [PATCH] feat: integrate zerolog for structured logging and replace fmt with logger --- go.mod | 4 ++++ go.sum | 15 +++++++++++++++ steamcache/gc.go | 18 ++++++++++++++---- steamcache/logger/logger.go | 9 +++++++++ steamcache/steamcache.go | 22 +++++++++++++--------- vfs/disk/disk.go | 8 ++++---- 6 files changed, 59 insertions(+), 17 deletions(-) create mode 100644 steamcache/logger/logger.go diff --git a/go.mod b/go.mod index 2fa4bb3..5ca4db0 100644 --- 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 ) diff --git a/go.sum b/go.sum index 9fd6e6e..b99509a 100644 --- 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= diff --git a/steamcache/gc.go b/steamcache/gc.go index 01a44d5..91a65f5 100644 --- 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 { diff --git a/steamcache/logger/logger.go b/steamcache/logger/logger.go new file mode 100644 index 0000000..d276484 --- /dev/null +++ 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() diff --git a/steamcache/steamcache.go b/steamcache/steamcache.go index 11f7649..628d606 100644 --- 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() diff --git a/vfs/disk/disk.go b/vfs/disk/disk.go index 2142a39..290234a 100644 --- 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 }) }()