Bugzilla – Bug 7916
Sound just stops playing on Duet receiver, remote shows the songs still playing
Last modified: 2009-06-17 09:35:09 UTC
Randomly audio will quit playing on my Duet receiver even though the remote shows the song still playing and counting down. If I RWD the song it will the procede to play all the way through. I can't repeat on any particular WMA lossless file, it seems totally random. It might very well be a sync problem where the receiver gets messed up and restarting a song fixes everything. This was happening occasionally on my friends Duet as well. I'm running 7.0.1 squeezecenter. The receiver has the lastest firmware and remote was updated yesterday to 2287. Remote is wireless to my DLink DIR-655 router. Receiver is wired.
If you can capture a log (Settings / Advanced / Logging) at level player.source=info and player.sync=info then this would be helpful.
Does this only happen with WMA files?
All I have is WMA Lossless files. I'll turn on logging and wait for it to happen again. It's only happened to me once, but I've seen it happen 4-5 times on a friends system. His library is WMA lossless as well. Note: The day it was bad on my friends system, we finally powered off the receiver and powered it back on and it worked perfectly all the next day.
Jeff, does you friend also have multiple, synced players?
Sorry for the confusion, neither of us have multiple synced players. It's happening for us on a single receiver. It seemed like it was a sync issue between the server and the receiver but it might very well be a transcoding issue. What debug information would you like me to catch for transcoding?
Hmm, that is harder; player.source=info is still good. Probably best to leave it at that for the present. If we get clues from that then we can look in more detail.
Jeff: Can you please try to reproduce this with the latest release version 7.0.1 - 19705 Make sure to set the debug logs listed, then attach them to this bug.
Created attachment 3353 [details] error log I was able to repo the problem using WMA lossless tracks on a Duet See attached log
Sorry I wasn't able to catch a log of the problem for you. I haven't had allot of time to listen to music lately. It's good to see you were able to reproduce the problem. Thanks!
James, I am very confused by what your log is showing me. There appear to be several things wrong. Looking just near the end (I presume that this is when it stopped playing) we have: [08-05-16 12:06:41.8661] Slim::Player::Source::trackStartEvent (1513) Song 11 has now started playing [08-05-16 12:06:41.8672] Slim::Player::Source::trackStartEvent (1541) Song queue is now 11 [08-05-16 12:07:04.6903] Slim::Player::Source::decoderUnderrun (582) 00:04:20:16:01:fb: Decoder underrun while this mode: play [08-05-16 12:07:04.6906] Slim::Player::Source::nextsong (1592) The next song is number 11, was 10 [08-05-16 12:07:04.6910] Slim::Player::Source::nextsong (1592) The next song is number 11, was 10 [08-05-16 12:07:14.5880] Slim::Player::Source::underrun (687) 00:04:20:16:01:fb: Underrun while this mode: play [08-05-16 12:07:14.5948] Slim::Player::Source::outputUnderrun (765) 00:04:20:16:01:fb: Output buffer underrun (decoder: 1638800 / output: 0) [08-05-16 12:07:14.5951] Slim::Player::Source::playmode (298) 00:04:20:16:01:fb: Switching to mode pause from play [08-05-16 12:07:14.5957] Slim::Player::Source::playmode (401) 00:04:20:16:01:fb New play mode: pause [08-05-16 12:07:14.5964] Slim::Player::Source::playmode (556) 00:04:20:16:01:fb: Current playmode: pause [08-05-16 12:07:15.5998] Slim::Player::Source::playmode (298) 00:04:20:16:01:fb: Switching to mode play from pause This starts out right - the track-start event is 10s after the previous decoder-underrun. The log says that it is playing track 11 and is not yet streaming a new track ("Song queue is now 11"). The next event is a decoder-underrun, 23s after the track start. This is wrong for two reasons: (1) because the track is 83s long and so the decoder-underrun should not occur until 73s after the track start (the output buffer is 10s); (2) because a "readNextChunk (2390) end of file or error on socket" should have occurred before the decoder-underrun. Then we get: "nextsong (1592) The next song is number 11, was 10". I do not know how it still knows about '10'. Did you have random-play or something running that could have been changing the playlist while the song was playing? Anyway, because of (2), we are not yet in state playout-play, so we do not try to start to stream the next track. I suppose that SC could try to trap this unexpected condition but I am not sure that it woudl solve the real problem. Then, 10s later, we get "Underrun", Since this comes 10s after the decoder-underrun, it makes sense. But it is followed by output-underrun and with a non-empty decode buffer (1638800). Output-underrun should not occur after Underrun. My conclusion is that this is a firmware bug. The STMd (decoder-underrun) event has occurred even though the stream has not been closed. After that, everything gets confused. I am assigning this to Felix. I suspect that it could be a duplicate of bug 6508, or maybe bug 4019 although the circumstances seem different. In the case that the player sends an STMd because of a problem with the FLAC decoding, then it is necessary that it also closes the stream - does it do that? I'll also look to see if we can handle this on the server. I guess that it would be useful to know, James, exactly what sort of setup you had. I see that Jeff is using a Duet with wireless - Jeff, can you confirm that your setup is completely wireless, not using a wired receive with the controller bridged via the receiver.
Change 20477 to SC 7.1 deals with part of the problem but it still needs the streaming connection to be closed. It might be possible to do this in the server but really a firmware change would be better. James, if you can test with this change to see if you can reproduce the problem then that would be good. If your log contains 'forcing playout mode on unexpected decoder underrun' but you do not get the hang then this change was sufficient. One way to reproduce the problem might be to play FLAC tracks that been deliberately corrupted part way through.
My duet setup is a wired receiver but the controller is going directly to my router it's not bridged. My friends setup is all wirless but again not bridged everything is going to his router. It happens far more often on his system. I've only seen it happen once on mine so far. I still haven't been able to reproduce it since I turned logging on.
Created attachment 3434 [details] error log
I think have the same problem here. The system worked just fine for a few weeks. Then after some experimenting with synchronised playing (with softsqueeze on antoher computer) and adding quite a lof of album art, I get the same symptoms as described here. At first I tried things like reset to factory settings, firmware updates, upgrading to squeezecenter 7.1 etc. and I ran into the known bug with apparmor (I'm on Ubuntu 8.04). That is solved now, but my receiver still randomly stops playing after a song. The only way to get it to play music again is to turn the receiver off with the remote, briefly unplug the power chord of the receiver and to restart the server. I mostly play random mix. Sometimes things go well for a while, sometimes it already fails after playing the first song. The sound stops, the squeezecenter shows that it repeats the same few seconds, the remote does the same, but with other timing information (and a weird remaining time, like 59:48 for example). Skipping to the next song still gives no sound. The squeezecenter and the remote show that the new song is started somewhere in the middle. In the log I've attached, things went wrong after the Kraftwerk song and I've skipped to the next song twice.
The proposed fix in firmware is not trivial and could potentially affect other scenarios which means we should do some serious testing first. After some discussion with Richard and Alan, I suggest moving this bug to 7.2 to allow for QA to recreate and test if it a) indeed fixes the issue and b) does not affect normal playback.
Fine, Felix. I'll leave it assigned to you for now. When you make a firmware suitable for testing feel free to assign this back to QA.
ping felix: are we working on this for 7.2?
I was until yesterday. While preparing a fw containing the proposed patch ( which essentially separates decoder underrun events from decoder error events so SC could distinguish between them) for James to test, I found that while playing mp3 files are still fine, playing flac is broken. When a song finishes the next would not start to play. It looks like that the flac decoder, when a song is done, sends a decoder error event instead of a decoder underrun event. I recall, that Richard was telling me when discussing the patch to check whether all decoder use a decoder underrun event to signal an end-of-song condition. I only looked through the code of each decoder and found that all of them can do decoder underrun, but it seems flac decoder is not using it. I have not looked into why that is the case. Looks like we need a better idea how to solve this.
When a FLAC song ends the decoder gets into DECODER_STATE_ERROR first and then into DECODER_STATE_UNDERRUN. In contrast the MP3 decoder only gets into DECODER_STATE_UNDERRUN when a song ends as I would have expected. I have not checked other decoders yet.
I am not sure this bug is still valid with new streaming coming up in 7.3. May I ask QA to have another look try to reproduce with 7.3? If it still fails another error log would be helpful. Thanks
I've got some extra information for my situation. After a lot of experimentation I found out that it's the ogg-files that cause the errors. It doesn't matter whether it's an ogg-file I encoded myself, or one I downloaded from the internet. Whenever I have ogg-files in my library, eventually the receiver will stop playing. Though not immediately at the start, during, of after playing an ogg-file. (That would be way to simple!) For some ogg-files I I ripped the cd again in flac and some ogg-files I just converted to mp3. The mp3's and flac's I had I kept the same. Now the system is working flawless for several weeks. This is a workaround I am ok with, so thats the end for the bug for me. But if you want, I can experiment a bit more an provide you with some log-files. Just tell me what you would like to see.
Jeff: I have been unable to reproduce this issue with either 7.2.1 or 7.3-nightly. Can you please try again? If you are able to, generate and attach another log. Erik: I believe you are having a different error (ogg files) which is not part of this bug. Please reference bug 4723 to see if that matches your issues. if so, please add your comments to that bug. If you are able to reproduce this bug with WMA Lossless files, then comment on this bug and attach a log file
This bug has been fixed in the 7.3.0 release version of SqueezeCenter! Please download the new version from http://www.slimdevices.com/su_downloads.html if you haven't already. If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.
Unfortunately transcoded WMA Lossless is now worst than it's ever been. 1) Infinite loop, playing a song for anywhere from 20 to a minute and restarting the song. Once it gets into a loop it does it at the same time mark each time. The only way to fix it is to stop the song. Resetting the receiver start the song again and then it's fine and plays through. 2) Songs getting cut off short of finishing and moving to the next song. Most of the time with just a few seconds left in the song. I've also seen it do it half way through a song. This has been going on since 7.2 and now it's still present in 7.3.1 Sorry I didn't get back to you sooner but I've been pretty busy. I've turned on logging and will get some logs to you shortly.
Created attachment 4512 [details] Skip to next song half way through current I had the player paused for a bit. I then started it again and it played for a bit and then just moved to the next song.
Created attachment 4516 [details] Here's a sample of the song into a loop In this case I was remote streaming to squeezeplay, but it's the same thing that happens streaming the the duet receiver.
I have not experienced this problem in the past. Over the weekend I updated to 7.3.1. Today the problem has occurred twice. Server is running on a headless XP Pro SP3 system as a service. I'm listening to a playlist with song shuffle enabled. The playlist has not been modified in over a week. The playlist consists solely of flac content. I have a duet system, but am not currently using the controller. Both times that it occurred today, I replayed the file that was stuck without reproducing the issue. Both times it was looping between 3 to 5 seconds of the file. Not sure whether both files had silence at the repeating positions, but no sound was audible through my stereo while the web ui showed the playback position repeating. The playlist has been in constant rotation since it was created. I am fairly confident that the 7.3.1 update is the cause.
I was using 7.2.1 before I updated to 7.3.1 over the weekend.
Created attachment 4521 [details] Music stopped and player kept going This log file the song quit playing the the player actually showed it as still playing. The only issue is that squeezeplay was the player so maybe it was the problem being beta and all.
Created attachment 4535 [details] Song was playing perfectly fine and then just skips to next track Again this was using squeezeplay remotely.
(In reply to comment #28) > I was using 7.2.1 before I updated to 7.3.1 over the weekend. Sean, can you capture a log file showing the problem? player.source=info and network.protocol.slimproto=info would be useful.
(In reply to comment #30) > Created an attachment (id=4535) [details] > Song was playing perfectly fine and then just skips to next track > > Again this was using squeezeplay remotely. > Jeff, the logfiles are great but you need to provide more information with each one, such as which song was playing before the skip occurred, which was the next song, and what time the event occurred. It would be useful to know approximately how much of the song was lost when there was a premature skip. In some cases the logfiles are a bit short and I could do with some more context before the problem occurs.
(In reply to comment #25) > Created an attachment (id=4512) [details] > Skip to next song half way through current > > I had the player paused for a bit. I then started it again and it played for a > bit and then just moved to the next song. > How did you do the Pause: with the Pause button or the Power button? Sounds a bit like bug 9875.
(In reply to comment #30) > Created an attachment (id=4535) > Song was playing perfectly fine and then just skips to next track > > Again this was using squeezeplay remotely. I may have something in this case. It looks like the streaming connection got broken, presumably while paused. In this case the remains of the buffered data will be played out and then it will move on to the next song. The fix to bug 10407 would cause it to skip sooner in these circumstance but would not address the underlying problem that the streaming connection got broken. Do you only see this specific behaviour with SqueezePlay? Can you think of anything that would have caused the connection to get broken? What was SqueezePlay running on: a PC or the Controller?
(In reply to comment #26) > Created an attachment (id=4516) > Here's a sample of the song into a loop > > In this case I was remote streaming to squeezeplay, but it's the same thing that > happens streaming the the duet receiver. The fix to bug 10451 in 7.3.2 may be relevant but it would be really helpful to know which song got into a 'loop'.
Ok since it looks like 7.3.2 might address some of the issues I'm having, I'm installing it and will report back with more details as requested if the problems persist.
Created attachment 4544 [details] Audio quits and player starts looping in a song. This is a log where the song quit playing and just started looping. The time remaining would say 40 seconds and then it would go back to 1:30 remaining and countdown to 40 seconds remaining and loop again. No audio being played at all while in this loop. Song is: Feed My Frankenstein which is track 11 of 13 on that album. Only that album was in the playlist. I hit pause in squeezeplay after I encountered the loop.
(In reply to comment #31) > (In reply to comment #28) > > I was using 7.2.1 before I updated to 7.3.1 over the weekend. > > > Sean, can you capture a log file showing the problem? player.source=info and > network.protocol.slimproto=info would be useful. I had logging enabled all weekend but the hang hasn't occurred again. It has happened a total of 3 times for me. I will continue to keep the logging enabled. Also, there is some similarity between this bug and bug 9807.
Created attachment 4553 [details] Song just skipped to the next track Ok the song that was playing was Elected the time stamp was 14:25:10 or so. It played part way through the songs and then just jumped to the song "Is Anyone Home". Again using squeezeplay from work, I haven't had a lot of time at home to listen via the duet and receiver. Ignore the stuff that happened after, I was trying to rewind to get the names of the songs for you.
Created attachment 4554 [details] Another skip before song is complete Another skip log. It happened just seconds before I hit pause at the very end of the log.
Created attachment 4567 [details] player.source I don't have the skip problem, but when I press the FF/skip button several times in a row, the sound disappears and the song that is playing(I have WMA-LL only) repeats it self, still without a sound. My SBv3 is wired to my router and digital output is used. It doesn't matter wether I'm using SC or the remote(7.3.1 - 24372 @ Fri Dec 19 17:56:44 PST 2008). PC is also wired. After som testing at my part I think I've found the reason why this is happening to my system. Currently I'm contributing to the World Community Grid ( http://www.worldcommunitygrid.org ) and my CPUs are used at 100%. By disabling the WCG software and then pressing FF many times in a row all works as it should. Hope this info and my log file helps.
Thank you for the log. I cannot see any useful hints in it. Are you saying, in that specific case, that Rags to Riches played fine but then Nordstoga-Mademoiselle played silently?
Created attachment 4596 [details] server log no sound - playback time looping
It just happened again for me. I did a reset of my library last night. Came in this morning and had album shuffle enabled. Started adding albums to the playlist (one album at a time). The very first played to the end (Supersonic). The second song is Prove It. Web UI shows the play icon on Supersonic. Time left was cycling between 1 and 0, but now is just showing 0. Paused button is enabled, so it must think it is still playing.
(In reply to comment #42) > Thank you for the log. I cannot see any useful hints in it. Are you saying, in > that specific case, that Rags to Riches played fine but then > Nordstoga-Mademoiselle played silently? > No. Rags to Riches was silent. You can see that the log shows "Slim::Player::StreamingController::_NoOp" after this song, while Mademoiselle is followed by "Slim::Player::StreamingController::_CheckSync" wich means it works ok, I think. Song that were silent(not sure it is all): Vaya Con Dios-Ultimate Collection Disc 1-08-Nah Neh Nah.wma Chicago-Chicago Story- The Complete Greatest Hits 1967-2002 Disc 2-02-Saturday in the Park.wma Elvis Presley-Walk a Mile in My Shoes The Essential 70s Masters Disc 1-08-Rags to Riches.wma
Alan, is there anything QA can do to help with this bug? Changing the target so that this won't hold up 7.3.2
It would be great if QA could reproduce it.
I know 4 other people with wma lossless libraries. All have the same issue(s). I'd suggest creating a small wma lossless library and playing it. It's bound to happen to QA team sooner or later.
Alan: What looging if any do you want? what happens if QA can repo, then what?
Created attachment 4617 [details] AC/DC track-Ride on Squeezebox stops playing tracks in Random. This track will also not play if selected manually. Linked to posting at http://forums.slimdevices.com/showthread.php?p=383108&posted=1#post383108
Alan has a possible fix for some of these issues. QA to validate this fix. Steven notes that some of the Windows decoders may change depending on what version of Media Player is installed. Alan notes the real problem is it's difficult to repro. Steven speculates that using SOX to make flac files might generate desirably dodgy flac. If users have flac files that have ever caused this problem, we'd love to have more examples attached to this bug.
The AC/DC example appears to be a reproducible issue related to a corrupt file. The log that I submitted shows an occurrence of an intermittent problem - the flac file played back fine later.
Bug 10692 is certainly one of the symptoms being described here. It is not sure if there are more.
(In reply to comment #52) > The AC/DC example appears to be a reproducible issue related to a corrupt file. > The log that I submitted shows an occurrence of an intermittent problem - the > flac file played back fine later. > Sean: since you have a reproducible case, can you please try 7.3.2 nightly r24652 or higher. report in this bug if that version fix's the issue for you or not. Jeff: can you try also, if your original bug is still valid with 7.3.2
I've installed the latest 7.3.2 and will listen to some stuff tomorrow. I've told one friend who is having major issues with tracks playing partially and and then just restarting(Infinitate Loop). He's installing it as well.
Jeff: any update on 7.3.2 testing?
I'll be honest I haven't had allot of time with 7.3.2 It has worked well with squeezeplay the few times I tried it minus some connection drops which of course are unrelated. I'll be able to give it a good work out with the duet receiver this Saturday evening. Jeff
(In reply to comment #54) > Sean: since you have a reproducible case, can you please try 7.3.2 nightly > r24652 or higher. report in this bug if that version fix's the issue for you > or not. I don't have a reproducible case for this - it is extremely intermittent for me (I must have caused confusion by commenting on someone else's corrupt file). Nonetheless, I have installed 7.3.2 - 24695. No recurrences yet. For what I was experiencing, I think it would be safe to say that if a month passes without any recurrences, then my particular issue would be resolved.
Created attachment 4695 [details] Song just quits part way through and next starts I'm running 7.3.2 official release First song played via squeezeplay and it plays part way through and then just skips to the next song. I'll attach a log file. Song that was playing and cut short is "01 We Die Young.wma" by Alice in Chains the next song that started playing just before I hit pause was "02 Man in the box.wma". I have debug on now so even more information. Not sure if this is squeezeplay related or what? I've listened to maybe one album at home through the duet receiver and it played fine, but really means nothing since it's very intermittent anyway.
Ignore my last log. I'm losing it that song actually played through it just ends out of no where and seems like the song stopped prematurely.
I managed to find time to listen to 5 or so albums this weekend on the Duet. No issues at all. I'm running 7.3.2 production release. One buddy that was experiencing the same issues says this release has been running good for him as well. Not sure if it's time to mark it fixed yet but I think we are getting there.
I'll mark it fixed for now, but not closed. Please reopen if the error happens again.
Created attachment 4733 [details] no sound - repeating end of file sigh... it just happened - new server log attached with player.source=info and network.protocol.slimproto=info
comparing to the two logs I submitted, the latest one shows an underrun which is not in the first. So maybe a different problem with same symptoms? Maybe bug 9393 or bug 10680?
Sean, actually this problem is bug 10692. Alan.
Oh, and thanks for the log. It made it easy to confirm that.
This bug has been fixed in the 7.3.3 release version of SqueezeCenter! If you haven't already. please download the new version from http://www.logitechsqueezebox.com/support/download-squeezecenter.html If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.