Bugzilla – Bug 3696
Random Mix stops if last track fails to play
Last modified: 2009-04-13 09:54:28 UTC
At first I thought this was a recurrence of bug 2510 because suddenly the track displayed is one step behind what's playing. However it appears what has happened is that Random Mix has failed. When I get to the end of that track, playback stops and no new songs are added. To get Random Mix going again, I press the forward skip button on the remote, which starts over at the start of the three songs in my playlist (I have Random Mix set to display one song ahead and one behind what's currently playing). Repeated presses bring playback to the last track, then a subsequent press gets Random Mix going again with a new track. This occurs about once an hour with me. I have set the d_plugins and d_source log but the issue hasn't occurred since I've enabled logging so far. I'll post a log snippet when this occurs again.
Mark - any update? Thanks
Still happens about once every 1-2 hours. Seeing as I seem to be the only one experiencing this and that it's rather minor, I forgot about it. I'll keep logging and post a snippet the next time it happens. Sure hope some of my more embarassing songs don't come up. ;-)
Created attachment 1376 [details] Log file I was playing "I'm Not Sleeping" from "Recovering the Satellites" by Counting Crows. The previous song was "On the Run" by Pink Floyd.
Whoops, my comment got overwritten. Anyway, this time I did something to cause Random Mix to fail. It shouldn't have caused it to fail, but it didn't fail on its own. I accidentally pressed the down key on the remote, which was supposed to list the upcoming song. Instead it listed the previous song. When I saw that, I knew Random Mix would fail when the current track ended, and it did.
is this an issue in 6.5 still? I'm not even finding the debug messages in the code for "open song" and "end of song" -k
Here is one case where random can stop. If the last song in teh playlist can't be played, there is no 'newsong' callback to trigger another track for addition. The log as follows: 2006-07-28 14:04:28.4851 openSong: Couldn't create command line for wma playback for [file:///D:/music/test/Liberty%20X%20-%20(08)%20Jumpin%27.wma] 2006-07-28 14:04:28.4862 Error opening current track, so mark it as already played 2006-07-28 14:04:28.4974 playmode: No more valid tracks on the playlist. Stopping. 2006-07-28 14:04:28.4977 ba:43:80:ae:96:cd New play mode: stop 2006-07-28 14:04:28.4979 Stopping and clearing out old chunks for client ba:43:80:ae:96:cd 2006-07-28 14:04:28.4998 Resetting song queue 2006-07-28 14:04:28.5002 Song queue is now 0 2006-07-28 14:04:28.5010 ba:43:80:ae:96:cd: Current playmode: stop 2006-07-28 14:04:32.6714 Setting maxBitRate for 127.0.0.1 to: 0 2006-07-28 14:04:32.6718 Setting maxBitRate for 127.0.0.1 to: 0
KDF: if your first comment was addressed to me, I'm using 6.3.0. As this has been marked to be fixed in 6.5, maybe that's another reason I should switch to it - so we can verify if this problem persists in 6.5 for me.
was addressed to anyone. I think you won't have to worry about it if you are hesitant. 6.5 does appear to still have an issue as described in my comment above, where the log does appear to show the same case as yours. This isn't a problem unless the server is set for ONE upcoming track, as any single bad track will simply move to another good one and continue to add tracks. If you have 2 upcoming, and you get 2 bad tracks, then I expect the results would be similar. There is no callback on a 'bad track' stoppage. Having played with this case a bit, the indexing needs a bit of rework as well. 1 upcoming and one previous is a playlist of only one track, but I can see now that it really should be three. The current song should not be included in the counts, certainly not in both :) I have a fix for that. I will have to find a reasonable way for random cyclic mode to continue on a bad track. I'm thinking it may be a useful thing to have a new callback for something like this. It could be that other functions may want to be notified if the playback stops. The other option is to check for random playback status the same way we do for repeat, but since random play is a plugin, I'm hesitant to add hooks into core code that are part of a plugin. Andy, are you the R.E for Source.pm now? thoughts?
Yes, I have the server to show only one upcoming track. I could change it, but then we may never squash this bug...
no worries, mark. as a workaround, try having two upcoming songs and see if the problem goes away. at least then I can more safely assume that I've found the cause. The other thing is to look at the tracks where it fails, and see if you can reliably stop playback on those tracks. might also be of value to find out why they stop and fix the server for that problem as well.
So in general it looks like bad tracks can stop the music. Dan says he will have a look.
Unfortunately this has persisted, even with two upcoming songs. It may still be bug 2510 I'm seeing because it's happened once or twice with a predefined playlist as well. I keep trying to log it, but I keep missing it. Since my screensaver is on, it's hard to tell when this happens, so it's hard to know when it started. I'm also not sure how much of the log to include, i.e. where the problem starts.
If you use d_plugins and d_source you can see if randomplay is stopped for some reason, and where playback stops. You only need to inlude about 100 lines or so with maybe 10 after the playback stops. If random play shows a "stopping continuous mode" then the relevant bit of log is probably only the 10 lines leading up to that one.
argh. twice in one day. time for new batteries.
Mark - any update here?
Nope, hasn't happened in a little while. I don't think it took care of itself, it's just a coincidence. BTW regarding corrupted files, I don't think I have that many. I suppose I could have a few but I do pay careful attention to my files and play them all at least once as I rip them.
Gotchya! I missed a few occurrances of this because I restarted SlimServer - when you do this, any checked debug flags are cleared. But I got it. The song "Inevitability of Death" by The Tragically Hip played and displayed fine. However while the next song played fine, the display was still on "Inevitability of Death". It's still playing right now, hasn't stopped yet, but it's one track behind. I'll post a log snippet right now, covering the loading of "Inevitability of Death" plus the next song and a bit more, then I'll wait until playback stops to post more of the log.
Created attachment 1475 [details] Display one track behind but still playing
It's still playing, with the player display one track behind. The SlimServer GUI is strange - I have it set to display one track behind and two ahead so it normally shows the currently playing track as the second one (i.e. one behind and two ahead on a list of four). But it's showing the first track in the playlist as the current one, i.e. the one it played earlier, plus *three* ahead. Which may give another clue as to what's going on - I requested *two* ahead.
Created attachment 1476 [details] Resolved by skipping a track This behavior stopped when I encountered a song I didn't want to hear. "Take On Me" by A-Ha - any wonder why I skipped it? :-) Anyway the "next" song that came up was the same one. (?) Skipped that one and everything synched up again - player UI, SlimServer GUI.
In change 10094 I've fixed the situation where the last track in the random playlist fails. When this happens the random mix will restart itself.
Unfortunately due to bug 7702 this change had to be reverted in 7.1 change 20743. Assigning to Alan to find a better fix as part of new streaming.
I cannot think of a sensible fix and I think that the presence of a workaround (put more upcoming tracks in your RandomPlay settings) is good enough in most cases.
We are unable to find a reasonable fix at this time, IF anyone is able to come up with a fix that won't break anything else, please attach a patch so we can evaluate it.