Pistons not firing completely / only half the time


#1

1) Give a description of the problem
I’ve noticed that several of my pistons have started to only fire once in a while, or in some cases not completely. And I am wondering if I am running into a memory issue or similiar.

In this example the Button was physically held but nothing happened, pressing it works fine and trying to trigger the Zzzz routine manually didn’t produce any results either.

2) What is the expected behaviour?
Holding down the Button should trigger the location mode change to Zzzz and that in turn should trigger another piston.

3) What is happening/not happening?
Button is being held, nothing happens.

**4) Post a Green Snapshot of the piston!


5) Attach logs after turning logging level to Full
Location Mode Change to Zzzz log
9.3.2021 11.19.35 +202ms
+1ms ╔Starting piston… (v0.3.113.20210203)
+596ms ║╔Subscribing to devices…
+605ms ║║Subscribing to Home.mode…
+795ms ║║Subscribing to Børneværelse Loft…
+796ms ║║Subscribing to Børneværelset 2…
+797ms ║║Subscribing to Entre 1…
+798ms ║║Subscribing to Entre 2…
+800ms ║║Subscribing to Køkken Lille Lampe 1 Bridge…
+801ms ║║Subscribing to Køkken Lille Lampe 2…
+802ms ║║Subscribing to Lyskæde…
+803ms ║║Subscribing to Reol Lampe…
+804ms ║║Subscribing to Reol Lampe 2…
+805ms ║║Subscribing to Rund Lampe…
+806ms ║║Subscribing to Skuret 1…
+807ms ║║Subscribing to Skuret 2…
+808ms ║║Subscribing to Skuret udenfor 1…
+809ms ║║Subscribing to Skuret udenfor 2…
+811ms ║║Subscribing to Skuret udenfor 3…
+812ms ║║Subscribing to Soveværelset Ny…
+813ms ║║Subscribing to Spisebordet 1…
+814ms ║║Subscribing to Spisebordet 2…
+815ms ║║Subscribing to Standerlampe 2…
+816ms ║║Subscribing to Stuen - Lille lampe…
+817ms ║║Subscribing to Stuen - Standerlampe 1…
+818ms ║║Subscribing to Stuen Loftslampe…
+819ms ║║Subscribing to Udestuen…
+820ms ║║Subscribing to Havedøren (Kamera)…
+821ms ║║Subscribing to Skuret (Kamera)…
+823ms ║║Subscribing to Udenfor (Kamera)…
+824ms ║║Subscribing to Hue Go…
+825ms ║╚Finished subscribing (242ms)
+851ms ║Comparison (string) :b642fe37bf906f8dc735b9c8b79b57d5: changes_to (string) :2bb8359ad700d5d6ed3a4f4fc2189689: = false (1ms)
+872ms ╚Piston successfully started (872ms)

Button being held piston log

