From 84d69a4f41fb881b798f21a3a5951e293e337026 Mon Sep 17 00:00:00 2001 From: Deluan Date: Wed, 8 Jan 2020 20:45:07 -0500 Subject: [PATCH] Replaced Beego logging --- api/album_lists.go | 14 +-- api/api_test.go | 89 +++++++-------- api/browsing.go | 32 +++--- api/media_annotation.go | 43 ++++---- api/media_retrieval.go | 8 +- api/media_retrieval_test.go | 3 +- api/middlewares.go | 8 +- api/playlists.go | 26 ++--- api/searching.go | 22 ++-- api/stream.go | 25 +++-- api/stream_test.go | 3 +- api/validation_test.go | 3 +- app.go | 17 ++- engine/browser.go | 37 +++---- engine/playlists.go | 16 +-- engine/ratings.go | 20 ++-- engine/scrobbler.go | 21 ++-- engine/scrobbler_test.go | 34 +++--- engine/search.go | 25 ++--- engine/stream.go | 15 +-- go.mod | 1 - go.sum | 2 - log/log.go | 167 +++++++++++++++++++++++++++++ log/log_test.go | 104 ++++++++++++++++++ persistence/checksum_repository.go | 6 +- scanner/importer.go | 66 ++++++------ scanner/itunes_scanner.go | 22 ++-- tests/init_tests.go | 12 +-- 28 files changed, 559 insertions(+), 282 deletions(-) create mode 100644 log/log.go create mode 100644 log/log_test.go diff --git a/api/album_lists.go b/api/album_lists.go index 85927d8c..9ddcedaa 100644 --- a/api/album_lists.go +++ b/api/album_lists.go @@ -4,9 +4,9 @@ import ( "errors" "net/http" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/utils" ) @@ -42,7 +42,7 @@ func (c *AlbumListController) getAlbumList(r *http.Request) (engine.Entries, err listFunc, found := c.listFunctions[typ] if !found { - beego.Error("albumList type", typ, "not implemented!") + log.Error(r, "albumList type not implemented", "type", typ) return nil, errors.New("Not implemented!") } @@ -51,7 +51,7 @@ func (c *AlbumListController) getAlbumList(r *http.Request) (engine.Entries, err albums, err := listFunc(offset, size) if err != nil { - beego.Error("Error retrieving albums:", err) + log.Error(r, "Error retrieving albums", "error", err) return nil, errors.New("Internal Error") } @@ -83,7 +83,7 @@ func (c *AlbumListController) GetAlbumList2(w http.ResponseWriter, r *http.Reque func (c *AlbumListController) GetStarred(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { albums, mediaFiles, err := c.listGen.GetAllStarred() if err != nil { - beego.Error("Error retrieving starred media:", err) + log.Error(r, "Error retrieving starred media", "error", err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -97,7 +97,7 @@ func (c *AlbumListController) GetStarred(w http.ResponseWriter, r *http.Request) func (c *AlbumListController) GetStarred2(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { albums, mediaFiles, err := c.listGen.GetAllStarred() if err != nil { - beego.Error("Error retrieving starred media:", err) + log.Error(r, "Error retrieving starred media", "error", err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -111,7 +111,7 @@ func (c *AlbumListController) GetStarred2(w http.ResponseWriter, r *http.Request func (c *AlbumListController) GetNowPlaying(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { npInfos, err := c.listGen.GetNowPlaying() if err != nil { - beego.Error("Error retrieving now playing list:", err) + log.Error(r, "Error retrieving now playing list", "error", err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -133,7 +133,7 @@ func (c *AlbumListController) GetRandomSongs(w http.ResponseWriter, r *http.Requ songs, err := c.listGen.GetRandomSongs(size) if err != nil { - beego.Error("Error retrieving random songs:", err) + log.Error(r, "Error retrieving random songs", "error", err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } diff --git a/api/api_test.go b/api/api_test.go index b2ce3300..8cdedba0 100644 --- a/api/api_test.go +++ b/api/api_test.go @@ -1,46 +1,47 @@ package api_test -import ( - "fmt" - "net/http" - "net/http/httptest" - "strings" - - "github.com/astaxie/beego" -) - -const ( - testUser = "deluan" - testPassword = "wordpass" - testClient = "test" - testVersion = "1.0.0" -) - -func AddParams(endpoint string, params ...string) string { - url := fmt.Sprintf("%s?u=%s&p=%s&c=%s&v=%s&f=json", endpoint, testUser, testPassword, testClient, testVersion) - if len(params) > 0 { - url = url + "&" + strings.Join(params, "&") - } - return url -} - -func Get(url string, testCase string) (*http.Request, *httptest.ResponseRecorder) { - r, _ := http.NewRequest("GET", url, nil) - w := httptest.NewRecorder() - beego.BeeApp.Handlers.ServeHTTP(w, r) - - beego.Debug("testing", testCase, fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%s", r.URL, w.Code, w.Body.String())) - - return r, w -} - -func GetWithHeader(url string, header, value, testCase string) (*http.Request, *httptest.ResponseRecorder) { - r, _ := http.NewRequest("GET", url, nil) - r.Header.Add(header, value) - w := httptest.NewRecorder() - beego.BeeApp.Handlers.ServeHTTP(w, r) - - beego.Debug("testing", testCase, fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%s", r.URL, w.Code, w.Body.String())) - - return r, w -} +// +//import ( +// "fmt" +// "net/http" +// "net/http/httptest" +// "strings" +// +// "github.com/astaxie/beego" +//) +// +//const ( +// testUser = "deluan" +// testPassword = "wordpass" +// testClient = "test" +// testVersion = "1.0.0" +//) +// +//func AddParams(endpoint string, params ...string) string { +// url := fmt.Sprintf("%s?u=%s&p=%s&c=%s&v=%s&f=json", endpoint, testUser, testPassword, testClient, testVersion) +// if len(params) > 0 { +// url = url + "&" + strings.Join(params, "&") +// } +// return url +//} +// +//func Get(url string, testCase string) (*http.Request, *httptest.ResponseRecorder) { +// r, _ := http.NewRequest("GET", url, nil) +// w := httptest.NewRecorder() +// beego.BeeApp.Handlers.ServeHTTP(w, r) +// +// log.Debug(r, "testing", testCase, fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%s", r.URL, w.Code, w.Body.String())) +// +// return r, w +//} +// +//func GetWithHeader(url string, header, value, testCase string) (*http.Request, *httptest.ResponseRecorder) { +// r, _ := http.NewRequest("GET", url, nil) +// r.Header.Add(header, value) +// w := httptest.NewRecorder() +// beego.BeeApp.Handlers.ServeHTTP(w, r) +// +// log.Debug(r, "testing", testCase, fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%s", r.URL, w.Code, w.Body.String())) +// +// return r, w +//} diff --git a/api/browsing.go b/api/browsing.go index 6a934c33..37d8e535 100644 --- a/api/browsing.go +++ b/api/browsing.go @@ -5,11 +5,11 @@ import ( "net/http" "time" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/conf" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/utils" ) @@ -33,10 +33,10 @@ func (c *BrowsingController) GetMusicFolders(w http.ResponseWriter, r *http.Requ return response, nil } -func (c *BrowsingController) getArtistIndex(ifModifiedSince time.Time) (*responses.Indexes, error) { +func (c *BrowsingController) getArtistIndex(r *http.Request, ifModifiedSince time.Time) (*responses.Indexes, error) { indexes, lastModified, err := c.browser.Indexes(ifModifiedSince) if err != nil { - beego.Error("Error retrieving Indexes:", err) + log.Error(r, "Error retrieving Indexes", "error", err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -61,7 +61,7 @@ func (c *BrowsingController) getArtistIndex(ifModifiedSince time.Time) (*respons func (c *BrowsingController) GetIndexes(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { ifModifiedSince := ParamTime(r, "ifModifiedSince", time.Time{}) - res, err := c.getArtistIndex(ifModifiedSince) + res, err := c.getArtistIndex(r, ifModifiedSince) if err != nil { return nil, err } @@ -72,7 +72,7 @@ func (c *BrowsingController) GetIndexes(w http.ResponseWriter, r *http.Request) } func (c *BrowsingController) GetArtists(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { - res, err := c.getArtistIndex(time.Time{}) + res, err := c.getArtistIndex(r, time.Time{}) if err != nil { return nil, err } @@ -84,13 +84,13 @@ func (c *BrowsingController) GetArtists(w http.ResponseWriter, r *http.Request) func (c *BrowsingController) GetMusicDirectory(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { id := ParamString(r, "id") - dir, err := c.browser.Directory(id) + dir, err := c.browser.Directory(r.Context(), id) switch { case err == domain.ErrNotFound: - beego.Error("Requested Id", id, "not found:", err) + log.Error(r, "Requested Id not found ", "id", id) return nil, NewError(responses.ErrorDataNotFound, "Directory not found") case err != nil: - beego.Error(err) + log.Error(err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -101,13 +101,13 @@ func (c *BrowsingController) GetMusicDirectory(w http.ResponseWriter, r *http.Re func (c *BrowsingController) GetArtist(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { id := ParamString(r, "id") - dir, err := c.browser.Artist(id) + dir, err := c.browser.Artist(r.Context(), id) switch { case err == domain.ErrNotFound: - beego.Error("Requested ArtistId", id, "not found:", err) + log.Error(r, "Requested ArtistId not found ", "id", id) return nil, NewError(responses.ErrorDataNotFound, "Artist not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -118,13 +118,13 @@ func (c *BrowsingController) GetArtist(w http.ResponseWriter, r *http.Request) ( func (c *BrowsingController) GetAlbum(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { id := ParamString(r, "id") - dir, err := c.browser.Album(id) + dir, err := c.browser.Album(r.Context(), id) switch { case err == domain.ErrNotFound: - beego.Error("Requested AlbumId", id, "not found:", err) + log.Error(r, "Requested Id not found ", "id", id) return nil, NewError(responses.ErrorDataNotFound, "Album not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -138,10 +138,10 @@ func (c *BrowsingController) GetSong(w http.ResponseWriter, r *http.Request) (*r song, err := c.browser.GetSong(id) switch { case err == domain.ErrNotFound: - beego.Error("Requested Id", id, "not found:", err) + log.Error(r, "Requested Id not found ", "id", id) return nil, NewError(responses.ErrorDataNotFound, "Song not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } diff --git a/api/media_annotation.go b/api/media_annotation.go index 39dfa0b4..71222dfb 100644 --- a/api/media_annotation.go +++ b/api/media_annotation.go @@ -1,14 +1,13 @@ package api import ( - "fmt" "net/http" "time" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" ) type MediaAnnotationController struct { @@ -33,15 +32,15 @@ func (c *MediaAnnotationController) SetRating(w http.ResponseWriter, r *http.Req return nil, err } - beego.Debug("Setting rating", rating, "for id", id) - err = c.ratings.SetRating(id, rating) + log.Debug(r, "Setting rating", "rating", rating, "id", id) + err = c.ratings.SetRating(r.Context(), id, rating) switch { case err == domain.ErrNotFound: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorDataNotFound, "Id not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -50,7 +49,7 @@ func (c *MediaAnnotationController) SetRating(w http.ResponseWriter, r *http.Req func (c *MediaAnnotationController) getIds(r *http.Request) ([]string, error) { ids := ParamStrings(r, "id") - albumIds := ParamStrings(r,"albumId") + albumIds := ParamStrings(r, "albumId") if len(ids) == 0 && len(albumIds) == 0 { return nil, NewError(responses.ErrorMissingParameter, "Required id parameter is missing") @@ -64,14 +63,14 @@ func (c *MediaAnnotationController) Star(w http.ResponseWriter, r *http.Request) if err != nil { return nil, err } - beego.Debug("Starring ids:", ids) - err = c.ratings.SetStar(true, ids...) + log.Debug(r, "Starring items", "ids", ids) + err = c.ratings.SetStar(r.Context(), true, ids...) switch { case err == domain.ErrNotFound: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorDataNotFound, "Id not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -83,14 +82,14 @@ func (c *MediaAnnotationController) Unstar(w http.ResponseWriter, r *http.Reques if err != nil { return nil, err } - beego.Debug("Unstarring ids:", ids) - err = c.ratings.SetStar(false, ids...) + log.Debug(r, "Unstarring items", "ids", ids) + err = c.ratings.SetStar(r.Context(), false, ids...) switch { case err == domain.ErrNotFound: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorDataNotFound, "Directory not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -111,7 +110,7 @@ func (c *MediaAnnotationController) Scrobble(w http.ResponseWriter, r *http.Requ playerName := ParamString(r, "c") username := ParamString(r, "u") - beego.Debug("Scrobbling ids:", ids, "times:", times, "submission:", submission) + log.Debug(r, "Scrobbling tracks", "ids", ids, "times", times, "submission", submission) for i, id := range ids { var t time.Time if len(times) > 0 { @@ -120,19 +119,19 @@ func (c *MediaAnnotationController) Scrobble(w http.ResponseWriter, r *http.Requ t = time.Now() } if submission { - mf, err := c.scrobbler.Register(playerId, id, t) + mf, err := c.scrobbler.Register(r.Context(), playerId, id, t) if err != nil { - beego.Error("Error scrobbling", id, "-", err) + log.Error(r, "Error scrobbling track", "id", id, err) continue } - beego.Info(fmt.Sprintf(`Scrobbled (%s) "%s" at %v`, id, mf.Title, t)) + log.Info(r, "Scrobbled", "id", id, "title", mf.Title, "timestamp", t) } else { - mf, err := c.scrobbler.NowPlaying(playerId, playerName, id, username) + mf, err := c.scrobbler.NowPlaying(r.Context(), playerId, playerName, id, username) if err != nil { - beego.Error("Error setting", id, "as current song:", err) + log.Error(r, "Error setting current song", "id", id, err) continue } - beego.Info(fmt.Sprintf(`Now Playing (%s) "%s" at %v`, id, mf.Title, t)) + log.Info(r, "Now Playing", "id", id, "title", mf.Title, "timestamp", t) } } return NewEmpty(), nil diff --git a/api/media_retrieval.go b/api/media_retrieval.go index 857d2931..459d1d7c 100644 --- a/api/media_retrieval.go +++ b/api/media_retrieval.go @@ -5,10 +5,10 @@ import ( "net/http" "os" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" ) type MediaRetrievalController struct { @@ -23,7 +23,7 @@ func (c *MediaRetrievalController) GetAvatar(w http.ResponseWriter, r *http.Requ var f *os.File f, err := os.Open("static/itunes.png") if err != nil { - beego.Error(err, "Image not found") + log.Error(r, "Image not found", err) return nil, NewError(responses.ErrorDataNotFound, "Avatar image not found") } defer f.Close() @@ -43,10 +43,10 @@ func (c *MediaRetrievalController) GetCoverArt(w http.ResponseWriter, r *http.Re switch { case err == domain.ErrNotFound: - beego.Error(err, "Id:", id) + log.Error(r, err.Error(), "id", id) return nil, NewError(responses.ErrorDataNotFound, "Cover not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } diff --git a/api/media_retrieval_test.go b/api/media_retrieval_test.go index 3790aa37..d1e376c7 100644 --- a/api/media_retrieval_test.go +++ b/api/media_retrieval_test.go @@ -1,4 +1,5 @@ package api_test + // //import ( // "fmt" @@ -20,7 +21,7 @@ package api_test // r, _ := http.NewRequest("GET", url, nil) // w := httptest.NewRecorder() // beego.BeeApp.Handlers.ServeHTTP(w, r) -// beego.Debug("testing TestGetCoverArt", fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%#v", r.URL, w.Code, w.HeaderMap)) +// log.Debug(r, "testing TestGetCoverArt", fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%#v", r.URL, w.Code, w.HeaderMap)) // return r, w //} // diff --git a/api/middlewares.go b/api/middlewares.go index 311c5b40..0b898de2 100644 --- a/api/middlewares.go +++ b/api/middlewares.go @@ -8,9 +8,9 @@ import ( "net/http" "strings" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/conf" + "github.com/cloudsonic/sonic-server/log" ) func checkRequiredParameters(next http.Handler) http.Handler { @@ -20,14 +20,14 @@ func checkRequiredParameters(next http.Handler) http.Handler { for _, p := range requiredParameters { if ParamString(r, p) == "" { msg := fmt.Sprintf(`Missing required parameter "%s"`, p) - beego.Warn(msg) + log.Warn(r, msg) SendError(w, r, NewError(responses.ErrorMissingParameter, msg)) return } } if ParamString(r, "p") == "" && (ParamString(r, "s") == "" || ParamString(r, "t") == "") { - beego.Warn("Missing authentication information") + log.Warn(r, "Missing authentication information") } ctx := r.Context() ctx = context.WithValue(ctx, "user", ParamString(r, "u")) @@ -63,7 +63,7 @@ func authenticate(next http.Handler) http.Handler { } if user != conf.Sonic.User || !valid { - beego.Warn(fmt.Sprintf(`Invalid login for user "%s"`, user)) + log.Warn(r, "Invalid login", "user", user) SendError(w, r, NewError(responses.ErrorAuthenticationFail)) return } diff --git a/api/playlists.go b/api/playlists.go index f0d580e9..e8fd7d32 100644 --- a/api/playlists.go +++ b/api/playlists.go @@ -4,10 +4,10 @@ import ( "fmt" "net/http" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" ) type PlaylistsController struct { @@ -21,7 +21,7 @@ func NewPlaylistsController(pls engine.Playlists) *PlaylistsController { func (c *PlaylistsController) GetPlaylists(w http.ResponseWriter, r *http.Request) (*responses.Subsonic, error) { allPls, err := c.pls.GetAll() if err != nil { - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal error") } playlists := make([]responses.Playlist, len(allPls)) @@ -47,10 +47,10 @@ func (c *PlaylistsController) GetPlaylist(w http.ResponseWriter, r *http.Request pinfo, err := c.pls.Get(id) switch { case err == domain.ErrNotFound: - beego.Error(err, "Id:", id) + log.Error(r, err.Error(), "id", id) return nil, NewError(responses.ErrorDataNotFound, "Directory not found") case err != nil: - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } @@ -68,9 +68,9 @@ func (c *PlaylistsController) CreatePlaylist(w http.ResponseWriter, r *http.Requ if err != nil { return nil, err } - err = c.pls.Create(name, songIds) + err = c.pls.Create(r.Context(), name, songIds) if err != nil { - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } return NewEmpty(), nil @@ -81,9 +81,9 @@ func (c *PlaylistsController) DeletePlaylist(w http.ResponseWriter, r *http.Requ if err != nil { return nil, err } - err = c.pls.Delete(id) + err = c.pls.Delete(r.Context(), id) if err != nil { - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } return NewEmpty(), nil @@ -103,16 +103,16 @@ func (c *PlaylistsController) UpdatePlaylist(w http.ResponseWriter, r *http.Requ pname = &s } - beego.Info(fmt.Sprintf("Updating playlist with id '%s'", playlistId)) + log.Info(r, "Updating playlist", "id", playlistId) if pname != nil { - beego.Debug(fmt.Sprintf("-- New Name: '%s'", *pname)) + log.Debug(r, fmt.Sprintf("-- New Name: '%s'", *pname)) } - beego.Debug(fmt.Sprintf("-- Adding: '%v'", songsToAdd)) - beego.Debug(fmt.Sprintf("-- Removing: '%v'", songIndexesToRemove)) + log.Debug(r, fmt.Sprintf("-- Adding: '%v'", songsToAdd)) + log.Debug(r, fmt.Sprintf("-- Removing: '%v'", songIndexesToRemove)) err = c.pls.Update(playlistId, pname, songsToAdd, songIndexesToRemove) if err != nil { - beego.Error(err) + log.Error(r, err) return nil, NewError(responses.ErrorGeneric, "Internal Error") } return NewEmpty(), nil diff --git a/api/searching.go b/api/searching.go index 5fda972c..6397860c 100644 --- a/api/searching.go +++ b/api/searching.go @@ -4,9 +4,9 @@ import ( "fmt" "net/http" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" ) type SearchingController struct { @@ -39,21 +39,21 @@ func (c *SearchingController) getParams(r *http.Request) error { return nil } -func (c *SearchingController) searchAll() (engine.Entries, engine.Entries, engine.Entries) { - as, err := c.search.SearchArtist(c.query, c.artistOffset, c.artistCount) +func (c *SearchingController) searchAll(r *http.Request) (engine.Entries, engine.Entries, engine.Entries) { + as, err := c.search.SearchArtist(r.Context(), c.query, c.artistOffset, c.artistCount) if err != nil { - beego.Error("Error searching for Artists:", err) + log.Error(r, "Error searching for Artists", err) } - als, err := c.search.SearchAlbum(c.query, c.albumOffset, c.albumCount) + als, err := c.search.SearchAlbum(r.Context(), c.query, c.albumOffset, c.albumCount) if err != nil { - beego.Error("Error searching for Albums:", err) + log.Error(r, "Error searching for Albums", err) } - mfs, err := c.search.SearchSong(c.query, c.songOffset, c.songCount) + mfs, err := c.search.SearchSong(r.Context(), c.query, c.songOffset, c.songCount) if err != nil { - beego.Error("Error searching for MediaFiles:", err) + log.Error(r, "Error searching for MediaFiles", err) } - beego.Debug(fmt.Sprintf("Searching for [%s] resulted in %d songs, %d albums and %d artists", c.query, len(mfs), len(als), len(as))) + log.Debug(r, fmt.Sprintf("Search resulted in %d songs, %d albums and %d artists", len(mfs), len(als), len(as)), "query", c.query) return mfs, als, as } @@ -62,7 +62,7 @@ func (c *SearchingController) Search2(w http.ResponseWriter, r *http.Request) (* if err != nil { return nil, err } - mfs, als, as := c.searchAll() + mfs, als, as := c.searchAll(r) response := NewEmpty() searchResult2 := &responses.SearchResult2{} @@ -81,7 +81,7 @@ func (c *SearchingController) Search3(w http.ResponseWriter, r *http.Request) (* if err != nil { return nil, err } - mfs, als, as := c.searchAll() + mfs, als, as := c.searchAll(r) response := NewEmpty() searchResult3 := &responses.SearchResult3{} diff --git a/api/stream.go b/api/stream.go index c66cdf0e..3c84a2b1 100644 --- a/api/stream.go +++ b/api/stream.go @@ -3,10 +3,10 @@ package api import ( "net/http" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/api/responses" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/utils" ) @@ -29,10 +29,10 @@ func (c *StreamController) Prepare(r *http.Request) (err error) { c.mf, err = c.repo.Get(c.id) switch { case err == domain.ErrNotFound: - beego.Error("MediaFile", c.id, "not found!") + log.Error(r, "Mediafile not found", "id", c.id) return NewError(responses.ErrorDataNotFound) case err != nil: - beego.Error("Error reading mediafile", c.id, "from the database", ":", err) + log.Error(r, "Error reading mediafile from DB", "id", c.id, err) return NewError(responses.ErrorGeneric, "Internal error") } return nil @@ -48,8 +48,7 @@ func (c *StreamController) Stream(w http.ResponseWriter, r *http.Request) (*resp maxBitRate := ParamInt(r, "maxBitRate", 0) maxBitRate = utils.MinInt(c.mf.BitRate, maxBitRate) - beego.Debug("Streaming file", c.id, ":", c.mf.Path) - beego.Debug("Bitrate", c.mf.BitRate, "MaxBitRate", maxBitRate) + log.Debug(r, "Streaming file", "id", c.id, "path", c.mf.Path, "bitrate", c.mf.BitRate, "maxBitRate", maxBitRate) // TODO Send proper estimated content-length //contentLength := c.mf.Size @@ -64,16 +63,16 @@ func (c *StreamController) Stream(w http.ResponseWriter, r *http.Request) (*resp h.Set("Pragma", "public") if r.Method == "HEAD" { - beego.Debug("Just a HEAD. Not streaming", c.mf.Path) + log.Debug(r, "Just a HEAD. Not streaming", "path", c.mf.Path) return nil, nil } - err = engine.Stream(c.mf.Path, c.mf.BitRate, maxBitRate, w) + err = engine.Stream(r.Context(), c.mf.Path, c.mf.BitRate, maxBitRate, w) if err != nil { - beego.Error("Error streaming file", c.id, ":", err) + log.Error(r, "Error streaming file", "id", c.id, err) } - beego.Debug("Finished streaming of", c.mf.Path) + log.Debug(r, "Finished streaming", "path", c.mf.Path) return nil, nil } @@ -82,14 +81,14 @@ func (c *StreamController) Download(w http.ResponseWriter, r *http.Request) (*re if err != nil { return nil, err } - beego.Debug("Sending file", c.mf.Path) + log.Debug(r, "Sending file", "path", c.mf.Path) - err = engine.Stream(c.mf.Path, 0, 0, w) + err = engine.Stream(r.Context(), c.mf.Path, 0, 0, w) if err != nil { - beego.Error("Error downloading file", c.mf.Path, ":", err.Error()) + log.Error(r, "Error downloading file", "path", c.mf.Path, err) } - beego.Debug("Finished sending", c.mf.Path) + log.Debug(r, "Finished sending", "path", c.mf.Path) return nil, nil } diff --git a/api/stream_test.go b/api/stream_test.go index 7d038db5..7811b2e6 100644 --- a/api/stream_test.go +++ b/api/stream_test.go @@ -1,4 +1,5 @@ package api_test + // //import ( // "fmt" @@ -20,7 +21,7 @@ package api_test // r, _ := http.NewRequest("GET", url, nil) // w := httptest.NewRecorder() // beego.BeeApp.Handlers.ServeHTTP(w, r) -// beego.Debug("testing TestStream", fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%#v", r.URL, w.Code, w.HeaderMap)) +// log.Debug(r, "testing TestStream", fmt.Sprintf("\nUrl: %s\nStatus Code: [%d]\n%#v", r.URL, w.Code, w.HeaderMap)) // return r, w //} // diff --git a/api/validation_test.go b/api/validation_test.go index fafe3be8..734f5c38 100644 --- a/api/validation_test.go +++ b/api/validation_test.go @@ -1,4 +1,5 @@ package api_test + // //import ( // "encoding/xml" @@ -92,7 +93,7 @@ package api_test // //func TestContext(t *testing.T) { // tests.Init(t, false) -// beego.Router("/rest/mocktest", &mockController{}) +// log.Router(r, "/rest/mocktest", &mockController{}) // // Convey("Subject: Context", t, func() { // _, w := GetWithHeader("/rest/mocktest?u=deluan&p=wordpass&c=testClient&v=1.0.0", "X-Request-Id", "123123", "TestContext") diff --git a/app.go b/app.go index 68c74049..c6cef350 100644 --- a/app.go +++ b/app.go @@ -8,20 +8,18 @@ import ( "time" "github.com/cloudsonic/sonic-server/conf" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/scanner" "github.com/go-chi/chi" "github.com/go-chi/chi/middleware" - "github.com/sirupsen/logrus" ) type App struct { router *chi.Mux - logger *logrus.Logger importer *scanner.Importer } func (a *App) Initialize() { - a.logger = logrus.New() initMimeTypes() a.initRoutes() a.initImporter() @@ -35,8 +33,8 @@ func (a *App) MountRouter(path string, subRouter http.Handler) { } func (a *App) Run(addr string) { - a.logger.Info("Listening on addr ", addr) - a.logger.Fatal(http.ListenAndServe(addr, a.router)) + log.Info("Started CloudSonic server", "address", addr) + log.Error(http.ListenAndServe(addr, a.router)) } func (a *App) initRoutes() { @@ -47,6 +45,7 @@ func (a *App) initRoutes() { r.Use(middleware.Recoverer) r.Use(middleware.Compress(5, "application/xml", "application/json")) r.Use(middleware.Heartbeat("/ping")) + r.Use(InjectLogger) r.Get("/", func(w http.ResponseWriter, r *http.Request) { http.Redirect(w, r, "/Jamstash", 302) @@ -89,3 +88,11 @@ func FileServer(r chi.Router, path string, root http.FileSystem) { fs.ServeHTTP(w, r) })) } + +func InjectLogger(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + ctx := r.Context() + ctx = log.NewContext(r.Context(), "requestId", ctx.Value(middleware.RequestIDKey)) + next.ServeHTTP(w, r.WithContext(ctx)) + }) +} diff --git a/engine/browser.go b/engine/browser.go index bd69de2b..ad8068df 100644 --- a/engine/browser.go +++ b/engine/browser.go @@ -1,21 +1,22 @@ package engine import ( + "context" "fmt" "strconv" "time" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/domain" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/utils" ) type Browser interface { MediaFolders() (domain.MediaFolders, error) Indexes(ifModifiedSince time.Time) (domain.ArtistIndexes, time.Time, error) - Directory(id string) (*DirectoryInfo, error) - Artist(id string) (*DirectoryInfo, error) - Album(id string) (*DirectoryInfo, error) + Directory(ctx context.Context, id string) (*DirectoryInfo, error) + Artist(ctx context.Context, id string) (*DirectoryInfo, error) + Album(ctx context.Context, id string) (*DirectoryInfo, error) GetSong(id string) (*Entry, error) } @@ -73,32 +74,32 @@ type DirectoryInfo struct { Genre string } -func (b *browser) Artist(id string) (*DirectoryInfo, error) { - beego.Debug("Found Artist with id", id) +func (b *browser) Artist(ctx context.Context, id string) (*DirectoryInfo, error) { a, albums, err := b.retrieveArtist(id) if err != nil { return nil, err } + log.Debug(ctx, "Found Artist", "id", id, "name", a.Name) return b.buildArtistDir(a, albums), nil } -func (b *browser) Album(id string) (*DirectoryInfo, error) { - beego.Debug("Found Album with id", id) +func (b *browser) Album(ctx context.Context, id string) (*DirectoryInfo, error) { al, tracks, err := b.retrieveAlbum(id) if err != nil { return nil, err } + log.Debug(ctx, "Found Album", "id", id, "name", al.Name) return b.buildAlbumDir(al, tracks), nil } -func (b *browser) Directory(id string) (*DirectoryInfo, error) { +func (b *browser) Directory(ctx context.Context, id string) (*DirectoryInfo, error) { switch { - case b.isArtist(id): - return b.Artist(id) - case b.isAlbum(id): - return b.Album(id) + case b.isArtist(ctx, id): + return b.Artist(ctx, id) + case b.isAlbum(ctx, id): + return b.Album(ctx, id) default: - beego.Debug("Id", id, "not found") + log.Debug(ctx, "Directory not found", "id", id) return nil, domain.ErrNotFound } } @@ -153,19 +154,19 @@ func (b *browser) buildAlbumDir(al *domain.Album, tracks domain.MediaFiles) *Dir return dir } -func (b *browser) isArtist(id string) bool { +func (b *browser) isArtist(ctx context.Context, id string) bool { found, err := b.artistRepo.Exists(id) if err != nil { - beego.Debug(fmt.Errorf("Error searching for Artist %s: %v", id, err)) + log.Debug(ctx, "Error searching for Artist", "id", id, err) return false } return found } -func (b *browser) isAlbum(id string) bool { +func (b *browser) isAlbum(ctx context.Context, id string) bool { found, err := b.albumRepo.Exists(id) if err != nil { - beego.Debug(fmt.Errorf("Error searching for Album %s: %v", id, err)) + log.Debug(ctx, "Error searching for Album", "id", id, err) return false } return found diff --git a/engine/playlists.go b/engine/playlists.go index d0564338..4cbbd07b 100644 --- a/engine/playlists.go +++ b/engine/playlists.go @@ -1,19 +1,19 @@ package engine import ( - "fmt" + "context" "sort" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/itunesbridge" + "github.com/cloudsonic/sonic-server/log" ) type Playlists interface { GetAll() (domain.Playlists, error) Get(id string) (*PlaylistInfo, error) - Create(name string, ids []string) error - Delete(playlistId string) error + Create(ctx context.Context, name string, ids []string) error + Delete(ctx context.Context, playlistId string) error Update(playlistId string, name *string, idsToAdd []string, idxToRemove []int) error } @@ -42,21 +42,21 @@ type PlaylistInfo struct { Comment string } -func (p *playlists) Create(name string, ids []string) error { +func (p *playlists) Create(ctx context.Context, name string, ids []string) error { pid, err := p.itunes.CreatePlaylist(name, ids) if err != nil { return err } - beego.Info(fmt.Sprintf("Created playlist '%s' with id '%s'", name, pid)) + log.Info(ctx, "Created playlist", "playlist", name, "id", pid) return nil } -func (p *playlists) Delete(playlistId string) error { +func (p *playlists) Delete(ctx context.Context, playlistId string) error { err := p.itunes.DeletePlaylist(playlistId) if err != nil { return err } - beego.Info(fmt.Sprintf("Deleted playlist with id '%s'", playlistId)) + log.Info(ctx, "Deleted playlist", "id", playlistId) return nil } diff --git a/engine/ratings.go b/engine/ratings.go index d544fbd4..76913ae0 100644 --- a/engine/ratings.go +++ b/engine/ratings.go @@ -1,15 +1,17 @@ package engine import ( - "github.com/astaxie/beego" + "context" + "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/itunesbridge" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/utils" ) type Ratings interface { - SetStar(star bool, ids ...string) error - SetRating(id string, rating int) error + SetStar(ctx context.Context, star bool, ids ...string) error + SetRating(ctx context.Context, id string, rating int) error } func NewRatings(itunes itunesbridge.ItunesControl, mr domain.MediaFileRepository, alr domain.AlbumRepository, ar domain.ArtistRepository) Ratings { @@ -23,14 +25,14 @@ type ratings struct { artistRepo domain.ArtistRepository } -func (r ratings) SetRating(id string, rating int) error { +func (r ratings) SetRating(ctx context.Context, id string, rating int) error { rating = utils.MinInt(rating, 5) * 20 isAlbum, _ := r.albumRepo.Exists(id) if isAlbum { mfs, _ := r.mfRepo.FindByAlbum(id) if len(mfs) > 0 { - beego.Debug("SetRating:", rating, "Album:", mfs[0].Album) + log.Debug(ctx, "Set Rating", "value", rating, "album", mfs[0].Album) if err := r.itunes.SetAlbumRating(mfs[0].Id, rating); err != nil { return err } @@ -43,7 +45,7 @@ func (r ratings) SetRating(id string, rating int) error { return err } if mf != nil { - beego.Debug("SetRating:", rating, "Song:", mf.Title) + log.Debug(ctx, "Set Rating", "value", rating, "song", mf.Title) if err := r.itunes.SetTrackRating(mf.Id, rating); err != nil { return err } @@ -52,13 +54,13 @@ func (r ratings) SetRating(id string, rating int) error { return domain.ErrNotFound } -func (r ratings) SetStar(star bool, ids ...string) error { +func (r ratings) SetStar(ctx context.Context, star bool, ids ...string) error { for _, id := range ids { isAlbum, _ := r.albumRepo.Exists(id) if isAlbum { mfs, _ := r.mfRepo.FindByAlbum(id) if len(mfs) > 0 { - beego.Debug("SetStar:", star, "Album:", mfs[0].Album) + log.Debug(ctx, "Set Star", "value", star, "album", mfs[0].Album) if err := r.itunes.SetAlbumLoved(mfs[0].Id, star); err != nil { return err } @@ -71,7 +73,7 @@ func (r ratings) SetStar(star bool, ids ...string) error { return err } if mf != nil { - beego.Debug("SetStar:", star, "Song:", mf.Title) + log.Debug(ctx, "Set Star", "value", star, "song", mf.Title) if err := r.itunes.SetTrackLoved(mf.Id, star); err != nil { return err } diff --git a/engine/scrobbler.go b/engine/scrobbler.go index 131a39e8..2f3f0dbd 100644 --- a/engine/scrobbler.go +++ b/engine/scrobbler.go @@ -1,13 +1,14 @@ package engine import ( + "context" "errors" "fmt" "time" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/itunesbridge" + "github.com/cloudsonic/sonic-server/log" ) const ( @@ -16,8 +17,8 @@ const ( ) type Scrobbler interface { - Register(playerId int, trackId string, playDate time.Time) (*domain.MediaFile, error) - NowPlaying(playerId int, playerName, trackId, username string) (*domain.MediaFile, error) + Register(ctx context.Context, playerId int, trackId string, playDate time.Time) (*domain.MediaFile, error) + NowPlaying(ctx context.Context, playerId int, playerName, trackId, username string) (*domain.MediaFile, error) } func NewScrobbler(itunes itunesbridge.ItunesControl, mr domain.MediaFileRepository, npr NowPlayingRepository) Scrobbler { @@ -30,7 +31,7 @@ type scrobbler struct { npRepo NowPlayingRepository } -func (s *scrobbler) detectSkipped(playerId int, trackId string) { +func (s *scrobbler) detectSkipped(ctx context.Context, playerId int, trackId string) { size, _ := s.npRepo.Count(playerId) switch size { case 0: @@ -53,22 +54,22 @@ func (s *scrobbler) detectSkipped(playerId int, trackId string) { } diff := np.Start.Sub(prev.Start) if diff < minSkipped || diff > maxSkipped { - beego.Debug(fmt.Sprintf("-- Playtime for track %s was %v. Not skipping.", prev.TrackId, diff)) + log.Debug(ctx, fmt.Sprintf("-- Playtime for track %s was %v. Not skipping.", prev.TrackId, diff)) prev = np continue } err = s.itunes.MarkAsSkipped(prev.TrackId, prev.Start.Add(1*time.Minute)) if err != nil { - beego.Warn("Error skipping track", prev.TrackId) + log.Warn(ctx, "Error skipping track", "id", prev.TrackId) } else { - beego.Debug("-- Skipped track", prev.TrackId) + log.Debug(ctx, "-- Skipped track "+prev.TrackId) } } } } -func (s *scrobbler) Register(playerId int, trackId string, playTime time.Time) (*domain.MediaFile, error) { - s.detectSkipped(playerId, trackId) +func (s *scrobbler) Register(ctx context.Context, playerId int, trackId string, playTime time.Time) (*domain.MediaFile, error) { + s.detectSkipped(ctx, playerId, trackId) mf, err := s.mfRepo.Get(trackId) if err != nil { @@ -85,7 +86,7 @@ func (s *scrobbler) Register(playerId int, trackId string, playTime time.Time) ( return mf, nil } -func (s *scrobbler) NowPlaying(playerId int, playerName, trackId, username string) (*domain.MediaFile, error) { +func (s *scrobbler) NowPlaying(ctx context.Context, playerId int, playerName, trackId, username string) (*domain.MediaFile, error) { mf, err := s.mfRepo.Get(trackId) if err != nil { return nil, err diff --git a/engine/scrobbler_test.go b/engine/scrobbler_test.go index 5c4e6bda..4c456e95 100644 --- a/engine/scrobbler_test.go +++ b/engine/scrobbler_test.go @@ -27,7 +27,7 @@ func TestScrobbler(t *testing.T) { Convey("When I scrobble an existing song", func() { now := time.Now() - mf, err := scrobbler.Register(1, "2", now) + mf, err := scrobbler.Register(nil, 1, "2", now) Convey("Then I get the scrobbled song back", func() { So(err, ShouldBeNil) @@ -42,7 +42,7 @@ func TestScrobbler(t *testing.T) { }) Convey("When the ID is not in the DB", func() { - _, err := scrobbler.Register(1, "3", time.Now()) + _, err := scrobbler.Register(nil, 1, "3", time.Now()) Convey("Then I receive an error", func() { So(err, ShouldNotBeNil) @@ -54,7 +54,7 @@ func TestScrobbler(t *testing.T) { }) Convey("When I inform the song that is now playing", func() { - mf, err := scrobbler.NowPlaying(1, "DSub", "2", "deluan") + mf, err := scrobbler.NowPlaying(nil, 1, "DSub", "2", "deluan") Convey("Then I get the song for that id back", func() { So(err, ShouldBeNil) @@ -100,11 +100,11 @@ func TestSkipping(t *testing.T) { npRepo.ClearAll() Convey("When I skip 2 songs", func() { npRepo.OverrideNow(aPointInTime) - scrobbler.NowPlaying(1, "DSub", "1", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "1", "deluan") npRepo.OverrideNow(aPointInTime.Add(2 * time.Second)) - scrobbler.NowPlaying(1, "DSub", "3", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "3", "deluan") npRepo.OverrideNow(aPointInTime.Add(3 * time.Second)) - scrobbler.NowPlaying(1, "DSub", "2", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "2", "deluan") Convey("Then the NowPlaying song should be the last one", func() { np, err := npRepo.GetAll() So(err, ShouldBeNil) @@ -114,12 +114,12 @@ func TestSkipping(t *testing.T) { }) Convey("When I play one song", func() { npRepo.OverrideNow(aPointInTime) - scrobbler.NowPlaying(1, "DSub", "1", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "1", "deluan") Convey("And I skip it before 20 seconds", func() { npRepo.OverrideNow(aPointInTime.Add(7 * time.Second)) - scrobbler.NowPlaying(1, "DSub", "2", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "2", "deluan") Convey("Then the first song should be marked as skipped", func() { - mf, err := scrobbler.Register(1, "2", aPointInTime.Add(3*time.Minute)) + mf, err := scrobbler.Register(nil, 1, "2", aPointInTime.Add(3*time.Minute)) So(mf.Id, ShouldEqual, "2") So(itCtrl.skipped, ShouldContainKey, "1") So(err, ShouldBeNil) @@ -127,9 +127,9 @@ func TestSkipping(t *testing.T) { }) Convey("And I skip it before 3 seconds", func() { npRepo.OverrideNow(aPointInTime.Add(2 * time.Second)) - scrobbler.NowPlaying(1, "DSub", "2", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "2", "deluan") Convey("Then the first song should be marked as skipped", func() { - mf, err := scrobbler.Register(1, "2", aPointInTime.Add(3*time.Minute)) + mf, err := scrobbler.Register(nil, 1, "2", aPointInTime.Add(3*time.Minute)) So(mf.Id, ShouldEqual, "2") So(itCtrl.skipped, ShouldBeEmpty) So(err, ShouldBeNil) @@ -137,16 +137,16 @@ func TestSkipping(t *testing.T) { }) Convey("And I skip it after 20 seconds", func() { npRepo.OverrideNow(aPointInTime.Add(30 * time.Second)) - scrobbler.NowPlaying(1, "DSub", "2", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "2", "deluan") Convey("Then the first song should be marked as skipped", func() { - mf, err := scrobbler.Register(1, "2", aPointInTime.Add(3*time.Minute)) + mf, err := scrobbler.Register(nil, 1, "2", aPointInTime.Add(3*time.Minute)) So(mf.Id, ShouldEqual, "2") So(itCtrl.skipped, ShouldBeEmpty) So(err, ShouldBeNil) }) }) Convey("And I scrobble it before starting to play the other song", func() { - mf, err := scrobbler.Register(1, "1", time.Now()) + mf, err := scrobbler.Register(nil, 1, "1", time.Now()) Convey("Then the first song should NOT marked as skipped", func() { So(mf.Id, ShouldEqual, "1") So(itCtrl.skipped, ShouldBeEmpty) @@ -156,10 +156,10 @@ func TestSkipping(t *testing.T) { }) Convey("When the NowPlaying for the next song happens before the Scrobble", func() { npRepo.OverrideNow(aPointInTime) - scrobbler.NowPlaying(1, "DSub", "1", "deluan") + scrobbler.NowPlaying(nil, 1, "DSub", "1", "deluan") npRepo.OverrideNow(aPointInTime.Add(10 * time.Second)) - scrobbler.NowPlaying(1, "DSub", "2", "deluan") - scrobbler.Register(1, "1", aPointInTime.Add(10*time.Minute)) + scrobbler.NowPlaying(nil, 1, "DSub", "2", "deluan") + scrobbler.Register(nil, 1, "1", aPointInTime.Add(10*time.Minute)) Convey("Then the NowPlaying song should be the last one", func() { np, _ := npRepo.GetAll() So(np, ShouldHaveLength, 1) diff --git a/engine/search.go b/engine/search.go index b00a834a..25af58d3 100644 --- a/engine/search.go +++ b/engine/search.go @@ -1,10 +1,11 @@ package engine import ( + "context" "strings" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/domain" + "github.com/cloudsonic/sonic-server/log" "github.com/deluan/gomate" "github.com/kennygrant/sanitize" ) @@ -19,9 +20,9 @@ type Search interface { RemoveAlbum(ids ...string) error RemoveMediaFile(ids ...string) error - SearchArtist(q string, offset int, size int) (Entries, error) - SearchAlbum(q string, offset int, size int) (Entries, error) - SearchSong(q string, offset int, size int) (Entries, error) + SearchArtist(ctx context.Context, q string, offset int, size int) (Entries, error) + SearchAlbum(ctx context.Context, q string, offset int, size int) (Entries, error) + SearchSong(ctx context.Context, q string, offset int, size int) (Entries, error) } type search struct { @@ -84,7 +85,7 @@ func (s *search) RemoveMediaFile(ids ...string) error { return s.idxSong.Remove(ids...) } -func (s *search) SearchArtist(q string, offset int, size int) (Entries, error) { +func (s *search) SearchArtist(ctx context.Context, q string, offset int, size int) (Entries, error) { q = sanitize.Accents(strings.ToLower(strings.TrimSuffix(q, "*"))) min := offset max := min + size - 1 @@ -95,7 +96,7 @@ func (s *search) SearchArtist(q string, offset int, size int) (Entries, error) { res := make(Entries, 0, len(resp)) for _, id := range resp { a, err := s.artistRepo.Get(id) - if criticalError("Artist", id, err) { + if criticalError(ctx, "Artist", id, err) { return nil, err } if err == nil { @@ -105,7 +106,7 @@ func (s *search) SearchArtist(q string, offset int, size int) (Entries, error) { return res, nil } -func (s *search) SearchAlbum(q string, offset int, size int) (Entries, error) { +func (s *search) SearchAlbum(ctx context.Context, q string, offset int, size int) (Entries, error) { q = sanitize.Accents(strings.ToLower(strings.TrimSuffix(q, "*"))) min := offset max := min + size - 1 @@ -116,7 +117,7 @@ func (s *search) SearchAlbum(q string, offset int, size int) (Entries, error) { res := make(Entries, 0, len(resp)) for _, id := range resp { al, err := s.albumRepo.Get(id) - if criticalError("Album", id, err) { + if criticalError(ctx, "Album", id, err) { return nil, err } if err == nil { @@ -126,7 +127,7 @@ func (s *search) SearchAlbum(q string, offset int, size int) (Entries, error) { return res, nil } -func (s *search) SearchSong(q string, offset int, size int) (Entries, error) { +func (s *search) SearchSong(ctx context.Context, q string, offset int, size int) (Entries, error) { q = sanitize.Accents(strings.ToLower(strings.TrimSuffix(q, "*"))) min := offset max := min + size - 1 @@ -137,7 +138,7 @@ func (s *search) SearchSong(q string, offset int, size int) (Entries, error) { res := make(Entries, 0, len(resp)) for _, id := range resp { mf, err := s.mfileRepo.Get(id) - if criticalError("Song", id, err) { + if criticalError(ctx, "Song", id, err) { return nil, err } if err == nil { @@ -147,12 +148,12 @@ func (s *search) SearchSong(q string, offset int, size int) (Entries, error) { return res, nil } -func criticalError(kind, id string, err error) bool { +func criticalError(ctx context.Context, kind, id string, err error) bool { switch { case err != nil: return true case err == domain.ErrNotFound: - beego.Warn(kind, "Id", id, "not in the DB. Need a reindex?") + log.Warn(ctx, kind+"Id not in DB. Need a reindex?", "id", id) } return false } diff --git a/engine/stream.go b/engine/stream.go index 7330261b..4cfc31f4 100644 --- a/engine/stream.go +++ b/engine/stream.go @@ -1,41 +1,42 @@ package engine import ( + "context" "io" "os" "os/exec" "strconv" "strings" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/conf" + "github.com/cloudsonic/sonic-server/log" ) // TODO Encapsulate as a io.Reader -func Stream(path string, bitRate int, maxBitRate int, w io.Writer) error { +func Stream(ctx context.Context, path string, bitRate int, maxBitRate int, w io.Writer) error { var f io.Reader var err error enabled := !conf.Sonic.DisableDownsampling if enabled && maxBitRate > 0 && bitRate > maxBitRate { - f, err = downsample(path, maxBitRate) + f, err = downsample(ctx, path, maxBitRate) } else { f, err = os.Open(path) } if err != nil { - beego.Error("Error opening file", path, ":", err) + log.Error(ctx, "Error opening file", "path", path, err) return err } if _, err = io.Copy(w, f); err != nil { - beego.Error("Error copying file", path, ":", err) + log.Error(ctx, "Error copying file", "path", path, err) return err } return err } -func downsample(path string, maxBitRate int) (f io.Reader, err error) { +func downsample(ctx context.Context, path string, maxBitRate int) (f io.Reader, err error) { cmdLine, args := createDownsamplingCommand(path, maxBitRate) - beego.Debug("Executing cmd:", cmdLine, args) + log.Debug(ctx, "Executing command", "cmdLine", cmdLine, "args", args) cmd := exec.Command(cmdLine, args...) cmd.Stderr = os.Stderr if f, err = cmd.StdoutPipe(); err != nil { diff --git a/go.mod b/go.mod index ddd5bff7..487051f0 100644 --- a/go.mod +++ b/go.mod @@ -4,7 +4,6 @@ go 1.13 require ( github.com/BurntSushi/toml v0.3.0 // indirect - github.com/astaxie/beego v1.8.0 github.com/cupcake/rdb v0.0.0-20161107195141-43ba34106c76 // indirect github.com/deluan/gomate v0.0.0-20160327212459-3eb40643dd6f github.com/dhowden/itl v0.0.0-20170329215456-9fbe21093131 diff --git a/go.sum b/go.sum index 1d48f386..2cf43824 100644 --- a/go.sum +++ b/go.sum @@ -1,7 +1,5 @@ github.com/BurntSushi/toml v0.3.0 h1:e1/Ivsx3Z0FVTV0NSOv/aVgbUWyQuzj7DDnFblkRvsY= github.com/BurntSushi/toml v0.3.0/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU= -github.com/astaxie/beego v1.8.0 h1:Rc5qRXMy5fpxq3FEi+4nmykYIMtANthRJ8hcoY+1VWM= -github.com/astaxie/beego v1.8.0/go.mod h1:0R4++1tUqERR0WYFWdfkcrsyoVBCG4DgpDGokT3yb+U= github.com/cupcake/rdb v0.0.0-20161107195141-43ba34106c76 h1:Lgdd/Qp96Qj8jqLpq2cI1I1X7BJnu06efS+XkhRoLUQ= github.com/cupcake/rdb v0.0.0-20161107195141-43ba34106c76/go.mod h1:vYwsqCOLxGiisLwp9rITslkFNpZD5rz43tf41QFkTWY= github.com/davecgh/go-spew v1.1.0 h1:ZDRjVQ15GmhC3fiQ8ni8+OwkZQO4DARzQgrnXU1Liz8= diff --git a/log/log.go b/log/log.go new file mode 100644 index 00000000..36225c82 --- /dev/null +++ b/log/log.go @@ -0,0 +1,167 @@ +package log + +import ( + "context" + "errors" + "net/http" + "os" + "strings" + + "github.com/sirupsen/logrus" +) + +type Level uint8 + +type LevelFunc = func(ctx interface{}, msg interface{}, keyValuePairs ...interface{}) + +const ( + LevelCritical = Level(logrus.FatalLevel) + LevelError = Level(logrus.ErrorLevel) + LevelWarn = Level(logrus.WarnLevel) + LevelInfo = Level(logrus.InfoLevel) + LevelDebug = Level(logrus.DebugLevel) +) + +var ( + currentLevel Level + defaultLogger = logrus.New() +) + +// SetLevel sets the global log level used by the simple logger. +func SetLevel(l Level) { + currentLevel = l + logrus.SetLevel(logrus.Level(l)) +} + +func NewContext(ctx context.Context, keyValuePairs ...interface{}) context.Context { + if ctx == nil { + ctx = context.Background() + } + + logger := addFields(createNewLogger(), keyValuePairs) + ctx = context.WithValue(ctx, "logger", logger) + + return ctx +} + +func SetDefaultLogger(l *logrus.Logger) { + defaultLogger = l +} + +func CurrentLevel() Level { + return currentLevel +} + +func Error(args ...interface{}) { + if currentLevel < LevelError { + return + } + logger, msg := parseArgs(args) + logger.Error(msg) +} + +func Warn(args ...interface{}) { + if currentLevel < LevelWarn { + return + } + logger, msg := parseArgs(args) + logger.Warn(msg) +} + +func Info(args ...interface{}) { + if currentLevel < LevelInfo { + return + } + logger, msg := parseArgs(args) + logger.Info(msg) +} + +func Debug(args ...interface{}) { + if currentLevel < LevelDebug { + return + } + logger, msg := parseArgs(args) + logger.Debug(msg) +} + +func parseArgs(args []interface{}) (*logrus.Entry, string) { + var l *logrus.Entry + var err error + if args[0] == nil { + l = createNewLogger() + args = args[1:] + } else { + l, err = extractLogger(args[0]) + if err != nil { + l = createNewLogger() + } else { + args = args[1:] + } + } + if len(args) > 1 { + kvPairs := args[1:] + l = addFields(l, kvPairs) + } + switch msg := args[0].(type) { + case error: + return l, msg.Error() + case string: + return l, msg + } + return l, "" +} + +func addFields(logger *logrus.Entry, keyValuePairs []interface{}) *logrus.Entry { + for i := 0; i < len(keyValuePairs); i += 2 { + switch name := keyValuePairs[i].(type) { + case error: + logger = logger.WithField("error", name.Error()) + case string: + value := keyValuePairs[i+1] + logger = logger.WithField(name, value) + } + } + return logger +} + +func extractLogger(ctx interface{}) (*logrus.Entry, error) { + switch ctx := ctx.(type) { + case *logrus.Entry: + return ctx, nil + case context.Context: + logger := ctx.Value("logger") + if logger != nil { + return logger.(*logrus.Entry), nil + } + case *http.Request: + return extractLogger(ctx.Context()) + } + return nil, errors.New("no logger found") +} + +func createNewLogger() *logrus.Entry { + //l.Formatter = &logrus.TextFormatter{ForceColors: true, DisableTimestamp: false, FullTimestamp: true} + defaultLogger.Level = logrus.Level(currentLevel) + logger := logrus.NewEntry(defaultLogger) + logger.Level = logrus.Level(currentLevel) + return logger +} + +func init() { + //logrus.SetFormatter(&logrus.TextFormatter{ForceColors: true, DisableTimestamp: false, FullTimestamp: true}) + envLevel := strings.ToLower(os.Getenv("LOG_LEVEL")) + var level Level + switch envLevel { + case "critical": + level = LevelCritical + case "error": + level = LevelError + case "warn": + level = LevelWarn + case "debug": + level = LevelDebug + default: + level = LevelInfo + } + SetLevel(level) +} diff --git a/log/log_test.go b/log/log_test.go new file mode 100644 index 00000000..4087c0bc --- /dev/null +++ b/log/log_test.go @@ -0,0 +1,104 @@ +package log + +import ( + "context" + "errors" + "net/http/httptest" + "testing" + + "github.com/sirupsen/logrus" + "github.com/sirupsen/logrus/hooks/test" + . "github.com/smartystreets/goconvey/convey" +) + +func TestLog(t *testing.T) { + + Convey("Test Logger", t, func() { + l, hook := test.NewNullLogger() + SetLevel(LevelInfo) + SetDefaultLogger(l) + + Convey("Plain message", func() { + Error("Simple Message") + So(hook.LastEntry().Message, ShouldEqual, "Simple Message") + So(hook.LastEntry().Data, ShouldBeEmpty) + }) + + Convey("Passing nil as context", func() { + Error(nil, "Simple Message") + So(hook.LastEntry().Message, ShouldEqual, "Simple Message") + So(hook.LastEntry().Data, ShouldBeEmpty) + }) + + Convey("Message with two kv pairs", func() { + Error("Simple Message", "key1", "value1", "key2", "value2") + So(hook.LastEntry().Message, ShouldEqual, "Simple Message") + So(hook.LastEntry().Data["key1"], ShouldEqual, "value1") + So(hook.LastEntry().Data["key2"], ShouldEqual, "value2") + So(hook.LastEntry().Data, ShouldHaveLength, 2) + }) + + Convey("Only error", func() { + Error(errors.New("error test")) + So(hook.LastEntry().Message, ShouldEqual, "error test") + So(hook.LastEntry().Data, ShouldBeEmpty) + }) + + Convey("Error as last argument", func() { + Error("Error scrobbling track", "id", 1, errors.New("some issue")) + So(hook.LastEntry().Message, ShouldEqual, "Error scrobbling track") + So(hook.LastEntry().Data["id"], ShouldEqual, 1) + So(hook.LastEntry().Data["error"], ShouldEqual, "some issue") + So(hook.LastEntry().Data, ShouldHaveLength, 2) + }) + + Convey("Passing a request", func() { + ctx := NewContext(nil, "foo", "bar") + req := httptest.NewRequest("get", "/", nil).WithContext(ctx) + + Error(req, "Simple Message", "key1", "value1") + So(hook.LastEntry().Message, ShouldEqual, "Simple Message") + So(hook.LastEntry().Data["foo"], ShouldEqual, "bar") + So(hook.LastEntry().Data["key1"], ShouldEqual, "value1") + So(hook.LastEntry().Data, ShouldHaveLength, 2) + }) + + Convey("Skip if level is lower", func() { + SetLevel(LevelError) + Info("Simple Message") + So(hook.LastEntry(), ShouldBeNil) + }) + }) + + Convey("Test extractLogger", t, func() { + Convey("It returns an error if the context is nil", func() { + _, err := extractLogger(nil) + So(err, ShouldNotBeNil) + }) + + Convey("It returns an error if the context is a string", func() { + _, err := extractLogger("any msg") + So(err, ShouldNotBeNil) + }) + + Convey("It returns the logger from context if it has one", func() { + logger := logrus.NewEntry(logrus.New()) + ctx := context.Background() + ctx = context.WithValue(ctx, "logger", logger) + + l, err := extractLogger(ctx) + So(err, ShouldBeNil) + So(l, ShouldEqual, logger) + }) + + Convey("It returns the logger from request's context if it has one", func() { + logger := logrus.NewEntry(logrus.New()) + ctx := context.Background() + ctx = context.WithValue(ctx, "logger", logger) + req := httptest.NewRequest("get", "/", nil).WithContext(ctx) + l, err := extractLogger(req) + So(err, ShouldBeNil) + So(l, ShouldEqual, logger) + }) + }) +} diff --git a/persistence/checksum_repository.go b/persistence/checksum_repository.go index f110aab8..6bf4e264 100644 --- a/persistence/checksum_repository.go +++ b/persistence/checksum_repository.go @@ -3,7 +3,7 @@ package persistence import ( "errors" - "github.com/astaxie/beego" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/scanner" "github.com/siddontang/ledisdb/ledis" ) @@ -27,12 +27,12 @@ func (r *checkSumRepository) loadData() { pairs, err := Db().HGetAll(checkSumKeyName) if err != nil { - beego.Error("Error loading CheckSums:", err) + log.Error("Error loading CheckSums", err) } for _, p := range pairs { r.data[string(p.Field)] = string(p.Value) } - beego.Debug("Loaded", len(r.data), "checksums") + log.Debug("Loaded checksums", "total", len(r.data)) } func (r *checkSumRepository) Put(id, sum string) error { diff --git a/scanner/importer.go b/scanner/importer.go index cb1ca5df..93e38637 100644 --- a/scanner/importer.go +++ b/scanner/importer.go @@ -7,10 +7,10 @@ import ( "strings" "time" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/conf" "github.com/cloudsonic/sonic-server/domain" "github.com/cloudsonic/sonic-server/engine" + "github.com/cloudsonic/sonic-server/log" "github.com/cloudsonic/sonic-server/utils" ) @@ -64,7 +64,7 @@ func (i *Importer) startImport() { go func() { info, err := os.Stat(i.mediaFolder) if err != nil { - beego.Error(err) + log.Error(err) return } if i.lastCheck.After(info.ModTime()) { @@ -80,39 +80,39 @@ func (i *Importer) scan() { i.lastScan = i.lastModifiedSince() if i.lastScan.IsZero() { - beego.Info("Starting first iTunes Library scan. This can take a while...") + log.Info("Starting first iTunes Library scan. This can take a while...") } total, err := i.scanner.ScanLibrary(i.lastScan, i.mediaFolder) if err != nil { - beego.Error("Error importing iTunes Library:", err) + log.Error("Error importing iTunes Library", err) return } - beego.Debug("Found", total, "tracks,", - len(i.scanner.MediaFiles()), "songs,", - len(i.scanner.Albums()), "albums,", - len(i.scanner.Artists()), "artists", - len(i.scanner.Playlists()), "playlists") + log.Debug("Found", "tracks", total, + "songs", len(i.scanner.MediaFiles()), + "albums", len(i.scanner.Albums()), + "artists", len(i.scanner.Artists()), + "playlists", len(i.scanner.Playlists())) if err := i.importLibrary(); err != nil { - beego.Error("Error persisting data:", err) + log.Error("Error persisting data", err) } if i.lastScan.IsZero() { - beego.Info("Finished first iTunes Library import") + log.Info("Finished first iTunes Library import") } else { - beego.Debug("Finished updating tracks from iTunes Library") + log.Debug("Finished updating tracks from iTunes Library") } } func (i *Importer) lastModifiedSince() time.Time { ms, err := i.propertyRepo.Get(engine.PropLastScan) if err != nil { - beego.Warn("Couldn't read LastScan:", err) + log.Warn("Couldn't read LastScan", err) return time.Time{} } if ms == "" { - beego.Debug("First scan") + log.Debug("First scan") return time.Time{} } s, _ := strconv.ParseInt(ms, 10, 64) @@ -125,31 +125,31 @@ func (i *Importer) importLibrary() (err error) { mfc, _ := i.mfRepo.CountAll() plc, _ := i.plsRepo.CountAll() - beego.Debug("Saving updated data") + log.Debug("Saving updated data") mfs, mfu := i.importMediaFiles() als, alu := i.importAlbums() ars := i.importArtists() pls := i.importPlaylists() i.importArtistIndex() - beego.Debug("Purging old data") + log.Debug("Purging old data") if deleted, err := i.mfRepo.PurgeInactive(mfs); err != nil { - beego.Error(err) + log.Error(err) } else { i.search.RemoveMediaFile(deleted...) } if deleted, err := i.albumRepo.PurgeInactive(als); err != nil { - beego.Error(err) + log.Error(err) } else { i.search.RemoveAlbum(deleted...) } if deleted, err := i.artistRepo.PurgeInactive(ars); err != nil { - beego.Error(err) + log.Error(err) } else { i.search.RemoveArtist(deleted...) } if _, err := i.plsRepo.PurgeInactive(pls); err != nil { - beego.Error(err) + log.Error(err) } arc2, _ := i.artistRepo.CountAll() @@ -158,16 +158,16 @@ func (i *Importer) importLibrary() (err error) { plc2, _ := i.plsRepo.CountAll() if arc != arc2 || alc != alc2 || mfc != mfc2 || plc != plc2 { - beego.Info(fmt.Sprintf("Updated library totals: %d(%+d) artists, %d(%+d) albums, %d(%+d) songs, %d(%+d) playlists", arc2, arc2-arc, alc2, alc2-alc, mfc2, mfc2-mfc, plc2, plc2-plc)) + log.Info(fmt.Sprintf("Updated library totals: %d(%+d) artists, %d(%+d) albums, %d(%+d) songs, %d(%+d) playlists", arc2, arc2-arc, alc2, alc2-alc, mfc2, mfc2-mfc, plc2, plc2-plc)) } if alu > 0 || mfu > 0 { - beego.Info(fmt.Sprintf("Updated items: %d album(s), %d song(s)", alu, mfu)) + log.Info(fmt.Sprintf("Updated items: %d album(s), %d song(s)", alu, mfu)) } if err == nil { millis := time.Now().UnixNano() / int64(time.Millisecond) i.propertyRepo.Put(engine.PropLastScan, fmt.Sprint(millis)) - beego.Debug("LastScan timestamp:", millis) + log.Debug("LastScan", "timestamp", millis) } return err @@ -192,14 +192,14 @@ func (i *Importer) importMediaFiles() (domain.MediaFiles, int) { } } if err := i.mfRepo.Put(mf); err != nil { - beego.Error(err) + log.Error(err) } if err := i.search.IndexMediaFile(mf); err != nil { - beego.Error("Error indexing artist:", err) + log.Error("Error indexing artist", err) } updates++ if !i.lastScan.IsZero() { - beego.Debug(fmt.Sprintf(`-- Updated Track: "%s"`, mf.Title)) + log.Debug(fmt.Sprintf(`-- Updated Track: "%s"`, mf.Title)) } } return mfs, updates @@ -224,14 +224,14 @@ func (i *Importer) importAlbums() (domain.Albums, int) { } } if err := i.albumRepo.Put(al); err != nil { - beego.Error(err) + log.Error(err) } if err := i.search.IndexAlbum(al); err != nil { - beego.Error("Error indexing artist:", err) + log.Error("Error indexing artist", err) } updates++ if !i.lastScan.IsZero() { - beego.Debug(fmt.Sprintf(`-- Updated Album: "%s" from "%s"`, al.Name, al.Artist)) + log.Debug(fmt.Sprintf(`-- Updated Album: "%s" from "%s"`, al.Name, al.Artist)) } } return als, updates @@ -244,10 +244,10 @@ func (i *Importer) importArtists() domain.Artists { ars[j] = *ar j++ if err := i.artistRepo.Put(ar); err != nil { - beego.Error(err) + log.Error(err) } if err := i.search.IndexArtist(ar); err != nil { - beego.Error("Error indexing artist:", err) + log.Error("Error indexing artist", err) } } return ars @@ -262,7 +262,7 @@ func (i *Importer) importArtistIndex() { } if err := i.saveIndex(artistIndex); err != nil { - beego.Error(err) + log.Error(err) } } @@ -276,7 +276,7 @@ func (i *Importer) importPlaylists() domain.Playlists { pls[j] = *pl j++ if err := i.plsRepo.Put(pl); err != nil { - beego.Error(err) + log.Error(err) } } return pls diff --git a/scanner/itunes_scanner.go b/scanner/itunes_scanner.go index 42adb3da..0e0e2dbe 100644 --- a/scanner/itunes_scanner.go +++ b/scanner/itunes_scanner.go @@ -13,9 +13,9 @@ import ( "strings" "time" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/conf" "github.com/cloudsonic/sonic-server/domain" + "github.com/cloudsonic/sonic-server/log" "github.com/dhowden/itl" "github.com/dhowden/tag" ) @@ -49,13 +49,13 @@ type plsRelation struct { } func (s *ItunesScanner) ScanLibrary(lastModifiedSince time.Time, path string) (int, error) { - beego.Debug("Checking for updates since", lastModifiedSince.String(), "- Library:", path) + log.Debug("Checking for updates", "lastModifiedSince", lastModifiedSince, "library", path) xml, _ := os.Open(path) l, err := itl.ReadFromXML(xml) if err != nil { return 0, err } - beego.Debug("Loaded", len(l.Tracks), "tracks") + log.Debug("Loaded tracks", "total", len(l.Tracks)) s.lastModifiedSince = lastModifiedSince s.mediaFiles = make(map[string]*domain.MediaFile) @@ -85,7 +85,7 @@ func (s *ItunesScanner) ScanLibrary(lastModifiedSince time.Time, path string) (i } i++ if i%1000 == 0 { - beego.Debug("Processed", i, "tracks.", len(s.artists), "artists,", len(s.albums), "albums", len(s.mediaFiles), "songs") + log.Debug(fmt.Sprintf("Processed %d tracks", i), "artists", len(s.artists), "albums", len(s.albums), "songs", len(s.mediaFiles)) } } @@ -98,9 +98,9 @@ func (s *ItunesScanner) ScanLibrary(lastModifiedSince time.Time, path string) (i } if err := s.checksumRepo.SetData(s.newSums); err != nil { - beego.Error("Error saving checksums:", err) + log.Error("Error saving checksums", err) } else { - beego.Debug("Saved", len(s.newSums), "checksums") + log.Debug("Saved checksums", "total", len(s.newSums)) } ignFolders := conf.Sonic.PlsIgnoreFolders @@ -116,7 +116,7 @@ func (s *ItunesScanner) ScanLibrary(lastModifiedSince time.Time, path string) (i s.collectPlaylists(&p, fullPath) } - beego.Debug("Processed", len(l.Playlists), "playlists.") + log.Debug("Processed playlists", "total", len(l.Playlists)) return len(l.Tracks), nil } @@ -346,26 +346,26 @@ func artistId(t *itl.Track) string { func hasCoverArt(path string) bool { defer func() { if r := recover(); r != nil { - beego.Error("Reading tag for", path, "Panic:", r) + log.Error("Panic reading tag", "path", path, "error", r) } }() if _, err := os.Stat(path); err == nil { f, err := os.Open(path) if err != nil { - beego.Warn("Error opening file", path, "-", err) + log.Warn("Error opening file", "path", path, err) return false } defer f.Close() m, err := tag.ReadFrom(f) if err != nil { - beego.Warn("Error reading tag from file", path, "-", err) + log.Warn("Error reading tag from file", "path", path, err) return false } return m.Picture() != nil } - //beego.Warn("File not found:", path) + //log.Warn("File not found", "path", path) return false } diff --git a/tests/init_tests.go b/tests/init_tests.go index e92e7e21..37a14287 100644 --- a/tests/init_tests.go +++ b/tests/init_tests.go @@ -4,15 +4,12 @@ import ( "os" "path/filepath" "runtime" - "sync" "testing" - "github.com/astaxie/beego" "github.com/cloudsonic/sonic-server/conf" + "github.com/cloudsonic/sonic-server/log" ) -var initSync sync.Once - func Init(t *testing.T, skipOnShort bool) { if skipOnShort && testing.Short() { t.Skip("skipping test in short mode.") @@ -21,14 +18,11 @@ func Init(t *testing.T, skipOnShort bool) { appPath, _ := filepath.Abs(filepath.Join(filepath.Dir(file), "..")) confPath, _ := filepath.Abs(filepath.Join(appPath, "tests", "sonic-test.toml")) + os.Chdir(appPath) conf.LoadFromFile(confPath) - initSync.Do(func() { - beego.TestBeegoInit(appPath) - }) - noLog := os.Getenv("NOLOG") if noLog != "" { - beego.SetLevel(beego.LevelError) + log.SetLevel(log.LevelError) } }