Piston Runs Twice

[markplewis]

1) Give a description of the problem

I have a piston that runs one hour before sunset. It runs fine each day but then runs again exactly one minute later. This happens every day. I’ve probably looked at it for too long and I’m missing something obvious but I can’t figure out what the trigger is that’s causing it to run the second time.

2) What is the expected behavior?
Piston should run once each day one hour prior to sunset.

3) What is happening/not happening?
The piston runs and then runs a second time exactly one minute later.

4) Post a Green Snapshot of the piston

5) Attach any logs (From ST IDE and by turning logging level to Full)

Here’s a side-by-side comparison of a portion of the logs for each run. The left-most one is the first time it ran. On the right is the second time. Text logs for both runs are below.

1/16/2018, 4:00:59 PM +235ms
+1ms ╔Received event [Home].time = 1516143660000 with a delay of -766ms
+432ms ║RunTime Analysis CS > 42ms > PS > 235ms > PE > 156ms > CE
+435ms ║Runtime (46265 bytes) successfully initialized in 235ms (v0.2.101.20171227) (433ms)
+436ms ║╔Execution stage started
+659ms ║║Comparison (time) 57659679 happens_daily_at (time) 1516147260000 = true (164ms)
+661ms ║║Time restriction check passed
+664ms ║║Condition #12 evaluated true (219ms)
+665ms ║║Cancelling statement #12’s schedules…
+674ms ║║Requesting time schedule wake up at Wed, Jan 17 2018 @ 4:01:00 PM MST
+677ms ║║Condition group #1 evaluated true (state did not change) (232ms)
+685ms ║║Comparison (string) :9984339f75f446f9c06978e611709967: is_any_of (string) :4f87089617dfb9cee9d4ec80da10baf8:,:fd6b2fd9366cdca291a786245b40fcf7: = false (3ms)
+686ms ║║Condition #11 evaluated false (6ms)
+687ms ║║Condition group #2 evaluated false (state did not change) (8ms)
+693ms ║║Comparison (string) :9984339f75f446f9c06978e611709967: is (string) :9984339f75f446f9c06978e611709967: = true (1ms)
+694ms ║║Condition #20 evaluated true (6ms)
+695ms ║║Condition group #13 evaluated true (state did not change) (7ms)
+697ms ║║Cancelling statement #17’s schedules…
+708ms ║║Skipped execution of physical command [Living Room Light].setLevel([30]) because it would make no change to the device. (4ms)
+709ms ║║Executed [Living Room Light].setLevel (6ms)
+736ms ║║Executed virtual command [Living Room Light].sendPushNotification (22ms)
+740ms ║║Cancelling statement #27’s schedules…
+749ms ║║Executed [Back Bedroom Light].setLevel (3ms)
+762ms ║║Executed virtual command [Back Bedroom Light].waitForTime (9ms)
+763ms ║║Requesting a wake up for Wed, Jan 17 2018 @ 9:00:00 AM MST (in 61140.004s)
+768ms ║║Cancelling statement #29’s schedules…
+779ms ║║Skipped execution of physical command [Patio Lights].setLevel([40]) because it would make no change to the device. (6ms)
+780ms ║║Executed [Patio Lights].setLevel (7ms)
+783ms ║║Cancelling statement #32’s schedules…
+793ms ║║Skipped execution of physical command [Chandelier].setLevel([25]) because it would make no change to the device. (5ms)
+794ms ║║Executed [Chandelier].setLevel (6ms)
+797ms ║║Cancelling statement #49’s schedules…
+809ms ║║Skipped execution of physical command [Bedroom Lights].setLevel([2]) because it would make no change to the device. (5ms)
+809ms ║║Executed [Bedroom Lights].setLevel (7ms)
+814ms ║╚Execution stage complete. (378ms)
+816ms ║Setting up scheduled job for Wed, Jan 17 2018 @ 9:00:00 AM MST (in 61139.953s), with 1 more job pending
+823ms ╚Event processed successfully (823ms)
1/16/2018, 3:58:59 PM +188ms
+0ms ╔Received event [Home].time = 1516143540000 with a delay of -813ms
+211ms ║RunTime Analysis CS > 32ms > PS > 54ms > PE > 126ms > CE
+214ms ║Runtime (46265 bytes) successfully initialized in 54ms (v0.2.101.20171227) (213ms)
+215ms ║╔Execution stage started
+406ms ║║Comparison (time) 57539410 happens_daily_at (time) 1516147260000 = true (1ms)
+407ms ║║Time restriction check passed
+408ms ║║Cancelling condition #12’s schedules…
+409ms ║║Condition #12 evaluated true (187ms)
+410ms ║║Cancelling statement #12’s schedules…
+414ms ║║Requesting time schedule wake up at Tue, Jan 16 2018 @ 4:01:00 PM MST
+417ms ║║Cancelling condition #1’s schedules…
+418ms ║║Condition group #1 evaluated true (state changed) (197ms)
+425ms ║║Comparison (string) :9984339f75f446f9c06978e611709967: is_any_of (string) :4f87089617dfb9cee9d4ec80da10baf8:,:fd6b2fd9366cdca291a786245b40fcf7: = false (3ms)
+426ms ║║Cancelling condition #11’s schedules…
+427ms ║║Condition #11 evaluated false (7ms)
+428ms ║║Cancelling condition #2’s schedules…
+428ms ║║Condition group #2 evaluated false (state changed) (8ms)
+433ms ║║Comparison (string) :9984339f75f446f9c06978e611709967: is (string) :9984339f75f446f9c06978e611709967: = true (2ms)
+434ms ║║Cancelling condition #20’s schedules…
+435ms ║║Condition #20 evaluated true (6ms)
+436ms ║║Cancelling condition #13’s schedules…
+437ms ║║Condition group #13 evaluated true (state changed) (7ms)
+439ms ║║Cancelling statement #17’s schedules…
+491ms ║║Executed physical command [Living Room Light].setLevel([30]) (46ms)
+491ms ║║Executed [Living Room Light].setLevel (47ms)
+520ms ║║Executed virtual command [Living Room Light].sendPushNotification (24ms)
+523ms ║║Cancelling statement #27’s schedules…
+576ms ║║Executed physical command [Back Bedroom Light].setLevel([10]) (44ms)
+577ms ║║Executed [Back Bedroom Light].setLevel (48ms)
+587ms ║║Executed virtual command [Back Bedroom Light].waitForTime (8ms)
+588ms ║║Requesting a wake up for Wed, Jan 17 2018 @ 9:00:00 AM MST (in 61260.226s)
+592ms ║║Cancelling statement #29’s schedules…
+621ms ║║Executed physical command [Patio Lights].setLevel([40]) (24ms)
+622ms ║║Executed [Patio Lights].setLevel (26ms)
+625ms ║║Cancelling statement #32’s schedules…
+648ms ║║Executed physical command [Chandelier].setLevel([25]) (17ms)
+648ms ║║Executed [Chandelier].setLevel (19ms)
+651ms ║║Cancelling statement #49’s schedules…
+709ms ║║Executed physical command [Bedroom Lights].setLevel([2]) (53ms)
+710ms ║║Executed [Bedroom Lights].setLevel (54ms)
+713ms ║╚Execution stage complete. (499ms)
+715ms ║Setting up scheduled job for Tue, Jan 16 2018 @ 4:01:00 PM MST (in 120.098s), with 1 more job pending
+722ms ╚Event processed successfully (722ms)

