Unwanted over execution of the same child piston


#1

1) Give a description of the problem
Executing a child piston happens multiple times on the same call (it is not in a loop, using a callback or recursion [in other words it does not call itself directly or indirectly]). The logs below show it happening twice but in some cases SmartThings reports three times.

2) What is the expected behaviour?
The instruction to call a piston happens only once.

3) What is happening/not happening?
A call made by a parent is happening multiple times (should be only once) on the same child piston. The “unwanted calls” have an argument value that is 0 (an integer type in my case) and it is easy to trap and exit the piston. I should not have to handle this condition.

**4) Post a Green Snapshot **

5) Attach logs after turning logging level to Full

7/15/2019, 7:21:36 PM +456ms
+0ms â•”Received event [Home].:de0ed8c9f29601e3ec8f1584cae0969c: = @LastChangedBy with a delay of 54ms
+85ms â•‘RunTime Analysis CS > 19ms > PS > 39ms > PE > 28ms > CE
+88ms â•‘Runtime (48569 bytes) successfully initialized in 39ms (v0.3.10e.20190628) (87ms)
+89ms â•‘â•”Execution stage started
+97ms â•‘â•‘Comparison (integer) 0 is_different_than (integer) 5 = true (1ms)
+98ms â•‘â•‘Condition #52 evaluated true (5ms)
+102ms â•‘â•‘Comparison (integer) 3 is_equal_to (integer) 5 = false (1ms)
+104ms â•‘â•‘Condition #53 evaluated false (4ms)
+104ms â•‘â•‘Condition group #57 evaluated false (state did not change) (11ms)
+110ms â•‘â•‘Comparison (integer) 0 is_equal_to (integer) 0 = true (1ms)
+111ms â•‘â•‘Cancelling condition #59's schedules...
+112ms â•‘â•‘Condition #59 evaluated true (6ms)
+113ms â•‘â•‘Cancelling condition #58's schedules...
+114ms â•‘â•‘Condition group #58 evaluated true (state changed) (8ms)
+115ms â•‘â•‘Cancelling condition #32's schedules...
+115ms â•‘â•‘Condition group #32 evaluated true (state changed) (23ms)
+117ms â•‘â•‘Cancelling statement #60's schedules...
+125ms â•‘â•‘Calculating (string) Exited at: + (string) -135199207 >> (string) Exited at:-135199207
+128ms â•‘â•‘Calculating (string) Exited at:-135199207 + (string) => RequestingSetting: >> (string) Exited at:-135199207 => RequestingSetting:
+130ms â•‘â•‘Calculating (string) Exited at:-135199207 => RequestingSetting: + (string) 0 >> (string) Exited at:-135199207 => RequestingSetting:0
+134ms â•‘â•‘Exited at:-135199207 => RequestingSetting:0
+135ms â•‘â•‘Executed virtual command log (1ms)
+139ms ║╚Execution stage complete. (51ms)
+140ms ╚Event processed successfully (140ms)
7/15/2019, 7:21:35 PM +403ms
+1ms â•”Received event [Home].execute = :b473d20bf1dd70d72b45ef8dd2c6db8c: with a delay of 52ms
+89ms â•‘RunTime Analysis CS > 20ms > PS > 39ms > PE > 30ms > CE
+91ms â•‘Runtime (48562 bytes) successfully initialized in 39ms (v0.3.10e.20190628) (90ms)
+92ms â•‘â•”Execution stage started
+101ms â•‘â•‘Comparison (integer) 3 is_different_than (integer) 5 = true (2ms)
+102ms â•‘â•‘Condition #52 evaluated true (5ms)
+106ms â•‘â•‘Comparison (integer) 2 is_equal_to (integer) 5 = false (1ms)
+108ms â•‘â•‘Condition #53 evaluated false (4ms)
+109ms â•‘â•‘Condition group #57 evaluated false (state did not change) (11ms)
+114ms â•‘â•‘Comparison (integer) 3 is_equal_to (integer) 0 = false (2ms)
+115ms â•‘â•‘Cancelling condition #59's schedules...
+116ms â•‘â•‘Condition #59 evaluated false (6ms)
+117ms â•‘â•‘Cancelling condition #58's schedules...
+118ms â•‘â•‘Condition group #58 evaluated false (state changed) (8ms)
+119ms â•‘â•‘Cancelling condition #32's schedules...
+120ms â•‘â•‘Condition group #32 evaluated false (state changed) (24ms)
+123ms â•‘â•‘Evaluating switch with values [[i:1:null:0, v:[t:integer, v:3, vt:string]]]
+125ms â•‘â•‘Comparison (integer) 3 is (integer) 2 = false (1ms)
+128ms â•‘â•‘Comparison (integer) 3 is (integer) 3 = true (1ms)
+130ms â•‘â•‘Cancelling statement #8's schedules...
+135ms â•‘â•‘Executed virtual command setVariable (3ms)
+142ms â•‘â•‘Comparison (integer) 3 is_equal_to (integer) 2 = false (2ms)
+143ms â•‘â•‘Condition #16 evaluated false (5ms)
+148ms â•‘â•‘Comparison (integer) 3 is_equal_to (integer) 3 = true (1ms)
+149ms â•‘â•‘Cancelling condition #17's schedules...
+150ms â•‘â•‘Condition #17 evaluated true (6ms)
+151ms â•‘â•‘Cancelling condition #15's schedules...
+152ms â•‘â•‘Condition group #15 evaluated true (state changed) (14ms)
+156ms â•‘â•‘Comparison (integer) 7 is_greater_than_or_equal_to (integer) 4 = true (1ms)
+157ms â•‘â•‘Condition #64 evaluated true (5ms)
+161ms â•‘â•‘Comparison (integer) 7 is_less_than_or_equal_to (integer) 9 = true (1ms)
+162ms â•‘â•‘Condition #65 evaluated true (4ms)
+163ms â•‘â•‘Cancelling condition #14's schedules...
+164ms â•‘â•‘Condition group #14 evaluated true (state changed) (27ms)
+166ms â•‘â•‘Cancelling statement #19's schedules...
+171ms â•‘â•‘Calculating (integer) 116 - (integer) 2 >> (integer) 114
+174ms â•‘â•‘Executed virtual command setVariable (2ms)
+177ms â•‘â•‘Cancelling statement #54's schedules...
+957ms â•‘â•‘Executed physical command [null].setHeatingSetpoint([114.0]) (776ms)
+958ms â•‘â•‘Executed [Thermostat1].setHeatingSetpoint (778ms)
+960ms â•‘â•‘Cancelling statement #62's schedules...
+966ms â•‘â•‘Calculating (string) Ended at: + (string) -135200257 >> (string) Ended at:-135200257
+969ms â•‘â•‘Ended at:-135200257
+970ms â•‘â•‘Executed virtual command log (1ms)
+972ms â•‘â•‘Cancelling statement #66's schedules...
+975ms â•‘â•‘Executed virtual command setVariable (1ms)
+977ms ║╚Execution stage complete. (885ms)
+978ms ╚Event processed successfully (978ms)

