Bug 9351 - Players unpause randomly
: Players unpause randomly
Status: CLOSED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Misc
: 7.2
: PC Windows Vista
: P2 normal (vote)
: 7.4.0
Assigned To: Alan Young
: CAT
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2008-08-31 12:17 UTC by Morgan
Modified: 2009-10-05 14:28 UTC (History)
6 users (show)

See Also:
Category: ---


Attachments
Log for random unpausing of player (339.43 KB, application/zip)
2009-04-14 12:15 UTC, Sami Sundell
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Morgan 2008-08-31 12:17:09 UTC
Over the past few weeks, several of my players have come off pause spontaneously.  Last night I was awakened twice, one at 2:10 AM by a Squeezebox 2 (Firmware 112) playing a Slacker stream, then I was awakened a second time by a second Squeezebox 2 (also 112) playing a different Slacker Stream.  This has happened to me before, although usually with a SqueezeCenter hosted mp3 stream playing.  This has occurred on both 7.1 and 7.2 running on a Vista Operating System.

There were no corresponding entries on the log files.
Comment 1 James Richardson 2008-09-04 11:28:53 UTC
Morgan:

do you have these players synced?

What 3rd party plugins do you have enabled
Comment 2 y360 2008-09-04 13:42:53 UTC
Perhaps SC access is not protected behind a firewall ?
Comment 3 Morgan 2008-09-05 03:24:39 UTC
(In reply to comment #2)
> Perhaps SC access is not protected behind a firewall ?
> 

The SC is behind a firewall, and I have port forwarding disabled for port 9000.  Wireless router access is WPA 2.  While I could not with absolute certainty rule out a dedicated hacking attempt, it would seem very odd that someone would go through the trouble to unpause a single player.  If I was being malicious, I would crank the volumes to full, and start up all 8 zones!
Comment 4 Morgan 2008-09-05 03:28:59 UTC
(In reply to comment #1)
> Morgan:
> 
> do you have these players synced?
> 
> What 3rd party plugins do you have enabled
> 

At the moment of the latest "unpause", the players were not synced.


There are no third party plug-ins installed.
Comment 5 Morgan 2008-09-05 03:31:44 UTC
One other comment - if you check the forums, there are several cases of this condition happening with others.
Comment 6 James Richardson 2008-09-08 10:49:52 UTC
Andy: what logs should we turn on to attempt to track this
Comment 7 James Richardson 2008-09-08 10:56:18 UTC
bug 7702 maybe related
Comment 8 James Richardson 2008-09-08 10:57:20 UTC
Morgan:  Can you please provide the forum links in this bug? then link this bug to those forum posts.
Comment 9 Jim McAtee 2008-09-08 11:01:08 UTC
Please see bug 9221.  I have a theory that SC is sending Pause commands to players at various times, with the thinking that it should be a benign operation if the player is stopped.  Instead, it causes the player to begin playing.  Encourage someone to merge the simple fix from bug 9221 into the 7.2 trunk.
Comment 10 James Richardson 2008-09-17 06:37:55 UTC
(In reply to comment #9)
> Please see bug 9221.  I have a theory that SC is sending Pause commands to
> players at various times, with the thinking that it should be a benign
> operation if the player is stopped.  Instead, it causes the player to begin
> playing.  Encourage someone to merge the simple fix from bug 9221 into the 7.2
> trunk.
> 

Andy: can you have a look and comment appropriately?
Comment 11 Andy Grundman 2008-09-17 07:21:57 UTC
Not sure what to do here, that fix is already part of 7.2.1.

If you want to try to get a log, enable player.source.
Comment 12 Chris Owens 2008-10-02 13:50:17 UTC
Since we haven't yet reproduced this in-house I'm moving it to 7.3
Comment 13 Morgan 2008-10-13 13:02:28 UTC
Hi, although very infrequent, this happened to me again on two different occasions.

1) Three SBR started up simultaneously at around 1:00 AM.  They were all playing different sources; one Pandora, one Slacker, one local SC mp3.  All three were connect to SC.

2) Last night at around 11:00 PM a SBR unpaused on a Rhapsody stream (via SC).

Very weird, very odd!  Kinda creepy.  

There seems to be no way to forcibly reproduce this.  I had gone a good month without this happening, then hit twich within a few days.  

This has happened in the middle of the day, too.  

Doubt ghots are involved :)
Comment 14 Andy Grundman 2008-10-14 08:43:04 UTC
*** Bug 9610 has been marked as a duplicate of this bug. ***
Comment 15 Andy Grundman 2008-10-14 08:44:04 UTC
Can anyone experiencing this problem please upgrade to 7.3 and try to reproduce it there?
Comment 16 Andy Grundman 2008-10-29 07:37:27 UTC
Anyone?  Assigning back to QA.
Comment 17 James Richardson 2008-11-04 13:51:37 UTC
QA is still unable to reproduce this.  Moving to monitor until such time someone can come up with a reproducible case to test against.
Comment 18 Sami Sundell 2009-04-14 11:20:23 UTC
Just a note. I'm using the development version of SqueezeCenter (at the moment I'm running 7.4 - 25912) and this problem still exists. The hardware is a single Squeezebox Duet, server is running Debian on x86-64.

