Sansan/MusicServer
1
0
Fork 0
Code Issues 15 Pull Requests Actions Packages Projects Releases Wiki Activity

Replace all log.Println and fmt.Printf with Zap structured logging

Browse Source
This commit is contained in:
Sebastian
2026-05-21 23:24:55 +02:00
parent f0653489d6
commit 89c31c2856
7 changed files with 184 additions and 162 deletions
Download Patch File Download Diff File Expand all files Collapse all files
internal/backend/sync.go
+99 -85
View File
@@ -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))
}