Alarm not stopping reliably after set duration

[MichaelSch]

Since some time I am experiencing the issue that my alarm does not stop after the set duration reliably - sometimes it's working and sometimes it's not.

I am running the latest nightly of LMS 8.3 and today I set the alarm logging to debug and set 2 dayly recurring alarms for 10:40 and 10:50 and the duration to 2 minutes. While the first alarm stopped after 2 minutes the second did not.

[22-09-26 10:35:26.8423] Slim::Utils::Alarm::save (1017) Saving alarm.
[22-09-26 10:35:26.8450] Slim::Utils::Alarm::save (1037) Alarm saved with id c6da5854 Rescheduling alarms...
[22-09-26 10:35:26.8466] Slim::Utils::Alarm::scheduleNext (1391) Asked to schedule next alarm for pi-schlafzimmer
[22-09-26 10:35:26.8479] Slim::Utils::Alarm::scheduleNext (1397) Previous scheduled alarm wasn't triggered.  Clearing nextAlarm and killing timer
[22-09-26 10:35:26.8498] Slim::Utils::Alarm::_startStopTimeCheck (1880) 0 scheduled alarm(s)
[22-09-26 10:35:26.8511] Slim::Utils::Alarm::_startStopTimeCheck (1889) Stopping time checker task
[22-09-26 10:35:26.8533] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 10:40:0 26/9/2022
[22-09-26 10:35:26.8547] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 6:40:0 26/9/2022
[22-09-26 10:35:26.8561] Slim::Utils::Alarm::scheduleNext (1424) Next alarm is at 10:40:0 26/9/2022
[22-09-26 10:35:26.8575] Slim::Utils::Alarm::scheduleNext (1435) Scheduling alarm
[22-09-26 10:35:26.8589] Slim::Utils::Alarm::_startStopTimeCheck (1880) 1 scheduled alarm(s)
[22-09-26 10:35:26.8601] Slim::Utils::Alarm::_startStopTimeCheck (1884) Starting time checker task
[22-09-26 10:40:00.0047] Slim::Utils::Alarm::sound (516) Alarm triggered for pi-schlafzimmer
[22-09-26 10:40:00.0064] Slim::Utils::Alarm::sound (560) Sounding alarm
[22-09-26 10:40:00.0107] Slim::Utils::Alarm::sound (589) Current Power State: On
[22-09-26 10:40:00.0132] Slim::Utils::Alarm::pushAlarmScreensaver (1839) Attempting to push into alarm screensaver: . Current mode: INPUT.List
[22-09-26 10:40:00.0148] Slim::Utils::Alarm::sound (609) Current vol: 25 Alarm vol: 25
[22-09-26 10:40:00.0163] Slim::Utils::Alarm::sound (622) Alarm playlist shufflemode: 0
[22-09-26 10:40:00.0189] Slim::Utils::Alarm::sound (628) Alarm playlist url: http://opml.radiotime.com/Tune.ashx?id=s18018&formats=aac,ogg,mp3&partnerId=16&serial=04a73375a8f9c9d8fdd8b10382153477
[22-09-26 10:40:00.0539] Slim::Utils::Alarm::_setAlarmSubscription (1204) Adding alarm subscription
[22-09-26 10:40:00.0567] Slim::Utils::Alarm::sound (697) Scheduling time out in 120 seconds
[22-09-26 10:40:00.0587] Slim::Utils::Alarm::_startStopTimeCheck (1880) 0 scheduled alarm(s)
[22-09-26 10:40:00.0600] Slim::Utils::Alarm::_startStopTimeCheck (1889) Stopping time checker task
[22-09-26 10:40:00.0617] Slim::Utils::Alarm::scheduleNext (1391) Asked to schedule next alarm for pi-schlafzimmer
[22-09-26 10:40:00.0634] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 10:40:0 26/9/2022
[22-09-26 10:40:00.0648] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 10:40:0 26/9/2022
[22-09-26 10:40:00.0661] Slim::Utils::Alarm::findNextTime (471) Skipping..
[22-09-26 10:40:00.0675] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 10:40:0 27/9/2022
[22-09-26 10:40:00.0688] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 10:40:0 26/9/2022
[22-09-26 10:40:00.0703] Slim::Utils::Alarm::scheduleNext (1424) Next alarm is at 10:40:0 27/9/2022
[22-09-26 10:40:00.0715] Slim::Utils::Alarm::scheduleNext (1435) Scheduling alarm
[22-09-26 10:40:00.0729] Slim::Utils::Alarm::_startStopTimeCheck (1880) 1 scheduled alarm(s)
[22-09-26 10:40:00.0742] Slim::Utils::Alarm::_startStopTimeCheck (1884) Starting time checker task
[22-09-26 10:40:00.0841] Slim::Utils::Alarm::_alarmEnd (1970) _alarmEnd called with request: stop
[22-09-26 10:40:00.0857] Slim::Utils::Alarm::_alarmEnd (1981) Ignoring self-created request
[22-09-26 10:40:03.2770] Slim::Utils::Alarm::_alarmEnd (1966) Ignoring unwanted notification: playlist pause
[22-09-26 10:41:30.0528] Slim::Utils::Alarm::_checkPlaying (1115) Checking whether client is playing for alarm c6da5854
[22-09-26 10:41:30.0546] Slim::Utils::Alarm::_checkPlaying (1122) Current playmode: play
[22-09-26 10:42:00.0589] Slim::Utils::Alarm::_timeout (1162) Alarm c6da5854 ending automatically due to timeout
[22-09-26 10:42:00.0760] Slim::Utils::Alarm::popAlarmScreensaver (1866) Attempting to pop alarm screensaver.  Current mode: INPUT.List
[22-09-26 10:42:01.0759] Slim::Utils::Alarm::__ANON__ (896) Restoring pre-alarm volume level: 25
[22-09-26 10:42:01.0779] Slim::Utils::Alarm::__ANON__ (901) Restoring pre-alarm shuffle mode: 0
[22-09-26 10:42:01.0799] Slim::Utils::Alarm::__ANON__ (905) Restoring pre-alarm power state: on
[22-09-26 10:42:29.1886] Slim::Utils::Alarm::save (1017) Saving alarm.
[22-09-26 10:42:29.1958] Slim::Utils::Alarm::save (1037) Alarm saved with id c6da5854 Rescheduling alarms...
[22-09-26 10:42:29.1969] Slim::Utils::Alarm::scheduleNext (1391) Asked to schedule next alarm for pi-schlafzimmer
[22-09-26 10:42:29.1980] Slim::Utils::Alarm::scheduleNext (1397) Previous scheduled alarm wasn't triggered.  Clearing nextAlarm and killing timer
[22-09-26 10:42:29.1993] Slim::Utils::Alarm::_startStopTimeCheck (1880) 0 scheduled alarm(s)
[22-09-26 10:42:29.2003] Slim::Utils::Alarm::_startStopTimeCheck (1889) Stopping time checker task
[22-09-26 10:42:29.2018] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 10:45:0 26/9/2022
[22-09-26 10:42:29.2029] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 10:40:0 26/9/2022
[22-09-26 10:42:29.2040] Slim::Utils::Alarm::scheduleNext (1424) Next alarm is at 10:45:0 26/9/2022
[22-09-26 10:42:29.2049] Slim::Utils::Alarm::scheduleNext (1435) Scheduling alarm
[22-09-26 10:42:29.2060] Slim::Utils::Alarm::_startStopTimeCheck (1880) 1 scheduled alarm(s)
[22-09-26 10:42:29.2069] Slim::Utils::Alarm::_startStopTimeCheck (1884) Starting time checker task
[22-09-26 10:45:00.0047] Slim::Utils::Alarm::sound (516) Alarm triggered for pi-schlafzimmer
[22-09-26 10:45:00.0064] Slim::Utils::Alarm::sound (560) Sounding alarm
[22-09-26 10:45:00.0102] Slim::Utils::Alarm::sound (589) Current Power State: On
[22-09-26 10:45:00.0128] Slim::Utils::Alarm::pushAlarmScreensaver (1839) Attempting to push into alarm screensaver: . Current mode: INPUT.List
[22-09-26 10:45:00.0144] Slim::Utils::Alarm::sound (609) Current vol: 25 Alarm vol: 25
[22-09-26 10:45:00.0159] Slim::Utils::Alarm::sound (622) Alarm playlist shufflemode: 0
[22-09-26 10:45:00.0183] Slim::Utils::Alarm::sound (628) Alarm playlist url: http://opml.radiotime.com/Tune.ashx?id=s18018&formats=aac,ogg,mp3&partnerId=16&serial=04a73375a8f9c9d8fdd8b10382153477
[22-09-26 10:45:00.0742] Slim::Utils::Alarm::_setAlarmSubscription (1204) Adding alarm subscription
[22-09-26 10:45:00.0770] Slim::Utils::Alarm::sound (697) Scheduling time out in 120 seconds
[22-09-26 10:45:00.0790] Slim::Utils::Alarm::_startStopTimeCheck (1880) 0 scheduled alarm(s)
[22-09-26 10:45:00.0803] Slim::Utils::Alarm::_startStopTimeCheck (1889) Stopping time checker task
[22-09-26 10:45:00.0821] Slim::Utils::Alarm::scheduleNext (1391) Asked to schedule next alarm for pi-schlafzimmer
[22-09-26 10:45:00.0838] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 10:45:0 26/9/2022
[22-09-26 10:45:00.0854] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 10:45:0 26/9/2022
[22-09-26 10:45:00.0867] Slim::Utils::Alarm::findNextTime (471) Skipping..
[22-09-26 10:45:00.0897] Slim::Utils::Alarm::findNextTime (461) Potential next time found: 10:45:0 27/9/2022
[22-09-26 10:45:00.0915] Slim::Utils::Alarm::findNextTime (466) Last alarm due: 10:45:0 26/9/2022
[22-09-26 10:45:00.0933] Slim::Utils::Alarm::scheduleNext (1424) Next alarm is at 10:45:0 27/9/2022
[22-09-26 10:45:00.0947] Slim::Utils::Alarm::scheduleNext (1435) Scheduling alarm
[22-09-26 10:45:00.0962] Slim::Utils::Alarm::_startStopTimeCheck (1880) 1 scheduled alarm(s)
[22-09-26 10:45:00.0989] Slim::Utils::Alarm::_startStopTimeCheck (1884) Starting time checker task
[22-09-26 10:45:00.1049] Slim::Utils::Alarm::_alarmEnd (1970) _alarmEnd called with request: stop
[22-09-26 10:45:00.1067] Slim::Utils::Alarm::_alarmEnd (1992) Stopping alarm
[22-09-26 10:45:00.1101] Slim::Utils::Alarm::popAlarmScreensaver (1866) Attempting to pop alarm screensaver.  Current mode: INPUT.List
[22-09-26 10:45:01.1095] Slim::Utils::Alarm::__ANON__ (901) Restoring pre-alarm shuffle mode: 0
[22-09-26 10:45:01.1102] Slim::Utils::Alarm::__ANON__ (905) Restoring pre-alarm power state: on

