diff --git a/core/playback/device.go b/core/playback/device.go index d7c7355f..2ece8906 100644 --- a/core/playback/device.go +++ b/core/playback/device.go @@ -2,6 +2,7 @@ package playback import ( "context" + "errors" "fmt" "github.com/navidrome/navidrome/core/playback/mpv" @@ -17,9 +18,10 @@ type Track interface { Position() int SetPosition(offset int) error Close() + String() string } -type PlaybackDevice struct { +type playbackDevice struct { ParentPlaybackServer PlaybackServer Default bool User string @@ -43,7 +45,7 @@ const DefaultGain float32 = 1.0 var EmptyStatus = DeviceStatus{CurrentIndex: -1, Playing: false, Gain: DefaultGain, Position: 0} -func (pd *PlaybackDevice) getStatus() DeviceStatus { +func (pd *playbackDevice) getStatus() DeviceStatus { pos := 0 if pd.ActiveTrack != nil { pos = pd.ActiveTrack.Position() @@ -59,8 +61,8 @@ func (pd *PlaybackDevice) getStatus() DeviceStatus { // NewPlaybackDevice creates a new playback device which implements all the basic Jukebox mode commands defined here: // http://www.subsonic.org/pages/api.jsp#jukeboxControl // Starts the trackSwitcher goroutine for the device. -func NewPlaybackDevice(playbackServer PlaybackServer, name string, deviceName string) *PlaybackDevice { - return &PlaybackDevice{ +func NewPlaybackDevice(playbackServer PlaybackServer, name string, deviceName string) *playbackDevice { + return &playbackDevice{ ParentPlaybackServer: playbackServer, User: "", Name: name, @@ -72,22 +74,24 @@ func NewPlaybackDevice(playbackServer PlaybackServer, name string, deviceName st } } -func (pd *PlaybackDevice) String() string { +func (pd *playbackDevice) String() string { return fmt.Sprintf("Name: %s, Gain: %.4f, Loaded track: %s", pd.Name, pd.Gain, pd.ActiveTrack) } -func (pd *PlaybackDevice) Get(ctx context.Context) (model.MediaFiles, DeviceStatus, error) { - log.Debug(ctx, "processing Get action") +func (pd *playbackDevice) Get(ctx context.Context) (model.MediaFiles, DeviceStatus, error) { + log.Debug(ctx, "Processing Get action", "device", pd) return pd.PlaybackQueue.Get(), pd.getStatus(), nil } -func (pd *PlaybackDevice) Status(ctx context.Context) (DeviceStatus, error) { +func (pd *playbackDevice) Status(ctx context.Context) (DeviceStatus, error) { log.Debug(ctx, fmt.Sprintf("processing Status action on: %s, queue: %s", pd, pd.PlaybackQueue)) return pd.getStatus(), nil } -// set is similar to a clear followed by a add, but will not change the currently playing track. -func (pd *PlaybackDevice) Set(ctx context.Context, ids []string) (DeviceStatus, error) { +// Set is similar to a clear followed by a add, but will not change the currently playing track. +func (pd *playbackDevice) Set(ctx context.Context, ids []string) (DeviceStatus, error) { + log.Debug(ctx, "Processing Set action", "ids", ids, "device", pd) + _, err := pd.Clear(ctx) if err != nil { log.Error(ctx, "error setting tracks", ids) @@ -96,8 +100,8 @@ func (pd *PlaybackDevice) Set(ctx context.Context, ids []string) (DeviceStatus, return pd.Add(ctx, ids) } -func (pd *PlaybackDevice) Start(ctx context.Context) (DeviceStatus, error) { - log.Debug(ctx, "processing Start action") +func (pd *playbackDevice) Start(ctx context.Context) (DeviceStatus, error) { + log.Debug(ctx, "Processing Start action", "device", pd) if !pd.TrackSwitcherStarted { log.Info(ctx, "Starting trackSwitcher goroutine") @@ -127,16 +131,16 @@ func (pd *PlaybackDevice) Start(ctx context.Context) (DeviceStatus, error) { return pd.getStatus(), nil } -func (pd *PlaybackDevice) Stop(ctx context.Context) (DeviceStatus, error) { - log.Debug(ctx, "processing Stop action") +func (pd *playbackDevice) Stop(ctx context.Context) (DeviceStatus, error) { + log.Debug(ctx, "Processing Stop action", "device", pd) if pd.ActiveTrack != nil { pd.ActiveTrack.Pause() } return pd.getStatus(), nil } -func (pd *PlaybackDevice) Skip(ctx context.Context, index int, offset int) (DeviceStatus, error) { - log.Debug(ctx, "processing Skip action", "index", index, "offset", offset) +func (pd *playbackDevice) Skip(ctx context.Context, index int, offset int) (DeviceStatus, error) { + log.Debug(ctx, "Processing Skip action", "index", index, "offset", offset, "device", pd) wasPlaying := pd.isPlaying() @@ -173,8 +177,11 @@ func (pd *PlaybackDevice) Skip(ctx context.Context, index int, offset int) (Devi return pd.getStatus(), nil } -func (pd *PlaybackDevice) Add(ctx context.Context, ids []string) (DeviceStatus, error) { - log.Debug(ctx, "processing Add action") +func (pd *playbackDevice) Add(ctx context.Context, ids []string) (DeviceStatus, error) { + log.Debug(ctx, "Processing Add action", "ids", ids, "device", pd) + if len(ids) < 1 { + return pd.getStatus(), nil + } items := model.MediaFiles{} @@ -191,8 +198,8 @@ func (pd *PlaybackDevice) Add(ctx context.Context, ids []string) (DeviceStatus, return pd.getStatus(), nil } -func (pd *PlaybackDevice) Clear(ctx context.Context) (DeviceStatus, error) { - log.Debug(ctx, fmt.Sprintf("processing Clear action on: %s", pd)) +func (pd *playbackDevice) Clear(ctx context.Context) (DeviceStatus, error) { + log.Debug(ctx, "Processing Clear action", "device", pd) if pd.ActiveTrack != nil { pd.ActiveTrack.Pause() pd.ActiveTrack.Close() @@ -202,8 +209,8 @@ func (pd *PlaybackDevice) Clear(ctx context.Context) (DeviceStatus, error) { return pd.getStatus(), nil } -func (pd *PlaybackDevice) Remove(ctx context.Context, index int) (DeviceStatus, error) { - log.Debug(ctx, "processing Remove action") +func (pd *playbackDevice) Remove(ctx context.Context, index int) (DeviceStatus, error) { + log.Debug(ctx, "Processing Remove action", "index", index, "device", pd) // pausing if attempting to remove running track if pd.isPlaying() && pd.PlaybackQueue.Index == index { _, err := pd.Stop(ctx) @@ -221,17 +228,17 @@ func (pd *PlaybackDevice) Remove(ctx context.Context, index int) (DeviceStatus, return pd.getStatus(), nil } -func (pd *PlaybackDevice) Shuffle(ctx context.Context) (DeviceStatus, error) { - log.Debug(ctx, "processing Shuffle action") +func (pd *playbackDevice) Shuffle(ctx context.Context) (DeviceStatus, error) { + log.Debug(ctx, "Processing Shuffle action", "device", pd) if pd.PlaybackQueue.Size() > 1 { pd.PlaybackQueue.Shuffle() } return pd.getStatus(), nil } -// Used to control the playback volume. A float value between 0.0 and 1.0. -func (pd *PlaybackDevice) SetGain(ctx context.Context, gain float32) (DeviceStatus, error) { - log.Debug(ctx, fmt.Sprintf("processing SetGain action. Actual gain: %f, gain to set: %f", pd.Gain, gain)) +// SetGain is used to control the playback volume. A float value between 0.0 and 1.0. +func (pd *playbackDevice) SetGain(ctx context.Context, gain float32) (DeviceStatus, error) { + log.Debug(ctx, "Processing SetGain action", "newGain", gain, "device", pd) if pd.ActiveTrack != nil { pd.ActiveTrack.SetVolume(gain) @@ -241,15 +248,15 @@ func (pd *PlaybackDevice) SetGain(ctx context.Context, gain float32) (DeviceStat return pd.getStatus(), nil } -func (pd *PlaybackDevice) isPlaying() bool { +func (pd *playbackDevice) isPlaying() bool { return pd.ActiveTrack != nil && pd.ActiveTrack.IsPlaying() } -func (pd *PlaybackDevice) trackSwitcherGoroutine() { - log.Info("Starting trackSwitcher goroutine") +func (pd *playbackDevice) trackSwitcherGoroutine() { + log.Debug("Started trackSwitcher goroutine", "device", pd) for { <-pd.PlaybackDone - log.Info("track switching detected") + log.Debug("Track switching detected") if pd.ActiveTrack != nil { pd.ActiveTrack.Close() pd.ActiveTrack = nil @@ -260,7 +267,7 @@ func (pd *PlaybackDevice) trackSwitcherGoroutine() { log.Debug("Switching to next song", "queue", pd.PlaybackQueue.String()) err := pd.switchActiveTrackByIndex(pd.PlaybackQueue.Index) if err != nil { - log.Error("error switching track", "error", err) + log.Error("Error switching track", err) } pd.ActiveTrack.Unpause() } else { @@ -269,11 +276,11 @@ func (pd *PlaybackDevice) trackSwitcherGoroutine() { } } -func (pd *PlaybackDevice) switchActiveTrackByIndex(index int) error { +func (pd *playbackDevice) switchActiveTrackByIndex(index int) error { pd.PlaybackQueue.SetIndex(index) currentTrack := pd.PlaybackQueue.Current() if currentTrack == nil { - return fmt.Errorf("could not get current track") + return errors.New("could not get current track") } track, err := mpv.NewTrack(pd.PlaybackDone, pd.DeviceName, *currentTrack) diff --git a/core/playback/mpv/track.go b/core/playback/mpv/track.go index 1008debc..d574508c 100644 --- a/core/playback/mpv/track.go +++ b/core/playback/mpv/track.go @@ -25,7 +25,7 @@ type MpvTrack struct { } func NewTrack(playbackDoneChannel chan bool, deviceName string, mf model.MediaFile) (*MpvTrack, error) { - log.Debug("loading track", "trackname", mf.Path, "mediatype", mf.ContentType()) + log.Debug("Loading track", "trackPath", mf.Path, "mediaType", mf.ContentType()) if _, err := mpvCommand(); err != nil { return nil, err @@ -36,14 +36,14 @@ func NewTrack(playbackDoneChannel chan bool, deviceName string, mf model.MediaFi args := createMPVCommand(mpvComdTemplate, deviceName, mf.Path, tmpSocketName) exe, err := start(args) if err != nil { - log.Error("error starting mpv process", "error", err) + log.Error("Error starting mpv process", err) return nil, err } // wait for socket to show up - err = waitForFile(tmpSocketName, 3*time.Second, 100*time.Millisecond) + err = waitForSocket(tmpSocketName, 3*time.Second, 100*time.Millisecond) if err != nil { - log.Error("error or timeout waiting for control socket", "socketname", tmpSocketName, "error", err) + log.Error("Error or timeout waiting for control socket", "socketname", tmpSocketName, err) return nil, err } @@ -51,7 +51,7 @@ func NewTrack(playbackDoneChannel chan bool, deviceName string, mf model.MediaFi err = conn.Open() if err != nil { - log.Error("error opening new connection", "error", err) + log.Error("Error opening new connection", err) return nil, err } @@ -92,7 +92,7 @@ func (t *MpvTrack) Unpause() { if err != nil { log.Error(err) } - log.Info("unpaused track") + log.Debug("Unpaused track", "track", t) } func (t *MpvTrack) Pause() { @@ -111,7 +111,7 @@ func (t *MpvTrack) Close() { log.Debug("sending shutdown command") _, err := t.Conn.Call("quit") if err != nil { - log.Error("error sending quit command to mpv-ipc socket", "error", err) + log.Error("Error sending quit command to mpv-ipc socket", err) if t.Exe != nil { log.Debug("cancelling executor") @@ -141,16 +141,16 @@ func (t *MpvTrack) isSocketfilePresent() bool { return err == nil && fileInfo != nil && !fileInfo.IsDir() } -// Position returns the playback position in seconds -// every now and then the mpv IPC interface returns "mpv error: property unavailable" +// Position returns the playback position in seconds. +// Every now and then the mpv IPC interface returns "mpv error: property unavailable" // in this case we have to retry func (t *MpvTrack) Position() int { retryCount := 0 for { position, err := t.Conn.Get("time-pos") if err != nil && err.Error() == "mpv error: property unavailable" { - log.Debug("got the mpv error: property unavailable error, retry ...") retryCount += 1 + log.Debug("Got mpv error, retrying...", "retries", retryCount, err) if retryCount > 5 { return 0 } @@ -158,13 +158,13 @@ func (t *MpvTrack) Position() int { } if err != nil { - log.Error("error getting position in track", "error", err) + log.Error("Error getting position in track", err) return 0 } pos, ok := position.(float64) if !ok { - log.Error("could not cast position from mpv into float64") + log.Error("Could not cast position from mpv into float64", "position", position) return 0 } else { return int(pos) @@ -181,7 +181,7 @@ func (t *MpvTrack) SetPosition(offset int) error { } err := t.Conn.Set("time-pos", float64(offset)) if err != nil { - log.Error("could not set the position in track", "offset", offset, "error", err) + log.Error("could not set the position in track", "offset", offset, err) return err } log.Info("set position", "offset", offset) @@ -191,7 +191,7 @@ func (t *MpvTrack) SetPosition(offset int) error { func (t *MpvTrack) IsPlaying() bool { pausing, err := t.Conn.Get("pause") if err != nil { - log.Error("problem getting paused status", "error", err) + log.Error("problem getting paused status", err) return false } @@ -203,7 +203,7 @@ func (t *MpvTrack) IsPlaying() bool { return !pause } -func waitForFile(path string, timeout time.Duration, pause time.Duration) error { +func waitForSocket(path string, timeout time.Duration, pause time.Duration) error { start := time.Now() end := start.Add(timeout) var retries int = 0 @@ -211,7 +211,7 @@ func waitForFile(path string, timeout time.Duration, pause time.Duration) error for { fileInfo, err := os.Stat(path) if err == nil && fileInfo != nil && !fileInfo.IsDir() { - log.Debug("file found", "retries", retries, "waittime", time.Since(start).Microseconds()) + log.Debug("Socket found", "retries", retries, "waitTime", time.Since(start)) return nil } if time.Now().After(end) { diff --git a/core/playback/playbackserver.go b/core/playback/playbackserver.go index 4281700a..c0b98ae7 100644 --- a/core/playback/playbackserver.go +++ b/core/playback/playbackserver.go @@ -19,7 +19,7 @@ import ( type PlaybackServer interface { Run(ctx context.Context) error - GetDeviceForUser(user string) (*PlaybackDevice, error) + GetDeviceForUser(user string) (*playbackDevice, error) GetMediaFile(id string) (*model.MediaFile, error) GetCtx() *context.Context } @@ -27,7 +27,7 @@ type PlaybackServer interface { type playbackServer struct { ctx *context.Context datastore model.DataStore - playbackDevices []PlaybackDevice + playbackDevices []playbackDevice } // GetInstance returns the playback-server singleton @@ -63,8 +63,8 @@ func (ps *playbackServer) GetCtx() *context.Context { return ps.ctx } -func (ps *playbackServer) initDeviceStatus(devices []conf.AudioDeviceDefinition, defaultDevice string) ([]PlaybackDevice, error) { - pbDevices := make([]PlaybackDevice, max(1, len(devices))) +func (ps *playbackServer) initDeviceStatus(devices []conf.AudioDeviceDefinition, defaultDevice string) ([]playbackDevice, error) { + pbDevices := make([]playbackDevice, max(1, len(devices))) defaultDeviceFound := false if defaultDevice == "" { @@ -76,13 +76,13 @@ func (ps *playbackServer) initDeviceStatus(devices []conf.AudioDeviceDefinition, // if there is but only one entry and no default given, just use that. if len(devices) == 1 { if len(devices[0]) != 2 { - return []PlaybackDevice{}, fmt.Errorf("audio device definition ought to contain 2 fields, found: %d ", len(devices[0])) + return []playbackDevice{}, fmt.Errorf("audio device definition ought to contain 2 fields, found: %d ", len(devices[0])) } pbDevices[0] = *NewPlaybackDevice(ps, devices[0][0], devices[0][1]) } if len(devices) > 1 { - return []PlaybackDevice{}, fmt.Errorf("number of audio device found is %d, but no default device defined. Set Jukebox.Default", len(devices)) + return []playbackDevice{}, fmt.Errorf("number of audio device found is %d, but no default device defined. Set Jukebox.Default", len(devices)) } pbDevices[0].Default = true @@ -91,7 +91,7 @@ func (ps *playbackServer) initDeviceStatus(devices []conf.AudioDeviceDefinition, for idx, audioDevice := range devices { if len(audioDevice) != 2 { - return []PlaybackDevice{}, fmt.Errorf("audio device definition ought to contain 2 fields, found: %d ", len(audioDevice)) + return []playbackDevice{}, fmt.Errorf("audio device definition ought to contain 2 fields, found: %d ", len(audioDevice)) } pbDevices[idx] = *NewPlaybackDevice(ps, audioDevice[0], audioDevice[1]) @@ -103,18 +103,18 @@ func (ps *playbackServer) initDeviceStatus(devices []conf.AudioDeviceDefinition, } if !defaultDeviceFound { - return []PlaybackDevice{}, fmt.Errorf("default device name not found: %s ", defaultDevice) + return []playbackDevice{}, fmt.Errorf("default device name not found: %s ", defaultDevice) } return pbDevices, nil } -func (ps *playbackServer) getDefaultDevice() (*PlaybackDevice, error) { +func (ps *playbackServer) getDefaultDevice() (*playbackDevice, error) { for idx, audioDevice := range ps.playbackDevices { if audioDevice.Default { return &ps.playbackDevices[idx], nil } } - return &PlaybackDevice{}, fmt.Errorf("no default device found") + return &playbackDevice{}, fmt.Errorf("no default device found") } // GetMediaFile retrieves the MediaFile given by the id parameter @@ -123,12 +123,12 @@ func (ps *playbackServer) GetMediaFile(id string) (*model.MediaFile, error) { } // GetDeviceForUser returns the audio playback device for the given user. As of now this is but only the default device. -func (ps *playbackServer) GetDeviceForUser(user string) (*PlaybackDevice, error) { - log.Debug("processing GetDevice") +func (ps *playbackServer) GetDeviceForUser(user string) (*playbackDevice, error) { + log.Debug("Processing GetDevice", "user", user) // README: here we might plug-in the user-device mapping one fine day device, err := ps.getDefaultDevice() if err != nil { - return &PlaybackDevice{}, err + return &playbackDevice{}, err } device.User = user return device, nil diff --git a/server/subsonic/album_lists.go b/server/subsonic/album_lists.go index 7f1ecea6..6fdabff1 100644 --- a/server/subsonic/album_lists.go +++ b/server/subsonic/album_lists.go @@ -64,13 +64,13 @@ func (api *Router) getAlbumList(r *http.Request) (model.Albums, int64, error) { albums, err := api.ds.Album(r.Context()).GetAllWithoutGenres(opts) if err != nil { - log.Error(r, "Error retrieving albums", "error", err) + log.Error(r, "Error retrieving albums", err) return nil, 0, newError(responses.ErrorGeneric, "internal error") } count, err := api.ds.Album(r.Context()).CountAll(opts) if err != nil { - log.Error(r, "Error counting albums", "error", err) + log.Error(r, "Error counting albums", err) return nil, 0, newError(responses.ErrorGeneric, "internal error") } @@ -108,17 +108,17 @@ func (api *Router) GetStarred(r *http.Request) (*responses.Subsonic, error) { options := filter.Starred() artists, err := api.ds.Artist(ctx).GetAll(options) if err != nil { - log.Error(r, "Error retrieving starred artists", "error", err) + log.Error(r, "Error retrieving starred artists", err) return nil, err } albums, err := api.ds.Album(ctx).GetAllWithoutGenres(options) if err != nil { - log.Error(r, "Error retrieving starred albums", "error", err) + log.Error(r, "Error retrieving starred albums", err) return nil, err } mediaFiles, err := api.ds.MediaFile(ctx).GetAll(options) if err != nil { - log.Error(r, "Error retrieving starred mediaFiles", "error", err) + log.Error(r, "Error retrieving starred mediaFiles", err) return nil, err } @@ -145,7 +145,7 @@ func (api *Router) GetNowPlaying(r *http.Request) (*responses.Subsonic, error) { ctx := r.Context() npInfo, err := api.scrobbler.GetNowPlaying(ctx) if err != nil { - log.Error(r, "Error retrieving now playing list", "error", err) + log.Error(r, "Error retrieving now playing list", err) return nil, err } @@ -170,7 +170,7 @@ func (api *Router) GetRandomSongs(r *http.Request) (*responses.Subsonic, error) songs, err := api.getSongs(r.Context(), 0, size, filter.SongsByRandom(genre, fromYear, toYear)) if err != nil { - log.Error(r, "Error retrieving random songs", "error", err) + log.Error(r, "Error retrieving random songs", err) return nil, err } @@ -187,7 +187,7 @@ func (api *Router) GetSongsByGenre(r *http.Request) (*responses.Subsonic, error) songs, err := api.getSongs(r.Context(), offset, count, filter.SongsByGenre(genre)) if err != nil { - log.Error(r, "Error retrieving random songs", "error", err) + log.Error(r, "Error retrieving random songs", err) return nil, err }