I thought I just simply didn’t understand what conditions to use for what I was trying to do.
I like your method because you can set a state using a variable and when to set that state.
I’ve set up your newest piston, but it seems like nothing is working now. I’ll have to go through it again to see if I entered it incorrectly.
Thank you again!
I am sorry, I don’t have extra devices laying around to set it up myself and test. Can you take a green camera and upload the picture here so I can look at it?
For some reason the variables stay screenopen=1 and screenactive=1 even after the screendoor was open then closed and stays closed.
Your code looks decent, although I would drop all 4 async commands. They should all be normal IF’s. In fact, async will break the 800 ms delay that is required to prevent false alarms.
Try this. I removed the asyncs and added 4 log points to help troubleshoot:
I think I’m misunderstanding of the use of async ifs. I thought they were used so each of the ifs could run indpendent of the ifs that came before it.
I paused my old piston and created one based on your backup code. Unfortunately, I’m still having a problem with ScreenActive and ScreenOpen staying as 1 after the screen door has closed. I will try to use “is” instead of “changed to” for the screendoor closed block.
I’ve added the log below.
5/27/2018, 7:58:27 AM +216ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 248ms
+104ms ║RunTime Analysis CS > 18ms > PS > 53ms > PE > 34ms > CE
+107ms ║Runtime (41975 bytes) successfully initialized in 53ms (v0.3.104.20180323) (104ms)
+108ms ║╔Execution stage started
+122ms ║║Condition #62 evaluated false (8ms)
+123ms ║║Condition group #29 evaluated false (state did not change) (10ms)
+129ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+131ms ║║Condition #89 evaluated false (5ms)
+132ms ║║Condition group #85 evaluated false (state did not change) (6ms)
+138ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+140ms ║║Condition #69 evaluated true (5ms)
+144ms ║║Comparison (dynamic) 1 is (integer) 0 = false (1ms)
+146ms ║║Condition #92 evaluated false (5ms)
+147ms ║║Condition group #65 evaluated false (state did not change) (13ms)
+155ms ║║Condition #84 evaluated false (5ms)
+156ms ║║Condition group #70 evaluated false (state did not change) (7ms)
+158ms ║╚Execution stage complete. (50ms)
+159ms ╚Event processed successfully (160ms)
5/27/2018, 7:58:14 AM +343ms
+1ms ╔Received event [Front Screen Door].contact = closed with a delay of 263ms
+10093ms ║RunTime Analysis CS > 24ms > PS > 10035ms > PE > 33ms > CE
+10094ms ║Piston waited at a semaphore for 9989ms
+10096ms ║Runtime (42044 bytes) successfully initialized in 10035ms (v0.3.104.20180323) (10094ms)
+10097ms ║╔Execution stage started
+10106ms ║║Comparison (enum) closed changes_to (string) open = false (1ms)
+10108ms ║║Condition #62 evaluated false (4ms)
+10109ms ║║Condition group #29 evaluated false (state did not change) (6ms)
+10119ms ║║Cancelling condition #89's schedules...
+10120ms ║║Condition #89 evaluated false (7ms)
+10121ms ║║Cancelling condition #85's schedules...
+10121ms ║║Condition group #85 evaluated false (state changed) (10ms)
+10128ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+10129ms ║║Condition #69 evaluated true (5ms)
+10134ms ║║Comparison (dynamic) 1 is (integer) 0 = false (2ms)
+10135ms ║║Condition #92 evaluated false (5ms)
+10136ms ║║Condition group #65 evaluated false (state did not change) (12ms)
+10142ms ║║Comparison (enum) closed changes_to (string) closed = false (0ms)
+10144ms ║║Condition #84 evaluated false (5ms)
+10145ms ║║Condition group #70 evaluated false (state did not change) (5ms)
+10147ms ║╚Execution stage complete. (50ms)
+10148ms ╚Event processed successfully (10148ms)
5/27/2018, 7:58:14 AM +263ms
+2ms ╔Received event [Front Screen Door].acceleration = active with a delay of 235ms
+95ms ║RunTime Analysis CS > 17ms > PS > 49ms > PE > 29ms > CE
+98ms ║Runtime (41980 bytes) successfully initialized in 49ms (v0.3.104.20180323) (96ms)
+99ms ║╔Execution stage started
+112ms ║║Cancelling condition #62's schedules...
+113ms ║║Condition #62 evaluated false (7ms)
+114ms ║║Cancelling condition #29's schedules...
+114ms ║║Condition group #29 evaluated false (state changed) (10ms)
+121ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+123ms ║║Cancelling condition #89's schedules...
+123ms ║║Condition #89 evaluated true (5ms)
+124ms ║║Cancelling condition #85's schedules...
+125ms ║║Condition group #85 evaluated true (state changed) (8ms)
+128ms ║║Cancelling statement #86's schedules...
+131ms ║║Executed virtual command wait (1ms)
+132ms ║║Waiting for 800ms
+940ms ║║Executed virtual command setVariable (3ms)
+949ms ║║Accel changed to Active
+950ms ║║Executed virtual command log (1ms)
+960ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+962ms ║║Cancelling condition #69's schedules...
+963ms ║║Condition #69 evaluated true (8ms)
+969ms ║║Comparison (dynamic) 1 is (integer) 0 = false (2ms)
+971ms ║║Condition #92 evaluated false (7ms)
+972ms ║║Condition group #65 evaluated false (state did not change) (17ms)
+984ms ║║Condition #84 evaluated false (8ms)
+985ms ║║Condition group #70 evaluated false (state did not change) (9ms)
+989ms ║╚Execution stage complete. (890ms)
+991ms ╚Event processed successfully (990ms)
5/27/2018, 7:58:11 AM +231ms
+2ms ╔Received event [Front Screen Door].contact = open with a delay of 245ms
+102ms ║RunTime Analysis CS > 18ms > PS > 56ms > PE > 27ms > CE
+104ms ║Runtime (41980 bytes) successfully initialized in 56ms (v0.3.104.20180323) (101ms)
+105ms ║╔Execution stage started
+115ms ║║Comparison (enum) open changes_to (string) open = true (1ms)
+117ms ║║Cancelling condition #62's schedules...
+118ms ║║Condition #62 evaluated true (6ms)
+119ms ║║Cancelling condition #29's schedules...
+120ms ║║Condition group #29 evaluated true (state changed) (8ms)
+122ms ║║Cancelling statement #63's schedules...
+130ms ║║Executed virtual command setVariable (4ms)
+136ms ║║Screen changed to Open
+137ms ║║Executed virtual command log (1ms)
+148ms ║║Condition #89 evaluated false (7ms)
+149ms ║║Condition group #85 evaluated false (state did not change) (9ms)
+156ms ║║Comparison (dynamic) null is (integer) 1 = false (2ms)
+157ms ║║Condition #69 evaluated false (5ms)
+158ms ║║Condition group #65 evaluated false (state did not change) (6ms)
+165ms ║║Comparison (enum) open changes_to (string) closed = false (1ms)
+166ms ║║Condition #84 evaluated false (5ms)
+167ms ║║Condition group #70 evaluated false (state did not change) (6ms)
+169ms ║╚Execution stage complete. (64ms)
+171ms ╚Event processed successfully (170ms)Good idea. This was going to be my next suggestion if the above failed.
I am studying your log now…
11.231 sec = Screen Open
11.361 sec = Variable ScreenOpen set (Quick response)
14.263 sec = Acceleration Active (Triggered as door close?)
14.343 sec = Screen Closed
14.394 sec = Begin 800ms Delay for ScreenActive
15.203 sec = Variable ScreenActive set (After our 800ms delay)
27.216 sec = Acceleration Inactive (This is your accel timing out)
From this analysis, it looks like the door was only open for 3.1 seconds. Is that really how quick you can open both doors, walk thru, and then close the screen?
I was surprised that the acceleration took over 3 seconds to trigger after the door opened. It actually seems like the acceleration only triggered when the door finally closed, not when it opened. (with the extra vibration, I guess that makes sense)
Also to note, There was a 10 second delay when the door closed before checks happened. At that time, the door is no longer “changed to”. Changing it to “is” on door close should resolve that.
I think we are on the home stretch now. Would you change the last block to “If Screen Door’s contact is closed” … Save… Clear logs… and test again?
On a side note, when posting logs in the future, please also include a green snapshot so we can see the Condition numbers. It makes troubleshooting much easier.
The time should be from opening screen door, walking through and closing the screen door.
I think if it senses acceleration after the door is opened it wouldn’t trigger the notification anyway since the screen door is opened. The problem I have is the random times when trying to open the screen door that it senses acceleration first then the door open. I’ve included a situation like that in the log below.
What causes this 10 second delay? I thought it was just some latency but it happened again according to the log.
I’ve cleared the log, and went through the following situations. Screen door knock (Notification sent. OK). Acceleration active immediately followed by screen door open (Notification sent. Not OK). And screen door closing which causes screen door close and acceleration active nearly simultaneously (No notification sent. OK).
5/27/2018, 12:54:45 PM +976ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 260ms
+105ms ║RunTime Analysis CS > 14ms > PS > 36ms > PE > 54ms > CE
+107ms ║Runtime (41965 bytes) successfully initialized in 36ms (v0.3.104.20180323) (105ms)
+108ms ║╔Execution stage started
+121ms ║║Condition #62 evaluated false (7ms)
+122ms ║║Condition group #29 evaluated false (state did not change) (8ms)
+129ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+131ms ║║Condition #89 evaluated false (6ms)
+132ms ║║Condition group #85 evaluated false (state did not change) (7ms)
+139ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+140ms ║║Condition #69 evaluated false (5ms)
+141ms ║║Condition group #65 evaluated false (state did not change) (6ms)
+151ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+152ms ║║Condition #84 evaluated true (8ms)
+153ms ║║Condition group #70 evaluated true (state did not change) (9ms)
+156ms ║║Cancelling statement #81's schedules...
+161ms ║║Executed virtual command setVariable (2ms)
+166ms ║║Executed virtual command setVariable (2ms)
+173ms ║║Screen changed to close
+174ms ║║Executed virtual command log (1ms)
+177ms ║╚Execution stage complete. (69ms)
+178ms ╚Event processed successfully (178ms)
5/27/2018, 12:54:33 PM +130ms
+1ms ╔Received event [Front Screen Door].contact = closed with a delay of 272ms
+10248ms ║RunTime Analysis CS > 25ms > PS > 10172ms > PE > 51ms > CE
+10249ms ║Piston waited at a semaphore for 10121ms
+10252ms ║Runtime (42035 bytes) successfully initialized in 10172ms (v0.3.104.20180323) (10249ms)
+10253ms ║╔Execution stage started
+10262ms ║║Comparison (enum) closed changes_to (string) open = false (1ms)
+10264ms ║║Condition #62 evaluated false (5ms)
+10265ms ║║Condition group #29 evaluated false (state did not change) (6ms)
+10274ms ║║Cancelling condition #89's schedules...
+10275ms ║║Condition #89 evaluated false (7ms)
+10276ms ║║Cancelling condition #85's schedules...
+10277ms ║║Condition group #85 evaluated false (state changed) (10ms)
+10283ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+10285ms ║║Cancelling condition #69's schedules...
+10286ms ║║Condition #69 evaluated false (6ms)
+10287ms ║║Condition group #65 evaluated false (state did not change) (7ms)
+10294ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+10295ms ║║Condition #84 evaluated true (5ms)
+10296ms ║║Condition group #70 evaluated true (state did not change) (7ms)
+10299ms ║║Cancelling statement #81's schedules...
+10306ms ║║Executed virtual command setVariable (4ms)
+10312ms ║║Executed virtual command setVariable (3ms)
+10319ms ║║Screen changed to close
+10320ms ║║Executed virtual command log (1ms)
+10323ms ║╚Execution stage complete. (71ms)
+10324ms ╚Event processed successfully (10324ms)
5/27/2018, 12:54:33 PM +35ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 259ms
+98ms ║RunTime Analysis CS > 14ms > PS > 37ms > PE > 47ms > CE
+100ms ║Runtime (41966 bytes) successfully initialized in 37ms (v0.3.104.20180323) (99ms)
+101ms ║╔Execution stage started
+114ms ║║Condition #62 evaluated false (7ms)
+115ms ║║Condition group #29 evaluated false (state did not change) (8ms)
+123ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+124ms ║║Cancelling condition #89's schedules...
+125ms ║║Condition #89 evaluated true (6ms)
+126ms ║║Cancelling condition #85's schedules...
+127ms ║║Condition group #85 evaluated true (state changed) (9ms)
+130ms ║║Cancelling statement #86's schedules...
+133ms ║║Executed virtual command wait (0ms)
+134ms ║║Waiting for 800ms
+987ms ║║Executed virtual command setVariable (3ms)
+996ms ║║Accel changed to Active
+998ms ║║Executed virtual command log (1ms)
+1008ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+1011ms ║║Cancelling condition #69's schedules...
+1012ms ║║Condition #69 evaluated true (10ms)
+1018ms ║║Comparison (dynamic) 1 is (integer) 0 = false (2ms)
+1019ms ║║Cancelling condition #92's schedules...
+1020ms ║║Condition #92 evaluated false (7ms)
+1021ms ║║Condition group #65 evaluated false (state did not change) (19ms)
+1032ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+1034ms ║║Cancelling condition #84's schedules...
+1034ms ║║Condition #84 evaluated true (10ms)
+1036ms ║║Cancelling condition #70's schedules...
+1036ms ║║Condition group #70 evaluated true (state changed) (12ms)
+1039ms ║║Cancelling statement #81's schedules...
+1045ms ║║Executed virtual command setVariable (3ms)
+1051ms ║║Executed virtual command setVariable (3ms)
+1058ms ║║Screen changed to close
+1059ms ║║Executed virtual command log (1ms)
+1063ms ║╚Execution stage complete. (962ms)
+1064ms ╚Event processed successfully (1064ms)
5/27/2018, 12:54:30 PM +189ms
+3ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 626ms
+93ms ║RunTime Analysis CS > 14ms > PS > 37ms > PE > 41ms > CE
+96ms ║Runtime (41964 bytes) successfully initialized in 37ms (v0.3.104.20180323) (92ms)
+97ms ║╔Execution stage started
+110ms ║║Cancelling condition #62's schedules...
+110ms ║║Condition #62 evaluated false (8ms)
+111ms ║║Cancelling condition #29's schedules...
+112ms ║║Condition group #29 evaluated false (state changed) (10ms)
+119ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+120ms ║║Condition #89 evaluated false (5ms)
+121ms ║║Condition group #85 evaluated false (state did not change) (6ms)
+127ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+129ms ║║Condition #69 evaluated false (5ms)
+130ms ║║Condition group #65 evaluated false (state did not change) (7ms)
+139ms ║║Comparison (enum) open is (string) closed = false (2ms)
+141ms ║║Condition #84 evaluated false (7ms)
+141ms ║║Condition group #70 evaluated false (state did not change) (9ms)
+144ms ║╚Execution stage complete. (48ms)
+145ms ╚Event processed successfully (145ms)
5/27/2018, 12:54:18 PM +18ms
+2ms ╔Received event [Front Screen Door].contact = open with a delay of 347ms
+116ms ║RunTime Analysis CS > 23ms > PS > 49ms > PE > 44ms > CE
+119ms ║Runtime (41951 bytes) successfully initialized in 49ms (v0.3.104.20180323) (117ms)
+120ms ║╔Execution stage started
+130ms ║║Comparison (enum) open changes_to (string) open = true (0ms)
+131ms ║║Cancelling condition #62's schedules...
+132ms ║║Condition #62 evaluated true (6ms)
+133ms ║║Cancelling condition #29's schedules...
+134ms ║║Condition group #29 evaluated true (state changed) (9ms)
+136ms ║║Cancelling statement #63's schedules...
+142ms ║║Executed virtual command setVariable (3ms)
+149ms ║║Screen changed to Open
+150ms ║║Executed virtual command log (1ms)
+161ms ║║Cancelling condition #89's schedules...
+162ms ║║Condition #89 evaluated false (9ms)
+163ms ║║Cancelling condition #85's schedules...
+164ms ║║Condition group #85 evaluated false (state changed) (11ms)
+170ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+172ms ║║Cancelling condition #69's schedules...
+173ms ║║Condition #69 evaluated false (5ms)
+174ms ║║Cancelling condition #65's schedules...
+175ms ║║Condition group #65 evaluated false (state changed) (8ms)
+182ms ║║Comparison (enum) open is (string) closed = false (2ms)
+183ms ║║Cancelling condition #84's schedules...
+184ms ║║Condition #84 evaluated false (7ms)
+185ms ║║Cancelling condition #70's schedules...
+186ms ║║Condition group #70 evaluated false (state changed) (9ms)
+189ms ║╚Execution stage complete. (69ms)
+190ms ╚Event processed successfully (190ms)
5/27/2018, 12:54:16 PM +874ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 255ms
+86ms ║RunTime Analysis CS > 13ms > PS > 37ms > PE > 35ms > CE
+88ms ║Runtime (41963 bytes) successfully initialized in 37ms (v0.3.104.20180323) (86ms)
+89ms ║╔Execution stage started
+102ms ║║Condition #62 evaluated false (7ms)
+103ms ║║Condition group #29 evaluated false (state did not change) (8ms)
+110ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+111ms ║║Cancelling condition #89's schedules...
+112ms ║║Condition #89 evaluated true (6ms)
+113ms ║║Cancelling condition #85's schedules...
+114ms ║║Condition group #85 evaluated true (state changed) (8ms)
+116ms ║║Cancelling statement #86's schedules...
+120ms ║║Executed virtual command wait (0ms)
+120ms ║║Waiting for 800ms
+927ms ║║Executed virtual command setVariable (2ms)
+934ms ║║Accel changed to Active
+935ms ║║Executed virtual command log (2ms)
+942ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+943ms ║║Cancelling condition #69's schedules...
+944ms ║║Condition #69 evaluated true (6ms)
+949ms ║║Comparison (dynamic) 0 is (integer) 0 = true (2ms)
+950ms ║║Condition #92 evaluated true (5ms)
+951ms ║║Cancelling condition #65's schedules...
+952ms ║║Condition group #65 evaluated true (state changed) (14ms)
+955ms ║║Cancelling statement #66's schedules...
+973ms ║║Executed virtual command sendSMSNotification (12ms)
+979ms ║║Executed virtual command setVariable (3ms)
+986ms ║║SMS sent
+987ms ║║Executed virtual command log (2ms)
+998ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+999ms ║║Condition #84 evaluated true (9ms)
+1000ms ║║Condition group #70 evaluated true (state did not change) (10ms)
+1002ms ║║Cancelling statement #81's schedules...
+1008ms ║║Executed virtual command setVariable (2ms)
+1014ms ║║Executed virtual command setVariable (3ms)
+1021ms ║║Screen changed to close
+1021ms ║║Executed virtual command log (1ms)
+1024ms ║╚Execution stage complete. (935ms)
+1026ms ╚Event processed successfully (1025ms)
5/27/2018, 12:54:13 PM +511ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 436ms
+86ms ║RunTime Analysis CS > 14ms > PS > 39ms > PE > 34ms > CE
+89ms ║Runtime (41959 bytes) successfully initialized in 39ms (v0.3.104.20180323) (87ms)
+90ms ║╔Execution stage started
+103ms ║║Condition #62 evaluated false (7ms)
+104ms ║║Condition group #29 evaluated false (state did not change) (8ms)
+111ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+112ms ║║Cancelling condition #89's schedules...
+113ms ║║Condition #89 evaluated false (6ms)
+114ms ║║Cancelling condition #85's schedules...
+115ms ║║Condition group #85 evaluated false (state changed) (8ms)
+122ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+123ms ║║Cancelling condition #69's schedules...
+124ms ║║Condition #69 evaluated false (6ms)
+125ms ║║Cancelling condition #65's schedules...
+126ms ║║Condition group #65 evaluated false (state changed) (8ms)
+136ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+138ms ║║Condition #84 evaluated true (8ms)
+139ms ║║Condition group #70 evaluated true (state did not change) (9ms)
+141ms ║║Cancelling statement #81's schedules...
+147ms ║║Executed virtual command setVariable (2ms)
+152ms ║║Executed virtual command setVariable (2ms)
+159ms ║║Screen changed to close
+160ms ║║Executed virtual command log (1ms)
+163ms ║╚Execution stage complete. (73ms)
+164ms ╚Event processed successfully (164ms)
5/27/2018, 12:54:00 PM +392ms
+2ms ╔Received event [Front Screen Door].acceleration = active with a delay of 271ms
+101ms ║RunTime Analysis CS > 18ms > PS > 51ms > PE > 31ms > CE
+103ms ║Runtime (41964 bytes) successfully initialized in 51ms (v0.3.104.20180323) (101ms)
+104ms ║╔Execution stage started
+117ms ║║Condition #62 evaluated false (7ms)
+118ms ║║Condition group #29 evaluated false (state did not change) (8ms)
+125ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+126ms ║║Cancelling condition #89's schedules...
+127ms ║║Condition #89 evaluated true (6ms)
+128ms ║║Cancelling condition #85's schedules...
+129ms ║║Condition group #85 evaluated true (state changed) (8ms)
+131ms ║║Cancelling statement #86's schedules...
+135ms ║║Executed virtual command wait (0ms)
+135ms ║║Waiting for 800ms
+942ms ║║Executed virtual command setVariable (3ms)
+949ms ║║Accel changed to Active
+950ms ║║Executed virtual command log (1ms)
+957ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+959ms ║║Cancelling condition #69's schedules...
+960ms ║║Condition #69 evaluated true (7ms)
+964ms ║║Comparison (dynamic) 0 is (integer) 0 = true (1ms)
+966ms ║║Condition #92 evaluated true (5ms)
+967ms ║║Cancelling condition #65's schedules...
+968ms ║║Condition group #65 evaluated true (state changed) (14ms)
+970ms ║║Cancelling statement #66's schedules...
+989ms ║║Executed virtual command sendSMSNotification (13ms)
+996ms ║║Executed virtual command setVariable (3ms)
+1002ms ║║SMS sent
+1003ms ║║Executed virtual command log (1ms)
+1014ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+1016ms ║║Condition #84 evaluated true (9ms)
+1017ms ║║Condition group #70 evaluated true (state did not change) (10ms)
+1019ms ║║Cancelling statement #81's schedules...
+1025ms ║║Executed virtual command setVariable (3ms)
+1031ms ║║Executed virtual command setVariable (2ms)
+1037ms ║║Screen changed to close
+1038ms ║║Executed virtual command log (1ms)
+1041ms ║╚Execution stage complete. (937ms)
+1042ms ╚Event processed successfully (1042ms)I am sorry to be a pain, but would you please clear the logs, test the failed example above, and repost the log?
Acceleration active immediately followed by screen door open (Notification sent. Not OK)
This will make my analysis a bit easier to dig thru. Thanks
Ooh, sorry about that! Just cleared the logs and did the test again. And thank you again, I really appreciate your help!
5/28/2018, 7:20:41 AM +736ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 1015ms
+88ms ║RunTime Analysis CS > 15ms > PS > 36ms > PE > 38ms > CE
+91ms ║Runtime (41965 bytes) successfully initialized in 36ms (v0.3.104.20180323) (89ms)
+92ms ║╔Execution stage started
+105ms ║║Cancelling condition #62's schedules...
+106ms ║║Condition #62 evaluated false (8ms)
+108ms ║║Cancelling condition #29's schedules...
+108ms ║║Condition group #29 evaluated false (state changed) (10ms)
+115ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+116ms ║║Condition #89 evaluated false (5ms)
+117ms ║║Condition group #85 evaluated false (state did not change) (6ms)
+124ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+126ms ║║Condition #69 evaluated false (5ms)
+127ms ║║Condition group #65 evaluated false (state did not change) (6ms)
+136ms ║║Comparison (enum) open is (string) closed = false (1ms)
+138ms ║║Condition #84 evaluated false (8ms)
+139ms ║║Condition group #70 evaluated false (state did not change) (10ms)
+141ms ║╚Execution stage complete. (49ms)
+143ms ╚Event processed successfully (142ms)
5/28/2018, 7:20:29 AM +867ms
+1ms ╔Received event [Front Screen Door].contact = open with a delay of 871ms
+89ms ║RunTime Analysis CS > 20ms > PS > 35ms > PE > 34ms > CE
+92ms ║Runtime (41950 bytes) successfully initialized in 35ms (v0.3.104.20180323) (89ms)
+93ms ║╔Execution stage started
+102ms ║║Comparison (enum) open changes_to (string) open = true (1ms)
+104ms ║║Cancelling condition #62's schedules...
+105ms ║║Condition #62 evaluated true (6ms)
+106ms ║║Cancelling condition #29's schedules...
+106ms ║║Condition group #29 evaluated true (state changed) (8ms)
+109ms ║║Cancelling statement #63's schedules...
+115ms ║║Executed virtual command setVariable (3ms)
+122ms ║║Screen changed to Open
+122ms ║║Executed virtual command log (1ms)
+133ms ║║Cancelling condition #89's schedules...
+133ms ║║Condition #89 evaluated false (7ms)
+134ms ║║Cancelling condition #85's schedules...
+135ms ║║Condition group #85 evaluated false (state changed) (9ms)
+142ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+143ms ║║Cancelling condition #69's schedules...
+144ms ║║Condition #69 evaluated false (6ms)
+145ms ║║Cancelling condition #65's schedules...
+146ms ║║Condition group #65 evaluated false (state changed) (8ms)
+154ms ║║Comparison (enum) open is (string) closed = false (2ms)
+155ms ║║Cancelling condition #84's schedules...
+156ms ║║Condition #84 evaluated false (7ms)
+157ms ║║Cancelling condition #70's schedules...
+158ms ║║Condition group #70 evaluated false (state changed) (9ms)
+161ms ║╚Execution stage complete. (69ms)
+162ms ╚Event processed successfully (162ms)
5/28/2018, 7:20:28 AM +571ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 802ms
+101ms ║RunTime Analysis CS > 17ms > PS > 51ms > PE > 33ms > CE
+103ms ║Runtime (41965 bytes) successfully initialized in 51ms (v0.3.104.20180323) (101ms)
+104ms ║╔Execution stage started
+118ms ║║Condition #62 evaluated false (8ms)
+119ms ║║Condition group #29 evaluated false (state did not change) (9ms)
+146ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+147ms ║║Cancelling condition #89's schedules...
+148ms ║║Condition #89 evaluated true (26ms)
+149ms ║║Cancelling condition #85's schedules...
+150ms ║║Condition group #85 evaluated true (state changed) (28ms)
+160ms ║║Cancelling statement #86's schedules...
+164ms ║║Executed virtual command wait (1ms)
+165ms ║║Waiting for 800ms
+972ms ║║Executed virtual command setVariable (3ms)
+979ms ║║Accel changed to Active
+980ms ║║Executed virtual command log (2ms)
+988ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+989ms ║║Cancelling condition #69's schedules...
+990ms ║║Condition #69 evaluated true (7ms)
+995ms ║║Comparison (dynamic) 0 is (integer) 0 = true (1ms)
+996ms ║║Cancelling condition #92's schedules...
+997ms ║║Condition #92 evaluated true (6ms)
+999ms ║║Cancelling condition #65's schedules...
+1000ms ║║Condition group #65 evaluated true (state changed) (17ms)
+1004ms ║║Cancelling statement #66's schedules...
+1022ms ║║Executed virtual command sendSMSNotification (10ms)
+1028ms ║║Executed virtual command setVariable (3ms)
+1037ms ║║SMS sent
+1038ms ║║Executed virtual command log (2ms)
+1049ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+1051ms ║║Condition #84 evaluated true (9ms)
+1052ms ║║Condition group #70 evaluated true (state did not change) (10ms)
+1054ms ║║Cancelling statement #81's schedules...
+1060ms ║║Executed virtual command setVariable (3ms)
+1066ms ║║Executed virtual command setVariable (3ms)
+1074ms ║║Screen changed to close
+1074ms ║║Executed virtual command log (1ms)
+1078ms ║╚Execution stage complete. (973ms)
+1079ms ╚Event processed successfully (1079ms)So here are the ‘highlights’ of your last log:
28.571 sec = Acceleration is Active
28.736 sec = Begin 800 ms Wait
29.543 sec = Set variable ScreenActive
29.592 sec = SMS sent
29.622 sec = Screen is still closed
29.631 sec = Set variable ScreenOpen = 0
29.637 sec = Set variable ScreenActive = 0
29.867 sec = Screen Opened
29.982 sec = Set variable ScreenOpen = 1
41.736 sec = Acceleration is Inactive
According to this, there was a 1.4 second delay between acceleration and screen open. (almost like a knock, then a slight pause, and then the screen opened) You can increase the 800 ms Wait to 1500 or 1600 ms, which should give enough time for the screen to open, and cancel the text message. Just be aware that the longer you make this delay, the longer it will take for you to actually be notified on a legitimate screen knock.
For future testing the Accel before screen open, I would: Knock and then immediately open the screen… Although, to be honest, I typically do most of my testing as naturally as possible. (this would mean not knocking before opening the screen) I understand why you did though because we wanted to force the acceleration BEFORE the opening for testing.
All in all though, I think the piston is beautiful. The only tweaking from this point should be fine tuning the Wait delay somewhere between 800 - 1600 ms.
(Too small will give you undesired SMS, too large and there will be a delay before legit SMS)
I actually did try changing the wait time to 1500ms earlier, but I noticed it always gave “piston waited at a semaphore” for around 10000ms which kept the if statement from seeing that the door was open.
I did try a knock followed by an immediate open every time. I’d say well less than a second. I think it may not be registering as quickly as I thought. I then started thinking maybe motion before opening was more rare than I was suspecting, but with casual opening and closing maybe 1 out of 3 would show a motion prior to opening the screen door.
I’ve attached the green camera and log that shows the semaphore waiting.
5/28/2018, 1:44:21 PM +636ms
+1ms ╔Received event [Front Screen Door].contact = open with a delay of 673ms
+9673ms ║RunTime Analysis CS > 26ms > PS > 9570ms > PE > 78ms > CE
+9674ms ║Piston waited at a semaphore for 9520ms
+9677ms ║Runtime (42030 bytes) successfully initialized in 9570ms (v0.3.104.20180323) (9674ms)
+9678ms ║╔Execution stage started
+9688ms ║║Comparison (enum) open changes_to (string) open = false (0ms)
+9689ms ║║Condition #62 evaluated false (5ms)
+9690ms ║║Condition group #29 evaluated false (state did not change) (7ms)
+9701ms ║║Cancelling condition #89's schedules...
+9702ms ║║Condition #89 evaluated false (9ms)
+9703ms ║║Cancelling condition #85's schedules...
+9704ms ║║Condition group #85 evaluated false (state changed) (11ms)
+9711ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+9712ms ║║Cancelling condition #69's schedules...
+9713ms ║║Condition #69 evaluated false (6ms)
+9714ms ║║Cancelling condition #65's schedules...
+9715ms ║║Condition group #65 evaluated false (state changed) (9ms)
+9723ms ║║Comparison (enum) open is (string) closed = false (1ms)
+9724ms ║║Condition #84 evaluated false (6ms)
+9725ms ║║Condition group #70 evaluated false (state did not change) (8ms)
+9728ms ║╚Execution stage complete. (50ms)
+9729ms ╚Event processed successfully (9729ms)
5/28/2018, 1:44:21 PM +28ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 986ms
+128ms ║RunTime Analysis CS > 22ms > PS > 37ms > PE > 69ms > CE
+131ms ║Runtime (41966 bytes) successfully initialized in 37ms (v0.3.104.20180323) (129ms)
+132ms ║╔Execution stage started
+145ms ║║Condition #62 evaluated false (7ms)
+146ms ║║Condition group #29 evaluated false (state did not change) (9ms)
+152ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+154ms ║║Cancelling condition #89's schedules...
+155ms ║║Condition #89 evaluated true (6ms)
+156ms ║║Cancelling condition #85's schedules...
+157ms ║║Condition group #85 evaluated true (state changed) (9ms)
+159ms ║║Cancelling statement #86's schedules...
+163ms ║║Executed virtual command wait (1ms)
+164ms ║║Waiting for 1500ms
+1671ms ║║Executed virtual command setVariable (3ms)
+1678ms ║║Accel changed to Active
+1679ms ║║Executed virtual command log (2ms)
+1686ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+1688ms ║║Cancelling condition #69's schedules...
+1689ms ║║Condition #69 evaluated true (7ms)
+1694ms ║║Comparison (dynamic) 0 is (integer) 0 = true (1ms)
+1695ms ║║Condition #92 evaluated true (5ms)
+1696ms ║║Cancelling condition #65's schedules...
+1697ms ║║Condition group #65 evaluated true (state changed) (15ms)
+1699ms ║║Cancelling statement #66's schedules...
+1715ms ║║Executed virtual command sendSMSNotification (9ms)
+1721ms ║║Executed virtual command setVariable (3ms)
+1729ms ║║SMS sent
+1729ms ║║Executed virtual command log (1ms)
+1740ms ║║Comparison (enum) open is (string) closed = false (2ms)
+1742ms ║║Cancelling condition #84's schedules...
+1743ms ║║Condition #84 evaluated false (9ms)
+1744ms ║║Cancelling condition #70's schedules...
+1745ms ║║Condition group #70 evaluated false (state changed) (11ms)
+1747ms ║╚Execution stage complete. (1616ms)
+1749ms ╚Event processed successfully (1749ms)Thanks for that. I didn’t catch the 9.5 second semaphore delay last time around. That is definitely causing the issue. Can you make the first IF block async. (Only the block “IF door changes to open” should be async) This should hopefully give that block permission to make snappy responses where it is needed most.
I’ve made the updates, and it looks like now I’m getting double semaphore delays. One upon open and one open closing. I feel like this might be a limitation of SmartThings?
5/29/2018, 9:55:17 AM +777ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 910ms
+160ms ║RunTime Analysis CS > 26ms > PS > 41ms > PE > 93ms > CE
+163ms ║Runtime (41966 bytes) successfully initialized in 41ms (v0.3.104.20180323) (160ms)
+164ms ║╔Execution stage started
+178ms ║║Condition #62 evaluated false (7ms)
+180ms ║║Condition group #29 evaluated false (state did not change) (10ms)
+387ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+389ms ║║Condition #89 evaluated false (205ms)
+390ms ║║Condition group #85 evaluated false (state did not change) (206ms)
+400ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+402ms ║║Condition #69 evaluated false (7ms)
+404ms ║║Condition group #65 evaluated false (state did not change) (9ms)
+416ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+418ms ║║Condition #84 evaluated true (10ms)
+420ms ║║Condition group #70 evaluated true (state did not change) (13ms)
+423ms ║║Cancelling statement #81's schedules...
+431ms ║║Executed virtual command setVariable (3ms)
+438ms ║║Executed virtual command setVariable (3ms)
+447ms ║║Screen changed to close
+448ms ║║Executed virtual command log (1ms)
+452ms ║╚Execution stage complete. (289ms)
+454ms ╚Event processed successfully (453ms)
5/29/2018, 9:55:04 AM +744ms
+1ms ╔Received event [Front Screen Door].contact = closed with a delay of 778ms
+10153ms ║RunTime Analysis CS > 14ms > PS > 10058ms > PE > 81ms > CE
+10154ms ║Piston waited at a semaphore for 10024ms
+10156ms ║Runtime (42035 bytes) successfully initialized in 10058ms (v0.3.104.20180323) (10154ms)
+10157ms ║╔Execution stage started
+10166ms ║║Comparison (enum) closed changes_to (string) open = false (1ms)
+10167ms ║║Condition #62 evaluated false (4ms)
+10168ms ║║Condition group #29 evaluated false (state did not change) (6ms)
+10178ms ║║Cancelling condition #89's schedules...
+10179ms ║║Condition #89 evaluated false (8ms)
+10180ms ║║Cancelling condition #85's schedules...
+10181ms ║║Condition group #85 evaluated false (state changed) (10ms)
+10188ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+10189ms ║║Cancelling condition #69's schedules...
+10190ms ║║Condition #69 evaluated false (6ms)
+10191ms ║║Cancelling condition #65's schedules...
+10192ms ║║Condition group #65 evaluated false (state changed) (8ms)
+10200ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+10201ms ║║Condition #84 evaluated true (6ms)
+10202ms ║║Condition group #70 evaluated true (state did not change) (7ms)
+10204ms ║║Cancelling statement #81's schedules...
+10211ms ║║Executed virtual command setVariable (3ms)
+10217ms ║║Executed virtual command setVariable (2ms)
+10224ms ║║Screen changed to close
+10225ms ║║Executed virtual command log (1ms)
+10228ms ║╚Execution stage complete. (71ms)
+10229ms ╚Event processed successfully (10229ms)
5/29/2018, 9:55:04 AM +727ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 811ms
+136ms ║RunTime Analysis CS > 24ms > PS > 51ms > PE > 61ms > CE
+138ms ║Runtime (41969 bytes) successfully initialized in 51ms (v0.3.104.20180323) (136ms)
+140ms ║╔Execution stage started
+154ms ║║Condition #62 evaluated false (8ms)
+155ms ║║Condition group #29 evaluated false (state did not change) (9ms)
+161ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+163ms ║║Cancelling condition #89's schedules...
+164ms ║║Condition #89 evaluated true (5ms)
+165ms ║║Cancelling condition #85's schedules...
+165ms ║║Condition group #85 evaluated true (state changed) (8ms)
+168ms ║║Cancelling statement #86's schedules...
+171ms ║║Executed virtual command wait (0ms)
+172ms ║║Waiting for 1500ms
+1680ms ║║Executed virtual command setVariable (3ms)
+1687ms ║║Accel changed to Active
+1688ms ║║Executed virtual command log (1ms)
+1695ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+1697ms ║║Cancelling condition #69's schedules...
+1698ms ║║Condition #69 evaluated true (6ms)
+1702ms ║║Comparison (dynamic) 0 is (integer) 0 = true (1ms)
+1704ms ║║Condition #92 evaluated true (6ms)
+1705ms ║║Cancelling condition #65's schedules...
+1706ms ║║Condition group #65 evaluated true (state changed) (14ms)
+1708ms ║║Cancelling statement #66's schedules...
+1727ms ║║Executed virtual command sendSMSNotification (12ms)
+1734ms ║║Executed virtual command setVariable (4ms)
+1741ms ║║SMS sent
+1742ms ║║Executed virtual command log (1ms)
+1753ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+1754ms ║║Cancelling condition #84's schedules...
+1755ms ║║Condition #84 evaluated true (9ms)
+1756ms ║║Cancelling condition #70's schedules...
+1757ms ║║Condition group #70 evaluated true (state changed) (12ms)
+1759ms ║║Cancelling statement #81's schedules...
+1766ms ║║Executed virtual command setVariable (3ms)
+1772ms ║║Executed virtual command setVariable (3ms)
+1779ms ║║Screen changed to close
+1780ms ║║Executed virtual command log (2ms)
+1783ms ║╚Execution stage complete. (1644ms)
+1784ms ╚Event processed successfully (1784ms)
5/29/2018, 9:55:02 AM +516ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 784ms
+137ms ║RunTime Analysis CS > 24ms > PS > 56ms > PE > 57ms > CE
+139ms ║Runtime (41969 bytes) successfully initialized in 56ms (v0.3.104.20180323) (137ms)
+140ms ║╔Execution stage started
+154ms ║║Condition #62 evaluated false (8ms)
+155ms ║║Condition group #29 evaluated false (state did not change) (9ms)
+162ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+163ms ║║Condition #89 evaluated false (4ms)
+164ms ║║Condition group #85 evaluated false (state did not change) (6ms)
+171ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+173ms ║║Condition #69 evaluated false (5ms)
+174ms ║║Condition group #65 evaluated false (state did not change) (6ms)
+184ms ║║Comparison (enum) open is (string) closed = false (2ms)
+186ms ║║Condition #84 evaluated false (8ms)
+187ms ║║Condition group #70 evaluated false (state did not change) (10ms)
+189ms ║╚Execution stage complete. (49ms)
+190ms ╚Event processed successfully (190ms)
5/29/2018, 9:54:51 AM +181ms
+1ms ╔Received event [Front Screen Door].contact = open with a delay of 1045ms
+8739ms ║RunTime Analysis CS > 23ms > PS > 8632ms > PE > 85ms > CE
+8740ms ║Piston waited at a semaphore for 8585ms
+8743ms ║Runtime (42031 bytes) successfully initialized in 8632ms (v0.3.104.20180323) (8740ms)
+8744ms ║╔Execution stage started
+8754ms ║║Comparison (enum) open changes_to (string) open = false (1ms)
+8755ms ║║Condition #62 evaluated false (5ms)
+8756ms ║║Condition group #29 evaluated false (state did not change) (6ms)
+8768ms ║║Cancelling condition #89's schedules...
+8768ms ║║Condition #89 evaluated false (8ms)
+8770ms ║║Cancelling condition #85's schedules...
+8770ms ║║Condition group #85 evaluated false (state changed) (11ms)
+8777ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+8779ms ║║Cancelling condition #69's schedules...
+8780ms ║║Condition #69 evaluated false (7ms)
+8781ms ║║Cancelling condition #65's schedules...
+8782ms ║║Condition group #65 evaluated false (state changed) (9ms)
+8790ms ║║Comparison (enum) open is (string) closed = false (1ms)
+8791ms ║║Condition #84 evaluated false (6ms)
+8792ms ║║Condition group #70 evaluated false (state did not change) (8ms)
+8795ms ║╚Execution stage complete. (51ms)
+8796ms ╚Event processed successfully (8796ms)
5/29/2018, 9:54:49 AM +574ms
+2ms ╔Received event [Front Screen Door].acceleration = active with a delay of 772ms
+129ms ║RunTime Analysis CS > 24ms > PS > 50ms > PE > 56ms > CE
+132ms ║Runtime (41966 bytes) successfully initialized in 50ms (v0.3.104.20180323) (128ms)
+133ms ║╔Execution stage started
+146ms ║║Condition #62 evaluated false (6ms)
+147ms ║║Condition group #29 evaluated false (state did not change) (8ms)
+153ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+154ms ║║Cancelling condition #89's schedules...
+155ms ║║Condition #89 evaluated true (5ms)
+156ms ║║Cancelling condition #85's schedules...
+157ms ║║Condition group #85 evaluated true (state changed) (8ms)
+159ms ║║Cancelling statement #86's schedules...
+163ms ║║Executed virtual command wait (1ms)
+164ms ║║Waiting for 1500ms
+1670ms ║║Executed virtual command setVariable (3ms)
+1677ms ║║Accel changed to Active
+1678ms ║║Executed virtual command log (1ms)
+1686ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+1687ms ║║Cancelling condition #69's schedules...
+1688ms ║║Condition #69 evaluated true (6ms)
+1693ms ║║Comparison (dynamic) 0 is (integer) 0 = true (2ms)
+1694ms ║║Condition #92 evaluated true (5ms)
+1695ms ║║Cancelling condition #65's schedules...
+1696ms ║║Condition group #65 evaluated true (state changed) (15ms)
+1699ms ║║Cancelling statement #66's schedules...
+1719ms ║║Executed virtual command sendSMSNotification (13ms)
+1726ms ║║Executed virtual command setVariable (3ms)
+1733ms ║║SMS sent
+1733ms ║║Executed virtual command log (1ms)
+1744ms ║║Comparison (enum) open is (string) closed = false (2ms)
+1745ms ║║Cancelling condition #84's schedules...
+1746ms ║║Condition #84 evaluated false (9ms)
+1747ms ║║Cancelling condition #70's schedules...
+1748ms ║║Condition group #70 evaluated false (state changed) (11ms)
+1751ms ║╚Execution stage complete. (1619ms)
+1752ms ╚Event processed successfully (1752ms)Whew… This one has been frustrating. Thanks for your patience.
The last log (2 events) are listed here:
49.574 sec = Screen Acceleration is Active
49.737 sec = Begin 1500 ms Wait
51.181 sec = Screen contact opened
51.244 sec = Set variable ScreenActive = 1
51.292 sec = Sent SMS
59.766 sec = Screen contact open semaphore completed (ACTION CANCELLED)
62.516 sec = Screen Acceleration is Inactive
This one never even detected the door opening
04.727 sec = Screen Acceleration is Active
04.744 sec = Screen contact is closed
04.898 sec = Begin 1500 ms Wait
06.407 sec = Set variable ScreenActive
06.454 sec = SMS sent
06.482 sec = Door seen as closed, so all variables are reset
14.768 sec = Screen contact close semaphore completed
14.955 sec = Door seen as closed, so all variables are reset
17.777 sec = Screen Acceleration is Inactive
18.195 sec = Door seen as closed, so all variables are reset
I left out a bunch of chatter, but it really looks like there are too many things happening simultaneously. (indicated by the semaphore delay) The delay also breaks the logic.
I have a few ideas in my head. But let’s start with the easiest one: Here is what I did below:
The async on this first block means the piston will continue on the other blocks the moment the Wait begins… and then come back to Set variable ScreenActive = 1 after the wait. This should get the variables the way you want in a timely fashion.
(I am tempted to change line 45 back to If contact CHANGES TO closed, but maybe test as is first)
I just tested the new piston and unfortunately, I’m still getting the ~9 second semaphore delays. I also tried with the last block switched to “changes to”. It does not change the variable to 0s because of the semaphore delay I’m guessing. This has definitely been very frustrating, but if anything I’ve learned a lot!
5/30/2018, 5:00:32 PM +23ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 130ms
+86ms ║RunTime Analysis CS > 19ms > PS > 33ms > PE > 34ms > CE
+89ms ║Runtime (41948 bytes) successfully initialized in 33ms (v0.3.104.20180323) (87ms)
+90ms ║╔Execution stage started
+99ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+100ms ║║Cancelling condition #89's schedules...
+101ms ║║Condition #89 evaluated true (6ms)
+102ms ║║Cancelling condition #85's schedules...
+103ms ║║Condition group #85 evaluated true (state changed) (8ms)
+105ms ║║Cancelling statement #86's schedules...
+108ms ║║Executed virtual command wait (1ms)
+109ms ║║Requesting a wake up for Wed, May 30 2018 @ 5:00:33 PM PDT (in 1.5s)
+121ms ║║Condition #62 evaluated false (6ms)
+122ms ║║Condition group #29 evaluated false (state did not change) (7ms)
+128ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+129ms ║║Condition #69 evaluated true (5ms)
+133ms ║║Comparison (dynamic) 1 is (integer) 0 = false (2ms)
+134ms ║║Condition #92 evaluated false (5ms)
+135ms ║║Condition group #65 evaluated false (state did not change) (11ms)
+143ms ║║Condition #84 evaluated false (5ms)
+144ms ║║Condition group #70 evaluated false (state did not change) (7ms)
+147ms ║║Fast executing schedules, waiting for 1464ms to sync up
+1626ms ║║Executed virtual command setVariable (3ms)
+1633ms ║║Accel changed to Active
+1634ms ║║Executed virtual command log (1ms)
+1636ms ║╚Execution stage complete. (1546ms)
+1637ms ╚Event processed successfully (1637ms)
5/30/2018, 5:00:29 PM +749ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 410ms
+78ms ║RunTime Analysis CS > 13ms > PS > 33ms > PE > 32ms > CE
+80ms ║Runtime (41948 bytes) successfully initialized in 33ms (v0.3.104.20180323) (78ms)
+81ms ║╔Execution stage started
+90ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+91ms ║║Condition #89 evaluated false (4ms)
+92ms ║║Condition group #85 evaluated false (state did not change) (6ms)
+101ms ║║Condition #62 evaluated false (6ms)
+113ms ║║Condition group #29 evaluated false (state did not change) (17ms)
+119ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+120ms ║║Condition #69 evaluated true (5ms)
+124ms ║║Comparison (dynamic) 1 is (integer) 0 = false (1ms)
+126ms ║║Condition #92 evaluated false (4ms)
+126ms ║║Condition group #65 evaluated false (state did not change) (11ms)
+135ms ║║Condition #84 evaluated false (6ms)
+136ms ║║Condition group #70 evaluated false (state did not change) (7ms)
+138ms ║╚Execution stage complete. (57ms)
+139ms ╚Event processed successfully (139ms)
5/30/2018, 5:00:16 PM +764ms
+2ms ╔Received event [Front Screen Door].contact = closed with a delay of 263ms
+10184ms ║RunTime Analysis CS > 28ms > PS > 10120ms > PE > 36ms > CE
+10185ms ║Piston waited at a semaphore for 10073ms
+10188ms ║Runtime (42021 bytes) successfully initialized in 10120ms (v0.3.104.20180323) (10184ms)
+10188ms ║╔Execution stage started
+10201ms ║║Cancelling condition #89's schedules...
+10202ms ║║Condition #89 evaluated false (8ms)
+10203ms ║║Cancelling condition #85's schedules...
+10204ms ║║Condition group #85 evaluated false (state changed) (11ms)
+10210ms ║║Comparison (enum) closed changes_to (string) open = false (0ms)
+10211ms ║║Condition #62 evaluated false (4ms)
+10212ms ║║Condition group #29 evaluated false (state did not change) (5ms)
+10218ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+10219ms ║║Cancelling condition #69's schedules...
+10220ms ║║Condition #69 evaluated true (6ms)
+10224ms ║║Comparison (dynamic) 1 is (integer) 0 = false (2ms)
+10225ms ║║Condition #92 evaluated false (5ms)
+10226ms ║║Condition group #65 evaluated false (state did not change) (12ms)
+10232ms ║║Comparison (enum) closed changes_to (string) closed = false (1ms)
+10234ms ║║Condition #84 evaluated false (4ms)
+10235ms ║║Condition group #70 evaluated false (state did not change) (7ms)
+10237ms ║╚Execution stage complete. (49ms)
+10238ms ╚Event processed successfully (10238ms)
5/30/2018, 5:00:16 PM +639ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 244ms
+73ms ║RunTime Analysis CS > 12ms > PS > 34ms > PE > 26ms > CE
+75ms ║Runtime (41948 bytes) successfully initialized in 34ms (v0.3.104.20180323) (74ms)
+76ms ║╔Execution stage started
+87ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+88ms ║║Cancelling condition #89's schedules...
+89ms ║║Condition #89 evaluated true (7ms)
+90ms ║║Cancelling condition #85's schedules...
+91ms ║║Condition group #85 evaluated true (state changed) (9ms)
+93ms ║║Cancelling statement #86's schedules...
+99ms ║║Executed virtual command wait (1ms)
+100ms ║║Requesting a wake up for Wed, May 30 2018 @ 5:00:18 PM PDT (in 1.5s)
+113ms ║║Condition #62 evaluated false (8ms)
+114ms ║║Condition group #29 evaluated false (state did not change) (10ms)
+120ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+121ms ║║Condition #69 evaluated false (4ms)
+123ms ║║Condition group #65 evaluated false (state did not change) (6ms)
+132ms ║║Condition #84 evaluated false (5ms)
+132ms ║║Condition group #70 evaluated false (state did not change) (7ms)
+135ms ║║Fast executing schedules, waiting for 1465ms to sync up
+1614ms ║║Executed virtual command setVariable (3ms)
+1620ms ║║Accel changed to Active
+1621ms ║║Executed virtual command log (0ms)
+1623ms ║╚Execution stage complete. (1547ms)
+1624ms ╚Event processed successfully (1624ms)
5/30/2018, 5:00:12 PM +683ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 323ms
+77ms ║RunTime Analysis CS > 13ms > PS > 34ms > PE > 29ms > CE
+79ms ║Runtime (41945 bytes) successfully initialized in 34ms (v0.3.104.20180323) (77ms)
+80ms ║╔Execution stage started
+89ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+91ms ║║Condition #89 evaluated false (5ms)
+92ms ║║Condition group #85 evaluated false (state did not change) (6ms)
+101ms ║║Cancelling condition #62's schedules...
+102ms ║║Condition #62 evaluated false (7ms)
+103ms ║║Cancelling condition #29's schedules...
+104ms ║║Condition group #29 evaluated false (state changed) (10ms)
+110ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+112ms ║║Cancelling condition #69's schedules...
+113ms ║║Condition #69 evaluated false (5ms)
+113ms ║║Condition group #65 evaluated false (state did not change) (7ms)
+123ms ║║Condition #84 evaluated false (6ms)
+124ms ║║Condition group #70 evaluated false (state did not change) (7ms)
+126ms ║╚Execution stage complete. (46ms)
+127ms ╚Event processed successfully (127ms)
5/30/2018, 5:00:00 PM +904ms
+1ms ╔Received event [Front Screen Door].contact = open with a delay of 400ms
+8981ms ║RunTime Analysis CS > 37ms > PS > 8913ms > PE > 32ms > CE
+8982ms ║Piston waited at a semaphore for 8851ms
+8984ms ║Runtime (42013 bytes) successfully initialized in 8913ms (v0.3.104.20180323) (8982ms)
+8985ms ║╔Execution stage started
+8999ms ║║Cancelling condition #89's schedules...
+8999ms ║║Condition #89 evaluated false (8ms)
+9000ms ║║Cancelling condition #85's schedules...
+9001ms ║║Condition group #85 evaluated false (state changed) (11ms)
+9007ms ║║Comparison (enum) open changes_to (string) open = true (1ms)
+9008ms ║║Cancelling condition #62's schedules...
+9009ms ║║Condition #62 evaluated true (5ms)
+9010ms ║║Cancelling condition #29's schedules...
+9011ms ║║Condition group #29 evaluated true (state changed) (7ms)
+9013ms ║║Cancelling statement #63's schedules...
+9019ms ║║Executed virtual command setVariable (3ms)
+9026ms ║║Screen changed to Open
+9026ms ║║Executed virtual command log (1ms)
+9033ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+9035ms ║║Cancelling condition #69's schedules...
+9035ms ║║Condition #69 evaluated true (6ms)
+9040ms ║║Comparison (dynamic) 1 is (integer) 0 = false (1ms)
+9041ms ║║Cancelling condition #92's schedules...
+9042ms ║║Condition #92 evaluated false (6ms)
+9043ms ║║Condition group #65 evaluated false (state did not change) (13ms)
+9049ms ║║Comparison (enum) open changes_to (string) closed = false (0ms)
+9050ms ║║Condition #84 evaluated false (5ms)
+9051ms ║║Condition group #70 evaluated false (state did not change) (6ms)
+9053ms ║╚Execution stage complete. (68ms)
+9054ms ╚Event processed successfully (9054ms)
5/30/2018, 4:59:59 PM +670ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 256ms
+101ms ║RunTime Analysis CS > 22ms > PS > 50ms > PE > 29ms > CE
+104ms ║Runtime (41947 bytes) successfully initialized in 50ms (v0.3.104.20180323) (102ms)
+105ms ║╔Execution stage started
+115ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+116ms ║║Cancelling condition #89's schedules...
+117ms ║║Condition #89 evaluated true (6ms)
+118ms ║║Cancelling condition #85's schedules...
+119ms ║║Condition group #85 evaluated true (state changed) (7ms)
+121ms ║║Cancelling statement #86's schedules...
+126ms ║║Executed virtual command wait (0ms)
+128ms ║║Requesting a wake up for Wed, May 30 2018 @ 5:00:01 PM PDT (in 1.5s)
+140ms ║║Condition #62 evaluated false (6ms)
+140ms ║║Condition group #29 evaluated false (state did not change) (8ms)
+147ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+149ms ║║Condition #69 evaluated false (6ms)
+150ms ║║Condition group #65 evaluated false (state did not change) (6ms)
+159ms ║║Condition #84 evaluated false (6ms)
+160ms ║║Condition group #70 evaluated false (state did not change) (7ms)
+163ms ║║Fast executing schedules, waiting for 1466ms to sync up
+1645ms ║║Executed virtual command setVariable (3ms)
+1652ms ║║Accel changed to Active
+1653ms ║║Executed virtual command log (1ms)
+1656ms ║╚Execution stage complete. (1552ms)
+1658ms ╚Event processed successfully (1657ms)That semaphore is going to be the death of me, LOL
The good news is, you did NOT get the unwanted SMS message!!
(Personally, I never worry about the semaphore unless I have errors)
Here is the latest analysis of your most recent log:
59.670 sec = Screen Acceleration is Active
59.798 sec = Requesting a wake up in 1.5 secs
61.315 sec = Set variable ScreenActive = 1
60.904 sec = Screen contact opened
69.886 sec = Screen contact opened semaphore complete
69.923 sec = Set variable ScreenOpen = 1
72.683 sec = Screen Acceleration is Inactive
The screen opened within the 1500ms time range (barely), but the semaphore forced a delay that we do not want. Also, for some reason, the door never registered as close, so the variables did not reset for the next test.
76.639 sec = Screen Acceleration is Active
76.739 sec = Requesting a wake up in 1.5 secs
78.253 sec = Set variable ScreenActive = 1
76.764 sec = Screen contact closed
86.949 sec = Screen contact closed semaphore complete
86.949 sec = Screen contact closed variables did NOT reset
89.749 sec = Screen Acceleration is Inactive
92.023 sec = Screen Acceleration is Active
92.132 sec = Requesting a wake up in 1.5 secs
93.649 sec = Set variable ScreenActive = 1
I am not sure if this is a second test, or just part two of the same test…
(Maybe you just held the screen open for 17 seconds, and then let it close.)
Also, I went back thru the last two days of your logs, and not once did I find where the Screen door closing reset your variables.
Condition group #70 evaluated false (state did not change)
This will affect any future tests.
Sooo, long story short, I loaded your latest piston, and made a few tiny adjustments to it:
I hope this will do what you need. If not, I may have to break up your piston into two pistons to get around the semaphore issue.
One small request I have though. For future testing, can you make sure that the variables are both at 0 (or blank) prior to running the test. (If a previous test failed, the numbers may start off wrong, and that would affect the current test) You do not have to do this on a brand new piston because no numbers have been set yet. Only on subsequent testing until we are sure the door closing did a successful reset of both variables to 0.
Thanks
Just tested the new piston. I’m still getting a semaphore delay. It seemed like it was working at first. That is, when I moved the screen door then opened. I did not receive the notification. Even after the acceleration went back to inactive state… but then right when I knocked on the screen door, I got the notification.
Maybe it’s just asking too much of webcore?
6/2/2018, 2:15:15 PM +263ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 706ms
+118ms ║RunTime Analysis CS > 18ms > PS > 48ms > PE > 53ms > CE
+121ms ║Runtime (41940 bytes) successfully initialized in 48ms (v0.3.104.20180323) (119ms)
+122ms ║╔Execution stage started
+132ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+134ms ║║Cancelling condition #89's schedules...
+134ms ║║Condition #89 evaluated false (6ms)
+135ms ║║Cancelling condition #85's schedules...
+136ms ║║Condition group #85 evaluated false (state changed) (8ms)
+147ms ║║Comparison (enum) closed is (string) open = false (2ms)
+148ms ║║Condition #62 evaluated false (9ms)
+149ms ║║Condition group #29 evaluated false (state did not change) (10ms)
+156ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+158ms ║║Cancelling condition #69's schedules...
+159ms ║║Condition #69 evaluated true (7ms)
+163ms ║║Comparison (dynamic) 0 is (integer) 0 = true (1ms)
+165ms ║║Condition #92 evaluated true (6ms)
+166ms ║║Cancelling condition #65's schedules...
+167ms ║║Condition group #65 evaluated true (state changed) (15ms)
+169ms ║║Cancelling statement #66's schedules...
+187ms ║║Executed virtual command sendSMSNotification (12ms)
+193ms ║║Executed virtual command setVariable (3ms)
+200ms ║║SMS sent
+201ms ║║Executed virtual command log (1ms)
+212ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+214ms ║║Condition #84 evaluated true (9ms)
+215ms ║║Condition group #70 evaluated true (state did not change) (11ms)
+217ms ║║Cancelling statement #81's schedules...
+223ms ║║Executed virtual command setVariable (3ms)
+229ms ║║Executed virtual command setVariable (3ms)
+236ms ║║Screen is closed - Variables reset
+237ms ║║Executed virtual command log (1ms)
+240ms ║╚Execution stage complete. (118ms)
+241ms ╚Event processed successfully (241ms)
6/2/2018, 2:15:02 PM +305ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 709ms
+126ms ║RunTime Analysis CS > 26ms > PS > 53ms > PE > 47ms > CE
+129ms ║Runtime (41942 bytes) successfully initialized in 53ms (v0.3.104.20180323) (127ms)
+130ms ║╔Execution stage started
+141ms ║║Comparison (enum) active changes_to (string) active = true (0ms)
+142ms ║║Cancelling condition #89's schedules...
+143ms ║║Condition #89 evaluated true (7ms)
+144ms ║║Cancelling condition #85's schedules...
+145ms ║║Condition group #85 evaluated true (state changed) (9ms)
+148ms ║║Cancelling statement #86's schedules...
+152ms ║║Executed virtual command wait (1ms)
+153ms ║║Requesting a wake up for Sat, Jun 2 2018 @ 2:15:03 PM PDT (in 1.5s)
+168ms ║║Comparison (enum) closed is (string) open = false (2ms)
+170ms ║║Condition #62 evaluated false (10ms)
+171ms ║║Condition group #29 evaluated false (state did not change) (12ms)
+178ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+180ms ║║Condition #69 evaluated false (6ms)
+181ms ║║Condition group #65 evaluated false (state did not change) (8ms)
+192ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+193ms ║║Condition #84 evaluated true (9ms)
+194ms ║║Condition group #70 evaluated true (state did not change) (10ms)
+197ms ║║Cancelling statement #81's schedules...
+204ms ║║Executed virtual command setVariable (3ms)
+210ms ║║Executed virtual command setVariable (3ms)
+218ms ║║Screen is closed - Variables reset
+219ms ║║Executed virtual command log (2ms)
+223ms ║║Fast executing schedules, waiting for 1432ms to sync up
+1676ms ║║Executed virtual command setVariable (3ms)
+1684ms ║║Accel changed to Active
+1685ms ║║Executed virtual command log (1ms)
+1689ms ║╚Execution stage complete. (1559ms)
+1690ms ╚Event processed successfully (1690ms)
6/2/2018, 2:15:00 PM +240ms
+1ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 740ms
+93ms ║RunTime Analysis CS > 19ms > PS > 34ms > PE > 40ms > CE
+95ms ║Runtime (41939 bytes) successfully initialized in 34ms (v0.3.104.20180323) (94ms)
+96ms ║╔Execution stage started
+106ms ║║Comparison (enum) inactive changes_to (string) active = false (1ms)
+107ms ║║Condition #89 evaluated false (5ms)
+108ms ║║Condition group #85 evaluated false (state did not change) (6ms)
+118ms ║║Comparison (enum) closed is (string) open = false (1ms)
+120ms ║║Condition #62 evaluated false (9ms)
+121ms ║║Condition group #29 evaluated false (state did not change) (10ms)
+127ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+129ms ║║Cancelling condition #69's schedules...
+130ms ║║Condition #69 evaluated false (5ms)
+131ms ║║Cancelling condition #65's schedules...
+131ms ║║Condition group #65 evaluated false (state changed) (8ms)
+141ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+143ms ║║Condition #84 evaluated true (9ms)
+144ms ║║Condition group #70 evaluated true (state did not change) (10ms)
+146ms ║║Cancelling statement #81's schedules...
+153ms ║║Executed virtual command setVariable (3ms)
+158ms ║║Executed virtual command setVariable (3ms)
+165ms ║║Screen is closed - Variables reset
+166ms ║║Executed virtual command log (1ms)
+168ms ║╚Execution stage complete. (72ms)
+170ms ╚Event processed successfully (169ms)
6/2/2018, 2:14:47 PM +318ms
+2ms ╔Received event [Front Screen Door].contact = closed with a delay of 717ms
+10165ms ║RunTime Analysis CS > 28ms > PS > 10095ms > PE > 41ms > CE
+10166ms ║Piston waited at a semaphore for 10046ms
+10168ms ║Runtime (42014 bytes) successfully initialized in 10095ms (v0.3.104.20180323) (10165ms)
+10169ms ║╔Execution stage started
+10183ms ║║Cancelling condition #89's schedules...
+10184ms ║║Condition #89 evaluated false (9ms)
+10185ms ║║Cancelling condition #85's schedules...
+10186ms ║║Condition group #85 evaluated false (state changed) (11ms)
+10193ms ║║Comparison (enum) closed is (string) open = false (1ms)
+10195ms ║║Condition #62 evaluated false (6ms)
+10196ms ║║Condition group #29 evaluated false (state did not change) (7ms)
+10203ms ║║Comparison (dynamic) 1 is (integer) 1 = true (2ms)
+10204ms ║║Cancelling condition #69's schedules...
+10205ms ║║Condition #69 evaluated true (6ms)
+10210ms ║║Comparison (dynamic) 0 is (integer) 0 = true (2ms)
+10211ms ║║Cancelling condition #92's schedules...
+10212ms ║║Condition #92 evaluated true (6ms)
+10213ms ║║Cancelling condition #65's schedules...
+10214ms ║║Condition group #65 evaluated true (state changed) (16ms)
+10217ms ║║Cancelling statement #66's schedules...
+10235ms ║║Executed virtual command sendSMSNotification (12ms)
+10242ms ║║Executed virtual command setVariable (4ms)
+10249ms ║║SMS sent
+10250ms ║║Executed virtual command log (2ms)
+10258ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+10260ms ║║Condition #84 evaluated true (6ms)
+10261ms ║║Condition group #70 evaluated true (state did not change) (7ms)
+10263ms ║║Cancelling statement #81's schedules...
+10269ms ║║Executed virtual command setVariable (3ms)
+10275ms ║║Executed virtual command setVariable (3ms)
+10282ms ║║Screen is closed - Variables reset
+10283ms ║║Executed virtual command log (1ms)
+10286ms ║╚Execution stage complete. (117ms)
+10287ms ╚Event processed successfully (10287ms)
6/2/2018, 2:14:47 PM +238ms
+2ms ╔Received event [Front Screen Door].acceleration = active with a delay of 696ms
+106ms ║RunTime Analysis CS > 17ms > PS > 51ms > PE > 37ms > CE
+108ms ║Runtime (41944 bytes) successfully initialized in 51ms (v0.3.104.20180323) (105ms)
+110ms ║╔Execution stage started
+120ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+121ms ║║Cancelling condition #89's schedules...
+122ms ║║Condition #89 evaluated true (6ms)
+123ms ║║Cancelling condition #85's schedules...
+124ms ║║Condition group #85 evaluated true (state changed) (9ms)
+127ms ║║Cancelling statement #86's schedules...
+131ms ║║Executed virtual command wait (0ms)
+132ms ║║Requesting a wake up for Sat, Jun 2 2018 @ 2:14:48 PM PDT (in 1.5s)
+146ms ║║Comparison (enum) closed is (string) open = false (2ms)
+148ms ║║Cancelling condition #62's schedules...
+148ms ║║Condition #62 evaluated false (11ms)
+150ms ║║Cancelling condition #29's schedules...
+150ms ║║Condition group #29 evaluated false (state changed) (13ms)
+158ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+159ms ║║Condition #69 evaluated false (5ms)
+160ms ║║Condition group #65 evaluated false (state did not change) (7ms)
+170ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+172ms ║║Cancelling condition #84's schedules...
+173ms ║║Condition #84 evaluated true (9ms)
+174ms ║║Cancelling condition #70's schedules...
+175ms ║║Condition group #70 evaluated true (state changed) (12ms)
+177ms ║║Cancelling statement #81's schedules...
+186ms ║║Executed virtual command setVariable (6ms)
+193ms ║║Executed virtual command setVariable (3ms)
+200ms ║║Screen is closed - Variables reset
+201ms ║║Executed virtual command log (1ms)
+205ms ║║Fast executing schedules, waiting for 1427ms to sync up
+1648ms ║║Executed virtual command setVariable (3ms)
+1656ms ║║Accel changed to Active
+1657ms ║║Executed virtual command log (1ms)
+1659ms ║╚Execution stage complete. (1550ms)
+1661ms ╚Event processed successfully (1661ms)
6/2/2018, 2:14:43 PM +237ms
+2ms ╔Received event [Front Screen Door].acceleration = inactive with a delay of 703ms
+106ms ║RunTime Analysis CS > 24ms > PS > 50ms > PE > 32ms > CE
+109ms ║Runtime (41943 bytes) successfully initialized in 50ms (v0.3.104.20180323) (107ms)
+110ms ║╔Execution stage started
+119ms ║║Comparison (enum) inactive changes_to (string) active = false (0ms)
+121ms ║║Condition #89 evaluated false (5ms)
+122ms ║║Condition group #85 evaluated false (state did not change) (7ms)
+133ms ║║Comparison (enum) open is (string) open = true (2ms)
+134ms ║║Condition #62 evaluated true (9ms)
+135ms ║║Condition group #29 evaluated true (state did not change) (11ms)
+138ms ║║Cancelling statement #63's schedules...
+145ms ║║Executed virtual command setVariable (3ms)
+151ms ║║Screen is Open
+152ms ║║Executed virtual command log (1ms)
+159ms ║║Comparison (dynamic) 0 is (integer) 1 = false (1ms)
+161ms ║║Cancelling condition #69's schedules...
+162ms ║║Condition #69 evaluated false (6ms)
+163ms ║║Condition group #65 evaluated false (state did not change) (8ms)
+173ms ║║Comparison (enum) open is (string) closed = false (1ms)
+174ms ║║Condition #84 evaluated false (8ms)
+175ms ║║Condition group #70 evaluated false (state did not change) (10ms)
+177ms ║╚Execution stage complete. (68ms)
+178ms ╚Event processed successfully (178ms)
6/2/2018, 2:14:31 PM +874ms
+2ms ╔Received event [Front Screen Door].contact = open with a delay of 1013ms
+8747ms ║RunTime Analysis CS > 18ms > PS > 8697ms > PE > 32ms > CE
+8748ms ║Piston waited at a semaphore for 8641ms
+8751ms ║Runtime (42010 bytes) successfully initialized in 8697ms (v0.3.104.20180323) (8748ms)
+8752ms ║╔Execution stage started
+8766ms ║║Cancelling condition #89's schedules...
+8767ms ║║Condition #89 evaluated false (9ms)
+8768ms ║║Cancelling condition #85's schedules...
+8769ms ║║Condition group #85 evaluated false (state changed) (11ms)
+8777ms ║║Comparison (enum) open is (string) open = true (2ms)
+8779ms ║║Cancelling condition #62's schedules...
+8780ms ║║Condition #62 evaluated true (7ms)
+8781ms ║║Cancelling condition #29's schedules...
+8782ms ║║Condition group #29 evaluated true (state changed) (9ms)
+8784ms ║║Cancelling statement #63's schedules...
+8791ms ║║Executed virtual command setVariable (2ms)
+8798ms ║║Screen is Open
+8799ms ║║Executed virtual command log (1ms)
+8808ms ║║Comparison (dynamic) 1 is (integer) 1 = true (1ms)
+8809ms ║║Cancelling condition #69's schedules...
+8810ms ║║Condition #69 evaluated true (7ms)
+8815ms ║║Comparison (dynamic) 1 is (integer) 0 = false (2ms)
+8817ms ║║Condition #92 evaluated false (5ms)
+8818ms ║║Condition group #65 evaluated false (state did not change) (14ms)
+8826ms ║║Comparison (enum) open is (string) closed = false (2ms)
+8828ms ║║Cancelling condition #84's schedules...
+8829ms ║║Condition #84 evaluated false (7ms)
+8830ms ║║Cancelling condition #70's schedules...
+8831ms ║║Condition group #70 evaluated false (state changed) (10ms)
+8833ms ║╚Execution stage complete. (82ms)
+8835ms ╚Event processed successfully (8835ms)
6/2/2018, 2:14:30 PM +266ms
+1ms ╔Received event [Front Screen Door].acceleration = active with a delay of 684ms
+85ms ║RunTime Analysis CS > 18ms > PS > 42ms > PE > 25ms > CE
+89ms ║Runtime (41947 bytes) successfully initialized in 42ms (v0.3.104.20180323) (86ms)
+90ms ║╔Execution stage started
+100ms ║║Comparison (enum) active changes_to (string) active = true (1ms)
+102ms ║║Cancelling condition #89's schedules...
+103ms ║║Condition #89 evaluated true (7ms)
+104ms ║║Cancelling condition #85's schedules...
+105ms ║║Condition group #85 evaluated true (state changed) (9ms)
+107ms ║║Cancelling statement #86's schedules...
+111ms ║║Executed virtual command wait (1ms)
+112ms ║║Requesting a wake up for Sat, Jun 2 2018 @ 2:14:31 PM PDT (in 1.5s)
+126ms ║║Comparison (enum) closed is (string) open = false (1ms)
+127ms ║║Condition #62 evaluated false (10ms)
+128ms ║║Condition group #29 evaluated false (state did not change) (11ms)
+135ms ║║Comparison (dynamic) 0 is (integer) 1 = false (2ms)
+136ms ║║Condition #69 evaluated false (5ms)
+137ms ║║Condition group #65 evaluated false (state did not change) (6ms)
+147ms ║║Comparison (enum) closed is (string) closed = true (2ms)
+149ms ║║Condition #84 evaluated true (8ms)
+150ms ║║Condition group #70 evaluated true (state did not change) (9ms)
+152ms ║║Cancelling statement #81's schedules...
+158ms ║║Executed virtual command setVariable (3ms)
+163ms ║║Executed virtual command setVariable (2ms)
+170ms ║║Screen is closed - Variables reset
+171ms ║║Executed virtual command log (1ms)
+174ms ║║Fast executing schedules, waiting for 1438ms to sync up
+1628ms ║║Executed virtual command setVariable (3ms)
+1635ms ║║Accel changed to Active
+1636ms ║║Executed virtual command log (1ms)
+1639ms ║╚Execution stage complete. (1549ms)
+1640ms ╚Event processed successfully (1639ms)
6/2/2018, 2:13:53 PM +773ms
+168ms ║Screen is closed - Variables resetWasn’t this our goal all along?!? I mean, I can honestly say that I never look at semaphore delays if the piston is doing what I want…
Oops. I meant to say that the notification received was a delayed response from the first acceleration active immediately followed by screen door open. It coincidentally sent this first notification right after the second acceleration active only. The second notification was sent a little after for the second acceleration active only.
I have never really looked in depth into any of the logs until after trying to set up these pistons for the screen door. For all I know, I have semaphore delays in all my other pistons, but I never really checked because they all seem to work ok…more or less. There are some hiccups here and there.
This entire exercise, though, has been so helpful to me anyway when I try to create future pistons or revisit older pistons.
I appreciate your positive outlook, even though so far, I feel like I have let you down…
I do not have an extra sensor to test this specifically, but I have created two tiny pistons, and all of my simulations have been 100% successful.
I am kind of disappointed we could not get this to work in one piston, but hopefully these work for you. To test, you will first need to make an integer global variable called @screenActive. The beauty is the second piston will check each time the screen goes active or inactive… but only sends the SMS when the screen is active and closed (in 100% of my testing)
The 6 log commands I inserted are handy to keep during your testing, but they aren’t needed once you are happy with it.
Also, don’t forget to pause any other pistons that may be monitoring the screen door, so as to not cause a conflict. (or needless semaphore delay)
(You will need to import both of these pistons to test)
