From 37909139de52b552e9e426ca360f7fb1fe4c5c52 Mon Sep 17 00:00:00 2001 From: Sebastian Date: Wed, 20 May 2026 22:29:45 +0200 Subject: [PATCH] Add Zap logging framework with structured logging for Echo and Grafana --- go.mod | 2 ++ go.sum | 4 ++++ internal/server/downloadHandler.go | 10 ++++----- internal/server/musicHandler.go | 31 ++++++++++++++------------- internal/server/routes.go | 3 ++- internal/server/server.go | 34 +++++++++++++++++++++++------- internal/server/syncHandler.go | 17 ++++++++------- 7 files changed, 64 insertions(+), 37 deletions(-) diff --git a/go.mod b/go.mod index 4ff8307..a69dc3a 100644 --- a/go.mod +++ b/go.mod @@ -37,6 +37,8 @@ require ( github.com/sv-tools/openapi v0.4.0 // indirect github.com/swaggo/files/v2 v2.0.2 // indirect github.com/swaggo/swag/v2 v2.0.0-rc5 // indirect + go.uber.org/multierr v1.10.0 // indirect + go.uber.org/zap v1.28.0 // indirect go.yaml.in/yaml/v2 v2.4.4 // indirect go.yaml.in/yaml/v3 v3.0.4 // indirect golang.org/x/mod v0.36.0 // indirect diff --git a/go.sum b/go.sum index bfea727..dd8887d 100644 --- a/go.sum +++ b/go.sum @@ -129,6 +129,10 @@ go.opentelemetry.io/otel/metric v1.37.0 h1:mvwbQS5m0tbmqML4NqK+e3aDiO02vsf/Wgbsd go.opentelemetry.io/otel/metric v1.37.0/go.mod h1:04wGrZurHYKOc+RKeye86GwKiTb9FKm1WHtO+4EVr2E= go.opentelemetry.io/otel/trace v1.37.0 h1:HLdcFNbRQBE2imdSEgm/kwqmQj1Or1l/7bW6mxVK7z4= go.opentelemetry.io/otel/trace v1.37.0/go.mod h1:TlgrlQ+PtQO5XFerSPUYG0JSgGyryXewPGyayAWSBS0= +go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ= +go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= +go.uber.org/zap v1.28.0 h1:IZzaP1Fv73/T/pBMLk4VutPl36uNC+OSUh3JLG3FIjo= +go.uber.org/zap v1.28.0/go.mod h1:rDLpOi171uODNm/mxFcuYWxDsqWSAVkFdX4XojSKg/Q= go.yaml.in/yaml/v2 v2.4.4 h1:tuyd0P+2Ont/d6e2rl3be67goVK4R6deVxCUX5vyPaQ= go.yaml.in/yaml/v2 v2.4.4/go.mod h1:gMZqIpDtDqOfM0uNfy0SkpRhvUryYH0Z6wdMYcacYXQ= go.yaml.in/yaml/v3 v3.0.4 h1:tfq32ie2Jv2UxXFdLJdh3jXuOzWiL1fo0bu/FbuKpbc= diff --git a/internal/server/downloadHandler.go b/internal/server/downloadHandler.go index c4fca00..abb6b5c 100644 --- a/internal/server/downloadHandler.go +++ b/internal/server/downloadHandler.go @@ -2,8 +2,8 @@ package server import ( "github.com/labstack/echo/v5" - "log" "music-server/internal/backend" + "music-server/internal/logging" "net/http" ) @@ -23,7 +23,7 @@ func NewDownloadHandler() *DownloadHandler { // @Success 200 {string} string // @Router /download [get] func (d *DownloadHandler) checkLatest(ctx *echo.Context) error { - log.Println("Checking latest version") + logging.GetLogger().Info("Checking latest version") latest := backend.CheckLatest() return ctx.JSON(http.StatusOK, latest) } @@ -37,7 +37,7 @@ func (d *DownloadHandler) checkLatest(ctx *echo.Context) error { // @Success 200 {array} string // @Router /download/list [get] func (d *DownloadHandler) listAssetsOfLatest(ctx *echo.Context) error { - log.Println("Listing assets") + logging.GetLogger().Info("Listing assets") assets := backend.ListAssetsOfLatest() return ctx.JSON(http.StatusOK, assets) } @@ -50,7 +50,7 @@ func (d *DownloadHandler) listAssetsOfLatest(ctx *echo.Context) error { // @Success 302 {string} string // @Router /download/windows [get] func (d *DownloadHandler) downloadLatestWindows(ctx *echo.Context) error { - log.Println("Downloading latest windows") + logging.GetLogger().Info("Downloading latest windows") asset := backend.DownloadLatestWindows() ctx.Response().Header().Set("Content-Type", "application/octet-stream") return ctx.Redirect(http.StatusFound, asset) @@ -64,7 +64,7 @@ func (d *DownloadHandler) downloadLatestWindows(ctx *echo.Context) error { // @Success 302 {string} string // @Router /download/linux [get] func (d *DownloadHandler) downloadLatestLinux(ctx *echo.Context) error { - log.Println("Downloading latest linux") + logging.GetLogger().Info("Downloading latest linux") asset := backend.DownloadLatestLinux() ctx.Response().Header().Set("Content-Type", "application/octet-stream") return ctx.Redirect(http.StatusFound, asset) diff --git a/internal/server/musicHandler.go b/internal/server/musicHandler.go index 2808507..f908e96 100644 --- a/internal/server/musicHandler.go +++ b/internal/server/musicHandler.go @@ -1,13 +1,14 @@ package server import ( - "log" "music-server/internal/backend" + "music-server/internal/logging" "net/http" "os" "strconv" "github.com/labstack/echo/v5" + "go.uber.org/zap" ) type MusicHandler struct { @@ -31,7 +32,7 @@ func NewMusicHandler() *MusicHandler { // @Router /music [get] func (m *MusicHandler) GetSong(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } song := ctx.QueryParam("song") @@ -58,7 +59,7 @@ func (m *MusicHandler) GetSong(ctx *echo.Context) error { // @Router /music/soundTest [get] func (m *MusicHandler) GetSoundCheckSong(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } songPath := backend.GetSoundCheckSong() @@ -80,7 +81,7 @@ func (m *MusicHandler) GetSoundCheckSong(ctx *echo.Context) error { // @Router /music/reset [get] func (m *MusicHandler) ResetMusic(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } backend.Reset() @@ -98,7 +99,7 @@ func (m *MusicHandler) ResetMusic(ctx *echo.Context) error { // @Router /music/rand [get] func (m *MusicHandler) GetRandomSong(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } songPath := backend.GetRandomSong() @@ -121,7 +122,7 @@ func (m *MusicHandler) GetRandomSong(ctx *echo.Context) error { // @Router /music/rand/low [get] func (m *MusicHandler) GetRandomSongLowChance(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } songPath := backend.GetRandomSongLowChance() @@ -144,7 +145,7 @@ func (m *MusicHandler) GetRandomSongLowChance(ctx *echo.Context) error { // @Router /music/rand/classic [get] func (m *MusicHandler) GetRandomSongClassic(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } songPath := backend.GetRandomSongClassic() @@ -193,7 +194,7 @@ func (m *MusicHandler) GetPlayedSongs(ctx *echo.Context) error { // @Router /music/next [get] func (m *MusicHandler) GetNextSong(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } songPath := backend.GetNextSong() @@ -216,7 +217,7 @@ func (m *MusicHandler) GetNextSong(ctx *echo.Context) error { // @Router /music/previous [get] func (m *MusicHandler) GetPreviousSong(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } songPath := backend.GetPreviousSong() @@ -239,7 +240,7 @@ func (m *MusicHandler) GetPreviousSong(ctx *echo.Context) error { // @Router /music/all/order [get] func (m *MusicHandler) GetAllGames(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } gameList := backend.GetAllGames() @@ -257,7 +258,7 @@ func (m *MusicHandler) GetAllGames(ctx *echo.Context) error { // @Router /music/all/random [get] func (m *MusicHandler) GetAllGamesRandom(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } gameList := backend.GetAllGamesRandom() @@ -277,14 +278,14 @@ func (m *MusicHandler) GetAllGamesRandom(ctx *echo.Context) error { // @Router /music/played [put] func (m *MusicHandler) PutPlayed(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } song, err := strconv.Atoi(ctx.QueryParam("song")) if err != nil { return ctx.JSON(http.StatusBadRequest, err.Error()) } - log.Println("song", song) + logging.GetLogger().Info("Marking song as played", zap.Int("song_id", song)) backend.SetPlayed(song) return ctx.NoContent(http.StatusOK) } @@ -299,7 +300,7 @@ func (m *MusicHandler) PutPlayed(ctx *echo.Context) error { // @Router /music/addQue [get] func (m *MusicHandler) AddLatestToQue(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } backend.AddLatestToQue() @@ -316,7 +317,7 @@ func (m *MusicHandler) AddLatestToQue(ctx *echo.Context) error { // @Router /music/addPlayed [get] func (m *MusicHandler) AddLatestPlayed(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Info("Syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } backend.AddLatestPlayed() diff --git a/internal/server/routes.go b/internal/server/routes.go index f5b0866..7f86fd8 100644 --- a/internal/server/routes.go +++ b/internal/server/routes.go @@ -11,6 +11,7 @@ import ( "github.com/labstack/echo/v5" "github.com/labstack/echo/v5/middleware" echoSwagger "github.com/swaggo/echo-swagger/v2" + "music-server/internal/logging" ) // @Title MusicServer API @@ -34,7 +35,7 @@ func (s *Server) RegisterRoutes() http.Handler { w.Header().Set("Content-Type", "application/json") http.ServeFile(w, r, "cmd/docs/swagger.json") }))) - e.Use(middleware.RequestLogger()) + e.Use(logging.RequestLogger()) e.Use(middleware.Recover()) e.Use(middleware.CORSWithConfig(middleware.CORSConfig{ diff --git a/internal/server/server.go b/internal/server/server.go index 7a3f696..83973d4 100644 --- a/internal/server/server.go +++ b/internal/server/server.go @@ -2,12 +2,15 @@ package server import ( "fmt" - "log" - "music-server/internal/db" - "net/http" "os" "strconv" "time" + + "music-server/internal/db" + "music-server/internal/logging" + "net/http" + + "go.uber.org/zap" ) type Server struct { @@ -22,24 +25,39 @@ var ( password = os.Getenv("DB_PASSWORD") musicPath = os.Getenv("MUSIC_PATH") charactersPath = os.Getenv("CHARACTERS_PATH") + logLevel = os.Getenv("LOG_LEVEL") + logJSON = os.Getenv("LOG_JSON") == "true" ) func NewServer() *http.Server { + // Initialize logger + if logLevel == "" { + logLevel = "info" + } + logging.Init(logLevel, logJSON) + + logger := logging.GetLogger() port, _ := strconv.Atoi(os.Getenv("PORT")) NewServer := &Server{ port: port, } - fmt.Printf("host: %s, dbPort: %v, username: %s, password: %s, dbName: %s\n", - host, dbPort, username, password, dbName) + logger.Info("Starting server", + zap.String("host", host), + zap.String("dbPort", dbPort), + zap.String("username", username), + zap.String("dbName", dbName), + ) - log.Printf("musicPath: %s\n", musicPath) - log.Printf("charactersPath: %s\n", charactersPath) + logger.Info("Paths", + zap.String("musicPath", musicPath), + zap.String("charactersPath", charactersPath), + ) //conf.SetupDb() if host == "" || dbPort == "" || username == "" || password == "" || dbName == "" || musicPath == "" || charactersPath == "" { - log.Fatal("Invalid settings") + logging.GetLogger().Fatal("Invalid settings - missing required environment variables") } db.Migrate_db(host, dbPort, username, password, dbName) diff --git a/internal/server/syncHandler.go b/internal/server/syncHandler.go index 2e8fec9..55e378c 100644 --- a/internal/server/syncHandler.go +++ b/internal/server/syncHandler.go @@ -1,8 +1,8 @@ package server import ( - "log" "music-server/internal/backend" + "music-server/internal/logging" "net/http" "github.com/labstack/echo/v5" @@ -25,11 +25,11 @@ func NewSyncHandler() *SyncHandler { // @Router /sync/progress [get] func (s *SyncHandler) SyncProgress(ctx *echo.Context) error { if backend.Syncing { - log.Println("Getting progress") + logging.GetLogger().Info("Getting sync progress") response := backend.SyncProgress() return ctx.JSON(http.StatusOK, response) } - log.Println("Getting result") + logging.GetLogger().Info("Getting sync result") response := backend.SyncResult() return ctx.JSON(http.StatusOK, response) } @@ -45,10 +45,10 @@ func (s *SyncHandler) SyncProgress(ctx *echo.Context) error { // @Router /sync [get] func (s *SyncHandler) SyncGamesNewOnlyChanges(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Warn("Syncing is already in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } - log.Println("Start syncing games") + logging.GetLogger().Info("Starting sync with only changes") go backend.SyncGamesNewOnlyChanges() return ctx.JSON(http.StatusOK, "Start syncing games") } @@ -64,10 +64,10 @@ func (s *SyncHandler) SyncGamesNewOnlyChanges(ctx *echo.Context) error { // @Router /sync/full [get] func (s *SyncHandler) SyncGamesNewFull(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Warn("Syncing is already in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } - log.Println("Start syncing games full") + logging.GetLogger().Info("Starting full sync") go backend.SyncGamesNewFull() return ctx.JSON(http.StatusOK, "Start syncing games full") } @@ -83,9 +83,10 @@ func (s *SyncHandler) SyncGamesNewFull(ctx *echo.Context) error { // @Router /sync/reset [get] func (s *SyncHandler) ResetGames(ctx *echo.Context) error { if backend.Syncing { - log.Println("Syncing is in progress") + logging.GetLogger().Warn("Cannot reset - syncing is in progress") return ctx.JSON(http.StatusLocked, "Syncing is in progress") } + logging.GetLogger().Info("Resetting games database") backend.ResetDB() return ctx.JSON(http.StatusOK, "Games and songs are deleted from the database") }