Understanding "On Events" behavior

Pacman45 · 2019-09-19 11:35:54 UTC

I am having difficulty troubleshooting a piston I designed that performs actions when a mobile phone presence sensor of any of our home occupants changes. This is for purposes of adjusting thermostats. Basically, when any of the presence sensors has an event, the piston runs to determine if anyone is left at home. If all presence sensors are away, the thermostat adjustment process begins. The piston first waits 4 hours, and then sets mode to Away and adjusts thermostats. It then waits an additional 24 hours and then sets mode to “Extended-Away” and adjusts thermostats even more. If any of the presence detectors are present AND the mode is either “Away” or “Extended-Away”, it runs the time-of-day appropriate thermostat setting routine for someone being present. The final action of the piston is to cancel all pending tasks (such as a Wait routine on a previously launched instance, I think) and then setting mode to “Home.” Here is the code:

I am expecting thermostats to adjust 4 hours after everyone is absent from the home, and again even more when everyone is absent from the home for 24 hours. At any time while that routine is running, if someone returns home, the thermostats will readjust, the pending task adjusting thermostats for away condition will cease, and the location mode will switch back to “Home.”

**3) The last two times our entire family left home for several hours and then returned home, the thermostats remained set for 'Away" conditions and location mode was stuck on “Away”, even though the presence sensors clearly showed our mobile phones as being “Present.”

**4)

5) Attach logs after turning logging level to Full
I am not sure how to switch logs to full. Where is that option located? WebCore Dashboard? Smartthings IDE?

Am I correct in assuming that each time an event is registered (i.e., one of the smartphones has changed its presence status), a new instance of this piston is launched? And if so, does a command in one instance to cancel all pending tasks affect what is going on in another instance? I just don’t have enough experience with this technology to fully understand its subliminal behaviors.

guxdude · 2019-09-19 20:55:56 UTC

Right now you have triggers everywhere because you used all conditions. This creates a mess with the piston executing for any of the conditions that occurs. Rather than using on events, I suggest you use if any of (iPhones) presence changes. This will be a trigger and the other conditions should stop triggering. I also suggest you simplify your three and conditions for iPhones not present. You can simply use if all of (iPhones) are not present. Make theses changes and see if it resolves your issue. I haven’t looked in detail at the rest of your logic yet.

Pacman45 · 2019-09-19 22:22:54 UTC

Ok, thanks. I’ll try to restructure the logic in the beginning.

I found the full log switch and have copied the log for today:

