Add Zap logging framework with structured logging for Echo and Grafana

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

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=

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)

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()

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{

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",
+	logger.Info("Starting server",
-		host, dbPort, username, password, dbName)
+		zap.String("host", host),
+		zap.String("dbPort", dbPort),
+		zap.String("username", username),
+		zap.String("dbName", dbName),
+	)
 
-	log.Printf("musicPath: %s\n", musicPath)
+	logger.Info("Paths",
-	log.Printf("charactersPath: %s\n", charactersPath)
+		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)

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")
 }