RM not tracking Sunset-offset?

When I read about Rule Machine issues with .703 I delayed upgrading to let the dust settle a bit. That’s a perk of not being on SmartThings anymore :slightly_smiling_face:

The fix was out in about 6 hours, irc. Not a huge deal.

Yes, the bug was a single character I omitted and had failed to test for. My bad. We posted the fix in something like 2 hours after we became aware of it. Not saying that will always happen that fast, but I was suitably embarrassed!

There is no reason that I know of that RM should not be doing sunset offsets correctly. And, I don't think this would have anything to do with the DST issue we had. So, if you notice a discrepancy between the scheduled time (visible on the app information page at the bottom), and the sunset time (visible on the Location page), please take screenshots of both and post them here, or by PM to me. Not saying there isn't some platform issue, just not one that I'm aware of.

Your responsiveness is evident and much appreciated; I certainly have no issues there.

Regarding the issue I do have, I have been running this rule since February 14 and can see in the event log that the scheduled turn on time would (correctly) happen a minute or so later each day, tracking the change in sunset time from 5:26pm to 5:42pm, up until March 05, when it ‘stuck’ at 5:42pm. This was maintained until until the DST changeover, when it ‘stuck’ at 6:54pm. That happened to be the last time I recall hitting ‘update’ on the location page, per your recommendation due to the DST issues that surfaced at that time. I noticed tonight that after hitting ‘update’ again, that the rule is now scheduled for the correct time; but if the behavior I’m seeing persists, this will be ‘the’ event time until I hit update again.

I will update to .704 and see if that fixes the problem; of course it will take a day or so for the problem to manifest (any screen shots I could send today would show nothing, since updating the location page resulted in the scheduled event for the rule also updating to the correct time).

You shouldn’t have to hitting update on the location page. So skip that part tomorrow and let me see what happens.

March 5 is when we released 702, and there were some timezone related changes in that build. It’s possible that something got messed up, but hard to tell at the moment. My own mode change happens right at sunset, and it has changed as expected each day by a minute or so, including since March 5.

OK ; I forgot to mention that I also have a Simple Lighting Rule set up to trigger the same lamp at the exact sunset-5 min. time (I had set up the RM to control the light as a circumvention for the original sunset bug in Simple Lighting). I accidentally looked at Simple Lighting rules’ schedule instead of RM’s schedule when I made that observation.

When i discovered that, I did note that RM’s schedule was still set for the incorrect time so obviously updating the location page had no effect on it. I did update to .704 and will report back.

Eoit: I also remember posting (on the Sunday of DST changeover) that my RM rule’s schedule was not updated-- and it did’t update until I refreshed the rule; that’s what bumped it to the 6:54 time: DST: Need to refresh RM rule using sunset -offset even if location times correct

@bravenel, it looks like Simple Lighting may be involved with this scenario; perhaps having a redundant RM trigger with an identical turn on time may be relevant?

After the update last evening to .704 here is what I see:

Hubitat Location page shows sunset at 7:04 PM.
Scheduled event for RM ‘light on at sunset - 5 minutes’ correctly shows a scheduled turn on event for 18:59:00:

Scheduled Jobs

Handler Next Run Time Prev Run Time Status Schedule
timeHandler Sat Mar 17 18:59:00 EDT 2018 PENDING 0 59 18 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 PENDING 29 5 2 * * ?

Here’s where things go astray:
Scheduled events for the redundant Simple Lighting app (‘Turn on at sunset -5 min’ along with a ‘Turn off at sunrise’) shows:

Scheduled Jobs

Handler Next Run Time Prev Run Time Status Schedule
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
doAntiAction Sun Mar 18 07:04:00 EDT 2018 Sat Mar 17 07:04:00 EDT 2018 PENDING 0 4 7 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
doAction Sat Mar 17 18:59:00 EDT 2018 PENDING 0 59 18 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 Sat Mar 17 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
scheduleAtTime Sun Mar 18 02:05:29 EDT 2018 PENDING 29 5 2 * * ?

Note that there is a scheduled Simple Lighting ‘doaction’ for the correct time (18:59) as well as the correct ‘doantiaction’. Could all the extra Simple Lighting schedules for 02:05:29 be a side effect of having both RM and Simple Lighting schedule an event for the exact same time, and could that somehow be the cause of the original ‘stuck’ time symptom due to some subsequent scheduling malfunction?

I’ll wait for your input before trying anything obvious (like deleting a redundant time-coincident schedule, or removing/reinstalling anything). I’m the guy with the 93 custom commands in Rule Machine that I’d like to avoid having to re-create if possible.

Reading @Tony’s post made me look at my sunrise/sunset app and I have over 600 scheduleAtTime events pending. Mine has been firing at the correct times, but 600 seems a little odd.

1 Like

We found a bug in Simple Lighting last night. It will get fixed in the next release, and we may do that sooner rather than later.

2 Likes

The scheduling bug in Simple Lighting has been fixed and released in 1.0.3.705.

1 Like

Thank you!

@bravenel Just wanted to give you a heads-up. After updating to 705, my Sunrise/Sunset scheduling completed 600 times.

But logged an error for each one.

Not sure if it's important, but thought I'd pass it along.

Interesting. Something is still amiss. I also updated to .705 and after doing so deleted my original SL 'turn on at sunset-offset and also turn off at sunrise' rule and recreated it. Here is a shot of the new Simple Lighting rule:

This morning app status shows this:

Scheduled Jobs

Handler Next Run Time Prev Run Time Status Schedule
scheduleSunrise Mon Mar 19 02:05:29 EDT 2018 Sun Mar 18 02:05:29 EDT 2018 PENDING 29 5 2 * * ?
doAction Sun Mar 18 18:59:00 EDT 2018 PENDING Once
scheduleSunset Mon Mar 19 02:05:29 EDT 2018 Sun Mar 18 02:05:29 EDT 2018 PENDING 29 5 2 * * ?

which shows the correct 'doAction' schedule, but the 'doAntiAction' is not scheduled (you can see in the screenshot of the app that 'ON' is selected for 'also turn off at sunrise'. Unfortunately I didn't have logging running at the time; maybe I didn't see the redundant scheduling errors because the SL rule was newly created (maybe they will manifest after another round through the scheduler).

I deleted and rebuilt the original SL rule. I do not have the multiple scheduling events and have a blank doAntiAction, which is to be expected. We’ll see what happens at 02:05.

If you want to troubleshoot sunrise/sunset events you can change your location to match an approaching sunrise/sunset but that’s a lot of work. :wink:

1 Like

Just a guess… Maybe when the ON action fires, it will schedule the OFF action?

It’s possible; but it appears that both sunrise and sunset get scheduled at 2:05:29 AM every day.

Since you did this after sunrise, tomorrow's sunrise event is not yet scheduled. Today's sunset event is scheduled. At 2:05 tomorrow morning, scheduleSunrise will run (so will schedule Sunset), and schedule tomorrow morning's sunrise action.

1 Like

Did you go into your SL rule and click Done? You need to do that for it to schedule itself correctly.

Ah ok, I will hang tight (my mind is still trying to unravel the sequencing of events… this stuff isn’t as easy as seems it should be).