Piston is called but sometimes does nothing?

bug
execution
#1

1) Give a description of the problem
I have a piston to set my thermostat whenever the mode changes. The last two mornings, it didn’t work. I tried changing mode manually again and it still didn’t work. Then I did it a third time and it worked fine.

2) What is the expected behavior?
Change the thermostat set point and log the changes.

3) What is happening/not happening?
Sometimes works, sometimes doesn’t. Maybe I need a check and re-run?

**4) Post a Green Snapshot of the piston

Unknown
Unknown.png1178×2454 617 KB

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

12/1/2018, 7:12:01 AM +168ms
+1ms ╔Received event [Las Vegas].mode = Home with a delay of 55ms
+124ms ║RunTime Analysis CS > 16ms > PS > 53ms > PE > 54ms > CE
+127ms ║Runtime (58481 bytes) successfully initialized in 53ms (v0.3.108.20180906) (125ms)
+128ms ║╔Execution stage started
+137ms ║║Comparison (string) :837d018e2cfe467fc4b4c2b5486d6e5b: changes = true (1ms)
+138ms ║║Condition #4 evaluated true (4ms)
+140ms ║║Condition group #3 evaluated true (state did not change) (5ms)
+143ms ║║Evaluating switch with values [[i:23:v, v:[t:string, v::837d018e2cfe467fc4b4c2b5486d6e5b:, n:Home]]]
+147ms ║║Comparison (string) :837d018e2cfe467fc4b4c2b5486d6e5b: is (string) Night = false (2ms)
+152ms ║║Comparison (string) :837d018e2cfe467fc4b4c2b5486d6e5b: is (string) Away = false (2ms)
+156ms ║║Comparison (string) :837d018e2cfe467fc4b4c2b5486d6e5b: is (string) Home = true (2ms)
+159ms ║║Cancelling statement #27's schedules...
+2617ms ║║Calculating (string) The outside temperature in Las Vegas is + (string) 39.2 >> (string) The outside temperature in Las Vegas is 39.2
+2623ms ║║Calculating (string) The outside temperature in Las Vegas is 39.2 + (string) but inside it is >> (string) The outside temperature in Las Vegas is 39.2 but inside it is
+2629ms ║║Calculating (string) The outside temperature in Las Vegas is 39.2 but inside it is + (string) 0 >> (string) The outside temperature in Las Vegas is 39.2 but inside it is 0
+2634ms ║║Calculating (string) The outside temperature in Las Vegas is 39.2 but inside it is 0 + (string) . Today's high will be >> (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be
+2639ms ║║Calculating (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be + (string) 61 >> (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61
+2644ms ║║Calculating (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61 + (string) and the low will be >> (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61 and the low will be
+2648ms ║║Calculating (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61 and the low will be + (string) 41 >> (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61 and the low will be 41
+2652ms ║║Calculating (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61 and the low will be 41 + (string) . >> (string) The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61 and the low will be 41.
+2724ms ║║Executed physical command [LV Thermostat - Downstairs].log([info, The outside temperature in Las Vegas is 39.2 but inside it is 0. Today's high will be 61 and the low will be 41., true]) (64ms)
+2725ms ║║Executed [LV Thermostat - Downstairs].log (67ms)
+2963ms ║║Executed physical command [LV Thermostat - Downstairs].setHeatingSetpoint([73.0]) (234ms)
+2965ms ║║Executed [LV Thermostat - Downstairs].setHeatingSetpoint (236ms)
+2972ms ║║Calculating (string) Las Vegas downstairs heating set to + (string) 73 >> (string) Las Vegas downstairs heating set to 73
+2988ms ║║Executed virtual command [LV Thermostat - Downstairs].sendPushNotification (11ms)
+3166ms ║║Executed physical command [LV Thermostat - Downstairs].setCoolingSetpoint([78.0]) (174ms)
+3167ms ║║Executed [LV Thermostat - Downstairs].setCoolingSetpoint (176ms)
+3174ms ║║Calculating (string) Las Vegas downstairs cooling set to + (string) 78 >> (string) Las Vegas downstairs cooling set to 78
+3190ms ║║Executed virtual command [LV Thermostat - Downstairs].sendPushNotification (11ms)
+3194ms ║║Cancelling statement #45's schedules...
+3392ms ║║Executed physical command [LV Thermostat - Upstairs].setHeatingSetpoint([71.0]) (192ms)
+3393ms ║║Executed [LV Thermostat - Upstairs].setHeatingSetpoint (194ms)
+3401ms ║║Calculating (string) Las Vegas upstairs heating set to + (string) 71 >> (string) Las Vegas upstairs heating set to 71
+3418ms ║║Executed virtual command [LV Thermostat - Upstairs].sendPushNotification (13ms)
+3595ms ║║Executed physical command [LV Thermostat - Upstairs].setCoolingSetpoint([76.0]) (173ms)
+3596ms ║║Executed [LV Thermostat - Upstairs].setCoolingSetpoint (175ms)
+3603ms ║║Calculating (string) Las Vegas upstairs cooling set to + (string) 76 >> (string) Las Vegas upstairs cooling set to 76
+3620ms ║║Executed virtual command [LV Thermostat - Upstairs].sendPushNotification (12ms)
+3626ms ║╚Execution stage complete. (3498ms)
+3627ms ╚Event processed successfully (3627ms)
12/1/2018, 7:09:11 AM +142ms
+0ms ╔Received event [Las Vegas].time/recovery = 1543676951141 with a delay of 0ms
+132ms ║RunTime Analysis CS > 14ms > PS > 62ms > PE > 56ms > CE
+135ms ║Runtime (58498 bytes) successfully initialized in 62ms (v0.3.108.20180906) (134ms)
+136ms ║╔Execution stage started
+137ms ║╚Execution stage complete. (1ms)
+139ms ╚Event processed successfully (139ms)
12/1/2018, 6:00:51 AM +96ms
+1ms ╔Received event [Las Vegas].time/recovery = 1543672851095 with a delay of 0ms
+242ms ║RunTime Analysis CS > 77ms > PS > 107ms > PE > 59ms > CE
+246ms ║Runtime (58500 bytes) successfully initialized in 107ms (v0.3.108.20180906) (244ms)
+247ms ║╔Execution stage started
+248ms ║╚Execution stage complete. (1ms)
+250ms ╚Event processed successfully (249ms)
11/30/2018, 11:00:29 PM +411ms
+0ms ╔Received event [Las Vegas].mode = Night with a delay of 153ms
+145ms ║RunTime Analysis CS > 22ms > PS > 62ms > PE > 62ms > CE
+149ms ║Runtime (58484 bytes) successfully initialized in 62ms (v0.3.108.20180906) (147ms)
+150ms ║╔Execution stage started
+159ms ║║Comparison (string) :029adf8e458ff2c389317cdd86776bd5: changes = true (1ms)
+160ms ║║Cancelling condition #4's schedules...
+161ms ║║Condition #4 evaluated true (5ms)
+163ms ║║Cancelling condition #3's schedules...
+164ms ║║Condition group #3 evaluated true (state changed) (8ms)
+167ms ║║Evaluating switch with values [[i:23:v, v:[t:string, v::029adf8e458ff2c389317cdd86776bd5:, n:Night]]]
+172ms ║║Comparison (string) :029adf8e458ff2c389317cdd86776bd5: is (string) Night = true (2ms)
+175ms ║║Cancelling statement #29's schedules...
+15611ms ║║Calculating (string) The nighttime temperature in Las Vegas is + (string) 46.4 >> (string) The nighttime temperature in Las Vegas is 46.4
+15618ms ║║Calculating (string) The nighttime temperature in Las Vegas is 46.4 + (string) but inside it is >> (string) The nighttime temperature in Las Vegas is 46.4 but inside it is
+15625ms ║║Calculating (string) The nighttime temperature in Las Vegas is 46.4 but inside it is + (string) 0 >> (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0
+15631ms ║║Calculating (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0 + (string) . Today's high will be >> (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be
+15637ms ║║Calculating (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be + (string) 0 >> (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0
+15643ms ║║Calculating (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0 + (string) and the low will be >> (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0 and the low will be
+15648ms ║║Calculating (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0 and the low will be + (string) 43 >> (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0 and the low will be 43
+15653ms ║║Calculating (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0 and the low will be 43 + (string) . >> (string) The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0 and the low will be 43.
+15747ms ║║Executed physical command [LV Thermostat - Downstairs].log([info, The nighttime temperature in Las Vegas is 46.4 but inside it is 0. Today's high will be 0 and the low will be 43., true]) (84ms)
+15748ms ║║Executed [LV Thermostat - Downstairs].log (87ms)
+15982ms ║║Executed physical command [LV Thermostat - Downstairs].setHeatingSetpoint([69.0]) (229ms)
+15983ms ║║Executed [LV Thermostat - Downstairs].setHeatingSetpoint (231ms)
+15990ms ║║Calculating (string) Las Vegas downstairs heating set to + (string) 69 >> (string) Las Vegas downstairs heating set to 69
+16010ms ║║Executed virtual command [LV Thermostat - Downstairs].sendPushNotification (14ms)
+16219ms ║║Executed physical command [LV Thermostat - Downstairs].setCoolingSetpoint([80.0]) (205ms)
+16220ms ║║Executed [LV Thermostat - Downstairs].setCoolingSetpoint (207ms)
+16228ms ║║Calculating (string) Las Vegas downstairs cooling set to + (string) 80 >> (string) Las Vegas downstairs cooling set to 80
+16246ms ║║Executed virtual command [LV Thermostat - Downstairs].sendPushNotification (13ms)
+16250ms ║║Cancelling statement #50's schedules...
+16470ms ║║Executed physical command [LV Thermostat - Upstairs].setHeatingSetpoint([68.0]) (212ms)
+16471ms ║║Executed [LV Thermostat - Upstairs].setHeatingSetpoint (214ms)
+16478ms ║║Calculating (string) Las Vegas upstairs heating set to + (string) 68 >> (string) Las Vegas upstairs heating set to 68
+16499ms ║║Executed virtual command [LV Thermostat - Upstairs].sendPushNotification (15ms)
+16697ms ║║Executed physical command [LV Thermostat - Upstairs].setCoolingSetpoint([77.0]) (193ms)
+16698ms ║║Executed [LV Thermostat - Upstairs].setCoolingSetpoint (195ms)
+16705ms ║║Calculating (string) Las Vegas upstairs cooling set to + (string) 77 >> (string) Las Vegas upstairs cooling set to 77
+16725ms ║║Executed virtual command [LV Thermostat - Upstairs].sendPushNotification (14ms)
+16731ms ║╚Execution stage complete. (16581ms)
+16732ms ╚Event processed successfully (16732ms)
#2

I notice in the logs it is receiving a time/recovery event instead of the mode event. Why would that be? Anything I can do to guard against this error and ensure my piston is properly executed? Thanks.

#3

I don’t see where you have any time triggers in your piston - only changes to Mode. Where is the time trigger?

#4

In the smart things app I have it change mode at 11 PM and 6 AM using the simple built in ‘Good Night’ and ‘Good Morning’ routines.

#5

Ah, gotcha. In that case you should be able to say:

IF
Location mode changes
OR
$currentEventAttribute is time/recovery

That should pick up the erroneous triggers for you. I’m not sure why it’s happening but I’m seeing it on all my pistons with a timer, too.

#6

Thanks for the suggestion. I ended up pulling the switch statement outside the ‘if’ statement so it is just always executed if the piston is triggered. I just left a log task inside the if so it wouldn’t be empty. This should work no mater what the erroneous event is.

HVAC%20control
HVAC control.png1178×2154 535 KB

I will see tomorrow if it works. Seems to fail more often first thing int he morning vs night.

#7

Ah, yep, that’ll do it too!