Fade over time and task cancellation

[allrak]

1) Give a description of the problem
Can’t get lights to stay off if manually changed to off during a fade routine

2) What is the expected behavior?
If the lights are manually adjusted during the fade duration, the remaining fade tasks should cancel.

3) What is happening/not happening?
Fade works as expected… Task cancellation policy not happening on state change during fade.

4) Post a Green Snapshot of the piston

So this piston works as expected. But if I change the lights via ST to dim them or turn them off during the fade routine, on the next iteration of the fade loop they get set back. So if I turn them off or dim them, I need the piston to cancel remaining tasks. All TCP’s are set to default (cancel task on condition state change).
I did some searching prior to posting this and ran across:
https://community.webcore.co/t/help-with-fade-to-0-piston/2743

So maybe this is a bug?

[michicago]

The “condition change” for TCP is not the condition of lights under control (fade level, switch position, etc.), it means if there is a change in the condition statement of your piston. For example, in yours if your location changed from Home to Away, it would cancel all pending tasks because the evaluation of your conditional statements changed.

I’ll post an updated piston in a minute that will add a cancellation for any changes made outside of the piston’s control.

[michicago]

This should do it. If it doesn’t, add your devices in place of “location” for the cancel all pending tasks step - but in the process of trying to figure out ‘cancel all pending tasks’ I remember it cancelling all the piston’s tasks regardless of what devices where selected.

[allrak]

I think I understand now… Updated piston:

To make sure I understand the logic…

The condition state change is what triggers the piston, so in the example above, it’d be:
“Switch 8’s switch is off” & “everyday at 30 mins before sunset”.
And by default when executing an “every” the blocks runs “async”, so the very last “if” which contains the “cancel all pending tasks” will continue to be evaluated while the other fade blocks are running.

Trying to wrap my head around it and understand, so let me know if that logic sounds right.

[michicago]

I think you’re on the right track. Let me see if I can explain this a bit differently. Let’s start with the piston above.

In the piston above, the 3rd IF block will only be evaluated if a the Dimmer 5 switch is changed, or its level is changed. It is not executed as part of the Async blocks… only the code covered by the purple line is executed for that specific asynchronous trigger. So your first block will only execute at 30 minute before sunset and your second only at 10:30pm. The third block will be run anytime there is a change made to the level or switch position for Dimmer 5.

As for the cancellation of tasks using, we used two different methods:

“Cancel all pending tasks” will do exactly as it says. In your latest piston, when a change in Dimmer 5’s switch position or level is made, that IF statement will be evaluated TRUE and the ‘cancel all pending tasks’ will be executed.

The other method is the Task Cancellation Policy which by default is set to cancel on “condition” changes. Those condition changes refer specifically to IF statements in your piston. For example:

Let’s say we had a piston that fades a light from 0% to 100% in one hour and forty minutes (100 minutes to make the math simple) anytime it’s turned on between sunset and sunrise.

Case 1: It’s turned on just after sunset - the dimmer starts at 0% and gradually fades to 100% (1% per minute). To accomplish this, webCoRE set’s the dimmer to 0% and schedules a wake-up call for one minute later. Then it sets the level to 1% and schedules another wake-up time one minute later.

As you discovered, if during this time you change the dimmer setting or turn it off - when the piston reaches it’s next wake-up time it will send the next level (3% in this case) regardless of the dimmer’s current switch and level setting.

In other words, the above change to the dimmer is not viewed as a “change in condition”.

Case 2: The light is switched on 30 minutes before sunrise. In this case, the dimmer would be at 30% when the condition “between sunset and sunrise” would change from TRUE to FALSE. At this point, the piston would recognize a “change in condition” and your pending tasks would be cancelled. The dimmer would stay at 30% until another piston or physical input was given to the dimmer.

I hope that makes sense and didn’t muddy the waters further?

[allrak]

As for the cancellation of tasks using, we used two different methods:

“Cancel all pending tasks” will do exactly as it says. In your latest piston, when a change in Dimmer 5’s switch position or level is made, that IF statement will be evaluated TRUE and the ‘cancel all pending tasks’ will be executed.

So this is a good way to do it then, since changing any switch/dimmer status outside of the time periods when the pistons fire has zero effect on anything (since there’s currently no pending tasks).
And if the switch/dimmer changes within the time restriction, there is obviously pending tasks (fade…) which will get cancelled. This makes sense.
What confused me at first is that when webcore is controlling the fading (thereby changing level), it’s not triggering a “cancel pending tasks (bottom of piston)”, because that event would have to happen by me physically switching it off, or changing the level.

Think I got it… appreciate the detailed explanation!

[michicago]

You got it!

As far is the changes to level or switch triggering the “cancel all pending tasks”… think of this as more like “if a change is reported TO your piston, cancel all pending tasks”. Changes made by your piston don’t result in the 3rd block evaluating as TRUE because it already knew about them. Manual changes or changes from another piston would put something in the piston’s log like:

“Received event [Family Room Lights].switch = off with a delay of 668ms.”

It’s those events (received) that will satisfy your 3rd IF statement.

Glad to help! I had the same questions you did and figured out most of this through trial and error. Often times, I’ve found, when in doubt webCoRE has some logic built in that makes it behave the way you’d want it to.

One example I had early on was turning on lights between sunset and sunrise. Technically, when time passes midnight and the sunrise and sunset variables are updated, my IF conditions would change to FALSE and my lights would turn off. But webCoRE has built-in logic to make it work the way you’d want it want it to, ideally.

[allrak]

As far is the changes to level or switch triggering the “cancel all pending tasks”… think of this as more like “if a change is reported TO your piston, cancel all pending tasks”. Changes made by your piston don’t result in the 3rd block evaluating as TRUE because it already knew about them.

^^This makes perfect sense now… Thanks again, now I have more ammo to create better and more efficient pistons.

woot!

[allrak]

okay, so the piston still won’t cancel when the switch’s level or switch changes… Am I missing something here, any ideas?

---

EDIT: I’ve also tried structuring it as:
ON EVENTS FROM
Dimmer5 or $lights
Cancel all pending tasks

---

that didn’t work either

[michicago]

Interesting that the dimmer 5 didn’t work. Can you turn logs on full and post?

[allrak]

okay, so here’s the logging output… During the transition, I went into smartthings and turned off one of the lights (which was turned back on and didn’t cancel all pending tasks).

