Smart Switch Piston not working

cyrus104 · 2017-12-31 02:02:11 UTC

1) Give a description of the problem
The piston log and devices are not acting as expected.

2) What is the expected behavior?
The simple piston should watch two smart switches, when either of the buttons of the switches are turned on it will turn number 2 on for 30 minutes, it will then make sure that number 1 is off for 15 and then on for 15 minutes.

3) What is happening/not happening?
The piston activates when either switch but does not follow the designed flow.

4) Post a Green Snapshot of the piston

5) Attach any logs (From ST IDE and by turning logging level to Full)
12/30/2017, 8:49:42 PM +749ms +1ms ╔Received event [Wemo2].switch = on with a delay of 73ms +70ms ║RunTime Analysis CS > 9ms > PS > 30ms > PE > 31ms > CE +72ms ║Runtime (37219 bytes) successfully initialized in 30ms (v0.2.101.20171227) (71ms) +73ms ║╔Execution stage started +85ms ║║Comparison (enum) on changes_to (string) on = true (1ms) +87ms ║║Cancelling condition #5's schedules... +88ms ║║Condition #5 evaluated true (9ms) +89ms ║║Cancelling condition #1's schedules... +89ms ║║Condition group #1 evaluated true (state changed) (11ms) +91ms ║║Cancelling statement #6's schedules... +94ms ║║Skipped execution of physical command [Wemo2].on([]) because it would make no change to the device. (0ms) +95ms ║║Executed [Wemo2].on (2ms) +98ms ║║Executed virtual command [Wemo2].wait (1ms) +99ms ║║Requesting a wake up for Sat, Dec 30 2017 @ 9:19:42 PM EST (in 1800.0s) +103ms ║╚Execution stage complete. (30ms) +104ms ║Setting up scheduled job for Sat, Dec 30 2017 @ 9:19:42 PM EST (in 1799.995s) +114ms ╚Event processed successfully (114ms) 12/30/2017, 8:49:38 PM +592ms +2ms ╔Received event [Wemo1].switch = on with a delay of 101ms +91ms ║RunTime Analysis CS > 13ms > PS > 45ms > PE > 33ms > CE +93ms ║Runtime (37221 bytes) successfully initialized in 45ms (v0.2.101.20171227) (91ms) +94ms ║╔Execution stage started +107ms ║║Comparison (enum) on changes_to (string) on = true (1ms) +109ms ║║Cancelling condition #5's schedules... +109ms ║║Condition #5 evaluated true (10ms) +110ms ║║Cancelling condition #1's schedules... +111ms ║║Condition group #1 evaluated true (state changed) (12ms) +113ms ║║Cancelling statement #6's schedules... +139ms ║║Executed physical command [Wemo2].on() (24ms) +140ms ║║Executed [Wemo2].on (26ms) +143ms ║║Executed virtual command [Wemo2].wait (0ms) +144ms ║║Requesting a wake up for Sat, Dec 30 2017 @ 9:19:38 PM EST (in 1800.0s) +148ms ║╚Execution stage complete. (54ms) +149ms ║Setting up scheduled job for Sat, Dec 30 2017 @ 9:19:38 PM EST (in 1799.995s) +160ms ╚Event processed successfully (160ms) 12/30/2017, 8:48:52 PM +326ms +4ms ╔Starting piston... (v0.2.101.20171227) +230ms ║╔Subscribing to devices... +253ms ║║Subscribing to Wemo1.switch... +264ms ║║Subscribing to Wemo2.switch... +326ms ║╚Finished subscribing (109ms) +386ms ╚Piston successfully started (385ms) 12/30/2017, 8:44:46 PM +55ms +1ms ╔Received event [Wemo1].switch = off with a delay of 103ms +94ms ║RunTime Analysis CS > 25ms > PS > 45ms > PE > 24ms > CE +97ms ║Runtime (37220 bytes) successfully initialized in 45ms (v0.2.101.20171227) (94ms) +97ms ║╔Execution stage started +111ms ║║Comparison (enum) off changes_to (string) on = false (0ms) +113ms ║║Condition #5 evaluated false (11ms) +114ms ║║Condition group #1 evaluated false (state did not change) (12ms) +116ms ║╚Execution stage complete. (18ms) +117ms ╚Event processed successfully (116ms) 12/30/2017, 8:40:35 PM +975ms +2ms ╔Received event [Wemo2].switch = off with a delay of 86ms +88ms ║RunTime Analysis CS > 24ms > PS > 40ms > PE > 24ms > CE +91ms ║Runtime (37213 bytes) successfully initialized in 40ms (v0.2.101.20171227) (88ms) +91ms ║╔Execution stage started +103ms ║║Comparison (enum) off changes_to (string) on = false (1ms) +104ms ║║Cancelling condition #5's schedules... +105ms ║║Condition #5 evaluated false (9ms) +106ms ║║Cancelling condition #1's schedules... +107ms ║║Condition group #1 evaluated false (state changed) (11ms) +109ms ║╚Execution stage complete. (18ms) +110ms ╚Event processed successfully (110ms) 12/30/2017, 8:40:34 PM +297ms +2ms ╔Received event [Home].time = 1514684435047 with a delay of -750ms +61ms ║RunTime Analysis CS > 13ms > PS > 29ms > PE > 18ms > CE +65ms ║Runtime (37222 bytes) successfully initialized in 29ms (v0.2.101.20171227) (62ms) +67ms ║╔Execution stage started +97ms ║║Executed physical command [Wemo2].off() (21ms) +97ms ║║Executed [Wemo2].off (24ms) +99ms ║║Cancelling statement #10's schedules... +126ms ║║Executed physical command [Wemo1].off() (25ms) +127ms ║║Executed [Wemo1].off (27ms) +132ms ║║Executed virtual command [Wemo1].wait (2ms) +137ms ║║Requesting a wake up for Sat, Dec 30 2017 @ 8:55:34 PM EST (in 900.0s) +139ms ║╚Execution stage complete. (74ms) +142ms ║Setting up scheduled job for Sat, Dec 30 2017 @ 8:55:34 PM EST (in 899.997s) +218ms ╚Event processed successfully (218ms) 12/30/2017, 8:10:34 PM +926ms +2ms ╔Received event [Wemo2].switch = on with a delay of 80ms +89ms ║RunTime Analysis CS > 15ms > PS > 51ms > PE > 22ms > CE +91ms ║Runtime (37218 bytes) successfully initialized in 51ms (v0.2.101.20171227) (88ms) +92ms ║╔Execution stage started +106ms ║║Comparison (enum) on changes_to (string) on = true (0ms) +107ms ║║Cancelling condition #5's schedules... +108ms ║║Condition #5 evaluated true (12ms) +109ms ║║Cancelling condition #1's schedules... +110ms ║║Condition group #1 evaluated true (state changed) (14ms) +112ms ║║Cancelling statement #6's schedules... +116ms ║║Skipped execution of physical command [Wemo2].on([]) because it would make no change to the device. (1ms) +116ms ║║Executed [Wemo2].on (1ms) +119ms ║║Executed virtual command [Wemo2].wait (0ms) +120ms ║║Requesting a wake up for Sat, Dec 30 2017 @ 8:40:35 PM EST (in 1800.0s) +125ms ║╚Execution stage complete. (33ms) +126ms ║Setting up scheduled job for Sat, Dec 30 2017 @ 8:40:35 PM EST (in 1799.996s) +136ms ╚Event processed successfully (136ms) 12/30/2017, 8:10:31 PM +761ms +2ms ╔Received event [Wemo2].switch = off with a delay of 313ms +92ms ║RunTime Analysis CS > 15ms > PS > 51ms > PE > 26ms > CE +94ms ║Runtime (37216 bytes) successfully initialized in 51ms (v0.2.101.20171227) (92ms) +95ms ║╔Execution stage started +116ms ║║Comparison (enum) off changes_to (string) on = false (1ms) +117ms ║║Condition #5 evaluated false (17ms) +118ms ║║Condition group #1 evaluated false (state did not change) (19ms) +120ms ║╚Execution stage complete. (25ms) +121ms ╚Event processed successfully (121ms) Clear Full

