Is WAIT eating some of my other pistons' results?


#1

1) Give a description of the problem
2 problems. I have two pistons monitoring doors and locks opening and closing. I have a third piston sending status commands to a Homeseer 200+ lightswitch with LEDs. As I test the pistons, not all of the verbal responses or status commands are being processed, and the LEDs won’t keep updating.

2) What is the expected behaviour?
As a door is opened or unlocked, ES will tell me the status of the door, and my Homeseer lightswitch LEDs should either show a solid light at top (for open door) or a flashing light (for unlocked door). Since some LEDs will be shared (back door and front door unlocked at same time), I’m trying to give each light status three seconds to run before switching over to the next status. I did this with a WAIT command.

3) What is happening/not happening?
Some verbal responses are disappearing. And the lights will switch once or twice (green for back door, white for front), but then they will stay one color or the other unless I make a change on either lock or door.

**4) Post a Green Snapshot of the piston![image|45x37]

5) Attach logs after turning logging level to Full

27/12/2019, 02:03:31 +93ms
+1ms ╔Received event [Back Door Deadbolt].contact = closed with a delay of 324ms
+9216ms ║RunTime Analysis CS > 36ms > PS > 9118ms > PE > 63ms > CE
+9217ms ║Piston waited at a semaphore for 9061ms
+9219ms ║Runtime (54544 bytes) successfully initialized in 9118ms (v0.3.110.20191009) (9217ms)
+9220ms ║╔Execution stage started
+9227ms ║║Comparison (integer) 1 is_equal_to (integer) 0 = false (1ms)
+9228ms ║║Condition #2 evaluated false (4ms)
+9229ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+9234ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9236ms ║║Cancelling condition #4's schedules...
+9237ms ║║Condition #4 evaluated false (5ms)
+9238ms ║║Cancelling condition #3's schedules...
+9238ms ║║Condition group #3 evaluated false (state changed) (7ms)
+9244ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9245ms ║║Condition #35 evaluated false (4ms)
+9246ms ║║Condition group #34 evaluated false (state did not change) (6ms)
+9255ms ║║Comparison (enum) closed is (string) open = false (2ms)
+9256ms ║║Condition #42 evaluated false (8ms)
+9257ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+9266ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9267ms ║║Condition #48 evaluated false (8ms)
+9268ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+9278ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9279ms ║║Condition #54 evaluated false (9ms)
+9280ms ║║Condition group #53 evaluated false (state did not change) (10ms)
+9289ms ║║Comparison (enum) closed is (string) open = false (2ms)
+9290ms ║║Condition #63 evaluated false (8ms)
+9291ms ║║Condition group #62 evaluated false (state did not change) (9ms)
+9299ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9300ms ║║Condition #70 evaluated false (7ms)
+9301ms ║║Condition group #69 evaluated false (state did not change) (8ms)
+9303ms ║╚Execution stage complete. (83ms)
+9304ms ╚Event processed successfully (9305ms)
27/12/2019, 02:03:31 +756ms
+1ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 189ms
+8412ms ║RunTime Analysis CS > 31ms > PS > 8322ms > PE > 59ms > CE
+8413ms ║Piston waited at a semaphore for 8273ms
+8416ms ║Runtime (54560 bytes) successfully initialized in 8322ms (v0.3.110.20191009) (8414ms)
+8417ms ║╔Execution stage started
+8424ms ║║Comparison (integer) 0 is_equal_to (integer) 0 = true (1ms)
+8425ms ║║Cancelling condition #2's schedules...
+8426ms ║║Condition #2 evaluated true (5ms)
+8451ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+8453ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+8455ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+8457ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+8459ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+8462ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+8464ms ║║Cancelling condition #76's schedules...
+8466ms ║║Cancelling statement #30's schedules...
+8507ms ║║Executed physical command [Front Door Light].setStatusLed([7, 3, 0]) (34ms)
+8508ms ║║Executed [Front Door Light].setStatusLed (36ms)
+8509ms ║║Condition #76 evaluated true (82ms)
+8517ms ║║Comparison (enum) locked is (string) locked = true (1ms)
+8520ms ║║Cancelling statement #78's schedules...
+8541ms ║║Executed physical command [Front Door Light].setStatusLed([6, 3, 0]) (15ms)
+8541ms ║║Executed [Front Door Light].setStatusLed (16ms)
+8543ms ║║Condition #77 evaluated true (32ms)
+8544ms ║║Cancelling condition #1's schedules...
+8544ms ║║Condition group #1 evaluated true (state changed) (124ms)
+8546ms ║╚Execution stage complete. (130ms)
+8547ms ╚Event processed successfully (8547ms)
27/12/2019, 02:03:31 +11ms
+0ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 199ms
+9171ms ║RunTime Analysis CS > 28ms > PS > 9080ms > PE > 63ms > CE
+9172ms ║Piston waited at a semaphore for 9028ms
+9175ms ║Runtime (54560 bytes) successfully initialized in 9080ms (v0.3.110.20191009) (9174ms)
+9176ms ║╔Execution stage started
+9183ms ║║Comparison (integer) 1 is_equal_to (integer) 0 = false (2ms)
+9184ms ║║Condition #2 evaluated false (4ms)
+9185ms ║║Condition group #1 evaluated false (state did not change) (6ms)
+9194ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9195ms ║║Cancelling condition #4's schedules...
+9196ms ║║Condition #4 evaluated false (9ms)
+9197ms ║║Cancelling condition #3's schedules...
+9198ms ║║Condition group #3 evaluated false (state changed) (10ms)
+9205ms ║║Comparison (enum) closed is (string) open = false (2ms)
+9206ms ║║Condition #35 evaluated false (6ms)
+9207ms ║║Condition group #34 evaluated false (state did not change) (7ms)
+9217ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9218ms ║║Condition #42 evaluated false (9ms)
+9219ms ║║Condition group #41 evaluated false (state did not change) (10ms)
+9229ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9231ms ║║Condition #48 evaluated false (10ms)
+9232ms ║║Condition group #47 evaluated false (state did not change) (11ms)
+9241ms ║║Comparison (enum) closed is (string) open = false (2ms)
+9242ms ║║Condition #54 evaluated false (8ms)
+9243ms ║║Condition group #53 evaluated false (state did not change) (9ms)
+9251ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9253ms ║║Condition #63 evaluated false (8ms)
+9254ms ║║Condition group #62 evaluated false (state did not change) (8ms)
+9261ms ║║Comparison (enum) closed is (string) open = false (1ms)
+9263ms ║║Condition #70 evaluated false (6ms)
+9264ms ║║Condition group #69 evaluated false (state did not change) (7ms)
+9266ms ║╚Execution stage complete. (91ms)
+9267ms ╚Event processed successfully (9267ms)
27/12/2019, 02:03:30 +21ms
+1ms ╔Received event [Back Door Sensor].contact = closed with a delay of 154ms
+114ms ║RunTime Analysis CS > 17ms > PS > 41ms > PE > 56ms > CE
+117ms ║Runtime (54465 bytes) successfully initialized in 41ms (v0.3.110.20191009) (115ms)
+118ms ║╔Execution stage started
+125ms ║║Comparison (integer) 2 is_equal_to (integer) 0 = false (1ms)
+127ms ║║Condition #2 evaluated false (4ms)
+127ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+136ms ║║Comparison (enum) open is (string) open = true (2ms)
+137ms ║║Condition #4 evaluated true (7ms)
+141ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+143ms ║║Cancelling condition #31's schedules...
+144ms ║║Condition #31 evaluated true (6ms)
+145ms ║║Cancelling condition #3's schedules...
+146ms ║║Condition group #3 evaluated true (state changed) (16ms)
+148ms ║║Cancelling statement #60's schedules...
+167ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (12ms)
+168ms ║║Executed [Front Door Light].setStatusLed (14ms)
+170ms ║║Cancelling statement #32's schedules...
+173ms ║║Executed virtual command wait (1ms)
+174ms ║║Waiting for 3000ms
+3183ms ║║Comparison (enum) closed is (string) open = false (2ms)
+3185ms ║║Cancelling condition #35's schedules...
+3185ms ║║Condition #35 evaluated false (8ms)
+3186ms ║║Cancelling condition #34's schedules...
+3187ms ║║Condition group #34 evaluated false (state changed) (10ms)
+3196ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3198ms ║║Condition #42 evaluated false (8ms)
+3199ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+3208ms ║║Comparison (enum) closed is (string) open = false (2ms)
+3209ms ║║Condition #48 evaluated false (8ms)
+3210ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+3219ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3220ms ║║Condition #54 evaluated false (8ms)
+3221ms ║║Condition group #53 evaluated false (state did not change) (9ms)
+3230ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3232ms ║║Condition #63 evaluated false (8ms)
+3233ms ║║Condition group #62 evaluated false (state did not change) (9ms)
+3241ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3243ms ║║Condition #70 evaluated false (7ms)
+3244ms ║║Condition group #69 evaluated false (state did not change) (8ms)
+3246ms ║╚Execution stage complete. (3128ms)
+3247ms ╚Event processed successfully (3247ms)
27/12/2019, 02:03:26 +470ms
+0ms ╔Received event [Home].time = 1577441006499 with a delay of -29ms
+173ms ║RunTime Analysis CS > 30ms > PS > 64ms > PE > 79ms > CE
+177ms ║Runtime (54457 bytes) successfully initialized in 64ms (v0.3.110.20191009) (175ms)
+178ms ║╔Execution stage started
+218ms ║║Comparison (enum) closed is (string) open = false (2ms)
+221ms ║║Condition #42 evaluated false (9ms)
+222ms ║║Condition group #41 evaluated false (state did not change) (11ms)
+234ms ║║Comparison (enum) closed is (string) open = false (2ms)
+236ms ║║Condition #48 evaluated false (10ms)
+238ms ║║Condition group #47 evaluated false (state did not change) (12ms)
+248ms ║║Comparison (enum) closed is (string) open = false (1ms)
+250ms ║║Condition #54 evaluated false (8ms)
+251ms ║║Condition group #53 evaluated false (state did not change) (10ms)
+262ms ║║Comparison (enum) closed is (string) open = false (2ms)
+264ms ║║Condition #63 evaluated false (10ms)
+265ms ║║Condition group #62 evaluated false (state did not change) (11ms)
+276ms ║║Comparison (enum) closed is (string) open = false (2ms)
+278ms ║║Condition #70 evaluated false (9ms)
+279ms ║║Condition group #69 evaluated false (state did not change) (11ms)
+283ms ║╚Execution stage complete. (104ms)
+284ms ╚Event processed successfully (284ms)
27/12/2019, 02:03:13 +762ms
+0ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 100ms
+9640ms ║RunTime Analysis CS > 27ms > PS > 9562ms > PE > 52ms > CE
+9641ms ║Piston waited at a semaphore for 9523ms
+9644ms ║Runtime (54557 bytes) successfully initialized in 9562ms (v0.3.110.20191009) (9643ms)
+9645ms ║╔Execution stage started
+9652ms ║║Comparison (integer) 2 is_equal_to (integer) 0 = false (2ms)
+9653ms ║║Condition #2 evaluated false (4ms)
+9654ms ║║Condition group #1 evaluated false (state did not change) (6ms)
+9662ms ║║Comparison (enum) open is (string) open = true (1ms)
+9664ms ║║Condition #4 evaluated true (7ms)
+9670ms ║║Comparison (enum) open is (string) closed = false (1ms)
+9672ms ║║Condition #31 evaluated false (7ms)
+9673ms ║║Condition group #3 evaluated false (state did not change) (16ms)
+9680ms ║║Comparison (enum) open is (string) open = true (1ms)
+9682ms ║║Condition #35 evaluated true (6ms)
+9688ms ║║Comparison (enum) open is (string) open = true (1ms)
+9689ms ║║Condition #36 evaluated true (7ms)
+9690ms ║║Condition group #34 evaluated true (state did not change) (15ms)
+9692ms ║║Cancelling statement #37's schedules...
+9712ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (12ms)
+9713ms ║║Executed [Front Door Light].setStatusLed (14ms)
+9729ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (11ms)
+9730ms ║║Executed [Front Door Light].setStatusLed (12ms)
+9732ms ║║Cancelling statement #39's schedules...
+9735ms ║║Executed virtual command wait (1ms)
+9736ms ║║Requesting a wake up for Fri, Dec 27 2019 @ 2:03:26 AM PST (in 3.0s)
+9740ms ║╚Execution stage complete. (96ms)
+9741ms ║Setting up scheduled job for Fri, Dec 27 2019 @ 2:03:26 AM PST (in 2.996s)
+9750ms ╚Event processed successfully (9750ms)
27/12/2019, 02:03:19 +291ms
+0ms ╔Received event [Home].time = 1577440999561 with a delay of -270ms
+247ms ║RunTime Analysis CS > 44ms > PS > 148ms > PE > 54ms > CE
+250ms ║Runtime (54455 bytes) successfully initialized in 148ms (v0.3.110.20191009) (248ms)
+251ms ║╔Execution stage started
+281ms ║║Comparison (enum) closed is (string) open = false (1ms)
+282ms ║║Condition #42 evaluated false (8ms)
+283ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+292ms ║║Comparison (enum) closed is (string) open = false (1ms)
+293ms ║║Condition #48 evaluated false (8ms)
+294ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+301ms ║║Comparison (enum) closed is (string) open = false (1ms)
+303ms ║║Condition #54 evaluated false (7ms)
+304ms ║║Condition group #53 evaluated false (state did not change) (8ms)
+311ms ║║Comparison (enum) closed is (string) open = false (1ms)
+313ms ║║Cancelling condition #63's schedules...
+314ms ║║Condition #63 evaluated false (7ms)
+315ms ║║Cancelling condition #62's schedules...
+315ms ║║Condition group #62 evaluated false (state changed) (9ms)
+323ms ║║Comparison (enum) closed is (string) open = false (1ms)
+325ms ║║Cancelling condition #70's schedules...
+326ms ║║Condition #70 evaluated false (7ms)
+326ms ║║Condition group #69 evaluated false (state did not change) (9ms)
+329ms ║╚Execution stage complete. (78ms)
+330ms ╚Event processed successfully (330ms)
27/12/2019, 02:03:06 +500ms
+0ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 183ms
+9961ms ║RunTime Analysis CS > 19ms > PS > 9883ms > PE > 60ms > CE
+9962ms ║Piston waited at a semaphore for 9828ms
+9965ms ║Runtime (54522 bytes) successfully initialized in 9883ms (v0.3.110.20191009) (9963ms)
+9965ms ║╔Execution stage started
+9972ms ║║Comparison (integer) 3 is_equal_to (integer) 0 = false (1ms)
+9973ms ║║Condition #2 evaluated false (4ms)
+9974ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+9983ms ║║Comparison (enum) open is (string) open = true (1ms)
+9985ms ║║Condition #4 evaluated true (9ms)
+9991ms ║║Comparison (enum) open is (string) closed = false (1ms)
+9993ms ║║Condition #31 evaluated false (7ms)
+9994ms ║║Condition group #3 evaluated false (state did not change) (17ms)
+10002ms ║║Comparison (enum) open is (string) open = true (1ms)
+10003ms ║║Condition #35 evaluated true (7ms)
+10008ms ║║Comparison (enum) open is (string) open = true (1ms)
+10010ms ║║Condition #36 evaluated true (6ms)
+10011ms ║║Condition group #34 evaluated true (state did not change) (14ms)
+10013ms ║║Cancelling statement #37's schedules...
+10035ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (15ms)
+10035ms ║║Executed [Front Door Light].setStatusLed (16ms)
+10053ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (13ms)
+10054ms ║║Executed [Front Door Light].setStatusLed (13ms)
+10056ms ║║Cancelling statement #39's schedules...
+10059ms ║║Executed virtual command wait (1ms)
+10060ms ║║Requesting a wake up for Fri, Dec 27 2019 @ 2:03:19 AM PST (in 3.0s)
+10064ms ║╚Execution stage complete. (99ms)
+10065ms ║Setting up scheduled job for Fri, Dec 27 2019 @ 2:03:19 AM PST (in 2.997s)
+10074ms ╚Event processed successfully (10075ms)
27/12/2019, 02:03:13 +59ms
+2ms ╔Received event [Front Door Sensor].contact = closed with a delay of 341ms
+138ms ║RunTime Analysis CS > 28ms > PS > 55ms > PE > 54ms > CE
+141ms ║Runtime (54431 bytes) successfully initialized in 55ms (v0.3.110.20191009) (138ms)
+142ms ║╔Execution stage started
+149ms ║║Comparison (integer) 3 is_equal_to (integer) 0 = false (1ms)
+150ms ║║Condition #2 evaluated false (5ms)
+151ms ║║Condition group #1 evaluated false (state did not change) (6ms)
+159ms ║║Comparison (enum) open is (string) open = true (1ms)
+161ms ║║Condition #4 evaluated true (8ms)
+170ms ║║Comparison (enum) open is (string) closed = false (1ms)
+171ms ║║Condition #31 evaluated false (10ms)
+172ms ║║Condition group #3 evaluated false (state did not change) (19ms)
+181ms ║║Comparison (enum) open is (string) open = true (1ms)
+182ms ║║Condition #35 evaluated true (7ms)
+188ms ║║Comparison (enum) open is (string) open = true (1ms)
+189ms ║║Condition #36 evaluated true (6ms)
+190ms ║║Condition group #34 evaluated true (state did not change) (16ms)
+192ms ║║Cancelling statement #37's schedules...
+235ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (35ms)
+236ms ║║Executed [Front Door Light].setStatusLed (37ms)
+255ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (14ms)
+256ms ║║Executed [Front Door Light].setStatusLed (15ms)
+258ms ║║Cancelling statement #39's schedules...
+261ms ║║Executed virtual command wait (0ms)
+262ms ║║Waiting for 3000ms
+3272ms ║║Comparison (enum) closed is (string) open = false (2ms)
+3273ms ║║Condition #42 evaluated false (8ms)
+3274ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+3283ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3285ms ║║Condition #48 evaluated false (7ms)
+3285ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+3295ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3296ms ║║Condition #54 evaluated false (8ms)
+3297ms ║║Condition group #53 evaluated false (state did not change) (9ms)
+3303ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3305ms ║║Cancelling condition #63's schedules...
+3306ms ║║Condition #63 evaluated false (5ms)
+3307ms ║║Cancelling condition #62's schedules...
+3307ms ║║Condition group #62 evaluated false (state changed) (8ms)
+3313ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3315ms ║║Cancelling condition #70's schedules...
+3316ms ║║Condition #70 evaluated false (5ms)
+3317ms ║║Condition group #69 evaluated false (state did not change) (7ms)
+3319ms ║╚Execution stage complete. (3178ms)
+3320ms ╚Event processed successfully (3320ms)
27/12/2019, 02:03:06 +194ms
+1ms ╔Received event [Front Door Lock].lock = locked with a delay of 154ms
+122ms ║RunTime Analysis CS > 25ms > PS > 41ms > PE > 55ms > CE
+125ms ║Runtime (54428 bytes) successfully initialized in 41ms (v0.3.110.20191009) (123ms)
+126ms ║╔Execution stage started
+133ms ║║Comparison (integer) 4 is_equal_to (integer) 0 = false (1ms)
+134ms ║║Condition #2 evaluated false (4ms)
+135ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+144ms ║║Comparison (enum) open is (string) open = true (2ms)
+145ms ║║Condition #4 evaluated true (8ms)
+153ms ║║Comparison (enum) open is (string) closed = false (2ms)
+154ms ║║Condition #31 evaluated false (8ms)
+155ms ║║Condition group #3 evaluated false (state did not change) (18ms)
+164ms ║║Comparison (enum) open is (string) open = true (2ms)
+165ms ║║Condition #35 evaluated true (7ms)
+180ms ║║Comparison (enum) open is (string) open = true (1ms)
+182ms ║║Condition #36 evaluated true (15ms)
+183ms ║║Condition group #34 evaluated true (state did not change) (26ms)
+185ms ║║Cancelling statement #37's schedules...
+234ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (41ms)
+235ms ║║Executed [Front Door Light].setStatusLed (43ms)
+279ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (37ms)
+280ms ║║Executed [Front Door Light].setStatusLed (39ms)
+282ms ║║Cancelling statement #39's schedules...
+286ms ║║Executed virtual command wait (0ms)
+286ms ║║Waiting for 3000ms
+3296ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3297ms ║║Condition #42 evaluated false (7ms)
+3298ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+3308ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3309ms ║║Condition #48 evaluated false (8ms)
+3310ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+3319ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3320ms ║║Condition #54 evaluated false (8ms)
+3321ms ║║Condition group #53 evaluated false (state did not change) (9ms)
+3331ms ║║Comparison (enum) open is (string) open = true (1ms)
+3332ms ║║Condition #63 evaluated true (8ms)
+3337ms ║║Comparison (enum) locked is (string) locked = true (1ms)
+3338ms ║║Cancelling condition #68's schedules...
+3339ms ║║Condition #68 evaluated true (6ms)
+3340ms ║║Cancelling condition #62's schedules...
+3341ms ║║Condition group #62 evaluated true (state changed) (18ms)
+3343ms ║║Cancelling statement #64's schedules...
+3365ms ║║Executed physical command [Front Door Light].setStatusLed([7, 7, 0]) (15ms)
+3366ms ║║Executed [Front Door Light].setStatusLed (17ms)
+3368ms ║║Cancelling statement #66's schedules...
+3371ms ║║Executed virtual command wait (1ms)
+3372ms ║║Waiting for 3000ms
+6382ms ║║Comparison (enum) open is (string) open = true (1ms)
+6383ms ║║Condition #70 evaluated true (8ms)
+6388ms ║║Comparison (enum) locked is (string) unlocked = false (2ms)
+6389ms ║║Cancelling condition #71's schedules...
+6390ms ║║Condition #71 evaluated false (6ms)
+6391ms ║║Cancelling condition #69's schedules...
+6392ms ║║Condition group #69 evaluated false (state changed) (17ms)
+6394ms ║╚Execution stage complete. (6268ms)
+6395ms ╚Event processed successfully (6395ms)
27/12/2019, 02:02:49 +269ms
+0ms ╔Received event [Home].time = 1577440969789 with a delay of -521ms
+139ms ║RunTime Analysis CS > 24ms > PS > 63ms > PE > 52ms > CE
+142ms ║Runtime (54425 bytes) successfully initialized in 63ms (v0.3.110.20191009) (141ms)
+143ms ║╔Execution stage started
+173ms ║║Comparison (enum) closed is (string) open = false (1ms)
+174ms ║║Condition #42 evaluated false (7ms)
+175ms ║║Condition group #41 evaluated false (state did not change) (8ms)
+184ms ║║Comparison (enum) closed is (string) open = false (1ms)
+186ms ║║Condition #48 evaluated false (8ms)
+187ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+196ms ║║Comparison (enum) closed is (string) open = false (1ms)
+197ms ║║Condition #54 evaluated false (8ms)
+198ms ║║Condition group #53 evaluated false (state did not change) (9ms)
+206ms ║║Comparison (enum) open is (string) open = true (1ms)
+208ms ║║Condition #63 evaluated true (8ms)
+215ms ║║Comparison (enum) unlocked is (string) locked = false (2ms)
+216ms ║║Condition #68 evaluated false (7ms)
+217ms ║║Condition group #62 evaluated false (state did not change) (17ms)
+225ms ║║Comparison (enum) open is (string) open = true (1ms)
+227ms ║║Condition #70 evaluated true (6ms)
+234ms ║║Comparison (enum) unlocked is (string) unlocked = true (2ms)
+235ms ║║Condition #71 evaluated true (8ms)
+236ms ║║Condition group #69 evaluated true (state did not change) (17ms)
+239ms ║║Cancelling statement #72's schedules...
+1352ms ║║Executed physical command [Front Door Light].setStatusLed([7, 7, 0]) (1106ms)
+1353ms ║║Executed [Front Door Light].setStatusLed (1108ms)
+1376ms ║║Executed physical command [Front Door Light].setStatusLed([6, 7, 1]) (18ms)
+1377ms ║║Executed [Front Door Light].setStatusLed (20ms)
+1380ms ║║Cancelling statement #74's schedules...
+1383ms ║║Executed virtual command wait (1ms)
+1384ms ║║Waiting for 3000ms
+4388ms ║╚Execution stage complete. (4245ms)
+4389ms ╚Event processed successfully (4389ms)
27/12/2019, 02:02:36 +766ms
+0ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 189ms
+9892ms ║RunTime Analysis CS > 28ms > PS > 9814ms > PE > 50ms > CE
+9893ms ║Piston waited at a semaphore for 9765ms
+9895ms ║Runtime (54524 bytes) successfully initialized in 9814ms (v0.3.110.20191009) (9894ms)
+9896ms ║╔Execution stage started
+9903ms ║║Comparison (integer) 4 is_equal_to (integer) 0 = false (1ms)
+9904ms ║║Condition #2 evaluated false (4ms)
+9905ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+9914ms ║║Comparison (enum) open is (string) open = true (1ms)
+9916ms ║║Condition #4 evaluated true (8ms)
+9925ms ║║Comparison (enum) open is (string) closed = false (1ms)
+9926ms ║║Condition #31 evaluated false (10ms)
+9927ms ║║Condition group #3 evaluated false (state did not change) (20ms)
+9937ms ║║Comparison (enum) open is (string) open = true (1ms)
+9938ms ║║Condition #35 evaluated true (9ms)
+9943ms ║║Comparison (enum) open is (string) open = true (1ms)
+9945ms ║║Condition #36 evaluated true (5ms)
+9946ms ║║Condition group #34 evaluated true (state did not change) (16ms)
+9948ms ║║Cancelling statement #37's schedules...
+9994ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (39ms)
+9995ms ║║Executed [Front Door Light].setStatusLed (40ms)
+10015ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (15ms)
+10016ms ║║Executed [Front Door Light].setStatusLed (17ms)
+10018ms ║║Cancelling statement #39's schedules...
+10022ms ║║Executed virtual command wait (0ms)
+10023ms ║║Requesting a wake up for Fri, Dec 27 2019 @ 2:02:49 AM PST (in 3.0s)
+10027ms ║╚Execution stage complete. (130ms)
+10028ms ║Setting up scheduled job for Fri, Dec 27 2019 @ 2:02:49 AM PST (in 2.996s)
+10036ms ╚Event processed successfully (10036ms)
27/12/2019, 02:02:36 +293ms
+0ms ╔Received event [Front Door Lock].lock = unlocked with a delay of 172ms
+109ms ║RunTime Analysis CS > 24ms > PS > 40ms > PE > 46ms > CE
+112ms ║Runtime (54456 bytes) successfully initialized in 40ms (v0.3.110.20191009) (111ms)
+113ms ║╔Execution stage started
+120ms ║║Comparison (integer) 3 is_equal_to (integer) 0 = false (1ms)
+122ms ║║Condition #2 evaluated false (4ms)
+122ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+132ms ║║Comparison (enum) open is (string) open = true (1ms)
+134ms ║║Condition #4 evaluated true (9ms)
+141ms ║║Comparison (enum) open is (string) closed = false (1ms)
+142ms ║║Condition #31 evaluated false (8ms)
+143ms ║║Condition group #3 evaluated false (state did not change) (19ms)
+151ms ║║Comparison (enum) open is (string) open = true (1ms)
+153ms ║║Condition #35 evaluated true (7ms)
+159ms ║║Comparison (enum) open is (string) open = true (2ms)
+160ms ║║Condition #36 evaluated true (7ms)
+161ms ║║Condition group #34 evaluated true (state did not change) (16ms)
+163ms ║║Cancelling statement #37's schedules...
+185ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (16ms)
+186ms ║║Executed [Front Door Light].setStatusLed (17ms)
+204ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (13ms)
+205ms ║║Executed [Front Door Light].setStatusLed (14ms)
+208ms ║║Cancelling statement #39's schedules...
+211ms ║║Executed virtual command wait (1ms)
+212ms ║║Waiting for 3000ms
+3221ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3222ms ║║Condition #42 evaluated false (7ms)
+3223ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+3232ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3233ms ║║Condition #48 evaluated false (7ms)
+3234ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+3243ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3244ms ║║Condition #54 evaluated false (7ms)
+3245ms ║║Condition group #53 evaluated false (state did not change) (9ms)
+3253ms ║║Comparison (enum) open is (string) open = true (1ms)
+3254ms ║║Condition #63 evaluated true (7ms)
+3258ms ║║Comparison (enum) unlocked is (string) locked = false (1ms)
+3259ms ║║Cancelling condition #68's schedules...
+3260ms ║║Condition #68 evaluated false (5ms)
+3261ms ║║Cancelling condition #62's schedules...
+3262ms ║║Condition group #62 evaluated false (state changed) (15ms)
+3271ms ║║Comparison (enum) open is (string) open = true (2ms)
+3272ms ║║Condition #70 evaluated true (8ms)
+3276ms ║║Comparison (enum) unlocked is (string) unlocked = true (1ms)
+3278ms ║║Cancelling condition #71's schedules...
+3279ms ║║Condition #71 evaluated true (5ms)
+3280ms ║║Cancelling condition #69's schedules...
+3280ms ║║Condition group #69 evaluated true (state changed) (16ms)
+3283ms ║║Cancelling statement #72's schedules...
+3301ms ║║Executed physical command [Front Door Light].setStatusLed([7, 7, 0]) (13ms)
+3302ms ║║Executed [Front Door Light].setStatusLed (15ms)
+3321ms ║║Executed physical command [Front Door Light].setStatusLed([6, 7, 1]) (14ms)
+3322ms ║║Executed [Front Door Light].setStatusLed (15ms)
+3324ms ║║Cancelling statement #74's schedules...
+3327ms ║║Executed virtual command wait (1ms)
+3328ms ║║Waiting for 3000ms
+6331ms ║╚Execution stage complete. (6219ms)
+6332ms ╚Event processed successfully (6332ms)
27/12/2019, 02:02:31 +362ms
+0ms ╔Received event [Home].time = 1577440951877 with a delay of -515ms
+132ms ║RunTime Analysis CS > 23ms > PS > 65ms > PE > 44ms > CE
+135ms ║Runtime (54451 bytes) successfully initialized in 65ms (v0.3.110.20191009) (134ms)
+136ms ║╔Execution stage started
+168ms ║║Comparison (enum) closed is (string) open = false (2ms)
+170ms ║║Condition #42 evaluated false (8ms)
+171ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+180ms ║║Comparison (enum) closed is (string) open = false (1ms)
+182ms ║║Condition #48 evaluated false (9ms)
+183ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+191ms ║║Comparison (enum) closed is (string) open = false (2ms)
+192ms ║║Condition #54 evaluated false (7ms)
+193ms ║║Condition group #53 evaluated false (state did not change) (8ms)
+388ms ║║Comparison (enum) open is (string) open = true (2ms)
+389ms ║║Condition #63 evaluated true (193ms)
+397ms ║║Comparison (enum) locked is (string) locked = true (1ms)
+398ms ║║Condition #68 evaluated true (8ms)
+399ms ║║Condition group #62 evaluated true (state did not change) (204ms)
+401ms ║║Cancelling statement #64's schedules...
+1469ms ║║Executed physical command [Front Door Light].setStatusLed([7, 7, 0]) (1060ms)
+1470ms ║║Executed [Front Door Light].setStatusLed (1062ms)
+1472ms ║║Cancelling statement #66's schedules...
+1476ms ║║Executed virtual command wait (0ms)
+1476ms ║║Waiting for 3000ms
+4485ms ║║Comparison (enum) open is (string) open = true (1ms)
+4487ms ║║Condition #70 evaluated true (8ms)
+4493ms ║║Comparison (enum) locked is (string) unlocked = false (2ms)
+4494ms ║║Condition #71 evaluated false (6ms)
+4495ms ║║Condition group #69 evaluated false (state did not change) (16ms)
+4497ms ║╚Execution stage complete. (4361ms)
+4498ms ╚Event processed successfully (4498ms)
27/12/2019, 02:02:19 +391ms
+0ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 97ms
+9365ms ║RunTime Analysis CS > 17ms > PS > 9307ms > PE > 42ms > CE
+9366ms ║Piston waited at a semaphore for 9267ms
+9369ms ║Runtime (54549 bytes) successfully initialized in 9307ms (v0.3.110.20191009) (9368ms)
+9370ms ║╔Execution stage started
+9376ms ║║Comparison (integer) 3 is_equal_to (integer) 0 = false (1ms)
+9378ms ║║Condition #2 evaluated false (5ms)
+9379ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+9388ms ║║Comparison (enum) open is (string) open = true (1ms)
+9389ms ║║Condition #4 evaluated true (8ms)
+9397ms ║║Comparison (enum) open is (string) closed = false (1ms)
+9398ms ║║Condition #31 evaluated false (8ms)
+9399ms ║║Condition group #3 evaluated false (state did not change) (19ms)
+9408ms ║║Comparison (enum) open is (string) open = true (1ms)
+9409ms ║║Condition #35 evaluated true (8ms)
+9416ms ║║Comparison (enum) open is (string) open = true (2ms)
+9417ms ║║Condition #36 evaluated true (7ms)
+9418ms ║║Condition group #34 evaluated true (state did not change) (17ms)
+9420ms ║║Cancelling statement #37's schedules...
+9459ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (33ms)
+9460ms ║║Executed [Front Door Light].setStatusLed (35ms)
+9479ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (13ms)
+9479ms ║║Executed [Front Door Light].setStatusLed (15ms)
+9482ms ║║Cancelling statement #39's schedules...
+9485ms ║║Executed virtual command wait (1ms)
+9486ms ║║Requesting a wake up for Fri, Dec 27 2019 @ 2:02:31 AM PST (in 3.0s)
+9489ms ║╚Execution stage complete. (120ms)
+9491ms ║Setting up scheduled job for Fri, Dec 27 2019 @ 2:02:31 AM PST (in 2.996s)
+9499ms ╚Event processed successfully (9499ms)
27/12/2019, 02:02:18 +579ms
+1ms ╔Received event [Front Door Sensor].contact = open with a delay of 165ms
+178ms ║RunTime Analysis CS > 23ms > PS > 110ms > PE > 45ms > CE
+181ms ║Runtime (54463 bytes) successfully initialized in 110ms (v0.3.110.20191009) (180ms)
+182ms ║╔Execution stage started
+190ms ║║Comparison (integer) 2 is_equal_to (integer) 0 = false (2ms)
+191ms ║║Condition #2 evaluated false (4ms)
+192ms ║║Condition group #1 evaluated false (state did not change) (6ms)
+202ms ║║Comparison (enum) open is (string) open = true (1ms)
+204ms ║║Condition #4 evaluated true (9ms)
+212ms ║║Comparison (enum) open is (string) closed = false (1ms)
+214ms ║║Condition #31 evaluated false (9ms)
+215ms ║║Condition group #3 evaluated false (state did not change) (21ms)
+224ms ║║Comparison (enum) open is (string) open = true (1ms)
+225ms ║║Condition #35 evaluated true (7ms)
+232ms ║║Comparison (enum) open is (string) open = true (1ms)
+234ms ║║Condition #36 evaluated true (7ms)
+235ms ║║Condition group #34 evaluated true (state did not change) (17ms)
+237ms ║║Cancelling statement #37's schedules...
+261ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (18ms)
+262ms ║║Executed [Front Door Light].setStatusLed (20ms)
+278ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (10ms)
+279ms ║║Executed [Front Door Light].setStatusLed (12ms)
+282ms ║║Cancelling statement #39's schedules...
+285ms ║║Executed virtual command wait (0ms)
+285ms ║║Waiting for 3000ms
+3295ms ║║Comparison (enum) closed is (string) open = false (2ms)
+3296ms ║║Condition #42 evaluated false (8ms)
+3297ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+3306ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3308ms ║║Condition #48 evaluated false (7ms)
+3309ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+3317ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3318ms ║║Condition #54 evaluated false (7ms)
+3319ms ║║Condition group #53 evaluated false (state did not change) (8ms)
+3325ms ║║Comparison (enum) open is (string) open = true (1ms)
+3327ms ║║Cancelling condition #63's schedules...
+3327ms ║║Condition #63 evaluated true (5ms)
+3335ms ║║Comparison (enum) locked is (string) locked = true (1ms)
+3336ms ║║Condition #68 evaluated true (8ms)
+3337ms ║║Cancelling condition #62's schedules...
+3338ms ║║Condition group #62 evaluated true (state changed) (17ms)
+3340ms ║║Cancelling statement #64's schedules...
+3359ms ║║Executed physical command [Front Door Light].setStatusLed([7, 7, 0]) (13ms)
+3360ms ║║Executed [Front Door Light].setStatusLed (15ms)
+3362ms ║║Cancelling statement #66's schedules...
+3365ms ║║Executed virtual command wait (0ms)
+3366ms ║║Waiting for 3000ms
+6373ms ║║Comparison (enum) open is (string) open = true (2ms)
+6374ms ║║Cancelling condition #70's schedules...
+6375ms ║║Condition #70 evaluated true (6ms)
+6381ms ║║Comparison (enum) locked is (string) unlocked = false (1ms)
+6383ms ║║Condition #71 evaluated false (7ms)
+6384ms ║║Condition group #69 evaluated false (state did not change) (15ms)
+6386ms ║╚Execution stage complete. (6204ms)
+6387ms ╚Event processed successfully (6387ms)
27/12/2019, 02:02:13 +189ms
+1ms ╔Received event [Home].time = 1577440933004 with a delay of 185ms
+106ms ║RunTime Analysis CS > 19ms > PS > 45ms > PE > 42ms > CE
+109ms ║Runtime (54454 bytes) successfully initialized in 45ms (v0.3.110.20191009) (108ms)
+110ms ║╔Execution stage started
+143ms ║║Comparison (enum) closed is (string) open = false (1ms)
+144ms ║║Condition #42 evaluated false (8ms)
+145ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+155ms ║║Comparison (enum) closed is (string) open = false (2ms)
+156ms ║║Condition #48 evaluated false (8ms)
+158ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+167ms ║║Comparison (enum) closed is (string) open = false (2ms)
+168ms ║║Condition #54 evaluated false (8ms)
+169ms ║║Condition group #53 evaluated false (state did not change) (9ms)
+178ms ║║Comparison (enum) closed is (string) open = false (2ms)
+179ms ║║Condition #63 evaluated false (7ms)
+180ms ║║Condition group #62 evaluated false (state did not change) (8ms)
+189ms ║║Comparison (enum) closed is (string) open = false (1ms)
+190ms ║║Condition #70 evaluated false (7ms)
+191ms ║║Condition group #69 evaluated false (state did not change) (8ms)
+193ms ║╚Execution stage complete. (83ms)
+195ms ╚Event processed successfully (194ms)
27/12/2019, 02:02:00 +158ms
+0ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 113ms
+9617ms ║RunTime Analysis CS > 23ms > PS > 9555ms > PE > 39ms > CE
+9618ms ║Piston waited at a semaphore for 9515ms
+9621ms ║Runtime (54554 bytes) successfully initialized in 9555ms (v0.3.110.20191009) (9620ms)
+9622ms ║╔Execution stage started
+9629ms ║║Comparison (integer) 2 is_equal_to (integer) 0 = false (1ms)
+9630ms ║║Condition #2 evaluated false (4ms)
+9631ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+9641ms ║║Comparison (enum) open is (string) open = true (1ms)
+9642ms ║║Condition #4 evaluated true (9ms)
+9649ms ║║Comparison (enum) open is (string) closed = false (1ms)
+9651ms ║║Condition #31 evaluated false (8ms)
+9652ms ║║Condition group #3 evaluated false (state did not change) (18ms)
+9659ms ║║Comparison (enum) open is (string) open = true (1ms)
+9661ms ║║Condition #35 evaluated true (6ms)
+9667ms ║║Comparison (enum) open is (string) open = true (1ms)
+9669ms ║║Condition #36 evaluated true (8ms)
+9670ms ║║Condition group #34 evaluated true (state did not change) (16ms)
+9672ms ║║Cancelling statement #37's schedules...
+9821ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (143ms)
+9822ms ║║Executed [Front Door Light].setStatusLed (145ms)
+9838ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (11ms)
+9839ms ║║Executed [Front Door Light].setStatusLed (12ms)
+9841ms ║║Cancelling statement #39's schedules...
+9844ms ║║Executed virtual command wait (0ms)
+9846ms ║║Requesting a wake up for Fri, Dec 27 2019 @ 2:02:13 AM PST (in 3.0s)
+9849ms ║╚Execution stage complete. (227ms)
+9851ms ║Setting up scheduled job for Fri, Dec 27 2019 @ 2:02:13 AM PST (in 2.996s)
+9893ms ╚Event processed successfully (9893ms)
27/12/2019, 02:02:05 +192ms
+1ms ╔Received event [Home].time = 1577440925971 with a delay of -779ms
+113ms ║RunTime Analysis CS > 19ms > PS > 52ms > PE > 41ms > CE
+116ms ║Runtime (54455 bytes) successfully initialized in 52ms (v0.3.110.20191009) (115ms)
+117ms ║╔Execution stage started
+153ms ║║Comparison (enum) closed is (string) open = false (2ms)
+154ms ║║Condition #42 evaluated false (8ms)
+155ms ║║Condition group #41 evaluated false (state did not change) (9ms)
+164ms ║║Comparison (enum) closed is (string) open = false (1ms)
+165ms ║║Condition #48 evaluated false (7ms)
+166ms ║║Condition group #47 evaluated false (state did not change) (9ms)
+196ms ║║Comparison (enum) closed is (string) open = false (1ms)
+198ms ║║Condition #54 evaluated false (28ms)
+199ms ║║Condition group #53 evaluated false (state did not change) (30ms)
+207ms ║║Comparison (enum) closed is (string) open = false (2ms)
+208ms ║║Condition #63 evaluated false (7ms)
+209ms ║║Condition group #62 evaluated false (state did not change) (8ms)
+216ms ║║Comparison (enum) closed is (string) open = false (1ms)
+218ms ║║Condition #70 evaluated false (7ms)
+219ms ║║Condition group #69 evaluated false (state did not change) (7ms)
+221ms ║╚Execution stage complete. (104ms)
+222ms ╚Event processed successfully (222ms)
27/12/2019, 02:01:53 +722ms
+1ms ╔Received event [Home].:91ea43d160f2868ef5602e7fa03adc3d: = @Homeseer with a delay of 190ms
+9136ms ║RunTime Analysis CS > 26ms > PS > 9068ms > PE > 41ms > CE
+9137ms ║Piston waited at a semaphore for 9014ms
+9139ms ║Runtime (54584 bytes) successfully initialized in 9068ms (v0.3.110.20191009) (9138ms)
+9140ms ║╔Execution stage started
+9148ms ║║Comparison (integer) 1 is_equal_to (integer) 0 = false (1ms)
+9149ms ║║Cancelling condition #2's schedules...
+9150ms ║║Condition #2 evaluated false (5ms)
+9151ms ║║Condition group #1 evaluated false (state did not change) (7ms)
+9161ms ║║Comparison (enum) open is (string) open = true (2ms)
+9162ms ║║Condition #4 evaluated true (9ms)
+9170ms ║║Comparison (enum) open is (string) closed = false (1ms)
+9172ms ║║Cancelling condition #31's schedules...
+9173ms ║║Condition #31 evaluated false (10ms)
+9174ms ║║Cancelling condition #3's schedules...
+9175ms ║║Condition group #3 evaluated false (state changed) (22ms)
+9183ms ║║Comparison (enum) open is (string) open = true (1ms)
+9185ms ║║Condition #35 evaluated true (8ms)
+9190ms ║║Comparison (enum) open is (string) open = true (1ms)
+9192ms ║║Cancelling condition #36's schedules...
+9193ms ║║Condition #36 evaluated true (7ms)
+9194ms ║║Cancelling condition #34's schedules...
+9195ms ║║Condition group #34 evaluated true (state changed) (18ms)
+9197ms ║║Cancelling statement #37's schedules...
+9221ms ║║Executed physical command [Front Door Light].setStatusLed([7, 2, 0]) (15ms)
+9222ms ║║Executed [Front Door Light].setStatusLed (17ms)
+9240ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (13ms)
+9241ms ║║Executed [Front Door Light].setStatusLed (15ms)
+9244ms ║║Cancelling statement #39's schedules...
+9247ms ║║Executed virtual command wait (1ms)
+9248ms ║║Requesting a wake up for Fri, Dec 27 2019 @ 2:02:05 AM PST (in 3.0s)
+9253ms ║╚Execution stage complete. (113ms)
+9254ms ║Setting up scheduled job for Fri, Dec 27 2019 @ 2:02:05 AM PST (in 2.995s)
+9264ms ╚Event processed successfully (9264ms)
27/12/2019, 02:01:52 +628ms
+0ms ╔Received event [Back Door Deadbolt].contact = open with a delay of 159ms
+107ms ║RunTime Analysis CS > 19ms > PS > 44ms > PE > 44ms > CE
+110ms ║Runtime (54467 bytes) successfully initialized in 44ms (v0.3.110.20191009) (108ms)
+111ms ║╔Execution stage started
+119ms ║║Comparison (integer) 0 is_equal_to (integer) 0 = true (1ms)
+120ms ║║Cancelling condition #2's schedules...
+121ms ║║Condition #2 evaluated true (6ms)
+142ms ║║Comparison (enum) open is (string) closed = false (1ms)
+144ms ║║Condition #76 evaluated false (22ms)
+145ms ║║Condition group #1 evaluated false (state did not change) (30ms)
+150ms ║║Comparison (enum) open is (string) open = true (1ms)
+152ms ║║Cancelling condition #4's schedules...
+152ms ║║Condition #4 evaluated true (5ms)
+159ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+161ms ║║Condition #31 evaluated true (8ms)
+162ms ║║Cancelling condition #3's schedules...
+163ms ║║Condition group #3 evaluated true (state changed) (15ms)
+165ms ║║Cancelling statement #60's schedules...
+205ms ║║Executed physical command [Front Door Light].setStatusLed([6, 2, 1]) (34ms)
+206ms ║║Executed [Front Door Light].setStatusLed (36ms)
+209ms ║║Cancelling statement #32's schedules...
+212ms ║║Executed virtual command wait (0ms)
+213ms ║║Waiting for 3000ms
+3219ms ║║Comparison (enum) open is (string) open = true (1ms)
+3221ms ║║Cancelling condition #35's schedules...
+3222ms ║║Condition #35 evaluated true (5ms)
+3228ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3230ms ║║Cancelling condition #36's schedules...
+3230ms ║║Condition #36 evaluated false (8ms)
+3231ms ║║Condition group #34 evaluated false (state did not change) (16ms)
+3239ms ║║Comparison (enum) closed is (string) open = false (2ms)
+3240ms ║║Condition #42 evaluated false (6ms)
+3241ms ║║Condition group #41 evaluated false (state did not change) (8ms)
+3249ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3250ms ║║Condition #48 evaluated false (7ms)
+3251ms ║║Condition group #47 evaluated false (state did not change) (8ms)
+3259ms ║║Comparison (enum) closed is (string) open = false (2ms)
+3260ms ║║Condition #54 evaluated false (7ms)
+3261ms ║║Condition group #53 evaluated false (state did not change) (8ms)
+3268ms ║║Comparison (enum) closed is (string) open = false (1ms)
+3270ms ║║Condition #63 evaluated false (6ms)
+3271ms ║║Condition group #62 evaluated false (state did not change) (7ms)
+3278ms ║║Comparison (enum) closed is (string) open = false (2ms)
+3279ms ║║Condition #70 evaluated false (6ms)
+3280ms ║║Condition group #69 evaluated false (state did not change) (7ms)
+3282ms ║╚Execution stage complete. (3172ms)
+3283ms ╚Event processed successfully (3283ms)

#2

I’m sure you figured it out, but I think what is happening is because of the default “Task Cancellation Policy”, which is to cancel any pending tasks if the parent condition’s state changes. Not digging into the details of your piston, but I think something in your logic changes, cancelling the wait statement.