Bug 18053 - Once a connected SB has "played", Server does not sleep even if SB is turned off (soft off)
: Once a connected SB has "played", Server does not sleep even if SB is turned ...
Status: RESOLVED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Sleep
: 7.8.0
: PC Windows 7
: -- normal with 3 votes (vote)
: 7.7.x
Assigned To: Michael Herger
http://forums.slimdevices.com/showthr...
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2013-09-20 14:57 UTC by David Gardner
Modified: 2013-09-24 15:58 UTC (History)
2 users (show)

See Also:
Category: ---


Attachments
Server log showing problem (1.23 KB, application/octet-stream)
2013-09-24 10:17 UTC, David Gardner
Details
Server log with default clock (746 bytes, application/octet-stream)
2013-09-24 10:40 UTC, David Gardner
Details

Note You need to log in before you can comment on or make changes to this bug.
Description David Gardner 2013-09-20 14:57:02 UTC
Since 7.7.3 (7.7.3 is not an option in the Version box above), the above behaviour is noticed. Seems to affect all (or at least most) SBs - Touch, Radio, Duet and Classic at least have been tested.

7.7.3 and 7.8 are affected, reverting to 7.7.2 fixes the problem.

It is suspected that the chance to improve Mac sleep behaviour (https://bugs-archive.lyrion.org/show_bug.cgi?id=8141) is responsible, as it was implemented as a cross platform patch in 7.7.3.

These threads discuss the issue:

http://forums.slimdevices.com/showthread.php?94898-7-7-2-PC-won-t-go-to-Sleep-anymore&p=756702&viewfull=1#post756702 (Title is confusing, thread was "hijacked" by a different user with the 7.7.3 problem)

http://forums.slimdevices.com/showthread.php?99486-Message-on-Touch-Screen-Says-Update-to-7-7-3-r16662&p=757199&viewfull=1#post757199 (also, a "hyjacked" thread!)
Comment 1 David Gardner 2013-09-20 15:56:26 UTC
Should, of course, be "the change to improve Mac sleep behaviour" above.
Comment 2 George Perkins 2013-09-21 23:19:08 UTC
Me too.
Comment 3 Michael Herger 2013-09-23 04:01:10 UTC
Could you please enable debugging for plugin.preventstandby, cause the issue you are seeing, then attach your server.log file here? What Windows versions are you using?
Comment 4 f3cea2b6 2013-09-23 16:36:50 UTC
*** This bug has been confirmed by popular vote. ***
Comment 5 David Gardner 2013-09-24 10:17:22 UTC
Created attachment 7704 [details]
Server log showing problem

Find attached server log.

At around 10:07 the "Kitchen SB" (a Squeezebox Touch) was unplugged at the mains. You can see standby was allowed around 10:17.

At 10:19 the Touch was plugged in, but immediately it booted it was turned off using the top left button on the touch screen. The SB was left displaying the daylight clock.

You can see that at random intervals the server believes the SB has become busy, although at no time was it touched and the clock continued to be displayed throughout.

I am now going to retest with the default clock, although since this problem has been reported with other types of SB, it seems unlikely that this is the cause.
Comment 6 Michael Herger 2013-09-24 10:39:34 UTC
Here's the condition leading to the busy message you're seeing:

if ( $client->isUpgrading() || $client->isPlaying() || (Time::HiRes::time() - $client->lastActivityTime <= INTERVAL) ) {...}
 
lastActivityTime would be set in any of the following cases:

- interaction with the player (IR, touch)
- a connection to the web UI, CLI, JSON/RPC interface or over cometd (any controller app)
- an alarm is being fired

Are you sure you don't have any computer accessing the web UI, smart phone app running etc.? Please note that iPeng et al. can stay active in the background.

This code is platform independent, and the OSX version had some thorough testing when we were working on it. I would be surprised if this was broken on Windows only.
Comment 7 David Gardner 2013-09-24 10:40:19 UTC
Created attachment 7705 [details]
Server log with default clock

Attached is the continuation of the previous log.

I uninstalled the daylight clock and restarted the Touch at about 11:19. The Touch was left off and with the regular digital clock displayed.

You can see that the server still believes the Touch goes active at random times even though at all times it remains untouched and displaying the digital clock.
Comment 8 David Gardner 2013-09-24 11:24:52 UTC
Thanks for looking at this Michael.

There has definitely been no user interaction with the Touch. There are no alarms.

I did have Squeezepad installed on 2 iPads but after I turned both of them "hard off" (long press of on/off button) the problem remained.

I do have a fairly complex network. It is hard to be 100% sure nothing "gropes" the Touch! As well as the, now off, iPads, it consists of:

- An SB Radio. However, I unplugged this from the mains and the problem remained
- 2 PCs, only the LMS server is on, but the other can be woken by WOL
- 2 DLNA capable TVs, but not ever linked in anyway with the Touch. They are able to discover the LMS server, when the relevant media playback app is used (it is not at present), but there is nothing to suggest they are at all involved.
- I still have my iPhone on, but it has no SB control app installed
- My AVR is also a DLNA player, but it is "soft off"/on standby
- A Femtocell (sure that should not be doing anything)
- TiVo


I'm pretty confident none of these are doing anything with the Touch. Certainly none are CONFIGURED to do so. Most importantly, this problem does not occur with 7.7.2, so if LMS is now sensitive to some network activity affecting the Touch, it   does not need to be and it is a regression on previous behaviour.
Comment 9 David Gardner 2013-09-24 12:31:58 UTC
Last bit of testing. All but the Touch, LMS server and Femtocell (tricky to disconnect) were removed from the network, my phone's Wifi was turned off, and still the problem remained.

So it does seem it some activity within the Touch itself that is causing the activity counter to reset. This is not just a Touch issue, though. Once the Radio has been restarted or used after the installation of 7.7.3 it shows the same log entries when soft-off.

Interestingly, maybe, the log entries did not appear when the Radio was soft-off and had NOT been used or restarted since the installation of 7.7.3, even though it was pointed at the same LMS server. In some way the activity inhibiting standby does not self-initiate after the server is upgraded. The SB has to be manually used or restarted first.
Comment 10 Michael Herger 2013-09-24 12:36:25 UTC
Ok, I double checked the changes since 7.7.2. The only difference there is is the lastActivityTime check newly added in 7.7.3. Would you be able to edit Slim/Plugin/PreventStandby/Plugin.pm? Around line 177 you would find the aforementioned condition. Please simplify this to the following:

if ( $client->isUpgrading() || $client->isPlaying() ) {}

Then restart your server and try again. Would it now work?
Comment 11 Michael Herger 2013-09-24 13:25:02 UTC
One more thing... I was able to reproduce this. What I'm seeing is that the UPnP plugin is causing this random activity. Has nothing to do with the player itself.

Can you make sure you disable the UPnP plugin (unless you need it)?
Comment 12 Michael Herger 2013-09-24 13:41:53 UTC
Oh well... it seems Windows Media Player doesn't give up too soon. It's still pinging my LMS though Explorer doesn't see it any more. It might take a while until it gives up (if at all - we'll see).
Comment 13 David Gardner 2013-09-24 14:31:53 UTC
I'm testing with uPnP disabled now. Looking promising but want to wait a while longer to be sure. I'll get back to you.
Comment 14 David Gardner 2013-09-24 14:37:23 UTC
Michael, once done with uPnP, I can try editing the plugin if it's still useful. On the other hand, if the culprit is known, maybe its a redundant test - we know that activity test is causing the problem. Please let me know.
Comment 15 Michael Herger 2013-09-24 15:58:03 UTC
UPnP was it. I added a line to not take those requests into account when tracking client activity.