I use a $ as a replacement in this post to denote an at symbol (followed by an underscore) as global variable that is a “constant”. I won’t let me use the at symbol for any reason, since it thinks I am adding users to a post. Because there are not global constants, I use this markup to tell me the variable should not be modified in a statement.

_Additional variable values _

integer $SettingCleaningTemperature = 4;
integer $SettingLowTemperature = 1;
integer $SettingNightCleaningTemperature = 5;
integer $SettingRegularTemperature = 2;
integer $SettingShoweringTemperature = 3;


#2

I see your child piston has triggers that subscribes to global variables that are also modified in the child piston. Try removing those subscriptions and then trigger the child piston to see if you get the unwanted double executions.


#3

For what it’s worth, I program my “child” pistons to have absolutely zero triggers. With your current wording, the parent can execute the large piston, but it will also execute whenever @LastChangedBy, RequestSetting, @_SettingNightCleaningTemperature, @_SettingRegularTemperature, or @_SettingShoweringTemperature changes in any way. (each time, the piston runs top to bottom in it’s entirety)

Ideally, the large piston will have no lightning bolts in the left margin, and you’ll see this up top once saved:

The easiest way to achieve this is to add a single IF to the larger piston:

IF $day changes


The reason this works is because if you have no triggers like above, then all your conditions become triggers. You do not want this on child pistons. Adding a trigger pointing towards a system variable prevents the conditions from becoming triggers, and yet, the system variable fails as a trigger, so you get the best of both worlds.

Here is a brief example. First, notice the condition treated as a trigger:

temp

and now that same code with my suggestion inserted:

temp

Notice the lightning bolt vanishes.
This last piston will never run unless an external command forces it to execute.


#4

I applied the piston setting “disable event subscriptions” (I did not need to subscribe to any events [value to value comparisons] in this piston) and that fixed it. Thank you the confirmation that was the issue.


#5

Yup. That method works, as long as you remember to repeat this on all conditions you add in the future…

My suggestion was one line of code to change the way the entire piston behaves. :sunglasses:

Both methods have their uses though…