Las week both the Receiver and Controller were powered off, I was away on a vacation - and for some reason the Receiver had woken up and played for two days striaght, about 500 songs.

Today, while I was at work, the Receiver had unpaused at 16:40, played for about three hours until it had stopped while trying to play a non-existing music file.

I can provide some logs about it. I set all the player-related logs to debug, but they don't tell anything to me. First it has heartbeat with status "PAUSED-STREAMOUT", then it just starts to play a file.

This seems to happen all too often, so I can probably add more detail into logging and see if something turns up elsewhere.
Comment 19 Alan Young 2009-04-14 11:44:23 UTC
Sami, please attach a (zipped/gzipped) logfile. As well as the player logging, network.protocol.slimproto is useful, usually at level info.
Comment 20 Sami Sundell 2009-04-14 12:15:40 UTC
Created attachment 5117 [details]
Log for random unpausing of player

I just grabbed the file, so there's quite a lot of fluff in it. The playing starts around 16:40. I'll add that network logging as well and see what happens.
Comment 21 Alan Young 2009-04-15 01:12:41 UTC
Thanks. That was very helpful - I don;'t need any more logs. I see the problem. There are a couple of positions in the state table where playing can start from a paused state where that probably should not happen.

In this specific case, which is probably the case which hits most people, the stream that is paused gets a connection break - that is, the TCP connection breaks unexpectedly - and this causes the current track to be aborted and the next track to start. I guess that is wrong.

I'm surprised that this was originally seen in 7.2, as this is a bug in the 7.3-introduced state table. I suppose that piece of the state table could just have been copying the 7.2 behaviour.

I have set the target to 7.4 but the bug-meeting can review and decide if they want it in 7.3.3. My guess is that this is pretty low risk but it is in an area of state-management where there have been a couple of problems in the past.
Comment 22 Alan Young 2009-04-15 01:19:05 UTC
On further review I can see how it would have done this for SC7.2 and earlier for direct-streaming of remote streams. It is an easy fix for 7.3.
Comment 23 Alan Young 2009-04-15 07:21:07 UTC
Change 25966 in 7.4.

My best guess is that would only have happened with 7.2 and before for remote streams but for 7.3 it could also happen for local streams (although the chance of the connection breaking is less in that case).
Comment 24 Sami Sundell 2009-04-15 11:35:20 UTC
Alrighty then, thanks for prompt reply. 8) I'll be upgrading as soon as the Debian package presents itself.
Comment 25 James Richardson 2009-10-05 14:28:43 UTC
This bug has been marked as fixed in the 7.4.0 release version of SqueezeBox Server!
    * SqueezeCenter: 28672
    * Squeezebox 2 and 3: 130
    * Transporter: 80
    * Receiver: 65
    * Boom: 50
    * Controller: 7790
    * Radio: 7790  

Please see the Release Notes for all the details: http://wiki.slimdevices.com/index.php/Release_Notes

If you haven't already, please download and install the new version from http://www.logitechsqueezebox.com/support/download-squeezebox-server.html

If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.