The last line is the last record as of 11:00. As you can see there's this line for the first alarm which is missing for the second: [22-09-26 10:42:00.0589] Slim::Utils::Alarm::_timeout (1162) Alarm c6da5854 ending automatically due to timeout In both cases it says Scheduling time out in 120 seconds.

[mw9]

Also, compare these lines when firing the first alarm:

[22-09-26 10:40:00.0742] Slim::Utils::Alarm::_startStopTimeCheck (1884) Starting time checker task
[22-09-26 10:40:00.0841] Slim::Utils::Alarm::_alarmEnd (1970) _alarmEnd called with request: stop
[22-09-26 10:40:00.0857] Slim::Utils::Alarm::_alarmEnd (1981) Ignoring self-created request

With these lines when firing the second alarm:

[22-09-26 10:45:00.0989] Slim::Utils::Alarm::_startStopTimeCheck (1884) Starting time checker task
[22-09-26 10:45:00.1049] Slim::Utils::Alarm::_alarmEnd (1970) _alarmEnd called with request: stop
[22-09-26 10:45:00.1067] Slim::Utils::Alarm::_alarmEnd (1992) Stopping alarm

I'm not sure what it means, or if it is, indeed, relevant. But intriguing, perhaps.

[mherger]

@MichaelSch are you using the Material skin? And do you still see this with the 8.3.1 nightly build (http://downloads-origin.slimdevices.com/nightly/?ver=8.3). There have been regressions in 8.3's alarm handling. It's not 100% clear to me yet what the issue really is, and what triggered the new behaviour. Some even claim it's got to do with Material, rather than 8.3.

But anyway: 8.3.1 mitigates some of the alarm issue(s). In particular the case @mw9 mentions should have been addressed.

[MichaelSch]

Hi, yes I am using Material Skin. But to be honest the problem vanished a while ago. I don't know why but I haven't experienced not stopping alarms for quite a while now. Thanks for the update - I suggest to close this ticket and reopen it in case the behaviour reappears.

[michaelherger]

Thanks for the update! Just in case: here's the lengthy forum thread dealing with alarm issues in 8.3 - http://forums.slimdevices.com/showthread.php?t=116649