I have used Mode Manager for over a year, but it has suddenly started misfiring. Below is the log from today:
2022-01-03 17:12:00.124 infoNot setting mode to Evening due to wrong day (2). Current mode is Day.
Setup:
I have mode manager set to Earlier of Sunset-15 or 1800hrs for M-F. On some days it will trigger the Made change correctly, on others it does not. Today is Monday and it did trigger, but obviously from the above, it fired at the correct time but did not execute the mode change.
Resolution attempts so far:
I had no issues until about a month ago. i do regular updates, but i cannot identify when this started exactly. I suspect it was around the 2.3.0.112 update applied in late November.
The HE has been restarted several times since then with each update. Currently running 2.3.0.124
I deleted the original Mode Manager. I then created an identical item from scratch.
In Summary, the shift from Day to Evening mode at the proscribed time works on some days but not on others. This errant behavior is not observed at the shift from Morning to Day mode, which is always at 0900hrs M-S.
Today is Tuesday and the Mode Manager trigger at Sunset -15 and processed the change. HEre is the log entry
2022-01-04 17:13:00.223 [info] Mode set to Evening from Day
THe Mode Manager triggered at the proper time and fired the mode change correctly on Wed, Thurs, and Friday.
Today, Saturday it did not behave as designed. Below is the log entry
2022-01-08 17:16:00.063 [info]Not setting mode to Evening due to wrong day (7). Current mode is Day.
I have a suspicion that I can't test until sunset today. You could help in one way: Open Mode Manager and hit Done. See if it works correctly today or not. If it does work, that would point the finger at it failing on subsequent days after first set up.
I believe i have done that... probably several times in trying to debug this issue,
And on Sunday, yesterday it worked. Here is the log
2022-01-09 17:17:00.549 [info] Mode set to Evening from Day
For clarity, after i originally noticed this behaviour, i have edited and clicked Done on many occasions, and i even deleted the rule and recreated it from scratch thinking perhaps it had been corrupted in the release update.
I will post todays results of success or fail when it happens at 1717hrs.
The scheduler shows an entry for this App at the correct time. It does seem to always have a correct entry scheduled for the app to run, but the app seems to fail on the logic.
[Mode Manager Day] () false timeHandlerNew 2022-01-10 17:18:00 EST
I have caught it in the act of failing! What it's doing is failing to schedule both events. It has to reschedule every day, since sunset changes every day. Now that I've seen it fail, I can track it down and fix it.
Maybe this will help. Mine seems to schedule both, but the app's logic is not processing correctly. Here are the logs for Mode Manager for the past several days.
2022-01-09 18:00:00.050 info Not setting mode to Evening due to wrong day (1). Current mode is Evening.
2022-01-09 17:17:00.549 info Mode set to Evening from Day
2022-01-09 09:00:00.090 info Mode set to Day from Morning
2022-01-09 05:30:00.069 info Not setting mode to Morning due to wrong day (1). Current mode is Night.
2022-01-08 18:00:00.066 info Not setting mode to Evening due to wrong day (7). Current mode is Evening.
2022-01-08 17:16:00.063 info Not setting mode to Evening due to wrong day (7). Current mode is Day.
2022-01-08 09:00:00.155 info Mode set to Day from Morning
2022-01-08 07:00:00.211 info Mode set to Morning from Night
2022-01-08 05:30:00.101 info Not setting mode to Morning due to wrong day (7). Current mode is Night.
2022-01-07 18:30:00.063 info Not setting mode to Evening due to wrong day (6). Current mode is Evening.
2022-01-07 17:15:00.232 info Mode set to Evening from Day
On the 7th it ran at sunset -15 and changed the mode to evening as designed. It also ran at the alternate time of 1830 as defined in the logic for Sa Sun. But the 7th was a Friday and by the logic should have scheduled run at 1800
On the 8th it ran at sunset -15, failed (i manually set to evening mode), and then ran again at 1800. But the 8th was Saturday and should have scheduled at 1830.
On the 9th is ran at sunset -15 and worked as designed. However the second time fired at 1800 instead of 1830. The 9th was a Sunday.
Also on the 9th the scheduled job was for morning at 0530 instead of 0700 for the Sa and Sunday, but on the 8th it fired the schedule at the correct time of 0700 for saturday.
It is almost as if the day of the week index is off. Should these be Monday = 1 and Sunday =7?
Mode Manager triggered at the proper time today (Monday) and changed the mode correctly per design. It triggered twice which would correlate to the previous post listing of the schedule entries.
2022-01-10 17:18:00.152 info Mode set to Evening from Day
2022-01-10 17:18:00.066 info Not setting mode to Evening due to wrong day (2). Current mode is Day.
SO if i am understanding this, it is creating a schedule entry for both M-F and the Sa-Su entries in the logic. I should expect to see the failure for the entry for the incorrect day of the week and an execution for the correct day of the week.
This issue has been worked, and resolved for the next release. Logging has been enhanced also, to give a clearer indication of what Mode Manager is doing.
I believe the previous issue with firing the scheduler at sunset has been resolved in the latest release.
However, now the Mode Manager is not working in the morning. Morning mode schedule is the same as the listing in the original post (above).
It looks like the sunrise was scheduled but seems to think it is the wrong day. Therefor does not execute the mode change. Here is the log from this morning (saturday May 7).
2022-05-07 07:00:00.157 [info]Not setting mode to Morning, earlier of two times already happened
2022-05-07 06:29:00.175 [info]Not setting mode to Morning due to wrong day (Saturday). Current mode is Night.
2022-05-07 06:29:00.156 [info]Not setting mode to Morning due to wrong day (Saturday). Current mode is Night.
2022-05-07 05:30:00.287 [info]Not setting mode to Morning due to wrong day (Saturday). Current mode is Night.
Day: at 09:00 on Sun, Mon, Tue, Wed, Thu, Fri, Sat Evening: Earlier of two times, 18:00 or Sunset -30 minutes on Mon, Tue, Wed, Thu, Fri Evening: Earlier of two times, 18:30 or Sunset -30 minutes on Sun, Sat Morning: Earlier of two times, Sunrise or 05:30 on Mon, Tue, Wed, Thu, Fri Morning: Earlier of two times, Sunrise or 07:00 on Sun, Sat Night: at 01:30 on Sun, Mon, Tue, Wed, Thu, Fri, Sat Modes to ignore time changes: Away, Movie
The publish schedule in the original post has been in place since 2020. THe new failure on the sunrise on weekends started recently, perhaps several weeks ago. I am not positive when it failed as we typically wakeup before sunrise / 7am trigger and morning mode is triggered manually.
So in summary i am not positive when it began to fail, but i first noticed in the last three weeks.
For the past couple days, my mode manager is not working correctly, either. Specifically, I set the mode to "Day" at sunrise, and after sunrise it has still been set to "Night" mode.