michicago · 2017-12-31 03:26:03 UTC

Click on both of your WITH statements, then the gear cog to expand your settings, and change the Task Cancellation Policy to “never cancel tasks” for each of them. Let us know if it works?

eibyer · 2017-12-31 03:50:44 UTC

Looks like it’s going to loop.

michicago · 2017-12-31 04:05:40 UTC

Ha, I didn’t catch that! Each “with” satisfies the IF statement again.

cyrus104 · 2017-12-31 04:12:11 UTC

I made the change to the cancellation policy, it’s interesting because switch 1 never turns off link it should.

Is there an option for the event trigger to be ignored “if cause by the piston”?

Thanks

michicago · 2017-12-31 04:26:54 UTC

You could try something like setting a variable called “AutomationActive” to true at the beginning of your WITH statements, then setting it false at the end of them. Then, in your IF statement you can have a “and AutomationActive is false” condition to avoid it tripping itself up.

cyrus104 · 2017-12-31 05:00:11 UTC

ok, so a soon it’s triggered the first time I’d change the variable to true. If I interrupt the piston and it resets that variable will never be reset to allow the piston to run again.

How about this… I don’t fully understand this framework yet but there is a physical button on these switches. Can I set the if statement to only trigger on a button press versus something I change in code?

Mike1616 · 2017-12-31 13:30:15 UTC

