From 89c31c2856f1592796ea5a4abd1309bf7e1f2f41 Mon Sep 17 00:00:00 2001 From: Sebastian Date: Thu, 21 May 2026 23:24:55 +0200 Subject: [PATCH] Replace all log.Println and fmt.Printf with Zap structured logging --- cmd/main.go | 17 +-- internal/backend/characters.go | 11 +- internal/backend/download.go | 39 ++++--- internal/backend/music.go | 27 +++-- internal/backend/sync.go | 184 ++++++++++++++++++--------------- internal/db/dbHelper.go | 64 ++++++------ internal/server/routes.go | 4 +- 7 files changed, 184 insertions(+), 162 deletions(-) diff --git a/cmd/main.go b/cmd/main.go index 13de699..8c47fdc 100644 --- a/cmd/main.go +++ b/cmd/main.go @@ -2,14 +2,15 @@ package main import ( "context" - "fmt" - "log" "music-server/internal/db" + "music-server/internal/logging" "music-server/internal/server" "net/http" "os/signal" "syscall" "time" + + "go.uber.org/zap" ) // @@ -41,15 +42,15 @@ func main() { // Run graceful shutdown in a separate goroutine go gracefulShutdown(server, done) - log.Printf("Open http://localhost%s in the browser", server.Addr) + logging.GetLogger().Info("Server starting", zap.String("address", server.Addr)) err := server.ListenAndServe() if err != nil && err != http.ErrServerClosed { - panic(fmt.Sprintf("http server error: %s", err)) + logging.GetLogger().Fatal("HTTP server error", zap.String("error", err.Error())) } // Wait for the graceful shutdown to complete <-done - log.Println("Graceful shutdown complete.") + logging.GetLogger().Info("Graceful shutdown complete") } func gracefulShutdown(apiServer *http.Server, done chan bool) { @@ -60,7 +61,7 @@ func gracefulShutdown(apiServer *http.Server, done chan bool) { // Listen for the interrupt signal. <-ctx.Done() - log.Println("shutting down gracefully, press Ctrl+C again to force") + logging.GetLogger().Info("Shutting down gracefully, press Ctrl+C again to force") db.CloseDb() // The context is used to inform the server it has 5 seconds to finish @@ -68,10 +69,10 @@ func gracefulShutdown(apiServer *http.Server, done chan bool) { ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) defer cancel() if err := apiServer.Shutdown(ctx); err != nil { - log.Printf("Server forced to shutdown with error: %v", err) + logging.GetLogger().Error("Server forced to shutdown with error", zap.String("error", err.Error())) } - log.Println("Server exiting") + logging.GetLogger().Info("Server exiting") // Notify the main goroutine that the shutdown is complete done <- true diff --git a/internal/backend/characters.go b/internal/backend/characters.go index 0ae5488..8ecdd77 100644 --- a/internal/backend/characters.go +++ b/internal/backend/characters.go @@ -1,21 +1,22 @@ package backend import ( - "fmt" - "log" "os" "strings" + + "music-server/internal/logging" + "go.uber.org/zap" ) func GetCharacterList() []string { charactersPath := os.Getenv("CHARACTERS_PATH") - fmt.Printf("dir: %s\n", charactersPath) + logging.GetLogger().Debug("Getting character list", zap.String("path", charactersPath)) if !strings.HasSuffix(charactersPath, "/") { charactersPath += "/" } files, err := os.ReadDir(charactersPath) if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to read characters directory", zap.String("path", charactersPath), zap.String("error", err.Error())) } var characters []string @@ -29,7 +30,7 @@ func GetCharacterList() []string { func GetCharacter(character string) string { charactersPath := os.Getenv("CHARACTERS_PATH") - fmt.Printf("dir: %s\n", charactersPath) + logging.GetLogger().Debug("Getting character", zap.String("character", character), zap.String("path", charactersPath)) if !strings.HasSuffix(charactersPath, "/") { charactersPath += "/" } diff --git a/internal/backend/download.go b/internal/backend/download.go index e51986d..df0d707 100644 --- a/internal/backend/download.go +++ b/internal/backend/download.go @@ -2,10 +2,11 @@ package backend import ( "encoding/json" - "fmt" - "log" "net/http" "strings" + + "music-server/internal/logging" + "go.uber.org/zap" ) type giteaResponse struct { @@ -23,37 +24,35 @@ type assetResponse struct { func CheckLatest() string { resp, err := http.Get("https://gitea.sanplex.xyz/api/v1/repos/sansan/MusicPlayer/releases/latest") if err != nil { - log.Fatalln(err) + logging.GetLogger().Fatal("Failed to check latest version", zap.String("error", err.Error())) } defer resp.Body.Close() //Create a variable of the same type as our model var cResp giteaResponse //Decode the data if err := json.NewDecoder(resp.Body).Decode(&cResp); err != nil { - fmt.Println(err) - log.Fatal("ooopsss! an error occurred, please try again") + logging.GetLogger().Fatal("Failed to decode response", zap.String("error", err.Error())) } - log.Printf("Id: %v, Name: %v", cResp.Id, cResp.Name) + logging.GetLogger().Debug("Checked latest version", zap.Int("id", cResp.Id), zap.String("name", cResp.Name)) return cResp.Name } func ListAssetsOfLatest() []string { resp, err := http.Get("https://gitea.sanplex.xyz/api/v1/repos/sansan/MusicPlayer/releases/latest") if err != nil { - log.Fatalln(err) + logging.GetLogger().Fatal("Failed to list assets", zap.String("error", err.Error())) } defer resp.Body.Close() //Create a variable of the same type as our model var cResp giteaResponse //Decode the data if err := json.NewDecoder(resp.Body).Decode(&cResp); err != nil { - fmt.Println(err) - log.Fatal("ooopsss! an error occurred, please try again") + logging.GetLogger().Fatal("Failed to decode response", zap.String("error", err.Error())) } - log.Printf("Id: %v, Name: %v", cResp.Id, cResp.Name) + logging.GetLogger().Debug("Listing assets", zap.Int("id", cResp.Id), zap.String("name", cResp.Name)) var assets []string for _, asset := range cResp.Assets { - log.Printf("Id: %v, Name: %v, Asset: %v", cResp.Id, cResp.Name, asset.Name) + logging.GetLogger().Debug("Found asset", zap.Int("id", cResp.Id), zap.String("name", cResp.Name), zap.String("asset", asset.Name)) assets = append(assets, asset.Name) } return assets @@ -62,19 +61,18 @@ func ListAssetsOfLatest() []string { func DownloadLatestWindows() string { resp, err := http.Get("https://gitea.sanplex.xyz/api/v1/repos/sansan/MusicPlayer/releases/latest") if err != nil { - log.Fatalln(err) + logging.GetLogger().Fatal("Failed to download latest Windows version", zap.String("error", err.Error())) } defer resp.Body.Close() //Create a variable of the same type as our model var cResp giteaResponse //Decode the data if err := json.NewDecoder(resp.Body).Decode(&cResp); err != nil { - fmt.Println(err) - log.Fatal("ooopsss! an error occurred, please try again") + logging.GetLogger().Fatal("Failed to decode response", zap.String("error", err.Error())) } - log.Printf("Id: %v, Name: %v", cResp.Id, cResp.Name) + logging.GetLogger().Debug("Downloading Windows version", zap.Int("id", cResp.Id), zap.String("name", cResp.Name)) for _, asset := range cResp.Assets { - log.Printf("Id: %v, Name: %v, Asset: %v", cResp.Id, cResp.Name, asset.Name) + logging.GetLogger().Debug("Checking asset", zap.Int("id", cResp.Id), zap.String("name", cResp.Name), zap.String("asset", asset.Name)) if strings.HasSuffix(asset.Name, ".exe") { return asset.DownloadUrl } @@ -85,19 +83,18 @@ func DownloadLatestWindows() string { func DownloadLatestLinux() string { resp, err := http.Get("https://gitea.sanplex.xyz/api/v1/repos/sansan/MusicPlayer/releases/latest") if err != nil { - log.Fatalln(err) + logging.GetLogger().Fatal("Failed to download latest Linux version", zap.String("error", err.Error())) } defer resp.Body.Close() //Create a variable of the same type as our model var cResp giteaResponse //Decode the data if err := json.NewDecoder(resp.Body).Decode(&cResp); err != nil { - fmt.Println(err) - log.Fatal("ooopsss! an error occurred, please try again") + logging.GetLogger().Fatal("Failed to decode response", zap.String("error", err.Error())) } - log.Printf("Id: %v, Name: %v", cResp.Id, cResp.Name) + logging.GetLogger().Debug("Downloading Linux version", zap.Int("id", cResp.Id), zap.String("name", cResp.Name)) for _, asset := range cResp.Assets { - log.Printf("Id: %v, Name: %v, Asset: %v", cResp.Id, cResp.Name, asset.Name) + logging.GetLogger().Debug("Checking asset", zap.Int("id", cResp.Id), zap.String("name", cResp.Name), zap.String("asset", asset.Name)) if strings.HasSuffix(asset.Name, ".x86_64") { return asset.DownloadUrl } diff --git a/internal/backend/music.go b/internal/backend/music.go index c950e65..b298975 100644 --- a/internal/backend/music.go +++ b/internal/backend/music.go @@ -1,13 +1,15 @@ package backend import ( - "log" "math/rand" "music-server/internal/db" "music-server/internal/db/repository" + "music-server/internal/logging" "os" "strconv" "strings" + + "go.uber.org/zap" ) type SongInfo struct { @@ -46,7 +48,7 @@ func getAllGames() []repository.Game { func GetSoundCheckSong() string { files, err := os.ReadDir("songs") if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to read songs directory", zap.String("error", err.Error())) } fileInfo := files[rand.Intn(len(files))] return "songs/" + fileInfo.Name() @@ -140,7 +142,10 @@ func GetRandomSongClassic() string { if err != nil { repo.RemoveBrokenSong(db.Ctx, song.Path) - log.Printf("Song not found, song '%s' deleted from game '%s' FileName: %s\n", song.SongName, gameData.GameName, *song.FileName) + logging.GetLogger().Warn("Song not found, removed from database", + zap.String("song", song.SongName), + zap.String("game", gameData.GameName), + zap.String("filename", *song.FileName)) continue } @@ -149,13 +154,16 @@ func GetRandomSongClassic() string { if err != nil || (song.FileName != nil && gameData.Path+*song.FileName != song.Path) { //File not found repo.RemoveBrokenSong(db.Ctx, song.Path) - log.Printf("Song not found, song '%s' deleted from game '%s' FileName: %s\n", song.SongName, gameData.GameName, *song.FileName) + logging.GetLogger().Warn("Song not found, removed from database", + zap.String("song", song.SongName), + zap.String("game", gameData.GameName), + zap.String("filename", *song.FileName)) } else { songFound = true } err = openFile.Close() if err != nil { - log.Println(err) + logging.GetLogger().Error("Failed to close file", zap.String("error", err.Error())) } } lastFetchedNew = song @@ -267,21 +275,24 @@ func getSongFromList(games []repository.Game) repository.Song { continue } song = songs[rand.Intn(len(songs))] - log.Println("song = ", song) + logging.GetLogger().Debug("Selected song", zap.String("song", song.SongName), zap.String("path", song.Path)) //Check if file exists and open openFile, err := os.Open(song.Path) if err != nil || (song.FileName != nil && game.Path+*song.FileName != song.Path) || (song.FileName != nil && strings.HasSuffix(*song.FileName, ".wav")) { //File not found repo.RemoveBrokenSong(db.Ctx, song.Path) - log.Printf("Song not found, song '%s' deleted from game '%s' FileName: %v\n", song.SongName, game.GameName, song.FileName) + logging.GetLogger().Warn("Song not found, removed from database", + zap.String("song", song.SongName), + zap.String("game", game.GameName), + zap.Any("filename", song.FileName)) } else { songFound = true } err = openFile.Close() if err != nil { - log.Println(err) + logging.GetLogger().Error("Failed to close file", zap.String("path", song.Path), zap.String("error", err.Error())) } } return song diff --git a/internal/backend/sync.go b/internal/backend/sync.go index 6b05e27..1a10ea2 100644 --- a/internal/backend/sync.go +++ b/internal/backend/sync.go @@ -7,9 +7,9 @@ import ( "fmt" "io" "io/fs" - "log" "music-server/internal/db" "music-server/internal/db/repository" + "music-server/internal/logging" "os" "sort" "strconv" @@ -21,6 +21,7 @@ import ( "github.com/MShekow/directory-checksum/directory_checksum" "github.com/spf13/afero" + "go.uber.org/zap" ) var Syncing = false @@ -86,9 +87,11 @@ func SyncProgress() ProgressResponse { currentTime := time.Now() timeSpent = currentTime.Sub(start) out := time.Time{}.Add(timeSpent) - fmt.Printf("\nTime spent: %v\n", timeSpent) - fmt.Printf("Time spent: %v\n", out.Format("15:04:05.00000")) - log.Printf("Progress: %v/%v %v%%\n", int(foldersSynced), int(numberOfFoldersToSync), progress) + logging.GetLogger().Debug("Sync progress", + zap.Int("progress_percent", progress), + zap.Int("folders_synced", int(foldersSynced)), + zap.Int("total_folders", int(numberOfFoldersToSync)), + zap.String("time_spent", out.Format("15:04:05.00000"))) return ProgressResponse{ Progress: fmt.Sprintf("%v", progress), TimeSpent: out.Format("15:04:05"), @@ -96,42 +99,36 @@ func SyncProgress() ProgressResponse { } func SyncResult() SyncResponse { - fmt.Printf("\nGames Before: %d\n", len(gamesBeforeSync)) - fmt.Printf("Games After: %d\n", len(gamesAfterSync)) + logging.GetLogger().Info("Sync completed", + zap.Int("games_before", len(gamesBeforeSync)), + zap.Int("games_after", len(gamesAfterSync))) - fmt.Printf("\nGames added: \n") - for _, game := range gamesAdded { - fmt.Printf("%s\n", game) + if len(gamesAdded) > 0 { + logging.GetLogger().Debug("Games added", zap.Strings("games", gamesAdded)) } - fmt.Printf("\nGames readded: \n") - for _, game := range gamesReAdded { - fmt.Printf("%s\n", game) + if len(gamesReAdded) > 0 { + logging.GetLogger().Debug("Games readded", zap.Strings("games", gamesReAdded)) } - fmt.Printf("\nGames with changed title: \n") - for key, value := range gamesChangedTitle { - fmt.Printf("The game: %s changed title to: %s\n", key, value) + if len(gamesChangedTitle) > 0 { + logging.GetLogger().Debug("Games with changed title", zap.Any("changes", gamesChangedTitle)) } - fmt.Printf("\nGames with changed content: \n") - for _, game := range gamesChangedContent { - fmt.Printf("%s\n", game) + if len(gamesChangedContent) > 0 { + logging.GetLogger().Debug("Games with changed content", zap.Strings("games", gamesChangedContent)) } - fmt.Printf("\n\n") var gamesRemovedTemp []string for _, beforeGame := range gamesBeforeSync { var found = false for _, afterGame := range gamesAfterSync { if beforeGame.GameName == afterGame.GameName { found = true - //fmt.Printf("Game: %s, Found: %v break\n", beforeGame.GameName, found) break } } if !found { - //fmt.Printf("Game: %s, Found: %v\n", beforeGame.GameName, found) gamesRemovedTemp = append(gamesRemovedTemp, beforeGame.GameName) } } @@ -141,7 +138,6 @@ func SyncResult() SyncResponse { for key := range gamesChangedTitle { if game == key { found = true - //fmt.Printf("Game: %s, Found: %v break2\n", game, found) break } } @@ -150,19 +146,16 @@ func SyncResult() SyncResponse { } } - fmt.Printf("\nGames removed: \n") - for _, game := range gamesRemoved { - fmt.Printf("%s\n", game) + if len(gamesRemoved) > 0 { + logging.GetLogger().Debug("Games removed", zap.Strings("games", gamesRemoved)) } - fmt.Printf("\nErrors catched: \n") - for _, error := range catchedErrors { - fmt.Printf("%s\n", error) + if len(catchedErrors) > 0 { + logging.GetLogger().Error("Errors caught during sync", zap.Strings("errors", catchedErrors)) } out := time.Time{}.Add(totalTime) - fmt.Printf("\nTotal time: %v\n", totalTime) - fmt.Printf("Total time: %v\n", out.Format("15:04:05.00000")) + logging.GetLogger().Info("Sync completed", zap.Duration("total_time", totalTime)) return SyncResponse{ GamesAdded: gamesAdded, @@ -199,7 +192,7 @@ func syncGamesNew(full bool) { initRepo() start = time.Now() foldersToSkip := []string{".sync", "dist", "old", "characters"} - fmt.Println(foldersToSkip) + logging.GetLogger().Debug("Folders to skip during sync", zap.Strings("folders", foldersToSkip)) var err error gamesAdded = nil @@ -212,7 +205,7 @@ func syncGamesNew(full bool) { gamesBeforeSync, err = repo.FindAllGames(db.Ctx) handleError("FindAllGames Before", err, "") - fmt.Printf("Games Before: %d\n", len(gamesBeforeSync)) + logging.GetLogger().Info("Starting sync", zap.Int("games_before", len(gamesBeforeSync))) allGames, err = repo.GetAllGamesIncludingDeleted(db.Ctx) handleError("GetAllGamesIncludingDeleted", err, "") @@ -221,7 +214,7 @@ func syncGamesNew(full bool) { directories, err := os.ReadDir(musicPath) if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to read music directory", zap.String("path", musicPath), zap.String("error", err.Error())) } pool, _ := ants.NewPool(50, ants.WithPreAlloc(true)) @@ -245,8 +238,7 @@ func syncGamesNew(full bool) { finished := time.Now() totalTime = finished.Sub(start) out := time.Time{}.Add(totalTime) - fmt.Printf("\nTotal time: %v\n", totalTime) - fmt.Printf("Total time: %v\n", out.Format("15:04:05.00000")) + logging.GetLogger().Info("Sync completed", zap.Duration("total_time", totalTime), zap.String("formatted_time", out.Format("15:04:05.00000"))) Syncing = false } @@ -276,18 +268,18 @@ func checkBrokenSongNew(song repository.Song) { if err != nil { //File not found brokenSongs = append(brokenSongs, song.Path) - fmt.Printf("song broken: %v\n", song.Path) + logging.GetLogger().Warn("Broken song found", zap.String("path", song.Path)) } else { err = openFile.Close() if err != nil { - log.Println(err) + logging.GetLogger().Error("Failed to close file", zap.String("path", song.Path), zap.String("error", err.Error())) } } } func syncGameNew(file os.DirEntry, foldersToSkip []string, baseDir string, full bool) { if file.IsDir() && !contains(foldersToSkip, file.Name()) { - fmt.Printf("Syncing: %s\n", file.Name()) + logging.GetLogger().Debug("Syncing game", zap.String("game", file.Name())) gameDir := baseDir + file.Name() + "/" dirHash := getHashForDir(gameDir) @@ -323,16 +315,16 @@ func syncGameNew(file os.DirEntry, foldersToSkip []string, baseDir string, full } entries, err := os.ReadDir(gameDir) if err != nil { - log.Println(err) + logging.GetLogger().Error("Failed to read game directory", zap.String("path", gameDir), zap.String("error", err.Error())) } switch status { case NewGame: if id != -1 { - for _, entry := range entries { - fileInfo, err := entry.Info() - if err != nil { - log.Println(err) - } + for _, entry := range entries { + fileInfo, err := entry.Info() + if err != nil { + logging.GetLogger().Error("Failed to get file info", zap.String("error", err.Error())) + } id = getIdFromFileNew(fileInfo) if id != -1 { break @@ -340,35 +332,48 @@ func syncGameNew(file os.DirEntry, foldersToSkip []string, baseDir string, full } err = repo.InsertGameWithExistingId(db.Ctx, repository.InsertGameWithExistingIdParams{ID: id, GameName: file.Name(), Path: gameDir, Hash: dirHash}) handleError("InsertGameWithExistingId", err, "") + if err != nil { + logging.GetLogger().Debug("Game already exists, removing old ID file", + zap.Int32("id", id), + zap.String("game_dir", gameDir)) + fileName := gameDir + "/." + strconv.Itoa(int(id)) + ".id" + logging.GetLogger().Debug("Removing ID file", zap.String("filename", fileName)) + + err := os.Remove(fileName) if err != nil { - fmt.Printf("id = %v\n", id) - fileName := gameDir + "/." + strconv.Itoa(int(id)) + ".id" - fmt.Printf("fileName = %v\n", fileName) - - err := os.Remove(fileName) - if err != nil { - fmt.Printf("%s\n", err) - } - - newDirHash := getHashForDir(gameDir) - - id = insertGameNew(file.Name(), gameDir, newDirHash) + logging.GetLogger().Error("Failed to remove ID file", zap.String("filename", fileName), zap.String("error", err.Error())) } + + newDirHash := getHashForDir(gameDir) + + id = insertGameNew(file.Name(), gameDir, newDirHash) + } } else { id = insertGameNew(file.Name(), gameDir, dirHash) } - //fmt.Printf("\n\nID: %d | GameName: %s | GameHash: %s | Status: %s\n", id, file.Name(), dirHash, status) + logging.GetLogger().Debug("New game detected", + zap.Int32("id", id), + zap.String("game", file.Name()), + zap.String("hash", dirHash), + zap.String("status", status.String())) gamesAdded = append(gamesAdded, file.Name()) newCheckSongs(entries, gameDir, id) case GameChanged: - //fmt.Printf("\n\nID: %d | GameName: %s | GameHash: %s | Status: %s\n", id, file.Name(), dirHash, status) + logging.GetLogger().Debug("Game changed", + zap.Int32("id", id), + zap.String("game", file.Name()), + zap.String("hash", dirHash), + zap.String("status", status.String())) err = repo.UpdateGameHash(db.Ctx, repository.UpdateGameHashParams{Hash: dirHash, ID: id}) handleError("UpdateGameHash", err, "") gamesChangedContent = append(gamesChangedContent, file.Name()) newCheckSongs(entries, gameDir, id) case TitleChanged: - //fmt.Printf("\n\nID: %d | GameName: %s | GameHash: %s | Status: %s\n", id, file.Name(), dirHash, status) - //println("TitleChanged") + logging.GetLogger().Debug("Game title changed", + zap.Int32("id", id), + zap.String("game", file.Name()), + zap.String("hash", dirHash), + zap.String("status", status.String())) err = repo.UpdateGameName(db.Ctx, repository.UpdateGameNameParams{Name: file.Name(), Path: gameDir, ID: id}) handleError("UpdateGameName", err, "") newCheckSongs(entries, gameDir, id) @@ -377,12 +382,10 @@ func syncGameNew(file os.DirEntry, foldersToSkip []string, baseDir string, full } gamesChangedTitle[oldGame.GameName] = file.Name() case NotChanged: - //println("NotChanged") var found bool = false for _, beforeGame := range gamesBeforeSync { if dirHash == beforeGame.Hash { found = true - //fmt.Printf("Game %s | %s | %s | %s | %v\n", beforeGame.GameName, beforeGame.Hash, dirHash, status, beforeGame.Deleted) } } if !found { @@ -391,12 +394,19 @@ func syncGameNew(file os.DirEntry, foldersToSkip []string, baseDir string, full } } - fmt.Printf("\n\nID: %d | GameName: %s | GameHash: %s | Status: %s\n", id, file.Name(), dirHash, status) + logging.GetLogger().Debug("Game sync status", + zap.Int32("id", id), + zap.String("game", file.Name()), + zap.String("hash", dirHash), + zap.String("status", status.String())) err = repo.RemoveDeletionDate(db.Ctx, id) handleError("RemoveDeletionDate", err, "") } foldersSynced++ - log.Printf("Progress: %v/%v %v%%\n", int(foldersSynced), int(numberOfFoldersToSync), int((foldersSynced/numberOfFoldersToSync)*100)) + logging.GetLogger().Debug("Sync progress", + zap.Int("folders_synced", int(foldersSynced)), + zap.Int("total_folders", int(numberOfFoldersToSync)), + zap.Int("percent", int((foldersSynced/numberOfFoldersToSync)*100))) } func insertGameNew(name string, path string, hash string) int32 { @@ -404,9 +414,9 @@ func insertGameNew(name string, path string, hash string) int32 { id, err := repo.InsertGame(db.Ctx, repository.InsertGameParams{GameName: name, Path: path, Hash: hash}) handleError("InsertGame", err, "") if err != nil { - fmt.Printf("Handle id busy\n") + logging.GetLogger().Warn("ID collision detected, resetting sequence") if strings.HasPrefix(err.Error(), duplicateError.Error()) { - fmt.Printf("Handeling this id\n") + logging.GetLogger().Debug("Resetting game ID sequence") _, err = repo.ResetGameIdSeq(db.Ctx) handleError("ResetGameIdSeq", err, "") id = insertGameNew(name, path, hash) @@ -441,7 +451,8 @@ func newCheckSongs(entries []os.DirEntry, gameDir string, id int32) int32 { func newCheckSong(entry os.DirEntry, gameDir string, id int32) bool { fileInfo, err := entry.Info() if err != nil { - log.Println(err) + logging.GetLogger().Error("Failed to get file info", zap.String("filename", entry.Name()), zap.String("error", err.Error())) + return false } if isSong(fileInfo) { @@ -454,15 +465,17 @@ func newCheckSong(entry os.DirEntry, gameDir string, id int32) bool { songName, _ := strings.CutSuffix(fileName, ".mp3") song, err := repo.GetSongWithHash(db.Ctx, songHash) - handleError("GetSongWithHash", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) + handleError("GetSongWithHash", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s", id, path, entry.Name(), songHash)) if err == nil { if song.SongName == songName && song.Path == path { return false } } - fmt.Printf("Song Changed\n") - - fmt.Printf("Path: %s | SongHash: %s\n", path, songHash) + logging.GetLogger().Debug("Song changed", + zap.Int32("game_id", id), + zap.String("path", path), + zap.String("song_name", songName), + zap.String("song_hash", songHash)) count, err := repo.CheckSongWithHash(db.Ctx, songHash) handleError("CheckSongWithHash", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) @@ -471,25 +484,25 @@ func newCheckSong(entry os.DirEntry, gameDir string, id int32) bool { handleError("CheckSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) if count2 > 0 { err = repo.AddHashToSong(db.Ctx, repository.AddHashToSongParams{Hash: songHash, Path: path}) - handleError("AddHashToSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) - count, err = repo.CheckSongWithHash(db.Ctx, songHash) - handleError("CheckSongWithHash 2", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) + handleError("AddHashToSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s", id, path, entry.Name(), songHash)) + count, err = repo.CheckSongWithHash(db.Ctx, songHash) + handleError("CheckSongWithHash 2", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s", id, path, entry.Name(), songHash)) } } //count, _ := repo.CheckSong(ctx, path) if count > 0 { err = repo.UpdateSong(db.Ctx, repository.UpdateSongParams{SongName: songName, FileName: &fileName, Path: path, Hash: songHash}) - handleError("UpdateSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) + handleError("UpdateSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s", id, path, entry.Name(), songHash)) } else { count2, err := repo.CheckSong(db.Ctx, path) - handleError("CheckSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) + handleError("CheckSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s", id, path, entry.Name(), songHash)) if count2 > 0 { err = repo.AddHashToSong(db.Ctx, repository.AddHashToSongParams{Hash: songHash, Path: path}) - handleError("AddHashToSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) + handleError("AddHashToSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s", id, path, entry.Name(), songHash)) } else { err = repo.AddSong(db.Ctx, repository.AddSongParams{GameID: id, SongName: songName, Path: path, FileName: &fileName, Hash: songHash}) - handleError("AddSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s\n", id, path, entry.Name(), songHash)) + handleError("AddSong", err, fmt.Sprintf("GameID: %d | Path: %s | SongName: %s | SongHash: %s", id, path, entry.Name(), songHash)) } } @@ -504,12 +517,14 @@ func handleError(funcName string, err error, msg string) { var compareError = errors.New("no rows in result set") if err != nil { if compareError.Error() != err.Error() { - fmt.Printf("%s Error: %s\n", funcName, err) + logging.GetLogger().Error("Database error", + zap.String("function", funcName), + zap.String("error", err.Error())) if msg != "" { - fmt.Printf("%s\n", msg) - catchedErrors = append(catchedErrors, fmt.Sprintf("Func: %s\nError message: %s\nDebug message: %s\n", funcName, err, msg)) + logging.GetLogger().Debug("Error context", zap.String("message", msg)) + catchedErrors = append(catchedErrors, fmt.Sprintf("Func: %s\nError message: %s\nDebug message: %s", funcName, err, msg)) } else { - catchedErrors = append(catchedErrors, fmt.Sprintf("Func: %s\nError message: %s\n", funcName, err)) + catchedErrors = append(catchedErrors, fmt.Sprintf("Func: %s\nError message: %s", funcName, err)) } } } @@ -519,7 +534,6 @@ func getHashForDir(gameDir string) string { directory, _ := directory_checksum.ScanDirectory(gameDir, afero.NewOsFs()) hash, _ := directory.ComputeDirectoryChecksums() - //fmt.Printf("Hash: |%s|\n", hash) return hash } @@ -527,13 +541,13 @@ func getHashForFile(path string) string { hasher := md5.New() readFile, err := os.Open(path) if err != nil { - panic(err) + logging.GetLogger().Fatal("Failed to open file for hashing", zap.String("path", path), zap.String("error", err.Error())) } defer readFile.Close() hasher.Reset() _, err = io.Copy(hasher, readFile) if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to hash file", zap.String("path", path), zap.String("error", err.Error())) } return hex.EncodeToString(hasher.Sum(nil)) } diff --git a/internal/db/dbHelper.go b/internal/db/dbHelper.go index dd653df..3f33450 100644 --- a/internal/db/dbHelper.go +++ b/internal/db/dbHelper.go @@ -5,11 +5,11 @@ import ( "database/sql" "embed" "fmt" - "log" - "os" "strconv" "time" + "music-server/internal/logging" + "github.com/golang-migrate/migrate/v4" "github.com/golang-migrate/migrate/v4/database/postgres" _ "github.com/golang-migrate/migrate/v4/database/postgres" @@ -17,6 +17,7 @@ import ( "github.com/golang-migrate/migrate/v4/source/iofs" "github.com/jackc/pgx/v5/pgxpool" _ "github.com/lib/pq" + "go.uber.org/zap" ) var Dbpool *pgxpool.Pool @@ -31,49 +32,46 @@ func InitDB(host string, port string, user string, password string, dbname strin "password=%s dbname=%s sslmode=disable", host, port, user, password, dbname) - fmt.Println(psqlInfo) + logging.GetLogger().Debug("Database connection info", zap.String("host", host), zap.String("port", port), zap.String("dbname", dbname)) var err error Dbpool, err = pgxpool.New(Ctx, psqlInfo) if err != nil { - _, _ = fmt.Fprintf(os.Stderr, "Unable to connect to database: %v\n", err) - os.Exit(1) + logging.GetLogger().Fatal("Unable to connect to database", zap.String("error", err.Error())) } var success string err = Dbpool.QueryRow(Ctx, "select 'Successfully connected!'").Scan(&success) if err != nil { - _, _ = fmt.Fprintf(os.Stderr, "QueryRow failed: %v\n", err) - os.Exit(1) + logging.GetLogger().Fatal("Database query failed", zap.String("error", err.Error())) } - fmt.Println(success) + logging.GetLogger().Info("Database connected", zap.String("status", success)) } func CloseDb() { - fmt.Println("Closing connection to database") + logging.GetLogger().Info("Closing database connection") Dbpool.Close() } func Testf() { rows, dbErr := Dbpool.Query(Ctx, "select game_name from game") if dbErr != nil { - _, _ = fmt.Fprintf(os.Stderr, "QueryRow failed: %v\n", dbErr) - os.Exit(1) + logging.GetLogger().Fatal("Query failed", zap.String("error", dbErr.Error())) } for rows.Next() { var gameName string dbErr = rows.Scan(&gameName) if dbErr != nil { - _, _ = fmt.Fprintf(os.Stderr, "QueryRow failed: %v\n", dbErr) + logging.GetLogger().Error("Row scan failed", zap.String("error", dbErr.Error())) } - _, _ = fmt.Fprintf(os.Stderr, "%v\n", gameName) + logging.GetLogger().Debug("Game found", zap.String("name", gameName)) } } func ResetGameIdSeq() { _, err := Dbpool.Query(Ctx, "SELECT setval('game_id_seq', (SELECT MAX(id) FROM game)+1);") if err != nil { - _, _ = fmt.Fprintf(os.Stderr, "Exec failed: %v\n", err) + logging.GetLogger().Error("Failed to reset game ID sequence", zap.String("error", err.Error())) } } @@ -83,85 +81,85 @@ func createDb(host string, port string, user string, password string, dbname str defer db.Close() if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to connect for database creation", zap.String("error", err.Error())) } _, err = db.Exec("create database " + dbname) if err != nil { //handle the error - log.Fatal(err) + logging.GetLogger().Fatal("Failed to create database", zap.String("error", err.Error())) } - log.Println("Finished creating database") + logging.GetLogger().Info("Database created", zap.String("dbname", dbname)) } func Migrate_db(host string, port string, user string, password string, dbname string) { migrationInfo := fmt.Sprintf("postgres://%s:%s@%s:%s/%s?sslmode=disable", user, password, host, port, dbname) - fmt.Println("Migration Info: ", migrationInfo) + logging.GetLogger().Debug("Migration info", zap.String("url", migrationInfo)) db, err := sql.Open("postgres", migrationInfo) if err != nil { - log.Println(err) + logging.GetLogger().Error("Failed to open database for migration", zap.String("error", err.Error())) } _, err = db.Query("select * from game") if err != nil { - log.Println(err) + logging.GetLogger().Warn("Game table not found, creating database", zap.String("error", err.Error())) createDb(host, port, user, password, dbname) db, err = sql.Open("postgres", migrationInfo) if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to reconnect after database creation", zap.String("error", err.Error())) } } driver, err := postgres.WithInstance(db, &postgres.Config{}) if err != nil { - log.Println(err) + logging.GetLogger().Error("Failed to create migration driver", zap.String("error", err.Error())) } files, err := iofs.New(MigrationsFs, "migrations") if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to create migration files", zap.String("error", err.Error())) } m, err := migrate.NewWithInstance("iofs", files, "postgres", driver) if err != nil { - log.Fatal(err) + logging.GetLogger().Fatal("Failed to create migrator", zap.String("error", err.Error())) } /*m, err := migrate.NewWithDatabaseInstance( "file://./db/migrations/", "postgres", driver) if err != nil { - log.Println(err) + logging.GetLogger().Error("Migration setup error", zap.String("error", err.Error())) }*/ version, _, err := m.Version() if err != nil { - log.Println("Migration version err: ", err) + logging.GetLogger().Error("Failed to get migration version", zap.String("error", err.Error())) } - fmt.Println("Migration version before: ", version) + logging.GetLogger().Info("Migration version before", zap.Uint("version", version)) //err = m.Force(1) //err = m.Up() // or m.Steps(2) if you want to explicitly set the number of migrations to run //if err != nil { - // log.Println("Force err: ", err) + // logging.GetLogger().Error("Force migration error", zap.String("error", err.Error())) //} err = m.Migrate(2) //err = m.Up() // or m.Steps(2) if you want to explicitly set the number of migrations to run if err != nil { - log.Println("Migration err: ", err) + logging.GetLogger().Error("Migration error", zap.String("error", err.Error())) } versionAfter, _, err := m.Version() if err != nil { - log.Println("Migration version err: ", err) + logging.GetLogger().Error("Failed to get migration version after", zap.String("error", err.Error())) } - fmt.Println("Migration version after: ", versionAfter) + logging.GetLogger().Info("Migration version after", zap.Uint("version", versionAfter)) - fmt.Println("Migration done") + logging.GetLogger().Info("Migration completed") db.Close() } @@ -180,7 +178,7 @@ func Health() map[string]string { if err != nil { stats["status"] = "down" stats["error"] = fmt.Sprintf("db down: %v", err) - log.Fatalf("db down: %v", err) // Log the error and terminate the program + logging.GetLogger().Fatal("Database health check failed", zap.String("error", err.Error())) return stats } diff --git a/internal/server/routes.go b/internal/server/routes.go index 7f86fd8..4092a67 100644 --- a/internal/server/routes.go +++ b/internal/server/routes.go @@ -1,7 +1,6 @@ package server import ( - "fmt" "music-server/cmd/web" "net/http" "sort" @@ -12,6 +11,7 @@ import ( "github.com/labstack/echo/v5/middleware" echoSwagger "github.com/swaggo/echo-swagger/v2" "music-server/internal/logging" + "go.uber.org/zap" ) // @Title MusicServer API @@ -105,7 +105,7 @@ func (s *Server) RegisterRoutes() http.Handler { }) for _, r := range routes { if (r.Method == "GET" || r.Method == "POST" || r.Method == "PUT" || r.Method == "DELETE") && !strings.Contains(r.Name, "github") { - fmt.Printf(" %s\t\t%s\n", r.Method, r.Path) + logging.GetLogger().Debug("Registered route", zap.String("method", r.Method), zap.String("path", r.Path)) } } return e