12/15/2017, 10:01:29 AM +860ms

+1ms ╔Received event [Dinner Table #1].switch = on with a delay of 925ms
+10427ms ║RunTime Analysis CS > 21ms > PS > 10258ms > PE > 148ms > CE
+10428ms ║Piston waited at a semaphore for 10219ms
+10431ms ║Runtime (41679 bytes) successfully initialized in 10258ms (v0.2.100.20171211) (10429ms)
+10432ms ║╔Execution stage started
+10449ms ║║Comparison (enum) off is (string) off = true (3ms)
+10451ms ║║Condition #9 evaluated true (12ms)
+10452ms ║║Condition group #1 evaluated true (state did not change) (13ms)
+10473ms ║║Comparison (enum) off is (string) off = true (3ms)
+10474ms ║║Condition #10 evaluated true (10ms)
+10475ms ║║Condition group #6 evaluated true (state did not change) (11ms)
+10495ms ║║Cancelling statement #16’s schedules…
+10497ms ║║Executed virtual command cancelTasks (1ms)
+10500ms ║╚Execution stage complete. (68ms)
+10502ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:30:00 PM EST (in 44899.639s), with 1 more job pending
+10512ms ╚Event processed successfully (10513ms)
12/15/2017, 10:01:30 AM +134ms
+1ms ╔Received event [Dinner Table #4].level = 11 with a delay of 946ms
+9892ms ║RunTime Analysis CS > 11ms > PS > 9794ms > PE > 87ms > CE
+9893ms ║Piston waited at a semaphore for 9767ms
+9896ms ║Runtime (41671 bytes) successfully initialized in 9794ms (v0.2.100.20171211) (9893ms)
+9897ms ║╔Execution stage started
+9914ms ║║Comparison (enum) off is (string) off = true (2ms)
+9915ms ║║Condition #9 evaluated true (13ms)
+9916ms ║║Condition group #1 evaluated true (state did not change) (15ms)
+9932ms ║║Comparison (enum) off is (string) off = true (2ms)
+9933ms ║║Condition #10 evaluated true (7ms)
+9934ms ║║Condition group #6 evaluated true (state did not change) (8ms)
+9947ms ║║Cancelling statement #16’s schedules…
+9949ms ║║Executed virtual command cancelTasks (1ms)
+9955ms ║╚Execution stage complete. (59ms)
+9957ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:30:00 PM EST (in 44899.91s), with 1 more job pending
+9966ms ╚Event processed successfully (9966ms)
12/15/2017, 10:01:29 AM +911ms
+1ms ╔Received event [Dinner Table #2].level = 11 with a delay of 927ms
+10074ms ║RunTime Analysis CS > 14ms > PS > 9970ms > PE > 91ms > CE
+10075ms ║Piston waited at a semaphore for 9939ms
+10078ms ║Runtime (41673 bytes) successfully initialized in 9970ms (v0.2.100.20171211) (10075ms)
+10079ms ║╔Execution stage started
+10092ms ║║Comparison (enum) off is (string) off = true (1ms)
+10093ms ║║Condition #9 evaluated true (9ms)
+10094ms ║║Condition group #1 evaluated true (state did not change) (10ms)
+10110ms ║║Comparison (enum) off is (string) off = true (2ms)
+10111ms ║║Condition #10 evaluated true (8ms)
+10112ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+10131ms ║║Cancelling statement #16’s schedules…
+10133ms ║║Executed virtual command cancelTasks (0ms)
+10135ms ║╚Execution stage complete. (57ms)
+10137ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:30:00 PM EST (in 44899.953s), with 1 more job pending
+10144ms ╚Event processed successfully (10144ms)
12/15/2017, 10:01:32 AM +495ms
+137ms ╔Stopping piston…
+320ms ╚Piston successfully stopped (184ms)
12/15/2017, 10:01:30 AM +200ms
+1ms ╔Received event [Dinner Table #3].level = 11 with a delay of 1107ms
+173ms ║RunTime Analysis CS > 18ms > PS > 34ms > PE > 121ms > CE
+175ms ║Runtime (41599 bytes) successfully initialized in 34ms (v0.2.100.20171211) (174ms)
+176ms ║╔Execution stage started
+190ms ║║Comparison (enum) off is (string) off = true (1ms)
+191ms ║║Condition #9 evaluated true (9ms)
+192ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+208ms ║║Comparison (enum) off is (string) off = true (2ms)
+209ms ║║Condition #10 evaluated true (7ms)
+210ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+224ms ║║Cancelling statement #16’s schedules…
+226ms ║║Executed virtual command cancelTasks (1ms)
+251ms ║╚Execution stage complete. (75ms)
+264ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:59 AM EST (in 28.974s), with 41 more jobs pending
+273ms ╚Event processed successfully (274ms)
12/15/2017, 10:01:29 AM +842ms
+1ms ╔Received event [Dinner Table #1].level = 11 with a delay of 912ms
+135ms ║RunTime Analysis CS > 18ms > PS > 28ms > PE > 90ms > CE
+138ms ║Runtime (41597 bytes) successfully initialized in 28ms (v0.2.100.20171211) (136ms)
+139ms ║╔Execution stage started
+151ms ║║Comparison (enum) off is (string) off = true (2ms)
+152ms ║║Condition #9 evaluated true (8ms)
+153ms ║║Condition group #1 evaluated true (state did not change) (10ms)
+169ms ║║Comparison (enum) off is (string) off = true (2ms)
+170ms ║║Condition #10 evaluated true (7ms)
+171ms ║║Condition group #6 evaluated true (state did not change) (8ms)
+185ms ║║Cancelling statement #16’s schedules…
+187ms ║║Executed virtual command cancelTasks (1ms)
+219ms ║║Executed physical command [Dinner Table #1].setLevel([11]) (8ms)
+238ms ║║Executed physical command [Dinner Table #2].setLevel([11]) (8ms)
+256ms ║║Executed physical command [Dinner Table #3].setLevel([11]) (7ms)
+274ms ║║Executed physical command [Dinner Table #4].setLevel([11]) (7ms)
+285ms ║╚Execution stage complete. (147ms)
+296ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:59 AM EST (in 29.299s), with 41 more jobs pending
+317ms ╚Event processed successfully (317ms)
12/15/2017, 10:01:29 AM +413ms
+1ms ╔Received event [Home].time = 1513350089437 with a delay of -24ms
+170ms ║RunTime Analysis CS > 41ms > PS > 31ms > PE > 98ms > CE
+173ms ║Runtime (41596 bytes) successfully initialized in 31ms (v0.2.100.20171211) (171ms)
+174ms ║╔Execution stage started
+195ms ║║Executed physical command [Dinner Table #1].setLevel([11]) (6ms)
+218ms ║║Executed physical command [Dinner Table #2].setLevel([11]) (6ms)
+236ms ║║Executed physical command [Dinner Table #3].setLevel([11]) (6ms)
+254ms ║║Executed physical command [Dinner Table #4].setLevel([11]) (6ms)
+266ms ║╚Execution stage complete. (92ms)
+278ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:59 AM EST (in 29.747s), with 41 more jobs pending
+286ms ╚Event processed successfully (285ms)
12/15/2017, 10:01:15 AM +835ms
+1ms ╔Received event [Dinner Table #1].switch = off with a delay of 942ms
+154ms ║RunTime Analysis CS > 17ms > PS > 42ms > PE > 96ms > CE
+157ms ║Runtime (41599 bytes) successfully initialized in 42ms (v0.2.100.20171211) (153ms)
+158ms ║╔Execution stage started
+171ms ║║Comparison (enum) off is (string) off = true (1ms)
+173ms ║║Condition #9 evaluated true (10ms)
+174ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+191ms ║║Comparison (enum) off is (string) off = true (2ms)
+192ms ║║Condition #10 evaluated true (8ms)
+193ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+208ms ║║Cancelling statement #16’s schedules…
+210ms ║║Executed virtual command cancelTasks (1ms)
+236ms ║╚Execution stage complete. (79ms)
+249ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 13.353s), with 45 more jobs pending
+260ms ╚Event processed successfully (260ms)
12/15/2017, 10:01:00 AM +177ms
+1ms ╔Received event [Dinner Table #3].level = 10 with a delay of 942ms
+10383ms ║RunTime Analysis CS > 21ms > PS > 10196ms > PE > 166ms > CE
+10384ms ║Piston waited at a semaphore for 10155ms
+10387ms ║Runtime (41678 bytes) successfully initialized in 10196ms (v0.2.100.20171211) (10384ms)
+10388ms ║╔Execution stage started
+10402ms ║║Comparison (enum) off is (string) off = true (2ms)
+10404ms ║║Condition #9 evaluated true (9ms)
+10405ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+10424ms ║║Comparison (enum) off is (string) off = true (2ms)
+10426ms ║║Condition #10 evaluated true (9ms)
+10427ms ║║Condition group #6 evaluated true (state did not change) (11ms)
+10444ms ║║Cancelling statement #16’s schedules…
+10446ms ║║Executed virtual command cancelTasks (1ms)
+10468ms ║╚Execution stage complete. (81ms)
+10483ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 18.778s), with 45 more jobs pending
+10494ms ╚Event processed successfully (10493ms)
12/15/2017, 10:01:00 AM +275ms
+1ms ╔Received event [Dinner Table #4].level = 10 with a delay of 949ms
+10047ms ║RunTime Analysis CS > 17ms > PS > 9877ms > PE > 154ms > CE
+10049ms ║Piston waited at a semaphore for 9838ms
+10051ms ║Runtime (41674 bytes) successfully initialized in 9877ms (v0.2.100.20171211) (10049ms)
+10052ms ║╔Execution stage started
+10066ms ║║Comparison (enum) off is (string) off = true (2ms)
+10067ms ║║Condition #9 evaluated true (10ms)
+10068ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+10087ms ║║Comparison (enum) off is (string) off = true (1ms)
+10088ms ║║Condition #10 evaluated true (9ms)
+10089ms ║║Condition group #6 evaluated true (state did not change) (10ms)
+10104ms ║║Cancelling statement #16’s schedules…
+10105ms ║║Executed virtual command cancelTasks (0ms)
+10126ms ║╚Execution stage complete. (75ms)
+10139ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 19.024s), with 45 more jobs pending
+10149ms ╚Event processed successfully (10149ms)
12/15/2017, 10:00:59 AM +807ms
+1ms ╔Received event [Dinner Table #3].switch = on with a delay of 925ms
+10301ms ║RunTime Analysis CS > 13ms > PS > 10208ms > PE > 80ms > CE
+10302ms ║Piston waited at a semaphore for 10178ms
+10304ms ║Runtime (41678 bytes) successfully initialized in 10208ms (v0.2.100.20171211) (10303ms)
+10305ms ║╔Execution stage started
+10317ms ║║Comparison (enum) off is (string) off = true (1ms)
+10319ms ║║Condition #9 evaluated true (9ms)
+10320ms ║║Condition group #1 evaluated true (state did not change) (10ms)
+10337ms ║║Comparison (enum) off is (string) off = true (2ms)
+10338ms ║║Condition #10 evaluated true (8ms)
+10339ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+10354ms ║║Cancelling statement #16’s schedules…
+10356ms ║║Executed virtual command cancelTasks (0ms)
+10377ms ║╚Execution stage complete. (71ms)
+10390ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 19.241s), with 45 more jobs pending
+10402ms ╚Event processed successfully (10403ms)
12/15/2017, 10:00:59 AM +772ms
+0ms ╔Received event [Dinner Table #1].switch = on with a delay of 1048ms
+10278ms ║RunTime Analysis CS > 17ms > PS > 10174ms > PE > 87ms > CE
+10279ms ║Piston waited at a semaphore for 10145ms
+10281ms ║Runtime (41679 bytes) successfully initialized in 10174ms (v0.2.100.20171211) (10280ms)
+10282ms ║╔Execution stage started
+10294ms ║║Comparison (enum) off is (string) off = true (1ms)
+10296ms ║║Condition #9 evaluated true (8ms)
+10296ms ║║Condition group #1 evaluated true (state did not change) (9ms)
+10317ms ║║Comparison (enum) off is (string) off = true (1ms)
+10318ms ║║Condition #10 evaluated true (8ms)
+10319ms ║║Condition group #6 evaluated true (state did not change) (10ms)
+10333ms ║║Cancelling statement #16’s schedules…
+10334ms ║║Executed virtual command cancelTasks (0ms)
+10354ms ║╚Execution stage complete. (73ms)
+10370ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 19.296s), with 45 more jobs pending
+10380ms ╚Event processed successfully (10380ms)
12/15/2017, 10:01:00 AM +96ms
+1ms ╔Received event [Dinner Table #2].level = 10 with a delay of 968ms
+137ms ║RunTime Analysis CS > 18ms > PS > 32ms > PE > 87ms > CE
+139ms ║Runtime (41597 bytes) successfully initialized in 32ms (v0.2.100.20171211) (138ms)
+140ms ║╔Execution stage started
+155ms ║║Comparison (enum) off is (string) off = true (2ms)
+156ms ║║Condition #9 evaluated true (10ms)
+157ms ║║Condition group #1 evaluated true (state did not change) (12ms)
+175ms ║║Comparison (enum) off is (string) off = true (1ms)
+176ms ║║Condition #10 evaluated true (8ms)
+177ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+192ms ║║Cancelling statement #16’s schedules…
+194ms ║║Executed virtual command cancelTasks (1ms)
+223ms ║╚Execution stage complete. (83ms)
+237ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 29.105s), with 45 more jobs pending
+245ms ╚Event processed successfully (245ms)
12/15/2017, 10:00:59 AM +732ms
+1ms ╔Received event [Dinner Table #2].switch = on with a delay of 968ms
+134ms ║RunTime Analysis CS > 18ms > PS > 33ms > PE > 83ms > CE
+137ms ║Runtime (41598 bytes) successfully initialized in 33ms (v0.2.100.20171211) (135ms)
+138ms ║╔Execution stage started
+152ms ║║Comparison (enum) off is (string) off = true (1ms)
+153ms ║║Condition #9 evaluated true (9ms)
+154ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+171ms ║║Comparison (enum) off is (string) off = true (1ms)
+173ms ║║Condition #10 evaluated true (8ms)
+174ms ║║Condition group #6 evaluated true (state did not change) (10ms)
+189ms ║║Cancelling statement #16’s schedules…
+191ms ║║Executed virtual command cancelTasks (1ms)
+220ms ║╚Execution stage complete. (82ms)
+233ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 29.473s), with 45 more jobs pending
+245ms ╚Event processed successfully (245ms)
12/15/2017, 10:00:59 AM +143ms
+1ms ╔Received event [Home].time = 1513350060000 with a delay of -857ms
+136ms ║RunTime Analysis CS > 16ms > PS > 43ms > PE > 76ms > CE
+138ms ║Runtime (41597 bytes) successfully initialized in 43ms (v0.2.100.20171211) (136ms)
+139ms ║╔Execution stage started
+155ms ║║Cancelling statement #2’s schedules…
+172ms ║║Executed physical command [Dinner Table #1].on() (11ms)
+173ms ║║Executed [Dinner Table #1].on (13ms)
+188ms ║║Executed physical command [Dinner Table #2].on() (10ms)
+188ms ║║Executed [Dinner Table #2].on (13ms)
+203ms ║║Executed physical command [Dinner Table #3].on() (11ms)
+204ms ║║Executed [Dinner Table #3].on (13ms)
+217ms ║║Executed physical command [Dinner Table #4].on() (10ms)
+218ms ║║Executed [Dinner Table #4].on (11ms)
+236ms ║║Executed physical command [Dinner Table #1].setLevel([10]) (8ms)
+237ms ║║Executed [Dinner Table #1].setLevel (16ms)
+246ms ║║Executed physical command [Dinner Table #2].setLevel([10]) (8ms)
+247ms ║║Executed [Dinner Table #2].setLevel (10ms)
+256ms ║║Executed physical command [Dinner Table #3].setLevel([10]) (8ms)
+257ms ║║Executed [Dinner Table #3].setLevel (8ms)
+265ms ║║Executed physical command [Dinner Table #4].setLevel([10]) (7ms)
+266ms ║║Executed [Dinner Table #4].setLevel (9ms)
+289ms ║║Executed physical command [Dinner Table #1].setLevel([10]) (8ms)
+302ms ║║Executed virtual command [Dinner Table #1].fadeLevel (30ms)
+312ms ║║Executed physical command [Dinner Table #2].setLevel([10]) (8ms)
+318ms ║║Executed virtual command [Dinner Table #2].fadeLevel (15ms)
+328ms ║║Executed physical command [Dinner Table #3].setLevel([10]) (8ms)
+334ms ║║Executed virtual command [Dinner Table #3].fadeLevel (15ms)
+344ms ║║Executed physical command [Dinner Table #4].setLevel([10]) (7ms)
+349ms ║║Executed virtual command [Dinner Table #4].fadeLevel (14ms)
+350ms ║║Requesting a wake up for Fri, Dec 15 2017 @ 10:05:59 AM EST (in 300.1s)
+391ms ║╚Execution stage complete. (252ms)
+404ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:29 AM EST (in 29.891s), with 46 more jobs pending
+411ms ╚Event processed successfully (411ms)
12/15/2017, 10:00:35 AM +232ms
+1ms ╔Received event [Home].execute = recovery with a delay of 85ms
+129ms ║RunTime Analysis CS > 16ms > PS > 30ms > PE > 83ms > CE
+132ms ║Runtime (41593 bytes) successfully initialized in 30ms (v0.2.100.20171211) (130ms)
+133ms ║╔Execution stage started
+146ms ║║Comparison (enum) off is (string) off = true (1ms)
+148ms ║║Condition #9 evaluated true (9ms)
+149ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+158ms ║║Comparison (enum) off is (string) off = true (2ms)
+159ms ║║Condition #10 evaluated true (7ms)
+160ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+166ms ║╚Execution stage complete. (33ms)
+167ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:00 AM EST (in 24.601s), with 1 more job pending
+178ms ╚Event processed successfully (177ms)
12/15/2017, 10:00:34 AM +391ms
+1ms ╔Starting piston… (v0.2.100.20171211)
+219ms ║╔Subscribing to devices…
+247ms ║║Subscribing to Kitchen Sink.level…
+263ms ║║Subscribing to Dinner Table #1.level…
+278ms ║║Subscribing to Dinner Table #2.level…
+295ms ║║Subscribing to Dinner Table #3.level…
+311ms ║║Subscribing to Dinner Table #4.level…
+325ms ║║Subscribing to Kitchen Sink.switch…
+339ms ║║Subscribing to Dinner Table #1.switch…
+352ms ║║Subscribing to Dinner Table #2.switch…
+366ms ║║Subscribing to Dinner Table #3.switch…
+379ms ║║Subscribing to Dinner Table #4.switch…
+524ms ║║Subscribing to Party…
+525ms ║╚Finished subscribing (312ms)
+557ms ║Comparison (enum) off is (string) off = true (2ms)
+622ms ║Comparison (enum) off is (string) off = true (1ms)
+648ms ║Setting up scheduled job for Fri, Dec 15 2017 @ 10:01:00 AM EST (in 24.962s), with 1 more job pending
+659ms ╚Piston successfully started (659ms)

[michicago]

That’s interesting - the part of the log you highlighted shows it cancelled tasks and the very next command set the next wake-up time.

Out of curiosity, what happens if you change the active device for Cancel All Pending Tasks to “Location”… where you currently have it as Dimmer 5 and Lights? I wonder if the pending tasks, since it’s a webCoRE timed level change, is associated with Home.[time] and not being cancelled.

Only one more flight and I should be home and able to help better… assuming the 8 hour backwards time change doesn’t make me pass out as soon as I get home, lol.

[allrak]

Whoa, 8 hour time change? That’s a heck of a flight…

So I’ve been toying with this piston and it still doesn’t work. I even tried putting the “cancel all tasks” inside the “every day at…” as shown below… Here’s a pic of the current piston and some more logs.

12/16/2017, 10:27:29 AM +727ms
+1ms ╔Received event [Dinner Table #1].switch = on with a delay of 430ms
+141ms ║RunTime Analysis CS > 16ms > PS > 29ms > PE > 96ms > CE
+144ms ║Runtime (41903 bytes) successfully initialized in 29ms (v0.2.100.20171211) (142ms)
+145ms ║╔Execution stage started
+158ms ║║Comparison (enum) off is (string) off = true (2ms)
+159ms ║║Condition #9 evaluated true (9ms)
+160ms ║║Condition group #1 evaluated true (state did not change) (10ms)
+177ms ║║Comparison (enum) off is (string) off = true (2ms)
+178ms ║║Condition #10 evaluated true (8ms)
+179ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+213ms ║║Condition #18 evaluated false (24ms)
+233ms ║║Comparison (enum) on changes = true (1ms)
+235ms ║║Condition #19 evaluated true (21ms)
+236ms ║║Condition group #15 evaluated true (state did not change) (47ms)
+238ms ║║Cancelling statement #16’s schedules…
+240ms ║║Executed virtual command cancelTasks (0ms)
+278ms ║║Executed physical command [Dinner Table #1].setLevel([11]) (6ms)
+297ms ║║Executed physical command [Dinner Table #2].setLevel([11]) (6ms)
+315ms ║║Executed physical command [Dinner Table #3].setLevel([11]) (6ms)
+332ms ║║Executed physical command [Dinner Table #4].setLevel([11]) (6ms)
+344ms ║╚Execution stage complete. (198ms)
+356ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:59 AM EST (in 29.411s), with 41 more jobs pending
+365ms ╚Event processed successfully (365ms)
12/16/2017, 10:27:29 AM +295ms
+0ms ╔Received event [Home].time = 1513438049492 with a delay of -198ms
+160ms ║RunTime Analysis CS > 18ms > PS > 43ms > PE > 96ms > CE
+165ms ║Runtime (41902 bytes) successfully initialized in 43ms (v0.2.100.20171211) (164ms)
+169ms ║╔Execution stage started
+194ms ║║Executed physical command [Dinner Table #1].setLevel([11]) (10ms)
+202ms ║║Fast executing schedules, waiting for 15ms to sync up
+236ms ║║Executed physical command [Dinner Table #2].setLevel([11]) (10ms)
+256ms ║║Executed physical command [Dinner Table #3].setLevel([11]) (10ms)
+278ms ║║Executed physical command [Dinner Table #4].setLevel([11]) (12ms)
+291ms ║╚Execution stage complete. (124ms)
+304ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:59 AM EST (in 29.895s), with 41 more jobs pending
+314ms ╚Event processed successfully (314ms)
12/16/2017, 10:27:22 AM +765ms
+1ms ╔Received event [Dinner Table #1].switch = off with a delay of 451ms
+139ms ║RunTime Analysis CS > 12ms > PS > 34ms > PE > 92ms > CE
+141ms ║Runtime (41907 bytes) successfully initialized in 34ms (v0.2.100.20171211) (139ms)
+142ms ║╔Execution stage started
+155ms ║║Comparison (enum) off is (string) off = true (1ms)
+157ms ║║Condition #9 evaluated true (9ms)
+158ms ║║Condition group #1 evaluated true (state did not change) (10ms)
+176ms ║║Comparison (enum) off is (string) off = true (2ms)
+177ms ║║Condition #10 evaluated true (8ms)
+178ms ║║Condition group #6 evaluated true (state did not change) (10ms)
+214ms ║║Condition #18 evaluated false (25ms)
+233ms ║║Comparison (enum) off changes = true (1ms)
+235ms ║║Cancelling condition #19’s schedules…
+236ms ║║Condition #19 evaluated true (21ms)
+237ms ║║Cancelling condition #15’s schedules…
+238ms ║║Condition group #15 evaluated true (state changed) (48ms)
+240ms ║║Cancelling statement #16’s schedules…
+241ms ║║Executed virtual command cancelTasks (0ms)
+282ms ║╚Execution stage complete. (140ms)
+295ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 6.432s), with 45 more jobs pending
+309ms ╚Event processed successfully (309ms)
12/16/2017, 10:27:00 AM +976ms
+1ms ╔Received event [Dinner Table #2].level = 10 with a delay of 1018ms
+10049ms ║RunTime Analysis CS > 16ms > PS > 9899ms > PE > 134ms > CE
+10050ms ║Piston waited at a semaphore for 9858ms
+10053ms ║Runtime (41983 bytes) successfully initialized in 9899ms (v0.2.100.20171211) (10050ms)
+10054ms ║╔Execution stage started
+10066ms ║║Comparison (enum) off is (string) off = true (1ms)
+10068ms ║║Condition #9 evaluated true (9ms)
+10069ms ║║Condition group #1 evaluated true (state did not change) (10ms)
+10086ms ║║Comparison (enum) off is (string) off = true (2ms)
+10087ms ║║Condition #10 evaluated true (8ms)
+10088ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+10118ms ║║Comparison (integer) 10 changes = false (0ms)
+10121ms ║║Condition #18 evaluated false (22ms)
+10185ms ║║Condition #19 evaluated false (63ms)
+10186ms ║║Condition group #15 evaluated false (state did not change) (87ms)
+10193ms ║╚Execution stage complete. (139ms)
+10207ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 18.31s), with 45 more jobs pending
+10220ms ╚Event processed successfully (10220ms)
12/16/2017, 10:27:00 AM +509ms
+1ms ╔Received event [Dinner Table #3].level = 10 with a delay of 459ms
+10080ms ║RunTime Analysis CS > 72ms > PS > 9886ms > PE > 123ms > CE
+10081ms ║Piston waited at a semaphore for 9848ms
+10083ms ║Runtime (41979 bytes) successfully initialized in 9886ms (v0.2.100.20171211) (10081ms)
+10084ms ║╔Execution stage started
+10099ms ║║Comparison (enum) off is (string) off = true (1ms)
+10100ms ║║Condition #9 evaluated true (10ms)
+10101ms ║║Condition group #1 evaluated true (state did not change) (12ms)
+10119ms ║║Comparison (enum) off is (string) off = true (1ms)
+10121ms ║║Condition #10 evaluated true (8ms)
+10121ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+10161ms ║║Comparison (integer) 10 changes = false (1ms)
+10163ms ║║Condition #18 evaluated false (31ms)
+10186ms ║║Condition #19 evaluated false (22ms)
+10187ms ║║Condition group #15 evaluated false (state did not change) (55ms)
+10194ms ║╚Execution stage complete. (110ms)
+10207ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 18.777s), with 45 more jobs pending
+10279ms ╚Event processed successfully (10280ms)
12/16/2017, 10:27:00 AM +602ms
+1ms ╔Received event [Dinner Table #4].level = 10 with a delay of 446ms
+9964ms ║RunTime Analysis CS > 16ms > PS > 9815ms > PE > 134ms > CE
+9965ms ║Piston waited at a semaphore for 9776ms
+9968ms ║Runtime (41977 bytes) successfully initialized in 9815ms (v0.2.100.20171211) (9965ms)
+9969ms ║╔Execution stage started
+9983ms ║║Comparison (enum) off is (string) off = true (2ms)
+9985ms ║║Condition #9 evaluated true (10ms)
+9986ms ║║Condition group #1 evaluated true (state did not change) (12ms)
+10005ms ║║Comparison (enum) off is (string) off = true (1ms)
+10006ms ║║Condition #10 evaluated true (9ms)
+10007ms ║║Condition group #6 evaluated true (state did not change) (11ms)
+10045ms ║║Comparison (integer) 10 changes = false (0ms)
+10047ms ║║Condition #18 evaluated false (27ms)
+10072ms ║║Condition #19 evaluated false (25ms)
+10073ms ║║Condition group #15 evaluated false (state did not change) (54ms)
+10079ms ║╚Execution stage complete. (111ms)
+10092ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 18.799s), with 45 more jobs pending
+10104ms ╚Event processed successfully (10104ms)
12/16/2017, 10:26:59 AM +530ms
+1ms ╔Received event [Dinner Table #1].switch = on with a delay of 427ms
+9936ms ║RunTime Analysis CS > 22ms > PS > 9803ms > PE > 112ms > CE
+9937ms ║Piston waited at a semaphore for 9761ms
+9940ms ║Runtime (41975 bytes) successfully initialized in 9803ms (v0.2.100.20171211) (9937ms)
+9941ms ║╔Execution stage started
+9955ms ║║Comparison (enum) off is (string) off = true (2ms)
+9956ms ║║Condition #9 evaluated true (10ms)
+9957ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+9975ms ║║Comparison (enum) off is (string) off = true (1ms)
+9976ms ║║Condition #10 evaluated true (8ms)
+9977ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+10017ms ║║Cancelling condition #18’s schedules…
+10018ms ║║Condition #18 evaluated false (30ms)
+10038ms ║║Comparison (enum) on changes = false (1ms)
+10041ms ║║Cancelling condition #19’s schedules…
+10042ms ║║Condition #19 evaluated false (22ms)
+10043ms ║║Cancelling condition #15’s schedules…
+10044ms ║║Condition group #15 evaluated false (state changed) (55ms)
+10062ms ║╚Execution stage complete. (122ms)
+10076ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 19.887s), with 45 more jobs pending
+10089ms ╚Event processed successfully (10089ms)
12/16/2017, 10:27:00 AM +798ms
+1ms ╔Received event [Dinner Table #2].level = 10 with a delay of 471ms
+148ms ║RunTime Analysis CS > 22ms > PS > 39ms > PE > 87ms > CE
+151ms ║Runtime (41900 bytes) successfully initialized in 39ms (v0.2.100.20171211) (149ms)
+152ms ║╔Execution stage started
+167ms ║║Comparison (enum) off is (string) off = true (2ms)
+169ms ║║Condition #9 evaluated true (9ms)
+170ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+190ms ║║Comparison (enum) off is (string) off = true (2ms)
+191ms ║║Condition #10 evaluated true (9ms)
+192ms ║║Condition group #6 evaluated true (state did not change) (10ms)
+230ms ║║Comparison (integer) 10 changes = true (1ms)
+232ms ║║Cancelling condition #18’s schedules…
+233ms ║║Condition #18 evaluated true (27ms)
+235ms ║║Condition group #15 evaluated true (state did not change) (29ms)
+238ms ║║Cancelling statement #16’s schedules…
+240ms ║║Executed virtual command cancelTasks (0ms)
+277ms ║╚Execution stage complete. (125ms)
+290ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 28.404s), with 45 more jobs pending
+303ms ╚Event processed successfully (302ms)
12/16/2017, 10:27:00 AM +319ms
+1ms ╔Received event [Dinner Table #4].switch = on with a delay of 482ms
+128ms ║RunTime Analysis CS > 17ms > PS > 27ms > PE > 84ms > CE
+131ms ║Runtime (41901 bytes) successfully initialized in 27ms (v0.2.100.20171211) (128ms)
+132ms ║╔Execution stage started
+146ms ║║Comparison (enum) off is (string) off = true (1ms)
+147ms ║║Condition #9 evaluated true (10ms)
+148ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+166ms ║║Comparison (enum) off is (string) off = true (1ms)
+168ms ║║Condition #10 evaluated true (8ms)
+168ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+203ms ║║Condition #18 evaluated false (24ms)
+221ms ║║Comparison (enum) on changes = true (1ms)
+223ms ║║Condition #19 evaluated true (19ms)
+224ms ║║Condition group #15 evaluated true (state did not change) (45ms)
+227ms ║║Cancelling statement #16’s schedules…
+228ms ║║Executed virtual command cancelTasks (0ms)
+262ms ║╚Execution stage complete. (131ms)
+276ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 28.898s), with 45 more jobs pending
+288ms ╚Event processed successfully (288ms)
12/16/2017, 10:26:59 AM +738ms
+1ms ╔Received event [Dinner Table #3].switch = on with a delay of 463ms
+173ms ║RunTime Analysis CS > 18ms > PS > 29ms > PE > 127ms > CE
+176ms ║Runtime (41909 bytes) successfully initialized in 29ms (v0.2.100.20171211) (174ms)
+177ms ║╔Execution stage started
+191ms ║║Comparison (enum) off is (string) off = true (1ms)
+192ms ║║Condition #9 evaluated true (9ms)
+193ms ║║Condition group #1 evaluated true (state did not change) (11ms)
+211ms ║║Comparison (enum) off is (string) off = true (2ms)
+212ms ║║Condition #10 evaluated true (8ms)
+213ms ║║Condition group #6 evaluated true (state did not change) (9ms)
+249ms ║║Condition #18 evaluated false (25ms)
+268ms ║║Comparison (enum) on changes = true (0ms)
+270ms ║║Cancelling condition #19’s schedules…
+271ms ║║Condition #19 evaluated true (21ms)
+272ms ║║Cancelling condition #15’s schedules…
+273ms ║║Condition group #15 evaluated true (state changed) (49ms)
+275ms ║║Cancelling statement #16’s schedules…
+277ms ║║Executed virtual command cancelTasks (0ms)
+315ms ║╚Execution stage complete. (138ms)
+329ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 29.426s), with 45 more jobs pending
+342ms ╚Event processed successfully (342ms)
12/16/2017, 10:26:59 AM +112ms
+1ms ╔Received event [Home].time = 1513438020000 with a delay of -888ms
+163ms ║RunTime Analysis CS > 17ms > PS > 45ms > PE > 101ms > CE
+166ms ║Runtime (41908 bytes) successfully initialized in 45ms (v0.2.100.20171211) (164ms)
+167ms ║╔Execution stage started
+187ms ║║Cancelling statement #2’s schedules…
+205ms ║║Executed physical command [Dinner Table #1].on() (10ms)
+206ms ║║Executed [Dinner Table #1].on (11ms)
+217ms ║║Executed physical command [Dinner Table #2].on() (9ms)
+218ms ║║Executed [Dinner Table #2].on (11ms)
+288ms ║║Executed physical command [Dinner Table #3].on() (68ms)
+289ms ║║Executed [Dinner Table #3].on (69ms)
+302ms ║║Executed physical command [Dinner Table #4].on() (10ms)
+303ms ║║Executed [Dinner Table #4].on (12ms)
+315ms ║║Executed physical command [Dinner Table #1].setLevel([10]) (7ms)
+316ms ║║Executed [Dinner Table #1].setLevel (9ms)
+327ms ║║Executed physical command [Dinner Table #2].setLevel([10]) (8ms)
+327ms ║║Executed [Dinner Table #2].setLevel (11ms)
+338ms ║║Executed physical command [Dinner Table #3].setLevel([10]) (8ms)
+339ms ║║Executed [Dinner Table #3].setLevel (11ms)
+348ms ║║Executed physical command [Dinner Table #4].setLevel([10]) (7ms)
+349ms ║║Executed [Dinner Table #4].setLevel (8ms)
+374ms ║║Executed physical command [Dinner Table #1].setLevel([10]) (8ms)
+388ms ║║Executed virtual command [Dinner Table #1].fadeLevel (32ms)
+399ms ║║Executed physical command [Dinner Table #2].setLevel([10]) (7ms)
+408ms ║║Executed virtual command [Dinner Table #2].fadeLevel (17ms)
+418ms ║║Executed physical command [Dinner Table #3].setLevel([10]) (7ms)
+425ms ║║Executed virtual command [Dinner Table #3].fadeLevel (15ms)
+436ms ║║Executed physical command [Dinner Table #4].setLevel([10]) (9ms)
+442ms ║║Executed virtual command [Dinner Table #4].fadeLevel (17ms)
+444ms ║║Requesting a wake up for Sat, Dec 16 2017 @ 10:31:59 AM EST (in 300.1s)
+508ms ║╚Execution stage complete. (341ms)
+523ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:29 AM EST (in 29.858s), with 46 more jobs pending
+532ms ╚Event processed successfully (532ms)
12/16/2017, 10:26:32 AM +998ms
+0ms ╔Starting piston… (v0.2.100.20171211)
+301ms ║╔Subscribing to devices…
+360ms ║║Subscribing to Kitchen Sink.level…
+378ms ║║Subscribing to Dinner Table #1.level…
+396ms ║║Subscribing to Dinner Table #2.level…
+414ms ║║Subscribing to Dinner Table #3.level…
+432ms ║║Subscribing to Dinner Table #4.level…
+450ms ║║Subscribing to Kitchen Sink.switch…
+465ms ║║Subscribing to Dinner Table #1.switch…
+480ms ║║Subscribing to Dinner Table #2.switch…
+496ms ║║Subscribing to Dinner Table #3.switch…
+512ms ║║Subscribing to Dinner Table #4.switch…
+667ms ║║Subscribing to Party…
+668ms ║╚Finished subscribing (374ms)
+709ms ║Comparison (enum) off is (string) off = true (1ms)
+748ms ║Comparison (enum) off is (string) off = true (1ms)
+975ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 10:27:00 AM EST (in 26.028s), with 1 more job pending
+1015ms ╚Piston successfully started (1015ms)

[michicago]

Yeah, I flew from Jeddah, Saudi Arabia to Frankfurt to Chicago and then home to NC. I was only there for a few days for a conference… just long enough to completely hose my body clock!

I notice in your logs something is taking 10 seconds to execute, too. That shouldn’t happen - is this piston colliding with another piston that is controlling these lights?

Either way, it’s really puzzling the piston is setting a wake-up time immediately after cancelling all tasks. Just for grins, what happens if you create a new piston that does something like this:

Fade lights X and Y from 0 to 100% over 10 minutes.
If switch X level changes, cancel all pending tasks.

If you run that and alter switch X’s level after 5 minutes, what happens and what shows up in the log? I’m almost wondering if the 10 second execution and 45 pending jobs for the piston we’re messing around with are causing odd behavior and have us chasing our tails.

[allrak]

okay, brand new piston, using only 1 light… should be super-simple, right? Still doesn’t work for some reason.

Note the above piston, I did change the AND to an OR re: cancel all pending tasks (just didn’t upload a fresh pic)

12/16/2017, 3:39:32 PM +842ms
+1ms ╔Received event [Dinner Table #1].level = 11 with a delay of 1230ms
+90ms ║RunTime Analysis CS > 18ms > PS > 32ms > PE > 39ms > CE
+92ms ║Runtime (36909 bytes) successfully initialized in 32ms (v0.2.100.20171211) (90ms)
+93ms ║╔Execution stage started
+99ms ║║Cancelling statement #1’s schedules…
+116ms ║║Executed physical command [Dinner Table #1].setLevel([10]) (8ms)
+163ms ║║Executed virtual command [Dinner Table #1].fadeLevel (55ms)
+164ms ║║Requesting a wake up for Sat, Dec 16 2017 @ 3:59:33 PM EST (in 1200.1s)
+211ms ║╚Execution stage complete. (118ms)
+238ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 3:39:46 PM EST (in 13.217s), with 91 more jobs pending
+248ms ╚Event processed successfully (248ms)
12/16/2017, 3:39:32 PM +278ms
+1ms ╔Received event [Home].time = 1513456772945 with a delay of -667ms
+92ms ║RunTime Analysis CS > 14ms > PS > 33ms > PE > 44ms > CE
+94ms ║Runtime (36908 bytes) successfully initialized in 33ms (v0.2.100.20171211) (92ms)
+96ms ║╔Execution stage started
+125ms ║║Executed physical command [Dinner Table #1].setLevel([11]) (7ms)
+152ms ║╚Execution stage complete. (56ms)
+179ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 3:39:46 PM EST (in 13.823s), with 90 more jobs pending
+188ms ╚Event processed successfully (188ms)
12/16/2017, 3:39:19 PM +502ms
+1ms ╔Received event [Dinner Table #1].switch = on with a delay of 980ms
+88ms ║RunTime Analysis CS > 18ms > PS > 33ms > PE > 37ms > CE
+90ms ║Runtime (36909 bytes) successfully initialized in 33ms (v0.2.100.20171211) (89ms)
+91ms ║╔Execution stage started
+97ms ║║Cancelling statement #1’s schedules…
+110ms ║║Skipped execution of physical command [Dinner Table #1].setLevel([10]) because it would make no change to the device. (2ms)
+149ms ║║Executed virtual command [Dinner Table #1].fadeLevel (44ms)
+150ms ║║Requesting a wake up for Sat, Dec 16 2017 @ 3:59:19 PM EST (in 1200.1s)
+196ms ║╚Execution stage complete. (105ms)
+222ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 3:39:32 PM EST (in 13.222s), with 91 more jobs pending
+234ms ╚Event processed successfully (235ms)
12/16/2017, 3:39:18 PM +918ms
+1ms ╔Received event [Dinner Table #1].switch = off with a delay of 1008ms
+100ms ║RunTime Analysis CS > 12ms > PS > 52ms > PE > 35ms > CE
+102ms ║Runtime (36912 bytes) successfully initialized in 52ms (v0.2.100.20171211) (100ms)
+103ms ║╔Execution stage started
+108ms ║║Cancelling statement #1’s schedules…
+127ms ║║Executed physical command [Dinner Table #1].setLevel([10]) (9ms)
+357ms ║║Executed virtual command [Dinner Table #1].fadeLevel (241ms)
+359ms ║║Requesting a wake up for Sat, Dec 16 2017 @ 3:59:19 PM EST (in 1200.1s)
+405ms ║╚Execution stage complete. (303ms)
+430ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 3:39:32 PM EST (in 13.032s), with 91 more jobs pending
+443ms ╚Event processed successfully (443ms)
12/16/2017, 3:39:12 PM +392ms
+2ms ╔Received event [Dinner Table #1].level = 10 with a delay of 1084ms
+103ms ║RunTime Analysis CS > 23ms > PS > 44ms > PE > 35ms > CE
+105ms ║Runtime (36910 bytes) successfully initialized in 44ms (v0.2.100.20171211) (102ms)
+106ms ║╔Execution stage started
+112ms ║║Cancelling statement #1’s schedules…
+131ms ║║Executed physical command [Dinner Table #1].setLevel([10]) (9ms)
+171ms ║║Executed virtual command [Dinner Table #1].fadeLevel (50ms)
+172ms ║║Requesting a wake up for Sat, Dec 16 2017 @ 3:59:12 PM EST (in 1200.1s)
+217ms ║╚Execution stage complete. (111ms)
+242ms ║Setting up scheduled job for Sat, Dec 16 2017 @ 3:39:25 PM EST (in 13.224s), with 91 more jobs pending
+254ms ╚Event processed successfully (253ms)

[allrak]

I also tried using a different light (and different brand [sengled vs. hue]), which I know has nothing else controlling it, same result. It actually even got stranger, I kept seeing the logs adjust it to 10, then adjust it to 12, then adjust it back to 10, back to 12, etc…

[michicago]

Usually my litmus test is going to basics to prove functionality, then rebuilding the complexities around it. I can’t understand why what you wrote there didn’t work…

paging @webCoRE_Minions to see if they can help!

[allrak]

I swear it seems the cancel pending events stanza is subscribing to the events occurring in the fade to level stanza.

[bobbles]

New to this thread so I apologise if I’ve missed something but what is the trigger for the piston in post 15.

[Robin]

The trigger appears to be a level change, and the action is a level change, so you’ve created an endless loop which will keep reverting to 10%