The issue is that your piston essentially calls itself…because when you Turn on the switch that you’re testing for…it runs the Piston again. So you can do this, which is what they’ve talked about so far.

Mike1616 · 2017-12-31 13:37:49 UTC

OR…You could do this…which is to use a Simulated Switch that you create in the ST IDE. So when you want to run this whole process, you take out your app and push the button on this switch to turn on the switch and voila…the whole thing runs w/o it looping back into itself…because the only event that it subscribes to is the virtual switch turning on. Then if you interrupt the process for whatever reason you just turn the virtual switch off and then when you turn it back on again this whole thing will run once more.

You can also add a command at the end of this to automatically turn OFF the virtual switch should you want to do that.

cyrus104 · 2017-12-31 17:20:46 UTC

Thanks a bunch, I’m in the process of testing the first one.

Can you explain the difference in these two options (physical vs programmatic), I haven’t been able to find it yet.

If physical on refers to me hitting the button, I could put that as the if condition and then all of the other turn on/off would technically be programmatic?

michicago · 2017-12-31 17:41:40 UTC

You’ll find most switches do not support physical/programmatic distinction. I’ve tried modifying device type handlers to support it,and it still doesn’t work.

In other words… you’ll spend more time debugging physical vs. programmatic than you want to, AND you’ll still be stuck where you are today.

If you’re concerned with interrupting a piston and it not running again, then instead of a true/false variable, make a date/time variable called LastRun and set it to “$now” when the piston starts. Then you can say limit repeat execution by including a condition AND $now is after addMinutes(LastRun,5).

That would prevent your piston from re-executing within 5 minutes. Change that 5 to whatever ‘lockout’ time you’d like there to be.

Mike1616 · 2017-12-31 17:48:02 UTC

I completely agree with this as it’s exactly what I’ve seen as well.

cyrus104 · 2017-12-31 17:55:56 UTC

Thanks, I’m implementing the time based lockout now.

If only they added that little extra functionality, maybe in the next generation.

cyrus104 · 2017-12-31 18:26:46 UTC

So I’m running into an issue with the new code and it’s never catching the event. Once it start, I can turn off and on the switches and the piston never executes.

For the LastRun at the beginning I set it to todays sunrise just for testing, once the piston is running it should matter as long as the first time is outside of that time.

12/31/2017, 1:24:27 PM +847ms
+1ms ╔Starting piston… (v0.2.101.20171227)
+177ms ║╔Subscribing to devices…
+185ms ║║Subscribing to Wemo1.switch…
+199ms ║║Subscribing to Wemo2.switch…
+259ms ║╚Finished subscribing (96ms)
+333ms ║Comparison (datetime) 1514744668142 is_after (datetime) 1514725140000 = true (2ms)
+344ms ╚Piston successfully started (344ms)

michicago · 2017-12-31 19:08:34 UTC

The log you posted is just the piston starting - you’re saying now that it’s running you can change switches from off to on and the piston doesn’t fire?

Do you see their status change if you open the SmartThings app and watch them in there? There’s nothing in your piston that shouldn’t work as intended… you’re still subscribed to switches 1 and 2 events.

cyrus104 · 2017-12-31 20:52:26 UTC

It’s working now, for some reason it wasn’t posting anything in the webCoRE log but it was in ST. After changing the oil in the Jeep it seems to be working…