9/19/2019, 5:20:19 PM +696ms
+1ms ╔Received event [Barbara’s iPhone].presence = present with a delay of 59ms
+209ms ║RunTime Analysis CS > 21ms > PS > 142ms > PE > 47ms > CE
+212ms ║Runtime (50310 bytes) successfully initialized in 142ms (v0.3.10e.20190628) (210ms)
+213ms ║╔Execution stage started
+217ms ║║Condition group #3 evaluated true (state did not change) (0ms)
+218ms ║║Condition group #1 evaluated true (state did not change) (2ms)
+231ms ║║Comparison (enum) present is (string) not present = false (2ms)
+232ms ║║Condition #6 evaluated false (11ms)
+239ms ║║Comparison (dynamic) Home is (string) Away = false (2ms)
+241ms ║║Condition #25 evaluated false (5ms)
+245ms ║║Comparison (dynamic) Home is (string) Away-Extended Absence = false (2ms)
+247ms ║║Condition #26 evaluated false (5ms)
+248ms ║║Condition group #24 evaluated false (state did not change) (12ms)
+249ms ║║Condition group #23 evaluated false (state did not change) (14ms)
+258ms ║║Comparison (enum) off is (string) off = true (1ms)
+260ms ║║Condition #56 evaluated true (9ms)
+261ms ║║Condition group #9 evaluated true (state did not change) (10ms)
+262ms ║║Cancelling statement #9’s schedules…
+264ms ║║Executed virtual command cancelTasks (1ms)
+304ms ║║Executed virtual command setLocationMode (38ms)
+308ms ║║Executed virtual command setVariable (0ms)
+311ms ║║Executed virtual command setVariable (1ms)
+320ms ║║Comparison (enum) off is (string) on = false (1ms)
+322ms ║║Condition #58 evaluated false (8ms)
+323ms ║║Condition group #57 evaluated false (state did not change) (9ms)
+324ms ║║Condition group #5 evaluated false (state did not change) (103ms)
+325ms ║║Condition group #4 evaluated false (state did not change) (104ms)
+329ms ║╚Execution stage complete. (115ms)
+330ms ╚Event processed successfully (330ms)
9/19/2019, 4:23:15 PM +367ms
+2ms ╔Received event [Barbara’s iPhone].presence = not present with a delay of 137ms
+319ms ║RunTime Analysis CS > 59ms > PS > 202ms > PE > 57ms > CE
+322ms ║Runtime (50315 bytes) successfully initialized in 202ms (v0.3.10e.20190628) (319ms)
+323ms ║╔Execution stage started
+328ms ║║Condition group #3 evaluated true (state did not change) (0ms)
+328ms ║║Condition group #1 evaluated true (state did not change) (2ms)
+341ms ║║Comparison (enum) present is (string) not present = false (2ms)
+342ms ║║Condition #6 evaluated false (10ms)
+350ms ║║Comparison (dynamic) Home is (string) Away = false (1ms)
+351ms ║║Condition #25 evaluated false (5ms)
+356ms ║║Comparison (dynamic) Home is (string) Away-Extended Absence = false (1ms)
+357ms ║║Condition #26 evaluated false (5ms)
+358ms ║║Condition group #24 evaluated false (state did not change) (13ms)
+359ms ║║Condition group #23 evaluated false (state did not change) (14ms)
+370ms ║║Comparison (enum) off is (string) off = true (2ms)
+372ms ║║Condition #56 evaluated true (10ms)
+373ms ║║Condition group #9 evaluated true (state did not change) (11ms)
+374ms ║║Cancelling statement #9’s schedules…
+376ms ║║Executed virtual command cancelTasks (1ms)
+422ms ║║Executed virtual command setLocationMode (43ms)
+426ms ║║Executed virtual command setVariable (1ms)
+430ms ║║Executed virtual command setVariable (1ms)
+438ms ║║Comparison (enum) off is (string) on = false (2ms)
+439ms ║║Condition #58 evaluated false (7ms)
+440ms ║║Condition group #57 evaluated false (state did not change) (8ms)
+441ms ║║Condition group #5 evaluated false (state did not change) (109ms)
+442ms ║║Condition group #4 evaluated false (state did not change) (111ms)
+458ms ║╚Execution stage complete. (136ms)
+459ms ╚Event processed successfully (459ms)
9/19/2019, 4:14:42 PM +550ms
+1ms ╔Received event [Barbara’s iPhone].presence = present with a delay of 67ms
+239ms ║RunTime Analysis CS > 39ms > PS > 150ms > PE > 49ms > CE
+242ms ║Runtime (50310 bytes) successfully initialized in 150ms (v0.3.10e.20190628) (239ms)
+243ms ║╔Execution stage started
+247ms ║║Condition group #3 evaluated true (state did not change) (0ms)
+248ms ║║Condition group #1 evaluated true (state did not change) (2ms)
+262ms ║║Comparison (enum) present is (string) not present = false (1ms)
+263ms ║║Condition #6 evaluated false (11ms)
+269ms ║║Comparison (dynamic) Home is (string) Away = false (1ms)
+271ms ║║Condition #25 evaluated false (4ms)
+275ms ║║Comparison (dynamic) Home is (string) Away-Extended Absence = false (1ms)
+276ms ║║Condition #26 evaluated false (5ms)
+277ms ║║Condition group #24 evaluated false (state did not change) (11ms)
+278ms ║║Condition group #23 evaluated false (state did not change) (13ms)
+287ms ║║Comparison (enum) off is (string) off = true (2ms)
+288ms ║║Condition #56 evaluated true (8ms)
+289ms ║║Condition group #9 evaluated true (state did not change) (9ms)
+290ms ║║Cancelling statement #9’s schedules…
+292ms ║║Executed virtual command cancelTasks (1ms)
+332ms ║║Executed virtual command setLocationMode (38ms)
+336ms ║║Executed virtual command setVariable (1ms)
+339ms ║║Executed virtual command setVariable (1ms)
+348ms ║║Comparison (enum) off is (string) on = false (1ms)
+349ms ║║Condition #58 evaluated false (8ms)
+350ms ║║Condition group #57 evaluated false (state did not change) (9ms)
+351ms ║║Condition group #5 evaluated false (state did not change) (100ms)
+352ms ║║Condition group #4 evaluated false (state did not change) (101ms)
+364ms ║╚Execution stage complete. (122ms)
+365ms ╚Event processed successfully (365ms)
9/19/2019, 4:13:51 PM +95ms
+0ms ╔Received event [Home].time = 1568924032202 with a delay of -1108ms
+216ms ║RunTime Analysis CS > 23ms > PS > 146ms > PE > 47ms > CE
+219ms ║Runtime (50303 bytes) successfully initialized in 146ms (v0.3.10e.20190628) (218ms)
+220ms ║╔Execution stage started
+221ms ║╚Execution stage complete. (1ms)
+222ms ╚Event processed successfully (222ms)
9/19/2019, 3:35:37 PM +633ms
+1ms ╔Received event [Matt’s iPhone].presence = present with a delay of 62ms
+292ms ║RunTime Analysis CS > 34ms > PS > 185ms > PE > 73ms > CE
+295ms ║Runtime (50308 bytes) successfully initialized in 185ms (v0.3.10e.20190628) (293ms)
+296ms ║╔Execution stage started
+300ms ║║Condition group #3 evaluated true (state did not change) (0ms)
+301ms ║║Condition group #1 evaluated true (state did not change) (2ms)
+308ms ║║Comparison (enum) present is (string) not present = false (2ms)
+310ms ║║Cancelling condition #6’s schedules…
+310ms ║║Condition #6 evaluated false (6ms)
+311ms ║║Cancelling condition #5’s schedules…
+317ms ║║Comparison (dynamic) Home is (string) Away = false (1ms)
+319ms ║║Condition #25 evaluated false (5ms)
+323ms ║║Comparison (dynamic) Home is (string) Away-Extended Absence = false (2ms)
+324ms ║║Condition #26 evaluated false (4ms)
+325ms ║║Condition group #24 evaluated false (state did not change) (11ms)
+326ms ║║Condition group #23 evaluated false (state did not change) (13ms)
+335ms ║║Comparison (enum) off is (string) off = true (1ms)
+337ms ║║Condition #56 evaluated true (7ms)
+338ms ║║Condition group #9 evaluated true (state did not change) (9ms)
+339ms ║║Cancelling statement #9’s schedules…
+341ms ║║Executed virtual command cancelTasks (0ms)
+388ms ║║Executed virtual command setLocationMode (45ms)
+392ms ║║Executed virtual command setVariable (1ms)
+395ms ║║Executed virtual command setVariable (1ms)
+404ms ║║Comparison (enum) off is (string) on = false (1ms)
+405ms ║║Condition #58 evaluated false (8ms)
+406ms ║║Condition group #57 evaluated false (state did not change) (9ms)
+407ms ║║Condition group #5 evaluated false (state changed) (103ms)
+408ms ║║Cancelling condition #4’s schedules…
+409ms ║║Condition group #4 evaluated false (state changed) (106ms)
+426ms ║╚Execution stage complete. (131ms)
+427ms ╚Event processed successfully (427ms)
9/19/2019, 12:13:51 PM +943ms
+1ms ╔Received event [Barbara’s iPhone].presence = not present with a delay of 60ms
+214ms ║RunTime Analysis CS > 21ms > PS > 138ms > PE > 55ms > CE
+217ms ║Runtime (50315 bytes) successfully initialized in 138ms (v0.3.10e.20190628) (214ms)
+218ms ║╔Execution stage started
+222ms ║║Condition group #3 evaluated true (state did not change) (0ms)
+223ms ║║Condition group #1 evaluated true (state did not change) (2ms)
+234ms ║║Comparison (enum) not present is (string) not present = true (1ms)
+235ms ║║Condition #6 evaluated true (9ms)
+239ms ║║Comparison (enum) not present is (string) not present = true (1ms)
+241ms ║║Condition #7 evaluated true (5ms)
+250ms ║║Comparison (enum) not present is (string) not present = true (1ms)
+251ms ║║Condition #8 evaluated true (9ms)
+254ms ║║Cancelling statement #14’s schedules…
+257ms ║║Executed virtual command wait (1ms)
+258ms ║║Requesting a wake up for Thu, Sep 19 2019 @ 4:13:52 PM EDT (in 14400.0s)
+261ms ║║Condition group #5 evaluated true (state did not change) (35ms)
+262ms ║║Condition group #4 evaluated true (state did not change) (37ms)
+265ms ║╚Execution stage complete. (48ms)
+266ms ║Setting up scheduled job for Thu, Sep 19 2019 @ 4:13:52 PM EDT (in 14399.993s)
+277ms ╚Event processed successfully (277ms)
9/19/2019, 10:07:23 AM +888ms
+2ms ╔Received event [Barbara’s iPhone].presence = not present with a delay of 68ms
+236ms ║RunTime Analysis CS > 22ms > PS > 152ms > PE > 61ms > CE
+239ms ║Runtime (50315 bytes) successfully initialized in 152ms (v0.3.10e.20190628) (236ms)
+240ms ║╔Execution stage started
+246ms ║║Condition group #3 evaluated true (state did not change) (1ms)
+247ms ║║Condition group #1 evaluated true (state did not change) (2ms)
+260ms ║║Comparison (enum) not present is (string) not present = true (1ms)
+262ms ║║Condition #6 evaluated true (10ms)
+267ms ║║Comparison (enum) not present is (string) not present = true (2ms)
+269ms ║║Condition #7 evaluated true (5ms)
+278ms ║║Comparison (enum) not present is (string) not present = true (2ms)
+280ms ║║Condition #8 evaluated true (10ms)
+285ms ║║Cancelling statement #14’s schedules…
+289ms ║║Executed virtual command wait (1ms)
+291ms ║║Requesting a wake up for Thu, Sep 19 2019 @ 2:07:24 PM EDT (in 14400.0s)
+295ms ║║Condition group #5 evaluated true (state did not change) (43ms)
+296ms ║║Condition group #4 evaluated true (state did not change) (46ms)
+299ms ║╚Execution stage complete. (59ms)
+301ms ║Setting up scheduled job for Thu, Sep 19 2019 @ 2:07:24 PM EDT (in 14399.992s)
+313ms ╚Event processed successfully (313ms)
9/19/2019, 8:51:59 AM +54ms
+1ms ╔Received event [Home].time/recovery = 1568897519053 with a delay of 1ms
+232ms ║RunTime Analysis CS > 19ms > PS > 159ms > PE > 54ms > CE
+235ms ║Runtime (50309 bytes) successfully initialized in 159ms (v0.3.10e.20190628) (233ms)
+236ms ║╔Execution stage started
+238ms ║╚Execution stage complete. (1ms)
+239ms ║Setting up scheduled job for Thu, Sep 19 2019 @ 12:31:40 PM EDT (in 13181.51s)
+250ms ╚Event processed successfully (250ms)
9/19/2019, 8:31:40 AM +536ms
+1ms ╔Received event [Matt’s iPhone].presence = not present with a delay of 62ms
+222ms ║RunTime Analysis CS > 20ms > PS > 145ms > PE > 56ms > CE
+225ms ║Runtime (50312 bytes) successfully initialized in 145ms (v0.3.10e.20190628) (223ms)
+226ms ║╔Execution stage started
+231ms ║║Condition group #3 evaluated true (state did not change) (1ms)
+232ms ║║Condition group #1 evaluated true (state did not change) (2ms)
+239ms ║║Comparison (enum) not present is (string) not present = true (2ms)
+240ms ║║Condition #6 evaluated true (5ms)
+248ms ║║Comparison (enum) not present is (string) not present = true (1ms)
+250ms ║║Condition #7 evaluated true (8ms)
+257ms ║║Comparison (enum) not present is (string) not present = true (1ms)
+258ms ║║Condition #8 evaluated true (8ms)
+261ms ║║Cancelling statement #14’s schedules…
+264ms ║║Executed virtual command wait (1ms)
+266ms ║║Requesting a wake up for Thu, Sep 19 2019 @ 12:31:40 PM EDT (in 14400.0s)
+269ms ║║Condition group #5 evaluated true (state did not change) (33ms)
+270ms ║║Condition group #4 evaluated true (state did not change) (35ms)
+272ms ║╚Execution stage complete. (46ms)
+274ms ║Setting up scheduled job for Thu, Sep 19 2019 @ 12:31:40 PM EDT (in 14399.993s)
+287ms ╚Event processed successfully (287ms)
9/19/2019, 7:47:59 AM +651ms
+1ms ╔Received event [Home].test = 1568893679648 with a delay of 3ms
+223ms ║RunTime Analysis CS > 18ms > PS > 147ms > PE > 58ms > CE
+227ms ║Runtime (50300 bytes) successfully initialized in 147ms (v0.3.10e.20190628) (224ms)
+228ms ║╔Execution stage started
+234ms ║║Condition group #3 evaluated true (state did not change) (0ms)
+235ms ║║Condition group #1 evaluated true (state did not change) (3ms)
+250ms ║╚Execution stage complete. (22ms)
+254ms ║Setting up scheduled job for Thu, Sep 19 2019 @ 11:12:40 PM EDT (in 55480.118s)
+268ms ╚Event processed successfully (267ms)
9/17/2019, 6:43:30 AM +720ms
+6724ms ║Piston waited at a semaphore for 6510ms
9/16/2019, 8:27:20 PM +679ms
+1842ms ║Invalid ternary operator. Ternary operator’s syntax is ( condition ? trueValue : falseValue ). Please check your syntax and try again.
+1848ms ║Invalid ternary operator. Ternary operator’s syntax is ( condition ? trueValue : falseValue ). Please check your syntax and try again.
+1857ms ║Invalid ternary operator. Ternary operator’s syntax is ( condition ? trueValue : falseValue ). Please check your syntax and try again.
+1863ms ║Invalid ternary operator. Ternary operator’s syntax is ( condition ? trueValue : falseValue ). Please check your syntax and try again.