Alarm not working with 8.3?

[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

[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.

[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

[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

[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

[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,
Despite 8.3.1 install yesterday, I had the fallback alarm this morning :-(

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

Vincent