1) Give a description of the problem
I have a piston that has a wait and then a turn off task. The piston wakes up after the wait period but seems to have forgotten the task it was supposed to execute.
Snippet of piston. Fairly straight forward:
Initial run sets up scheduled job:
Scheduled job wakes up but doesn’t execute the turn off task:
How is this possible?
It’s cancelling pending tasks because your condition probably changed (motion changed to inactive or something else in your IF condition changed.
Edit your piston and click on the WITH statement, then click on the gear cog to expand the settings section. In this screen, look for Task Cancellation Policy and change it to “Never Cancel Tasks”. Then try your experiment again:
Hey @wgmcg I think you need to click “Solution” on @michicago message if indeed he provided a solution, it helps other people reading your post title looking for similar solutions, and shows appreciation to people taking the time to help us with our piston problems just out of the goodness of their hearts.
I’ll give this a shot after trying one other thing first. It just occurred to me (I just woke up, it actually came to me in a dream) that when I was messing around with yesterday’s ST outage (before I figured out it was them) I set the WebCoRE recovery time to less than the wait time in this piston. I’m going to shut that off and see if it does anything.
The thing is, this piston used to work as is. Also, generally I do want to cancel tasks on condition state change. If the light is set to shutoff after an 8 min wait and I go back in the bathroom and cause a motion event, I want the turn off to cancel.
There’ something very wrong about this. If i change my timeout to 15 seconds this piston behaves properly and shuts the light off, but if i make it 210 seconds the light doesn’t shutoff. The piston wakes up and doesn’t execute the event.
All other logic is identical, only change is the wait time.
I have 5 other rooms using the same basic logic too. They all behave properly.
Oh… well it appears the motion sensor is sending motion events every couple of minutes even when there is no motion. That would do it. Rebooted it…we’ll see.
Or… maybe not.
Yeah this isn’t solved. still an ongoing issue.
1/20/2018, 5:01:20 PM +310ms
+2ms ╔Received event [Motion Bath].motion = inactive with a delay of 725ms
+238ms ║RunTime Analysis CS > 19ms > PS > 97ms > PE > 122ms > CE
+241ms ║Runtime (46400 bytes) successfully initialized in 97ms (v0.2.102.20180116) (238ms)
+242ms ║╔Execution stage started
-----snipped for brevity-----
+320ms ║║Executed virtual command [Bathroom Light].wait (1ms)
+321ms ║║Requesting a wake up for Sat, Jan 20 2018 @ 5:04:50 PM PST (in 210.0s)
+326ms ║╚Execution stage complete. (84ms)
+328ms ║Setting up scheduled job for Sat, Jan 20 2018 @ 5:04:50 PM PST (in 209.995s)
+338ms ╚Event processed successfully (338ms)
And then at 5:04:50:
1/20/2018, 5:04:49 PM +352ms
+0ms ╔Received event [Home].time = 1516496690632 with a delay of -1281ms
+246ms ║RunTime Analysis CS > 18ms > PS > 80ms > PE > 145ms > CE
+251ms ║Runtime (46396 bytes) successfully initialized in 80ms (v0.2.102.20180116) (250ms)
+255ms ║╔Execution stage started
+256ms ║╚Execution stage complete. (4ms)
+257ms ╚Event processed successfully (258ms)
Piston wakes up but does not execute the off command. I look in the ST IDE to see if perhaps some motion event cancelled the task, but nothing. Last motion event was the inactive at 5:01:19. There are no other events between then and the 5:04:50 wait.
WTF??? Why does it not schedule and execute my Turn Off??? Why does it work sometimes and not other times? If some event cancelled the task why isn’t it logged?
OK well here’s my theory of what is going on. The piston had a restriction based on luminance from another device, which required it to subscribe to that device.
During the wait period that other device updated, causing a notification to my piston. If my piston was notified of an event during the wait period, my piston would wake up and run. After that run all the tasks in the previously scheduled wakeup were cancelled. If per chance, my other device didn’t send any notification, my piston would run normally.
I’m not sure why this would be the case, and I’m not quite sure if it is in fact the case but that’s my current theory.
In the snapshot below I’ve removed the luminance restriction from the other device and all (so far) seems to be working correctly.
yeah, no. still doesn’t work. I don’t understand what is causing the piston to wake or restart or whatever it is doing at 10:13:52 here, but whatever it is it seems to be causing it to cancel the events at 10:17:18. It doesn’t appear to be receiving an event, why did it start???
1/20/2018, 10:17:18 PM +351ms
+0ms ╔Received event [Home].time = 1516515439779 with a delay of -1428ms
+261ms ║RunTime Analysis CS > 17ms > PS > 81ms > PE > 162ms > CE
+264ms ║Runtime (45419 bytes) successfully initialized in 81ms (v0.2.102.20180116) (263ms)
+266ms ║╔Execution stage started
+267ms ║╚Execution stage complete. (2ms)
+269ms ╚Event processed successfully (269ms)
1/20/2018, 10:13:52 PM +904ms
+1ms ╔Starting piston… (v0.2.102.20180116)
+551ms ║╔Subscribing to devices…
+607ms ║║Subscribing to Motion Bath.motion…
+640ms ║║Subscribing to Home.:b300e0dd4e7736464f59af96b60fe2fb:.@WestHigh…
+959ms ║║Subscribing to West Lights…
+961ms ║║Subscribing to Bathroom Light…
+962ms ║║Subscribing to Bathroom Fan…
+962ms ║╚Finished subscribing (440ms)
+1011ms ║Comparison (string) :38257d9da371f028a2fb17a159be81d1: is_any_of (string) :38257d9da371f028a2fb17a159be81d1:,:5161f73fe5f37e27dbb10f3270119051: = true (2ms)
+1022ms ║Comparison (enum) on is (string) on = true (2ms)
+1033ms ║Comparison (enum) inactive is (string) active = false (2ms)
+1043ms ║Comparison (integer) 60 is_less_than_or_equal_to (integer) 30 = false (1ms)
+1051ms ║Comparison (enum) on is (string) off = false (1ms)
+1063ms ║Cancelling condition #15’s schedules…
+1064ms ║Cancelling condition #11’s schedules…
+1074ms ║Comparison (enum) off is (string) off = true (1ms)
+1081ms ║Comparison (integer) 60 changes = false (1ms)
+1091ms ║Comparison (enum) on is (string) on = true (1ms)
+1098ms ║Comparison (integer) 60 is_equal_to (integer) 60 = true (1ms)
+1107ms ╚Piston successfully started (1106ms)
1/20/2018, 10:13:49 PM +497ms
+1ms ╔Received event [Motion Bath].motion = inactive with a delay of 810ms
+217ms ║RunTime Analysis CS > 27ms > PS > 63ms > PE > 126ms > CE
+220ms ║Runtime (45434 bytes) successfully initialized in 63ms (v0.2.102.20180116) (218ms)
+221ms ║╔Execution stage started
+230ms ║║Comparison (string) :38257d9da371f028a2fb17a159be81d1: is_any_of (string) :38257d9da371f028a2fb17a159be81d1:,:5161f73fe5f37e27dbb10f3270119051: = true (1ms)
+231ms ║║Condition #1 evaluated true (5ms)
+240ms ║║Comparison (enum) on is (string) on = true (2ms)
+241ms ║║Condition #32 evaluated true (9ms)
+242ms ║║Condition group #null evaluated true (state did not change) (17ms)
+249ms ║║Comparison (enum) inactive is (string) active = false (1ms)
+251ms ║║Cancelling condition #6’s schedules…
+252ms ║║Condition #6 evaluated false (7ms)
+253ms ║║Condition group #2 evaluated false (state did not change) (9ms)
+259ms ║║Comparison (enum) inactive changes_to (string) inactive = true (1ms)
+261ms ║║Cancelling condition #15’s schedules…
+261ms ║║Condition #15 evaluated true (5ms)
+262ms ║║Cancelling condition #11’s schedules…
+263ms ║║Condition group #11 evaluated true (state changed) (8ms)
+273ms ║║Comparison (enum) off is (string) off = true (1ms)
+274ms ║║Condition #36 evaluated true (8ms)
+275ms ║║Condition group #12 evaluated true (state did not change) (10ms)
+276ms ║║Cancelling statement #12’s schedules…
+281ms ║║Executed virtual command [Bathroom Light].wait (0ms)
+282ms ║║Requesting a wake up for Sat, Jan 20 2018 @ 10:17:19 PM PST (in 210.0s)
+287ms ║╚Execution stage complete. (66ms)
+288ms ║Setting up scheduled job for Sat, Jan 20 2018 @ 10:17:19 PM PST (in 209.994s)
+299ms ╚Event processed successfully (299ms)
Ha… ok I think I’ve found it. Typo in another piston which was sending a “resume piston” cmd to this piston when a light in a whole other room changed. Geez… that only took 3 weeks to debug.
Seems like that would do it! Would have been hard to figure that out from the piston logging.