11.3.2021 17.53.52 +391ms
+1ms ╔Received event [Button Soveværelset].button = pushed with a delay of 64ms
+65ms ║RunTime Analysis CS > 19ms > PS > 8ms > PE > 38ms > CE
+67ms ║Runtime (40196 bytes) successfully initialized in 8ms (v0.3.113.20210203) (65ms)
+68ms ║╔Execution stage started
+75ms ║║Comparison (enum) pushed gets (string) pushed = true (0ms)
+77ms ║║Condition #2 evaluated true (5ms)
+78ms ║║Condition group #1 evaluated true (state did not change) (5ms)
+83ms ║║Comparison (integer) 0 is_even = true (1ms)
+84ms ║║Condition #11 evaluated true (4ms)
+85ms ║║Condition group #10 evaluated true (state did not change) (6ms)
+87ms ║║Cancelling statement #13’s schedules…
+107ms ║║Executed physical command [Sengen].setLevel([30]) (15ms)
+108ms ║║Executed [Sengen].setLevel (17ms)
+116ms ║║Executed physical command [Sengen].setColorTemperature([2400]) (4ms)
+116ms ║║Executed [Sengen].setColorTemperature (5ms)
+122ms ║║Calculating (integer) 0 + (integer) 1 >> (integer) 1
+125ms ║║Executed virtual command [Sengen].setVariable (1ms)
+131ms ║║Comparison (integer) 1 is_odd = true (1ms)
+132ms ║║Condition #22 evaluated true (3ms)
+133ms ║║Condition group #21 evaluated true (state did not change) (5ms)
+135ms ║║Cancelling statement #3’s schedules…
+142ms ║║Skipped execution of physical command [Sengen].off([]) because it would make no change to the device. (4ms)
+143ms ║║Executed [Sengen].off (6ms)
+148ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+151ms ║║Executed virtual command [Sengen].setVariable (1ms)
+158ms ║║Comparison (enum) pushed gets (string) held = false (1ms)
+159ms ║║Condition #17 evaluated false (4ms)
+160ms ║║Condition group #16 evaluated false (state did not change) (6ms)
+162ms ║╚Execution stage complete. (94ms)
+163ms ╚Event processed successfully (163ms)
10.3.2021 22.27.16 +964ms
+1ms ╔Received event [Button Soveværelset].button = pushed with a delay of 44ms
+54ms ║RunTime Analysis CS > 17ms > PS > 6ms > PE > 31ms > CE
+57ms ║Runtime (40196 bytes) successfully initialized in 6ms (v0.3.113.20210203) (55ms)
+57ms ║╔Execution stage started
+64ms ║║Comparison (enum) pushed gets (string) pushed = true (1ms)
+65ms ║║Condition #2 evaluated true (4ms)
+66ms ║║Condition group #1 evaluated true (state did not change) (5ms)
+71ms ║║Comparison (integer) 0 is_even = true (1ms)
+72ms ║║Condition #11 evaluated true (4ms)
+73ms ║║Condition group #10 evaluated true (state did not change) (5ms)
+75ms ║║Cancelling statement #13’s schedules…
+85ms ║║Skipped execution of physical command [Sengen].setLevel([30]) because it would make no change to the device. (5ms)
+85ms ║║Executed [Sengen].setLevel (7ms)
+92ms ║║Executed physical command [Sengen].setColorTemperature([2400]) (4ms)
+93ms ║║Executed [Sengen].setColorTemperature (5ms)
+99ms ║║Calculating (integer) 0 + (integer) 1 >> (integer) 1
+102ms ║║Executed virtual command [Sengen].setVariable (0ms)
+106ms ║║Comparison (integer) 1 is_odd = true (1ms)
+107ms ║║Condition #22 evaluated true (3ms)
+108ms ║║Condition group #21 evaluated true (state did not change) (4ms)
+110ms ║║Cancelling statement #3’s schedules…
+118ms ║║Executed physical command [Sengen].off() (6ms)
+119ms ║║Executed [Sengen].off (7ms)
+124ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+127ms ║║Executed virtual command [Sengen].setVariable (1ms)
+133ms ║║Comparison (enum) pushed gets (string) held = false (0ms)
+134ms ║║Condition #17 evaluated false (4ms)
+135ms ║║Condition group #16 evaluated false (state did not change) (6ms)
+137ms ║╚Execution stage complete. (79ms)
+138ms ╚Event processed successfully (137ms)
10.3.2021 22.05.13 +86ms
+1ms ╔Received event [Button Soveværelset].button = pushed with a delay of 73ms
+59ms ║RunTime Analysis CS > 19ms > PS > 8ms > PE > 33ms > CE
+62ms ║Runtime (40196 bytes) successfully initialized in 8ms (v0.3.113.20210203) (60ms)
+63ms ║╔Execution stage started
+70ms ║║Comparison (enum) pushed gets (string) pushed = true (0ms)
+71ms ║║Condition #2 evaluated true (4ms)
+72ms ║║Condition group #1 evaluated true (state did not change) (6ms)
+77ms ║║Comparison (integer) 0 is_even = true (0ms)
+78ms ║║Condition #11 evaluated true (4ms)
+79ms ║║Condition group #10 evaluated true (state did not change) (6ms)
+81ms ║║Cancelling statement #13’s schedules…
+99ms ║║Executed physical command [Sengen].setLevel([30]) (14ms)
+100ms ║║Executed [Sengen].setLevel (15ms)
+108ms ║║Executed physical command [Sengen].setColorTemperature([2400]) (5ms)
+109ms ║║Executed [Sengen].setColorTemperature (5ms)
+114ms ║║Calculating (integer) 0 + (integer) 1 >> (integer) 1
+117ms ║║Executed virtual command [Sengen].setVariable (1ms)
+122ms ║║Comparison (integer) 1 is_odd = true (1ms)
+123ms ║║Condition #22 evaluated true (3ms)
+124ms ║║Condition group #21 evaluated true (state did not change) (4ms)
+126ms ║║Cancelling statement #3’s schedules…
+133ms ║║Skipped execution of physical command [Sengen].off([]) because it would make no change to the device. (4ms)
+134ms ║║Executed [Sengen].off (6ms)
+139ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+141ms ║║Executed virtual command [Sengen].setVariable (1ms)
+147ms ║║Comparison (enum) pushed gets (string) held = false (0ms)
+149ms ║║Condition #17 evaluated false (4ms)
+150ms ║║Condition group #16 evaluated false (state did not change) (5ms)
+151ms ║╚Execution stage complete. (88ms)
+152ms ╚Event processed successfully (152ms)
10.3.2021 22.05.10 +838ms
+1ms ╔Received event [Button Soveværelset].button = pushed with a delay of 46ms
+52ms ║RunTime Analysis CS > 16ms > PS > 6ms > PE > 29ms > CE
+54ms ║Runtime (40191 bytes) successfully initialized in 6ms (v0.3.113.20210203) (52ms)
+55ms ║╔Execution stage started
+62ms ║║Comparison (enum) pushed gets (string) pushed = true (1ms)
+63ms ║║Cancelling condition #2’s schedules…
+64ms ║║Condition #2 evaluated true (5ms)
+65ms ║║Cancelling condition #1’s schedules…
+66ms ║║Condition group #1 evaluated true (state changed) (7ms)
+71ms ║║Comparison (integer) 0 is_even = true (1ms)
+72ms ║║Condition #11 evaluated true (4ms)
+73ms ║║Condition group #10 evaluated true (state did not change) (5ms)
+76ms ║║Cancelling statement #13’s schedules…
+158ms ║║Skipped execution of physical command [Sengen].setLevel([30]) because it would make no change to the device. (7ms)
+159ms ║║Executed [Sengen].setLevel (8ms)
+165ms ║║Executed physical command [Sengen].setColorTemperature([2400]) (3ms)
+166ms ║║Executed [Sengen].setColorTemperature (5ms)
+172ms ║║Calculating (integer) 0 + (integer) 1 >> (integer) 1
+175ms ║║Executed virtual command [Sengen].setVariable (1ms)
+179ms ║║Comparison (integer) 1 is_odd = true (1ms)
+181ms ║║Condition #22 evaluated true (3ms)
+181ms ║║Condition group #21 evaluated true (state did not change) (4ms)
+184ms ║║Cancelling statement #3’s schedules…
+192ms ║║Executed physical command [Sengen].off() (5ms)
+193ms ║║Executed [Sengen].off (7ms)
+197ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+200ms ║║Executed virtual command [Sengen].setVariable (1ms)
+206ms ║║Comparison (enum) pushed gets (string) held = false (1ms)
+208ms ║║Cancelling condition #17’s schedules…
+208ms ║║Condition #17 evaluated false (5ms)
+209ms ║║Cancelling condition #16’s schedules…
+210ms ║║Condition group #16 evaluated false (state changed) (7ms)
+212ms ║╚Execution stage complete. (157ms)
+213ms ╚Event processed successfully (213ms)
10.3.2021 22.05.04 +10ms
+1ms ╔Received event [Button Soveværelset].button = held with a delay of 76ms
+69ms ║RunTime Analysis CS > 25ms > PS > 9ms > PE > 36ms > CE
+72ms ║Runtime (40194 bytes) successfully initialized in 9ms (v0.3.113.20210203) (69ms)
+72ms ║╔Execution stage started
+80ms ║║Comparison (enum) held gets (string) pushed = false (1ms)
+82ms ║║Cancelling condition #2’s schedules…
+83ms ║║Condition #2 evaluated false (6ms)
+84ms ║║Cancelling condition #1’s schedules…
+85ms ║║Condition group #1 evaluated false (state changed) (7ms)
+91ms ║║Comparison (enum) held gets (string) held = true (0ms)
+92ms ║║Cancelling condition #17’s schedules…
+93ms ║║Condition #17 evaluated true (6ms)
+95ms ║║Cancelling condition #16’s schedules…
+96ms ║║Condition group #16 evaluated true (state changed) (9ms)
+98ms ║║Cancelling statement #18’s schedules…
+124ms ║║Executed virtual command setLocationMode (23ms)
+127ms ║╚Execution stage complete. (55ms)
+129ms ╚Event processed successfully (129ms)
10.3.2021 22.04.59 +464ms
+1ms ╔Received event [Button Soveværelset].button = pushed with a delay of 62ms
+52ms ║RunTime Analysis CS > 18ms > PS > 7ms > PE > 28ms > CE
+54ms ║Runtime (40196 bytes) successfully initialized in 7ms (v0.3.113.20210203) (53ms)
+55ms ║╔Execution stage started
+61ms ║║Comparison (enum) pushed gets (string) pushed = true (0ms)
+63ms ║║Condition #2 evaluated true (3ms)
+63ms ║║Condition group #1 evaluated true (state did not change) (5ms)
+68ms ║║Comparison (integer) 0 is_even = true (1ms)
+69ms ║║Condition #11 evaluated true (4ms)
+70ms ║║Condition group #10 evaluated true (state did not change) (5ms)
+72ms ║║Cancelling statement #13’s schedules…
+89ms ║║Executed physical command [Sengen].setLevel([30]) (13ms)
+90ms ║║Executed [Sengen].setLevel (14ms)
+95ms ║║Executed physical command [Sengen].setColorTemperature([2400]) (2ms)
+96ms ║║Executed [Sengen].setColorTemperature (4ms)
+102ms ║║Calculating (integer) 0 + (integer) 1 >> (integer) 1
+104ms ║║Executed virtual command [Sengen].setVariable (1ms)
+109ms ║║Comparison (integer) 1 is_odd = true (1ms)
+110ms ║║Condition #22 evaluated true (3ms)
+111ms ║║Condition group #21 evaluated true (state did not change) (4ms)
+113ms ║║Cancelling statement #3’s schedules…
+119ms ║║Skipped execution of physical command [Sengen].off([]) because it would make no change to the device. (4ms)
+120ms ║║Executed [Sengen].off (6ms)
+124ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+127ms ║║Executed virtual command [Sengen].setVariable (1ms)
+132ms ║║Comparison (enum) pushed gets (string) held = false (0ms)
+134ms ║║Condition #17 evaluated false (3ms)
+135ms ║║Condition group #16 evaluated false (state did not change) (5ms)
+136ms ║╚Execution stage complete. (81ms)
+137ms ╚Event processed successfully (137ms)
10.3.2021 22.04.56 +311ms
+0ms ╔Received event [Button Soveværelset].button = pushed with a delay of 41ms
+57ms ║RunTime Analysis CS > 17ms > PS > 7ms > PE > 33ms > CE
+59ms ║Runtime (40191 bytes) successfully initialized in 7ms (v0.3.113.20210203) (58ms)
+60ms ║╔Execution stage started
+67ms ║║Comparison (enum) pushed gets (string) pushed = true (1ms)
+68ms ║║Cancelling condition #2’s schedules…
+69ms ║║Condition #2 evaluated true (5ms)
+70ms ║║Cancelling condition #1’s schedules…
+71ms ║║Condition group #1 evaluated true (state changed) (8ms)
+76ms ║║Comparison (integer) 0 is_even = true (0ms)
+77ms ║║Condition #11 evaluated true (4ms)
+78ms ║║Condition group #10 evaluated true (state did not change) (6ms)
+80ms ║║Cancelling statement #13’s schedules…
+91ms ║║Skipped execution of physical command [Sengen].setLevel([30]) because it would make no change to the device. (7ms)
+92ms ║║Executed [Sengen].setLevel (8ms)
+98ms ║║Executed physical command [Sengen].setColorTemperature([2400]) (4ms)
+99ms ║║Executed [Sengen].setColorTemperature (5ms)
+105ms ║║Calculating (integer) 0 + (integer) 1 >> (integer) 1
+107ms ║║Executed virtual command [Sengen].setVariable (1ms)
+112ms ║║Comparison (integer) 1 is_odd = true (1ms)
+113ms ║║Condition #22 evaluated true (3ms)
+114ms ║║Condition group #21 evaluated true (state did not change) (4ms)
+116ms ║║Cancelling statement #3’s schedules…
+125ms ║║Executed physical command [Sengen].off() (7ms)
+126ms ║║Executed [Sengen].off (7ms)
+130ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+133ms ║║Executed virtual command [Sengen].setVariable (1ms)
+139ms ║║Comparison (enum) pushed gets (string) held = false (1ms)
+140ms ║║Cancelling condition #17’s schedules…
+141ms ║║Condition #17 evaluated false (5ms)
+142ms ║║Cancelling condition #16’s schedules…
+143ms ║║Condition group #16 evaluated false (state changed) (7ms)
+145ms ║╚Execution stage complete. (84ms)
+146ms ╚Event processed successfully (146ms)
10.3.2021 22.04.52 +980ms
+1ms ╔Received event [Button Soveværelset].button = held with a delay of 68ms
+54ms ║RunTime Analysis CS > 19ms > PS > 8ms > PE > 28ms > CE
+56ms ║Runtime (40189 bytes) successfully initialized in 8ms (v0.3.113.20210203) (54ms)
+57ms ║╔Execution stage started
+64ms ║║Comparison (enum) held gets (string) pushed = false (1ms)
+65ms ║║Condition #2 evaluated false (4ms)
+66ms ║║Condition group #1 evaluated false (state did not change) (5ms)
+71ms ║║Comparison (enum) held gets (string) held = true (0ms)
+73ms ║║Condition #17 evaluated true (4ms)
+74ms ║║Condition group #16 evaluated true (state did not change) (6ms)
+76ms ║║Cancelling statement #18’s schedules…
+107ms ║║Executed virtual command setLocationMode (29ms)
+109ms ║╚Execution stage complete. (52ms)
+110ms ╚Event processed successfully (110ms)
10.3.2021 22.04.46 +671ms
+1ms ╔Received event [Button Soveværelset].button = held with a delay of 66ms
+71ms ║RunTime Analysis CS > 21ms > PS > 8ms > PE > 41ms > CE
+73ms ║Runtime (40189 bytes) successfully initialized in 8ms (v0.3.113.20210203) (71ms)
+74ms ║╔Execution stage started
+83ms ║║Comparison (enum) held gets (string) pushed = false (1ms)
+85ms ║║Condition #2 evaluated false (4ms)
+86ms ║║Condition group #1 evaluated false (state did not change) (7ms)
+92ms ║║Comparison (enum) held gets (string) held = true (1ms)
+94ms ║║Condition #17 evaluated true (5ms)
+95ms ║║Condition group #16 evaluated true (state did not change) (7ms)
+98ms ║║Cancelling statement #18’s schedules…
+119ms ║║Executed virtual command setLocationMode (19ms)
+122ms ║╚Execution stage complete. (48ms)
+123ms ╚Event processed successfully (123ms)
10.3.2021 22.04.41 +838ms
+1ms ╔Received event [Button Soveværelset].button = held with a delay of 67ms
+58ms ║RunTime Analysis CS > 21ms > PS > 7ms > PE > 31ms > CE
+60ms ║Runtime (40194 bytes) successfully initialized in 7ms (v0.3.113.20210203) (58ms)
+61ms ║╔Execution stage started
+69ms ║║Comparison (enum) held gets (string) pushed = false (1ms)
+70ms ║║Cancelling condition #2’s schedules…
+71ms ║║Condition #2 evaluated false (5ms)
+72ms ║║Cancelling condition #1’s schedules…
+73ms ║║Condition group #1 evaluated false (state changed) (8ms)
+79ms ║║Comparison (enum) held gets (string) held = true (1ms)
+81ms ║║Cancelling condition #17’s schedules…
+82ms ║║Condition #17 evaluated true (5ms)
+83ms ║║Cancelling condition #16’s schedules…
+84ms ║║Condition group #16 evaluated true (state changed) (7ms)
+86ms ║║Cancelling statement #18’s schedules…
+187ms ║║Executed virtual command setLocationMode (98ms)
+189ms ║╚Execution stage complete. (128ms)
+191ms ╚Event processed successfully (190ms)
10.3.2021 22.04.11 +792ms
+0ms ╔Received event [Button Soveværelset].button = pushed with a delay of 40ms
+48ms ║RunTime Analysis CS > 18ms > PS > 7ms > PE > 24ms > CE
+51ms ║Runtime (40196 bytes) successfully initialized in 7ms (v0.3.113.20210203) (50ms)
+52ms ║╔Execution stage started
+58ms ║║Comparison (enum) pushed gets (string) pushed = true (0ms)
+60ms ║║Condition #2 evaluated true (3ms)
+61ms ║║Condition group #1 evaluated true (state did not change) (5ms)
+65ms ║║Comparison (integer) 0 is_even = true (1ms)
+66ms ║║Condition #11 evaluated true (4ms)
+67ms ║║Condition group #10 evaluated true (state did not change) (5ms)
+69ms ║║Cancelling statement #13’s schedules…
+84ms ║║Executed physical command [Sengen].setLevel([30]) (10ms)
+85ms ║║Executed [Sengen].setLevel (11ms)
+90ms ║║Executed physical command [Sengen].setColorTemperature([2400]) (3ms)
+91ms ║║Executed [Sengen].setColorTemperature (4ms)
+96ms ║║Calculating (integer) 0 + (integer) 1 >> (integer) 1
+99ms ║║Executed virtual command [Sengen].setVariable (1ms)
+103ms ║║Comparison (integer) 1 is_odd = true (1ms)
+105ms ║║Condition #22 evaluated true (2ms)
+105ms ║║Condition group #21 evaluated true (state did not change) (4ms)
+107ms ║║Cancelling statement #3’s schedules…
+114ms ║║Skipped execution of physical command [Sengen].off([]) because it would make no change to the device. (4ms)
+114ms ║║Executed [Sengen].off (5ms)
+119ms ║║Calculating (integer) 1 + (integer) 1 >> (integer) 2
+121ms ║║Executed virtual command [Sengen].setVariable (0ms)
+127ms ║║Comparison (enum) pushed gets (string) held = false (1ms)
+128ms ║║Condition #17 evaluated false (4ms)
+129ms ║║Condition group #16 evaluated false (state did not change) (5ms)
+131ms ║╚Execution stage complete. (80ms)
+132ms ╚Event processed successfully (132ms)


