Async statements not working and blocking the piston to flow


#1

1) Give a description of the problem
I have a simple routine which I want part of it to run as “async” but it stops (in sync it runs all the way dough)

2) What is the expected behaviour?
I would like to:
stop the lights on my living room;
then stop the lights on my kitchen;
then fork into 3: main bedroom, son´s bedroom, daugther´s bedroom -> all of those 3 happening at the same time.
then while those 3 are happening, close my front door.

3) What is happening/not happening?
When the execution arives on the first async it stops indefinitely.

4) Post a Green Snapshot of the pistonimage

5) Attach logs after turning logging level to Full
(PASTE YOUR LOGS HERE THEN HIGHLIGHT ALL OF THE LOGS AND CLICK ON THE </> ICON TO FORMAT THEM CORRECTLY)

2/5/2021, 11:54:00 AM +201ms
+3ms ╔Received event [Home].time = 1612536840113 with a delay of 88ms, canQueue: true, calledMyself: false
+6ms ║RunTime initialize > 5 LockT > 1ms > rtDT > 0ms > pistonT > 0ms (first state access 4 4 1)
+10ms ║Runtime (14475 bytes) successfully initialized in 0ms (v0.3.112.20210202_HE)
+49ms ║╔Execution stage started
+77ms ║╚Execution stage complete. (29ms)
+93ms ╚Event processed successfully (92ms)
2/5/2021, 11:53:55 AM +21ms
+3ms ╔Received event [Home].time = 1612536834915 with a delay of 106ms, canQueue: true, calledMyself: false
+5ms ║RunTime initialize > 4 LockT > 0ms > rtDT > 1ms > pistonT > 0ms (first state access 3 3 1)
+9ms ║Runtime (14471 bytes) successfully initialized in 1ms (v0.3.112.20210202_HE)
+48ms ║╔Execution stage started
+60ms ║║Comparison (enum) off is (string) off = true (1ms)
+61ms ║║Condition #14 evaluated true (3ms)
+62ms ║║Condition group #13 evaluated true (state did not change) (4ms)
+63ms ║║Cancelling statement #15’s schedules…
+69ms ║║Skipped execution of physical command [Abajur Victor].off([]) because it would make no change to the device. (3ms)
+69ms ║║Executed [Abajur Victor].off (5ms)
+77ms ║║Skipped execution of physical command [Ar Condicionado Victor].off([]) because it would make no change to the device. (4ms)
+77ms ║║Executed [Ar Condicionado Victor].off (6ms)
+80ms ║║Skipped execution of physical command [Luz Victor].off([]) because it would make no change to the device. (1ms)
+81ms ║║Executed [Luz Victor].off (2ms)
+86ms ║║Skipped execution of physical command [Ventilador Victor].off([]) because it would make no change to the device. (3ms)
+87ms ║║Executed [Ventilador Victor].off (5ms)
+90ms ║║Executed virtual command [Abajur Victor, Ar Condicionado Victor, Luz Victor, Ventilador Victor].wait (0ms)
+92ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:54:00 PM BRST (in 5s)
+111ms ║╚Execution stage complete. (63ms)
+149ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:54:00 PM BRST (in 5s)
+151ms ╚Event processed successfully (150ms)
2/5/2021, 11:53:51 AM +841ms
+3ms ╔Received event [Home].time = 1612536831776 with a delay of 65ms, canQueue: true, calledMyself: false
+5ms ║RunTime initialize > 4 LockT > 0ms > rtDT > 1ms > pistonT > 0ms (first state access 3 3 1)
+10ms ║Runtime (14465 bytes) successfully initialized in 1ms (v0.3.112.20210202_HE)
+51ms ║╔Execution stage started
+60ms ║║Cancelling statement #44’s schedules…
+66ms ║║Skipped execution of physical command [Luz Sanca].off([]) because it would make no change to the device. (3ms)
+67ms ║║Executed [Luz Sanca].off (5ms)
+71ms ║║Executed virtual command [Luz Sanca].wait (0ms)
+73ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:53:54 PM BRST (in 3s)
+92ms ║╚Execution stage complete. (42ms)
+128ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:53:54 PM BRST (in 3s)
+129ms ╚Event processed successfully (128ms)
2/5/2021, 11:53:49 AM +706ms
+3ms ╔Received event [Home].time = 1612536829617 with a delay of 89ms, canQueue: true, calledMyself: false
+5ms ║RunTime initialize > 4 LockT > 0ms > rtDT > 1ms > pistonT > 0ms (first state access 3 3 1)
+9ms ║Runtime (14460 bytes) successfully initialized in 1ms (v0.3.112.20210202_HE)
+48ms ║╔Execution stage started
+57ms ║║Cancelling statement #56’s schedules…
+64ms ║║Skipped execution of physical command [Luz Corredor].off([]) because it would make no change to the device. (4ms)
+65ms ║║Executed [Luz Corredor].off (6ms)
+67ms ║║Executed virtual command [Luz Corredor].wait (0ms)
+69ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:53:51 PM BRST (in 2s)
+88ms ║╚Execution stage complete. (40ms)
+129ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:53:51 PM BRST (in 2s)
+131ms ╚Event processed successfully (129ms)
2/5/2021, 11:53:44 AM +535ms
+3ms ╔Received event [Home].time = 1612536824443 with a delay of 92ms, canQueue: true, calledMyself: false
+5ms ║RunTime initialize > 4 LockT > 0ms > rtDT > 1ms > pistonT > 1ms (first state access 3 3 1)
+9ms ║Runtime (14455 bytes) successfully initialized in 1ms (v0.3.112.20210202_HE)
+49ms ║╔Execution stage started
+57ms ║║Cancelling statement #47’s schedules…
+66ms ║║Skipped execution of physical command [Ar Condicionado Sala TV].off([]) because it would make no change to the device. (6ms)
+67ms ║║Executed [Ar Condicionado Sala TV].off (8ms)
+69ms ║║Skipped execution of physical command [Luz TV].off([]) because it would make no change to the device. (1ms)
+70ms ║║Executed [Luz TV].off (3ms)
+73ms ║║Skipped execution of physical command [Ventilador Cozinha].off([]) because it would make no change to the device. (1ms)
+73ms ║║Executed [Ventilador Cozinha].off (2ms)
+76ms ║║Skipped execution of physical command [Ventilador TV].off([]) because it would make no change to the device. (0ms)
+77ms ║║Executed [Ventilador TV].off (2ms)
+80ms ║║Executed virtual command [Ar Condicionado Sala TV, Luz TV, Ventilador Cozinha, Ventilador TV].wait (0ms)
+82ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:53:49 PM BRST (in 5s)
+101ms ║╚Execution stage complete. (51ms)
+138ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:53:49 PM BRST (in 5s)
+139ms ╚Event processed successfully (138ms)
2/5/2021, 11:53:41 AM +353ms
+3ms ╔Received event [Home].time = 1612536821260 with a delay of 93ms, canQueue: true, calledMyself: false
+5ms ║RunTime initialize > 4 LockT > 0ms > rtDT > 1ms > pistonT > 1ms (first state access 3 3 1)
+9ms ║Runtime (14450 bytes) successfully initialized in 1ms (v0.3.112.20210202_HE)
+74ms ║╔Execution stage started
+81ms ║║Cancelling statement #61’s schedules…
+85ms ║║Skipped execution of physical command [Luz Sala].off([]) because it would make no change to the device. (1ms)
+85ms ║║Executed [Luz Sala].off (3ms)
+88ms ║║Executed virtual command [Luz Sala].wait (1ms)
+90ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:53:44 PM BRST (in 3s)
+110ms ║╚Execution stage complete. (36ms)
+147ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:53:44 PM BRST (in 3s)
+150ms ╚Event processed successfully (148ms)
2/5/2021, 11:53:38 AM +190ms
+2ms ╔Received event [Home].time = 1612536818132 with a delay of 58ms, canQueue: true, calledMyself: false
+4ms ║RunTime initialize > 3 LockT > 0ms > rtDT > 1ms > pistonT > 0ms (first state access 2 2 1)
+8ms ║Runtime (14445 bytes) successfully initialized in 1ms (v0.3.112.20210202_HE)
+46ms ║╔Execution stage started
+54ms ║║Comparison (enum) off is (string) off = true (0ms)
+55ms ║║Condition #9 evaluated true (3ms)
+56ms ║║Condition group #8 evaluated true (state did not change) (4ms)
+57ms ║║Cancelling statement #41’s schedules…
+60ms ║║Skipped execution of physical command [Luz Jantar].off([]) because it would make no change to the device. (1ms)
+61ms ║║Executed [Luz Jantar].off (2ms)
+64ms ║║Skipped execution of physical command [Luz Sacada].off([]) because it would make no change to the device. (1ms)
+64ms ║║Executed [Luz Sacada].off (2ms)
+67ms ║║Executed virtual command [Luz Jantar, Luz Sacada].wait (1ms)
+69ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:53:41 PM BRST (in 3s)
+89ms ║╚Execution stage complete. (43ms)
+128ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:53:41 PM BRST (in 3s)
+129ms ╚Event processed successfully (129ms)
2/5/2021, 11:53:35 AM +30ms
+3ms ╔Received event [Home].time = 1612536814897 with a delay of 133ms, canQueue: true, calledMyself: false
+5ms ║RunTime initialize > 4 LockT > 0ms > rtDT > 1ms > pistonT > 0ms (first state access 3 3 1)
+41ms ║Runtime (14445 bytes) successfully initialized in 1ms (v0.3.112.20210202_HE)
+82ms ║╔Execution stage started
+95ms ║║Skipped execution of physical command [Luz cozinha].off([]) because it would make no change to the device. (4ms)
+96ms ║║Executed [Luz cozinha].off (6ms)
+99ms ║║Executed virtual command [Luz cozinha].wait (0ms)
+101ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:53:38 PM BRST (in 3s)
+119ms ║╚Execution stage complete. (37ms)
+156ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:53:38 PM BRST (in 3s)
+157ms ╚Event processed successfully (156ms)
2/5/2021, 11:53:31 AM +571ms
+2ms ╔Received event [Home].mode = Dormir with a delay of 263ms, canQueue: true, calledMyself: false
+179ms ║RunTime initialize > 178 LockT > 0ms > rtDT > 175ms > pistonT > 175ms (first state access 3 2 176)
+202ms ║Runtime (14525 bytes) successfully initialized in 175ms (v0.3.112.20210202_HE)
+203ms ║╔Execution stage started
+208ms ║║Comparison (string) :32e164a2e42f34f83c6d5126248c9a8d: changes_to (string) :32e164a2e42f34f83c6d5126248c9a8d: = true (1ms)
+210ms ║║Cancelling condition #2’s schedules…
+211ms ║║Condition #2 evaluated true (6ms)
+212ms ║║Cancelling condition #1’s schedules…
+214ms ║║Condition group #1 evaluated true (state changed) (9ms)
+219ms ║║Comparison (enum) off is (string) off = true (1ms)
+220ms ║║Condition #7 evaluated true (5ms)
+222ms ║║Condition group #6 evaluated true (state did not change) (7ms)
+227ms ║║Comparison (enum) off is (string) off = true (1ms)
+229ms ║║Condition #60 evaluated true (6ms)
+231ms ║║Condition group #59 evaluated true (state did not change) (7ms)
+232ms ║║Cancelling statement #10’s schedules…
+237ms ║║Executed virtual command [Luz cozinha].wait (1ms)
+326ms ║║Requesting a wake up for Fri, Feb 5 2021 @ 12:53:34 PM BRST (in 3s)
+380ms ║╚Execution stage complete. (177ms)
+412ms ║Setting up scheduled job for Fri, Feb 5 2021 @ 12:53:34 PM BRST (in 3s)
+413ms ╚Event processed successfully (412ms)
2/5/2021, 11:52:33 AM +660ms
+19ms ╔Subscribing to devices…
+153ms ║Device missing from piston. Loading all from parent (129ms)
+191ms ║Subscribing to Home.mode…
+207ms ║Piston controls Visita…
+208ms ║Piston controls CASA-COZINHA…
+209ms ║Piston controls Luz cozinha…
+210ms ║Piston controls CASA-SALA…
+211ms ║Piston controls Luz Jantar…
+212ms ║Piston controls Luz Sacada…
+213ms ║Piston controls Luz Sala…
+214ms ║Piston controls Ar Condicionado Sala TV…
+215ms ║Piston controls Luz TV…
+216ms ║Piston controls Ventilador Cozinha…
+217ms ║Piston controls Ventilador TV…
+218ms ║Piston controls Luz Corredor…
+220ms ║Piston controls Luz Sanca…
+221ms ║Piston controls CASA-VICTOR…
+222ms ║Piston controls Abajur Victor…
+223ms ║Piston controls Ar Condicionado Victor…
+224ms ║Piston controls Luz Victor…
+225ms ║Piston controls Ventilador Victor…
+226ms ║Piston controls CASA-NATHALIA…
+227ms ║Piston controls Abajur Nathália…
+228ms ║Piston controls Luz Nathalia…
+229ms ║Piston controls Ventilador Nathália…
+230ms ║Piston controls CASA-CASAL…
+231ms ║Piston controls Ar Condicionado…
+232ms ║Piston controls Luz Ale…
+233ms ║Piston controls Luz Cama…
+234ms ║Piston controls Luz Debora…
+235ms ║Piston controls Luz Quarto…
+236ms ║Piston controls Quarto …
+237ms ║Piston controls Quarto Casal…
+238ms ║Piston controls Ventilador…
+240ms ║Piston controls Sensor Quarto…
+241ms ║Piston controls Porta frente…
+278ms ╚Finished subscribing (262ms)
+286ms ║Comparison (string) :7c76bcf13f4437d56396ddf04776b595: changes_to (string) :32e164a2e42f34f83c6d5126248c9a8d: = false (1ms)
+290ms ║Comparison (enum) off is (string) off = true (1ms)
+294ms ║Comparison (enum) off is (string) off = true (0ms)
+300ms ║Comparison (enum) off is (string) off = true (2ms)
+307ms ║Comparison (enum) off is (string) off = true (1ms)
+311ms ║Comparison (enum) off is (string) off = true (1ms)
+316ms ║Comparison (enum) on is (string) off = false (0ms)
+321ms ║Comparison (decimal) 20.6 is_greater_than (integer) 22 = false (1ms)
+348ms ╔Starting piston… (v0.3.112.20210202_HE)
+349ms ╚Piston successfully started (334ms)

REMOVE BELOW AFTER READING
If a solution is found for your question then please mark the post as the solution.


#2

Do you have parallel piston execution turned on the piston?

(note in HE, that has a lot more overhead as atomicState has to be used rather than state)


#3

Yes. Parallel execution is on:

Should I turn it off?