[c1arkbar]

If I had to guess it is because sunset is getting later and later each day. Everything else looks right

[Mike1616]

If I had to guess it is because sunset is getting later and later each day. Everything else looks right

There’s some merit to that possibility. Clearly there’s nothing wrong with the logic in this piston, but the piston itself is scheduling itself to run again…as sunset is indeed happening later and later each day right now. You can see in the last line of the Log that it schedules itself for 2 minutes in the future.

I have some routines that run each day at Sunset and they only run once per day, but I’m using a Timer to do them rather than using “Time”. My suggestion would be to switch over to that, instead of what you’re doing.

So you’d have something like:

Every day at 60 minutes to Sunset
Do

Otherwise your piston would be the same. It’s worth a shot, Timers work well for me.

[Gopack2]

Ok here is my thought.

It runs today, then set up the timer for tomorrow based on today’s sunset time. So that will trigger tomorrow at the same time as today.

However tomorrow the sunset is actually 1 minute later. So, with that being said, once the piston runs, it is looking for the sunset time as of when the piston has executed, which is now a minute later.

Then the cycle starts all over again.

Can you eliminate the restriction and try to set a wait timer for the next sunset time? Something like $nextsunset. Or addhours($nextsunset,-1)

[michicago]

I think @c1arkbar is right - I’ve seen this type of repeat trigger a few times (when the days are getting shorter so sunset is a minute or two earlier each day, it’s not an issue).

When I need/want to limit piston executions to once per day, I use a variable to store the last date it was run. At the top of the piston, check to see if the last date it was run was today or any other day… and bail on execution if it was today.

Here’s an example with your piston:

[markplewis]

Guys, thanks for your help. I changed the if time happens to every day at 1 hour before sunset and the piston only ran once.