Alarm not working with 8.3?

[vhenninot]

Hello all,
Despite 8.3.1 install yesterday, I had the fallback alarm this morning :-(

Edit : but after a whole week : no more fallback.

Vincent

[vhenninot]

Ok, i will install it shortly, meanwhile here are my LMS infos :

Logitech Media Server Version : 8.3.0- 1667251155 @ Fri 04 Nov 2022 09:16:39 AM CET
Nom d'hôte : raspberrypi
IP : 192.168.1.28
Port HTTP : 9000
SE : Debian - FR - utf8
Plate-forme : armv7l-linux
Version de Perl : 5.24.1 - arm-linux-gnueabihf-thread-multi-64int
Audio::Scan : 1.02
IO::Socket::SSL : 2.044
Version de la base de données : DBD::SQLite 1.58 (sqlite 3.22.0)

Edit : 8.3.1 installed, thanks for alarm improvements !! I will let you know in a few days if everything is working fine !

[vhenninot]

Hello all,
Many thanks for all tests and work ☺️

LMS is running on a raspberry, and I upgraded all radios with latest community firmware.

I’m using LMS alarm since 10 years and never had problems until i upgraded to 8.3.
I also confirm that i did not use material skin when the alarm bug started to occur.

I’m streaming from Deezer, I will try to use local music files only for next alarm to be sure that there is no network timeout…

Vincent

[SamY]

I had my first confirmed occurrence this morning of Michael's recent LMS change saving me from a missed alarm due to a "playerprefs" stop command, which originated from an Android instance of Material Skin running on my phone. Running LMS 8.3.1 Nov 28 build and Material Skin 4.0.1. Here is the log:

[22-12-06 08:30:00.0052] Slim::Utils::Alarm::sound (516) Alarm triggered for Bedroom pair
[22-12-06 08:30:00.0061] Slim::Utils::Alarm::sound (560) Sounding alarm
[22-12-06 08:30:00.0148] Slim::Utils::Alarm::sound (589) Current Power State: On
[22-12-06 08:30:00.0190] Slim::Utils::Alarm::pushAlarmScreensaver (1839) Attempting to push into alarm screensaver: . Current mode: INPUT.List
[22-12-06 08:30:00.0203] Slim::Utils::Alarm::sound (609) Current vol: 26 Alarm vol: 30
[22-12-06 08:30:00.0206] Slim::Utils::Alarm::sound (612) Changing volume from 26 to 30
[22-12-06 08:30:00.0250] Slim::Utils::Alarm::sound (622) Alarm playlist shufflemode: 0
[22-12-06 08:30:00.0280] Slim::Utils::Alarm::sound (628) Alarm playlist url: http://www.folkalley.com/membership.pls
[22-12-06 08:30:00.0809] Slim::Utils::Alarm::_setAlarmSubscription (1204) Adding alarm subscription
[22-12-06 08:30:00.0825] Slim::Utils::Alarm::sound (697) Scheduling time out in 3600 seconds
[22-12-06 08:30:00.0839] Slim::Utils::Alarm::_startStopTimeCheck (1880) 0 scheduled alarm(s)
[22-12-06 08:30:00.0842] Slim::Utils::Alarm::_startStopTimeCheck (1889) Stopping time checker task
[22-12-06 08:30:00.0846] Slim::Utils::Alarm::scheduleNext (1391) Asked to schedule next alarm for Bedroom pair
[22-12-06 08:30:00.0855] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 8:30:0 6/12/2022
[22-12-06 08:30:00.0857] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 8:30:0 6/12/2022
[22-12-06 08:30:00.0859] Slim::Utils::Alarm::findNextTime (471) Skipping..
[22-12-06 08:30:00.0861] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 8:30:0 7/12/2022
[22-12-06 08:30:00.0863] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 8:30:0 6/12/2022
[22-12-06 08:30:00.0866] Slim::Utils::Alarm::scheduleNext (1424) Next alarm is at 8:30:0 7/12/2022
[22-12-06 08:30:00.0868] Slim::Utils::Alarm::scheduleNext (1435) Scheduling alarm
[22-12-06 08:30:00.0870] Slim::Utils::Alarm::_startStopTimeCheck (1880) 1 scheduled alarm(s)
[22-12-06 08:30:00.0872] Slim::Utils::Alarm::_startStopTimeCheck (1884) Starting time checker task
[22-12-06 08:30:00.0910] Slim::Utils::Alarm::_alarmEnd (1970) _alarmEnd called with request: stop
[22-12-06 08:30:00.1038] Slim::Utils::Misc::msg (1325) Warning: [08:30:00.1012] (
  bless({
    _cb_args      => undef,
    _cb_enable    => 1,
    _cb_func      => undef,
    _clientid     => "cc:cc:4c:51:85:cb",
    _func         => sub { "???" },
    _isQuery      => 0,
    _langoverride => undef,
    _needClient   => 1,
    _params       => {},
    _request      => ["stop"],
    _requeststr   => "stop",
    _results      => {},
    _source       => "/93e24c28/slim/playerprefs/cc:cc:4c:51:85:cb|274||93e24c28|Mozilla/5.0 (Linux; Android 7.1.1; ZTE A2017U Build/NMF26V; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/107.0.5304.141 Mobile Safari/537.36",
    _status       => 10,
    _useixhash    => 0,
  }, "Slim::Control::Request"),
  "Alarm: ignored event",
) at /Slim/Utils/Alarm.pm line 1986.
[22-12-06 08:30:00.1041] Slim::Utils::Alarm::_alarmEnd (1987) Ignoring notification to subscriber

[SamY]

> When registering a notification callback for a particular player
> ($client), e.g.
> Code:
> --------------------
> Slim::Control::Request::subscribe( \&commandCallback, [['power', 'play', 'playlist', 'pause', 'mixer']], $client);
> --------------------
> is it expected/intended that the callback should also be invoked for
> other players that are synched with that player?

I don't think it is. But I'm not too familiar with that code. If you
check the client in your callback, would it be called for _all_ synched
players or only ever one, but not always the one to be expected?

The latter, it seems. The name of the player using the plugin is "Max2Play". The two other synced players are "DAC32" and "Bedroom pair". Here is a portion of the plugin's debug log when initiating playback from the DAC32 player. Note that none of the callback calls are from the plugin client itself.

[22-12-04 20:53:43.6701] Plugins::DenonAvpControl::Plugin::commandCallback (2172) *** DenonAvpControl: commandCallback() p0: playlist
[22-12-04 20:53:43.6704] Plugins::DenonAvpControl::Plugin::commandCallback (2173) *** DenonAvpControl: commandCallback() p1: jump
[22-12-04 20:53:43.6706] Plugins::DenonAvpControl::Plugin::commandCallback (2174) *** DenonAvpControl: commandCallback() p2: 
[22-12-04 20:53:43.6707] Plugins::DenonAvpControl::Plugin::commandCallback (2184) *** DenonAvpControl: commandCallback() Player: DAC32
[22-12-04 20:53:43.6709] Plugins::DenonAvpControl::Plugin::commandCallback (2187) *** DenonAvpControl: commandCallback() Unregistered player - bypassing 
[22-12-04 20:53:43.7314] Plugins::DenonAvpControl::Plugin::commandCallback (2172) *** DenonAvpControl: commandCallback() p0: playlist
[22-12-04 20:53:43.7316] Plugins::DenonAvpControl::Plugin::commandCallback (2173) *** DenonAvpControl: commandCallback() p1: open
[22-12-04 20:53:43.7318] Plugins::DenonAvpControl::Plugin::commandCallback (2174) *** DenonAvpControl: commandCallback() p2: 
[22-12-04 20:53:43.7320] Plugins::DenonAvpControl::Plugin::commandCallback (2184) *** DenonAvpControl: commandCallback() Player: Bedroom pair
[22-12-04 20:53:43.7322] Plugins::DenonAvpControl::Plugin::commandCallback (2187) *** DenonAvpControl: commandCallback() Unregistered player - bypassing 
[22-12-04 20:53:43.7471] Plugins::DenonAvpControl::Plugin::commandCallback (2172) *** DenonAvpControl: commandCallback() p0: playlist
[22-12-04 20:53:43.7474] Plugins::DenonAvpControl::Plugin::commandCallback (2173) *** DenonAvpControl: commandCallback() p1: open
[22-12-04 20:53:43.7476] Plugins::DenonAvpControl::Plugin::commandCallback (2174) *** DenonAvpControl: commandCallback() p2: 
[22-12-04 20:53:43.7478] Plugins::DenonAvpControl::Plugin::commandCallback (2184) *** DenonAvpControl: commandCallback() Player: Bedroom pair
[22-12-04 20:53:43.7479] Plugins::DenonAvpControl::Plugin::commandCallback (2187) *** DenonAvpControl: commandCallback() Unregistered player - bypassing 
[22-12-04 20:53:44.3219] Plugins::DenonAvpControl::Plugin::commandCallback (2172) *** DenonAvpControl: commandCallback() p0: playlist
[22-12-04 20:53:44.3228] Plugins::DenonAvpControl::Plugin::commandCallback (2173) *** DenonAvpControl: commandCallback() p1: newsong
[22-12-04 20:53:44.3233] Plugins::DenonAvpControl::Plugin::commandCallback (2174) *** DenonAvpControl: commandCallback() p2: 
[22-12-04 20:53:44.3239] Plugins::DenonAvpControl::Plugin::commandCallback (2184) *** DenonAvpControl: commandCallback() Player: Bedroom pair
[22-12-04 20:53:44.3243] Plugins::DenonAvpControl::Plugin::commandCallback (2187) *** DenonAvpControl: commandCallback() Unregistered player - bypassing 
[22-12-04 20:58:52.2127] Plugins::DenonAvpControl::Plugin::commandCallback (2172) *** DenonAvpControl: commandCallback() p0: playlist
[22-12-04 20:58:52.2130] Plugins::DenonAvpControl::Plugin::commandCallback (2173) *** DenonAvpControl: commandCallback() p1: open
[22-12-04 20:58:52.2131] Plugins::DenonAvpControl::Plugin::commandCallback (2174) *** DenonAvpControl: commandCallback() p2: 
[22-12-04 20:58:52.2133] Plugins::DenonAvpControl::Plugin::commandCallback (2184) *** DenonAvpControl: commandCallback() Player: Bedroom pair
[22-12-04 20:58:52.2135] Plugins::DenonAvpControl::Plugin::commandCallback (2187) *** DenonAvpControl: commandCallback() Unregistered player - bypassing 
[22-12-04 20:58:52.2209] Plugins::DenonAvpControl::Plugin::commandCallback (2172) *** DenonAvpControl: commandCallback() p0: playlist
[22-12-04 20:58:52.2212] Plugins::DenonAvpControl::Plugin::commandCallback (2173) *** DenonAvpControl: commandCallback() p1: open
[22-12-04 20:58:52.2214] Plugins::DenonAvpControl::Plugin::commandCallback (2174) *** DenonAvpControl: commandCallback() p2: 
[22-12-04 20:58:52.2216] Plugins::DenonAvpControl::Plugin::commandCallback (2184) *** DenonAvpControl: commandCallback() Player: Bedroom pair
[22-12-04 20:58:52.2218] Plugins::DenonAvpControl::Plugin::commandCallback (2187) *** DenonAvpControl: commandCallback() Unregistered player - bypassing 
[22-12-04 20:58:58.8217] Plugins::DenonAvpControl::Plugin::commandCallback (2172) *** DenonAvpControl: commandCallback() p0: playlist
[22-12-04 20:58:58.8221] Plugins::DenonAvpControl::Plugin::commandCallback (2173) *** DenonAvpControl: commandCallback() p1: newsong
[22-12-04 20:58:58.8224] Plugins::DenonAvpControl::Plugin::commandCallback (2174) *** DenonAvpControl: commandCallback() p2: 
[22-12-04 20:58:58.8227] Plugins::DenonAvpControl::Plugin::commandCallback (2184) *** DenonAvpControl: commandCallback() Player: Bedroom pair
[22-12-04 20:58:58.8230] Plugins::DenonAvpControl::Plugin::commandCallback (2187) *** DenonAvpControl: commandCallback() Unregistered player - bypassing

[gordonb3]

Well somewhat disappointing news today...

This morning my 7am Back Bedroom alarm failed to trigger...

[22-12-04 07:00:37.4903] Slim::Utils::Alarm::_alarmEnd (1970) _alarmEnd called with request: pause

_source => "/5cf52aae/slim/request|100||5cf52aae|SqueezePlay-baby/8.0.1-r16855 (armv5tejl)",

So this was a "request" from the player itself (I know that because it's the only player with firmware 16855), even though the player was not touched (I slept through till 9:30), but possibly relevant the last thing done on the player was to turn it off by it's power button and the player is configured to pause on power off.

The Radio in my bedroom is always operated locally. My GF actually even programs the alarms on the thing itself even after I showed her that it is much easier to do using the web frontend. She never missed any alarm but I can't really state that the issue discussed here never occurred. Over the years we have had several occurrences of the fallback alarm sounding but I always figured it was a WiFi issue and I can in fact state that after inspection later I did see a red WiFi icon but I don't really know if that was always the case. As I mentioned before my GF is a fairly light sleeper and she often responses to nothing more than the power on 'plop' sound, which I know because sometimes the paperboy wakes me about an hour earlier and I have not fully dozed back but even then I often miss the 'plop' but it is the 'bleep' from the poweroff button pressed without having heard any music prior to that. What I found during testing is that sometimes the Radio would turn on, then the alarmOff signal was logged and executed, and after that the backup alarm sounded. Intriguing as it is I really have no clue how many times that may have happened if she hadn't killed it just from hearing the device powering on.

[KeBul]

Well somewhat disappointing news today...

This morning my 7am Back Bedroom alarm failed to trigger...

[22-12-04 07:00:37.4903] Slim::Utils::Alarm::_alarmEnd (1970) _alarmEnd called with request: pause

_source => "/5cf52aae/slim/request|100||5cf52aae|SqueezePlay-baby/8.0.1-r16855 (armv5tejl)",

So this was a "request" from the player itself (I know that because it's the only player with firmware 16855), even though the player was not touched (I slept through till 9:30), but possibly relevant the last thing done on the player was to turn it off by it's power button and the player is configured to pause on power off.

There was a nice block of "ignoring self-created request" and "Ignoring unwanted notifications" - so handling of those seemed to be working fine

[22-12-04 07:00:00.0625] Slim::Utils::Alarm::_alarmEnd (1982) Ignoring self-created request
[22-12-04 07:00:00.0811] Slim::Utils::Alarm::_alarmEnd (1966) Ignoring unwanted notification: playlist stop
[22-12-04 07:00:10.2100] Slim::Utils::Alarm::_alarmEnd (1966) Ignoring unwanted notification: playlist pause
[22-12-04 07:00:37.2776] Slim::Utils::Alarm::_alarmEnd (1966) Ignoring unwanted notification: mode stop
[22-12-04 07:00:37.2836] Slim::Utils::Alarm::_alarmEnd (1966) Ignoring unwanted notification: playlist stop

So unlike my testing scenarios this wasn't a failure with a 'playerprefs' source directly involved, the system had not been restarted after Friday's testing, so I guess still had all the elements for trigger and failure embedded in there somewhere.

I've tried to put MaterialSkin vTest back on, but fails to load with "Can't locate Plugins/MaterialSkin/Plugin.pm in @INC", I think I'm doing the same as before for a manual plugin zip install, but I must be missing something because it's not having it.

Kev

[mherger]

Alarm not working with 8.3?

> When registering a notification callback for a particular player
> ($client), e.g.
> Code:
> --------------------
> Slim::Control::Request::subscribe( \&commandCallback, [['power', 'play', 'playlist', 'pause', 'mixer']], $client);
> --------------------
> is it expected/intended that the callback should also be invoked for
> other players that are synched with that player?

I don't think it is. But I'm not too familiar with that code. If you
check the client in your callback, would it be called for _all_ synched
players or only ever one, but not always the one to be expected?

[SamY]

I apologize if this post is off-topic but there is a chance that it might be related in a tangential way. About 3 months ago, a user of the Denon AVR plugin that I co-maintain reported strange behavior and provided a debug log illustrating it. It appeared that the problem was caused by the notification callback in the plugin being called for events from players other than those for which the plugin had registered (subscribed) the callback --- a condition that the code was completely unprepared to handle. Upon further research, it was discovered that the players in questions were ones that had been synched with a player that WAS registered for the events. I was able to easily recreate the situation and coded a fix (workaround?) that was fairly simple but added some cpu overhead --- add and maintain an array of player id's that are currently registered for the notifications and ignore any event callbacks from unregistered players. However, it seemed strange to me at the time that a problem with as common a use case as this should suddenly appear in a plugin that had been in fairly widespread use for over 10 years. I also had doubts about whether or not the behavior was intentional/correct after looking at the LMS doc pages. So here's my question:

When registering a notification callback for a particular player ($client), e.g.

Slim::Control::Request::subscribe( \&commandCallback, [['power', 'play', 'playlist', 'pause', 'mixer']], $client);

is it expected/intended that the callback should also be invoked for other players that are synched with that player?

[mherger]

Alarm not working with 8.3?

> Michael doesn't seem to believe Material is to blame - however, I have
> tested several times without Material installed and not had any alarm
> failures, but there's a caveat to that - the only way I can "reliably"
> induce failures during testing is by playing around and changing between
> players in Material - with no Material installed I can't do that.

Yes, I believe Material is only triggering an issue in LMS. But to
ignore _notifications_ in the alarm code seems the right thing to me.
They usually echo an action taken elsewhere. And we should only act on
actual input, not on notification (unless we subscribe to them, of course).

Why that introduces another issue, I have no clue. I remember Felix, and
old Squeezebox buddie of the time, who had to work on Alarm code at a
later stage, once mentioned he would never use it. The Alarm code
combined (LMS & firmware) was just too complicated, dealing with too
many possible failures...

> I think it's also worth noting that Michael started this thread and
> first reported he was having strange alarm issues early Aug, about 2
> weeks after your unsubscribe change. ~Insert smoking gun emoji here~

It was the return to school time - we hadn't used the alarm for several
weeks :-).

[KeBul]

Mainly to cleanup - I believe if you subscribe to a message you should unsubscribe when you no longer want to be informed. I think it was missing before due to a simple oversight.

Yeah sure, makes sense - wish I had a better understanding of all this (and a better capability to understand all this . )

Probably none, as Material has worked for years before this change.

So although not as tidy as you would like, a very low risk to revert that change.

I don't 100% believe Material is wrong, just that its behaviour triggers this issue in LMS.

Same place I've got to on this one.
There's been some good work done investigating though by yourself, Michael and gordonb3, but seems to be quite a few unanswered questions floating around, like yours on correct method to unsubscribe and gordon's on why the alarms always seem to start with an ignored self request "Stop"

Must say as well, while conversing with you - amazing job you've done on Material it's a lovely modern interface for LMS

Kev

[cpd73]

Checking back on your posts you say you introduced this method of unsubscribe in July 22 - what was the reason for that introduction?

Mainly to cleanup - I believe if you subscribe to a message you should unsubscribe when you no longer want to be informed. I think it was missing before due to a simple oversight.

What would be the potential impact of removing the unsubscribe (apart from maybe a fix for the alarm problem)?

Probably none, as Material has worked for years before this change.

Michael doesn't seem to believe Material is to blame - however, I have tested several times without Material installed and not had any alarm failures, but there's a caveat to that - the only way I can "reliably" induce failures during testing is by playing around and changing between players in Material - with no Material installed I can't do that.
Having said that, the testing I did with your MaterialSkin vTest, which had the unsubscribe removed, was quite extensive with lots of changing between players but no alarm failures were seen.

I don't 100% believe Material is wrong, just that its behavior triggers this issue in LMS.

[KeBul]

I'm going to release an update to Material soon. Should I remove the unsubscribe? Will that work-around the issue? Or should I leave Material as is and wait for the fix in LMS itself?

Hi Craig,

Checking back on your posts you say you introduced this method of unsubscribe in July 2022 - what was the reason for that introduction?
What would be the potential impact of removing the unsubscribe, apart from maybe a fix for the recent alarm problem(s)?

Michael doesn't seem to believe Material is to blame - however, I have tested extensively several times without Material installed and not had any alarm failures, but there's a caveat to that - the only way I can "reliably" induce failures during testing is by playing around and changing between players in Material - with no Material installed I can't do that.
Having said that, the testing I did with your MaterialSkin vTest, which had the unsubscribe removed, was quite extensive with lots of changing between players but no alarm failures were seen.

Michaels ignore 'playerprefs' fix in Alarm.pm resolves or at least drastically improves the problem where an alarm fails to trigger, but seems to have made another issue worse - "using a remote device to pause or stop an alarm". Although I agree with him that this is considerably less of an issue than an alarm failing to trigger, so we are in a better place at the moment.
The testing I've done for this issue also seems to indicate that without Material installed pause works every time, i.e. the alarm is successfully shutdown, once Material is installed the issue for me becomes prevalent, pause regularly fails to completely shutdown an alarm.
I haven't tested MaterialSkin vTest against this issue, if you would like me to do so let me know, but from what I'm seeing in the logs I would be surprised if removing the unsubscribe didn't also help with this.

In short, albeit from a pure testing evidential standpoint rather than in-depth knowledge of Material and LMS and the protocols/code/interactions between them etc.. I think that Material currently is a trigger for whatever is going wrong within the player and alarm handling, from the testing with MaterialSkin vTest, it looks like removing the unsubscribe either stops that trigger or greatly reduces it.

I think it's also worth noting that Michael started this thread and first reported he was having strange alarm issues early Aug, possibly not that long after your July unsubscribe change. ~Insert smoking gun emoji here~

Kev

[slartibartfast]

Yep seriously, worked for the first couple of alarms but then started failing each time. Just set up another test - failed 3 out of 4.

Not as reliable to fail as pause on a Radio, but definitely still happening.

Kev

I wonder why we don't see the same behaviour...

Sent from my Pixel 3a using Tapatalk

[cpd73]

I'm going to release an update to Material soon. Should I remove the unsubscribe? Will that work-around the issue? Or should I leave Material as is and wait for the fix in LMS itself?