Semaphore is causing events to be received out of order

lights
execution
triggers

#1

In the logs I can see that event are being received out of order, causing activities to function incorrectly. Here’s the logs:

**Piston waited at a semaphore for 9663ms**

3/9/2018, 5:52:09 PM +10ms
+1ms ╔Received event [Kitchen Fan Light].switch = on with a delay of 135ms
+9872ms ║RunTime Analysis CS > 31ms > PS > 9721ms > PE > 121ms > CE
+9873ms ║Piston waited at a semaphore for 9663ms
+9875ms ║Runtime (42897 bytes) successfully initialized in 9721ms (v0.3.000.20180224) (9873ms)
+9877ms ║╔Execution stage started
+9885ms ║║Comparison (string) :10ce40f8d22974532815992ec1f4d574: is_not (string) :ee9bdca69a7b039efb14d0cc92a5eae8: = true (2ms)
+9887ms ║║Condition #1 evaluated true (6ms)
+9888ms ║║Condition group #null evaluated true (state did not change) (7ms)
+9898ms ║║Condition #15 evaluated false (7ms)
+9899ms ║║Condition group #14 evaluated false (state did not change) (8ms)
+9908ms ║║Cancelling condition #17’s schedules…
+9908ms ║║Condition #17 evaluated false (8ms)
+9909ms ║║Cancelling condition #2’s schedules…
+9910ms ║║Condition group #2 evaluated false (state changed) (20ms)
+9919ms ║║Condition #11 evaluated false (6ms)
+9926ms ║║Condition #12 evaluated false (6ms)
+9927ms ║║Condition group #8 evaluated false (state did not change) (14ms)
+9944ms ║║Comparison (enum) on stays (string) off = false (2ms)
+9948ms ║║Cancelling any timed trigger schedules for condition 21
+9949ms ║║Cancelling statement #21’s schedules…
+9950ms ║║Condition #21 evaluated false (17ms)
+9951ms ║║Condition group #18 evaluated false (state did not change) (19ms)
+9959ms ║║Comparison (enum) on changes_to (string) off = false (1ms)
+9960ms ║║Condition #25 evaluated false (5ms)
+9961ms ║║Condition group #22 evaluated false (state did not change) (7ms)
+9964ms ║╚Execution stage complete. (87ms)
+9965ms ╚Event processed successfully (9965ms)
3/9/2018, 5:52:08 PM +440ms
+2ms ╔Received event [Kitchen Overhead Light].level = 91 with a delay of 130ms
+206ms ║RunTime Analysis CS > 18ms > PS > 62ms > PE > 125ms > CE
+209ms ║Runtime (42829 bytes) successfully initialized in 62ms (v0.3.000.20180224) (207ms)
+210ms ║╔Execution stage started
+219ms ║║Comparison (string) :10ce40f8d22974532815992ec1f4d574: is_not (string) :ee9bdca69a7b039efb14d0cc92a5eae8: = true (2ms)
+220ms ║║Condition #1 evaluated true (5ms)
+221ms ║║Condition group #null evaluated true (state did not change) (7ms)
+356ms ║║Cancelling condition #15’s schedules…
+357ms ║║Condition #15 evaluated false (132ms)
+358ms ║║Condition group #14 evaluated false (state did not change) (134ms)
+362ms ║║Comparison (integer) 91 rises_to_or_above (integer) 91 = true (1ms)
+364ms ║║Cancelling condition #17’s schedules…
+365ms ║║Condition #17 evaluated true (6ms)
+366ms ║║Cancelling condition #2’s schedules…
+367ms ║║Condition group #2 evaluated true (state changed) (143ms)
+369ms ║║Cancelling statement #3’s schedules…
+415ms ║║Executed physical command [Kitchen Counter Light].on() (41ms)
+416ms ║║Executed [Kitchen Counter Light].on (43ms)
+448ms ║║Executed physical command [Kitchen Fan Light].on() (29ms)
+449ms ║║Executed [Kitchen Fan Light].on (31ms)
+480ms ║║Executed physical command [Kitchen Sink Light].on() (29ms)
+481ms ║║Executed [Kitchen Sink Light].on (30ms)
+495ms ║║Condition #11 evaluated false (10ms)
+500ms ║║Comparison (integer) 91 drops_below (integer) 91 = false (1ms)
+501ms ║║Condition #12 evaluated false (5ms)
+503ms ║║Condition group #8 evaluated false (state did not change) (17ms)
+702ms ║║Comparison (enum) on stays (string) off = false (190ms)
+705ms ║║Cancelling any timed trigger schedules for condition 21
+706ms ║║Cancelling statement #21’s schedules…
+707ms ║║Condition #21 evaluated false (201ms)
+708ms ║║Condition group #18 evaluated false (state did not change) (203ms)
+720ms ║║Condition #25 evaluated false (7ms)
+721ms ║║Condition group #22 evaluated false (state did not change) (9ms)
+723ms ║╚Execution stage complete. (514ms)
+725ms ╚Event processed successfully (725ms)
+9873ms ║Piston waited at a semaphore for 9663ms

This happens almost every time that I manually change the level in ST. I can reproduce the problem around 91% consistently over and over.


#2

any solution on this? Im having something similar if a piston is triggered repeatably – the delay then make the sequence out of order


#3

That problem was almost 2 years ago. I wouldnt know at this point.