#2

I don’t know what is happening there. The location mode is clearly being set and yet there is no sign of the piston receiving an event. It could be as trivial as stopping and starting it but it is a bit odd.

On a secondary note, your piston initialises count to 0 every time it runs, so when the button is pushed it will always be even and the piston will try to turn the bulb on. Any time it is even it will be incremented to an odd number and so the piston will try to turn the bulb off again. The logs suggest the only reason this doesn’t happen is that the piston doesn’t immediately notice the bulb was turned on.


#3

I’ll try and “turn off and on” everything and see if that changes.

Are there any memory-management things I should be aware off? Is there an overview of that somewhere in WebCore that could tell me of my hub runs out of memory and therefore fails to do stuff?

Also, what would I change in the count in order for it to work as intended?


#4

Just remove the initialization in the define section. If you set a value there, it will be set every time the piston runs. If you leave the value unassigned in the define section, the value will be remembered from run to run.


#5

Hi.

I removed the section in the “define” section, and now the light won’t turn off when pressing the button a second time. I can only turn it on.

Did I completely misunderstand, or what should I be doing?


#6

@guxdude meant to remove the zero value from count, leave it with no value set.

image


#7

A interesting observation to the issue of the piston not firing (as well as an entirely different piston not activating).

If I set both the problem pistons to giving me a “full log file”, then they won’t work. And if I set it to “None” and clear the logs, then they start working agian.

Am I hitting some sort of memory limit? Is there a way for me to check on that, and is there a community guideline on writing efficient / smart pistons that don’t take up a ton of space?