Actions after wait are never executing?


#1

1) Give a description of the problem
I have a “Wait 15 minutes” action and then a couple more actions. The following actions aren’t executing.

2) What is the expected behaviour?
Wait 15 minutes and then execute the two remaining actions (write to log file and set light level)

3) What is happening/not happening?
The final two actions aren’t executing.

4) Post a Green Snapshot of the pistonimage
2020-10-14%2021_44_14-webCoRE%20Dashboard

5) Attach logs after turning logging level to Full
10/14/2020, 9:50:33 PM +550ms
+4ms ╔Received event [Babysitter Presence Sensor].presence = present with a delay of 73ms, canQueue: true, calledMyself: false
+404ms ║RunTime initialize > 402 LockT > 2ms > rtDT > 381ms > pistonT > 380ms (first state access 19 7 395)
+409ms ║Runtime (8743 bytes) successfully initialized in 381ms (v0.3.110.20200916_HE)
+412ms ║╔Execution stage started
+438ms ║║Condition #3 evaluated false (10ms)
+447ms ║║Condition #4 evaluated false (8ms)
+454ms ║║Condition #5 evaluated false (6ms)
+461ms ║║Comparison (enum) present changes_to (string) present = true (1ms)
+464ms ║║Cancelling condition #15’s schedules…
+466ms ║║Condition #15 evaluated true (10ms)
+469ms ║║Cancelling condition #2’s schedules…
+471ms ║║Condition group #2 evaluated true (state changed) (44ms)
+480ms ║║Comparison (enum) on is (string) on = true (4ms)
+483ms ║║Condition #6 evaluated true (10ms)
+491ms ║║Comparison (integer) 25 is_less_than (integer) 100 = true (2ms)
+493ms ║║Condition #7 evaluated true (9ms)
+495ms ║║Cancelling condition #1’s schedules…
+497ms ║║Condition group #1 evaluated true (state changed) (72ms)
+500ms ║║Cancelling statement #8’s schedules…
+513ms ║║Lights set to 100%
+516ms ║║Executed virtual command [Garage Outdoor Lights].log (4ms)
+693ms ║║Executed physical command [Garage Outdoor Lights].setLevel([100], ) (167ms)
+695ms ║║Executed virtual command [Garage Outdoor Lights].adjustLevel (172ms)
+705ms ║║Waiting 15 minutes…
+707ms ║║Executed virtual command [Garage Outdoor Lights].log (2ms)
+715ms ║║Executed virtual command [Garage Outdoor Lights].wait (1ms)
+722ms ║║Requesting a wake up for Wed, Oct 14 2020 @ 10:05:34 PM EDT (in 900s)
+738ms ║╚Execution stage complete. (326ms)
+793ms ║Setting up scheduled job for Wed, Oct 14 2020 @ 10:05:34 PM EDT (in 900s)
+795ms ╚Event processed successfully (793ms)
10/14/2020, 9:50:13 PM +248ms
+21ms ╔Subscribing to devices…
+26ms ║Using Attribute subscription
+209ms ║Device missing from piston. Loading all from parent (179ms)
+215ms ║Using Attribute subscription
+222ms ║Using Attribute subscription
+228ms ║Using Attribute subscription
+249ms ║Subscribing to August - Front Door.contact…
+262ms ║Subscribing to E.presence…
+269ms ║Subscribing to S.presence…
+274ms ║Subscribing to Babysitter Presence Sensor.presence…
+282ms ║Piston controls Garage Outdoor Lights…
+299ms ╚Finished subscribing (281ms)
+358ms ║Comparison (enum) on is (string) on = true (2ms)
+360ms ║Cancelling condition #6’s schedules…
+370ms ║Comparison (integer) 25 is_less_than (integer) 100 = true (2ms)
+372ms ║Cancelling condition #7’s schedules…
+391ms ╔Starting piston… (v0.3.110.20200916_HE)
+393ms ╚Piston successfully started (377ms)


#2

Your log does not show what happened between 9:50:34 and 10:06, but I think I can still elaborate…

9:50:33 = Presence changed (piston ran lines 16-36)
… then something happened within the next 15 minutes, which aborted the timer.
(a Full Log Level will show what really happened)

If you want the final things to happen regardless of external events, you can click on the WITH on line 30, and change Task Cancellation Policy to Never.


#3

That’s my fault, I didn’t wait 15 minutes to grab the log. I changed the task cancellation policy and will test again tonight. Thanks for your reply! As soon as I can either confirm it worked or have more info, I’ll come back and post again.


#4

I think I’ve got it. This is the first time I’ve seen the rest of these logs so the task cancellation policy was definitely part of it. As you can see below, though, it was sending 100 back to the lights (when they were already 100). I figured out why on that as well. I had selected the “emulated Adjust level” instead of the “device Set level” action. Once I chose that, the piston completed as expected.

Thanks again for your help!

10/15/2020, 10:04:59 PM +551ms
+8ms ╔Received event [Home].time = 1602813899474 with a delay of 77ms, canQueue: true, calledMyself: false
+30ms ║RunTime initialize > 29 LockT > 2ms > rtDT > 1ms > pistonT > 0ms (first state access 26 10 19)
+34ms ║Runtime (8643 bytes) successfully initialized in 1ms (v0.3.110.20200916_HE)
+41ms ║╔Execution stage started
+64ms ║║Lights set to 25%
+67ms ║║Executed virtual command [Garage Outdoor Lights].log (3ms)
+84ms ║║Skipped execution of physical command [Garage Outdoor Lights].setLevel([100]) because it would make no change to the device. (2ms)
+85ms ║║Executed virtual command [Garage Outdoor Lights].adjustLevel (13ms)
+91ms ║╚Execution stage complete. (50ms)
+95ms ╚Event processed successfully (94ms)

#5

Interesting… Most bulbs respond better with “Set level to” instead…

Glad you got it working though! :+1:


#6

Just to be clear, that’s what I’m using now :slight_smile: I had missed that in the event selection and clicked “Adjust level” and that didn’t work either. So I was fighting multiple issues. Thanks again!