Hey peeps,
Loving webcore thus far, am impressed. Thanks to all those that made this a reality.
I read all I can find (within reason lol), however I can’t seem to grasp one thing entirely. Can someone please explain this a little further?
What is this, is it bad, how do you avoid it?:
Pistons and semaphores.
A lot of my pistons have:
" piston waited at semaphore for [real example ->] 10seconds". Yes I know it doesn’t report in seconds.
webCoRE has a built in mechanism to serialize piston executions. Sometimes, two events execute a piston at roughly the same time. Since you are building logic that is more or less a series of statements, you don’t expect things to change while you’re following the execution path. That is why webCoRE will attempt to have the second execution wait for the first (up to 10 seconds). This usually happens with very rapid firing events such as power meter events. If all works fine, I would not worry. You can always simply allow parallelism in the piston’s advanced settings.
An answer from the master. I’m honored!
Ok. So slightly understand more while slightly being more confused lol.
So if I understand correctly:
If I have 2 seperate if statements opposite in test (similar to else/elseif, but not excluded) to one another in the same “execute” in the same piston, semaphore waits are bad in this situation? Correct me if I’m wrong, but does that mean that if2 will not execute after if1 executes while piston is at semaphore. And so if there’s a state change while at semaphore it will not be seen?
I think my last statement just confused me more lol
I only ask as I’m having these semaphore waits cause delays with certain things
It’s about events themselves, not the statements you have or their order. Some or maybe all of your IF statements subscribe to events coming from ST. A semaphore is hit when two or more such events happen in a rapid succession. This can be the result of using power meter readings or what’s called “positive feedback” where you subscribe to events that are generated by the actions taken by your piston (ie subscribe to a switch change and have the piston change that switch - this will keep generating events that will rerun the same piston).
A green snapshot of your piston would help in figuring out why you’re getting semaphore waits.
I was about to post the same question. I have a door automatic lock piston based on the door lock and contact events. Every once in while, the open/close and locked/unclocked events are of sync due to the semaphore delay as 2 events can easily happen exactly at the same time. Is there anything that can be done to prevent this?
Piston:
Logs:
12/28/2017, 6:13:30 PM +369ms
+0ms ╔Received event [Home].time = 1514502811449 with a delay of -1081ms
+142ms ║RunTime Analysis CS > 22ms > PS > 24ms > PE > 95ms > CE
+145ms ║Runtime (38075 bytes) successfully initialized in 24ms (v0.2.100.20171211) (144ms)
+147ms ║╔Execution stage started
+176ms ║║Executed virtual command [Front Door].sendPushNotification (16ms)
+179ms ║╚Execution stage complete. (33ms)
+180ms ╚Event processed successfully (180ms)
12/28/2017, 6:13:16 PM +303ms
+1ms ╔Received event [Home].time = 1514502796611 with a delay of -308ms
+117ms ║RunTime Analysis CS > 16ms > PS > 15ms > PE > 86ms > CE
+120ms ║Runtime (38074 bytes) successfully initialized in 15ms (v0.2.100.20171211) (117ms)
+121ms ║╔Execution stage started
+139ms ║║Skipped execution of physical command [Front Door].lock([]) because it would make no change to the device. (6ms)
+140ms ║║Executed [Front Door].lock (6ms)
+144ms ║║Executed virtual command [Front Door].wait (1ms)
+145ms ║║Requesting a wake up for Thu, Dec 28 2017 @ 6:13:31 PM EST (in 15.0s)
+150ms ║╚Execution stage complete. (30ms)
+151ms ║Setting up scheduled job for Thu, Dec 28 2017 @ 6:13:31 PM EST (in 14.995s)
+158ms ╚Event processed successfully (158ms)
12/28/2017, 6:11:51 PM +431ms
+1ms ╔Received event [Front Door].lock = locked with a delay of 1479ms
+146ms ║RunTime Analysis CS > 18ms > PS > 21ms > PE > 107ms > CE
+148ms ║Runtime (38061 bytes) successfully initialized in 21ms (v0.2.100.20171211) (146ms)
+149ms ║╔Execution stage started
+157ms ║║Comparison (enum) locked is (string) unlocked = false (2ms)
+158ms ║║Cancelling condition #8’s schedules…
+159ms ║║Condition #8 evaluated false (6ms)
+160ms ║║Condition group #16 evaluated false (state did not change) (6ms)
+162ms ║╚Execution stage complete. (13ms)
+163ms ║Setting up scheduled job for Thu, Dec 28 2017 @ 6:13:16 PM EST (in 85.017s)
+173ms ╚Event processed successfully (173ms)
12/28/2017, 6:11:39 PM +849ms
+1ms ╔Received event [Front Door Sensor].contact = open with a delay of 413ms
+10015ms ║RunTime Analysis CS > 14ms > PS > 9861ms > PE > 139ms > CE
+10015ms ║Piston waited at a semaphore for 9849ms
+10018ms ║Runtime (38144 bytes) successfully initialized in 9861ms (v0.2.100.20171211) (10016ms)
+10018ms ║╔Execution stage started
+10029ms ║║Comparison (enum) unlocked is (string) unlocked = true (1ms)
+10031ms ║║Condition #8 evaluated true (7ms)
+10034ms ║║Comparison (enum) open is (string) closed = false (1ms)
+10035ms ║║Cancelling condition #17’s schedules…
+10036ms ║║Condition #17 evaluated false (5ms)
+10037ms ║║Cancelling condition #16’s schedules…
+10038ms ║║Condition group #16 evaluated false (state changed) (15ms)
+10040ms ║╚Execution stage complete. (21ms)
+10041ms ╚Event processed successfully (10040ms)
12/28/2017, 6:11:46 PM +419ms
+1ms ╔Received event [Front Door Sensor].contact = closed with a delay of 185ms
+159ms ║RunTime Analysis CS > 24ms > PS > 25ms > PE > 110ms > CE
+161ms ║Runtime (38073 bytes) successfully initialized in 25ms (v0.2.100.20171211) (159ms)
+162ms ║╔Execution stage started
+177ms ║║Comparison (enum) unlocked is (string) unlocked = true (2ms)
+178ms ║║Condition #8 evaluated true (11ms)
+182ms ║║Comparison (enum) closed is (string) closed = true (1ms)
+183ms ║║Cancelling condition #17’s schedules…
+184ms ║║Condition #17 evaluated true (5ms)
+185ms ║║Cancelling condition #16’s schedules…
+186ms ║║Condition group #16 evaluated true (state changed) (20ms)
+188ms ║║Cancelling statement #5’s schedules…
+191ms ║║Executed virtual command [Front Door].wait (0ms)
+192ms ║║Requesting a wake up for Thu, Dec 28 2017 @ 6:13:16 PM EST (in 90.0s)
+195ms ║╚Execution stage complete. (33ms)
+197ms ║Setting up scheduled job for Thu, Dec 28 2017 @ 6:13:16 PM EST (in 89.996s)
+204ms ╚Event processed successfully (203ms)
12/28/2017, 6:11:39 PM +684ms
+2ms ╔Received event [Front Door].lock = unlocked with a delay of 1011ms
+160ms ║RunTime Analysis CS > 22ms > PS > 26ms > PE > 112ms > CE
+162ms ║Runtime (38066 bytes) successfully initialized in 26ms (v0.2.100.20171211) (160ms)
+163ms ║╔Execution stage started
+171ms ║║Comparison (enum) unlocked is (string) unlocked = true (1ms)
+172ms ║║Cancelling condition #8’s schedules…
+172ms ║║Condition #8 evaluated true (5ms)
+181ms ║║Comparison (enum) open is (string) closed = false (2ms)
+182ms ║║Cancelling condition #17’s schedules…
+183ms ║║Condition #17 evaluated false (9ms)
+183ms ║║Condition group #16 evaluated false (state did not change) (16ms)
+185ms ║╚Execution stage complete. (22ms)
+186ms ╚Event processed successfully (186ms)
Wondering what happens if the event takes longer than 10 seconds? Does the piston continue on or just stop right there? Also curious if anyone has ever had issues where events took longer than 10 seconds and what could cause such delays. Is this at all common or extremely rare?
Hmm what do you know I’ve actually got a piston that seems to be doing this repeatedly just going a little over that 10 second maximum and that’s all it seems to be doing. The automation in the piston seems to work alright, but don’t understand why the logs are filled with that message.
Here’s what I mean about the logs.
https://drive.google.com/open?id=1FsJo87_OHUBzPMQeYWIP4OsJHIUm6tO0
Hi Eibyer,
Sorry I tryed a lot but could not find where is this settings, is it in mobile webcore settings or web?
Does this basically apply ASYNC to the whole piston? Wouldn’t that execute some piston lines out of order? Or does it just allow two pistons (or the same piston activated more than once) to execute simultaneously? (If that were the case, it would be nice if it was a system-wide setting).
By default, a new instance of a piston will wait for up to ten seconds to allow any already executing instances of the same piston to finish off before it proceeds. This can result in pistons running at the same time but it will be quite rare as ten seconds without encountering a wait is going it some.
With parallelism enabled new instances of the piston won’t wait, they just run straight away.
As FYI
On HE I was able to break down this type of locking to be per piston. Further on HE subsequent events queue quickly if the piston is already running.
All of above is for parallel off.
The result was quite a speedup and reduction in overhead on HE.
Some of these optimizations won’t work with ST, as there are less synchronization methods available (and they have higher overhead on ST - basically atomicState).