Right now it looks as if each with/do is blocking…
Capture

Log:
12/31/2017, 3:49:14 PM +781ms
+1ms ╔Received event [Wemo2].switch = on with a delay of 80ms
+82ms ║RunTime Analysis CS > 22ms > PS > 27ms > PE > 32ms > CE
+84ms ║Runtime (38232 bytes) successfully initialized in 27ms (v0.2.101.20171227) (83ms)
+85ms ║╔Execution stage started
+96ms ║║Comparison (enum) on changes_to (string) on = true (1ms)
+97ms ║║Condition #5 evaluated true (8ms)
+124ms ║║Comparison (datetime) 1514753354880 is_after (datetime) 1514725140000 = true (2ms)
+125ms ║║Condition #18 evaluated true (27ms)
+126ms ║║Condition group #1 evaluated true (state did not change) (37ms)
+128ms ║║Cancelling statement #16’s schedules…
+132ms ║║Executed virtual command setVariable (0ms)
+134ms ║║Cancelling statement #6’s schedules…
+137ms ║║Skipped execution of physical command [Wemo2].on([]) because it would make no change to the device. (0ms)
+137ms ║║Executed [Wemo2].on (1ms)
+140ms ║║Executed virtual command [Wemo2].wait (0ms)
+141ms ║║Requesting a wake up for Sun, Dec 31 2017 @ 4:19:14 PM EST (in 1800.0s)
+145ms ║╚Execution stage complete. (60ms)
+147ms ║Setting up scheduled job for Sun, Dec 31 2017 @ 3:57:28 PM EST (in 493.84s), with 1 more job pending
+159ms ╚Event processed successfully (158ms)
12/31/2017, 3:49:12 PM +684ms
+1ms ╔Received event [Wemo1].switch = on with a delay of 99ms
+90ms ║RunTime Analysis CS > 14ms > PS > 44ms > PE > 33ms > CE
+93ms ║Runtime (38238 bytes) successfully initialized in 44ms (v0.2.101.20171227) (90ms)
+94ms ║╔Execution stage started
+105ms ║║Comparison (enum) on changes_to (string) on = true (0ms)
+106ms ║║Cancelling condition #5’s schedules…
+107ms ║║Condition #5 evaluated true (9ms)
+136ms ║║Comparison (datetime) 1514753352792 is_after (datetime) 1514725140000 = true (1ms)
+137ms ║║Condition #18 evaluated true (29ms)
+138ms ║║Cancelling condition #1’s schedules…
+139ms ║║Condition group #1 evaluated true (state changed) (40ms)
+141ms ║║Cancelling statement #16’s schedules…
+144ms ║║Executed virtual command setVariable (1ms)
+147ms ║║Cancelling statement #6’s schedules…
+174ms ║║Executed physical command [Wemo2].on() (26ms)
+175ms ║║Executed [Wemo2].on (27ms)
+178ms ║║Executed virtual command [Wemo2].wait (1ms)
+179ms ║║Requesting a wake up for Sun, Dec 31 2017 @ 4:19:12 PM EST (in 1800.0s)
+183ms ║╚Execution stage complete. (90ms)
+185ms ║Setting up scheduled job for Sun, Dec 31 2017 @ 3:57:28 PM EST (in 495.899s), with 1 more job pending
+194ms ╚Event processed successfully (194ms)

cyrus104 · 2017-12-31 21:04:52 UTC

Interesting, as you can see by my logs these are belink wemo switches. I seems like the events are not getting to the ST. I can watch the ST log and specific devices, switch it on and off and it won’t pick it up. I’ll give it another little while but it might come back.

michicago · 2017-12-31 21:55:40 UTC

Yeah, unfortunately there’s no programming your way around that! You can try the ST Z-Wave and Zigbee utilities (not sure what those switches run) to see if that cleans it up. Otherwise if I were you, I’d try another brand.

cyrus104 · 2017-12-31 22:00:18 UTC

Just to clarify, is there no way around the blocking issue?

I do have a few of the ST plugs and will put them through a similar test to see if they keep a better connection since they should be connecting directly to the hub and not through the cloud to the hub.

cyrus104 · 2017-12-31 22:07:28 UTC

So they just came back up and here is the next test I did using async. I think it worked… but had several side effects but they aren’t deal breakers yet.