Sometime in the last few weeks one of the hub updates I applied must have broken one of my rules.
I have a local variable that triggers a chime if a door opens while HSM is armed.... triggers based on state change of that variable and then starts looping to play the chime sound every few seconds until the variable becomes false. I am not sure this would be a bug in the rule machine itself or something with the way some other code is sending the notification.
When I turn on debugging for the rule I can see that:
the event comes in saying the variable became true
it goes to the while loop and it skips the loop and exit because it still thinks the value of the variable is false even though it just got the event saying it was true
therefore the chime never sounds and my kids don't know to disarm the alarm within grace period to prevent sirens, etc
Very certain this is pretty recent because this rule has always worked fine for a long time (years). I will experiment with adding a short delay between the event and starting the loop, because I suspect the bug is that something is sending the event BEFORE changing the variable and therefore causes a race condition.
EDIT: First experiment failed, adding a delay before entering the loop does not work. Perhaps rule execution is single threaded event loop and therefore variable value still does not change after waiting one second. I still have to open and close a door twice before the chime will start. I'll try other things and update again if I find a temporary work around.
EDIT 2: Next I tried setting the variable true twice in the rule for when a door is opened... that did not work either, then I tried setting it true, and after a delay of two seconds setting it true again...... then it triggers the desired behavior at least. The chime rule fails the first time and then starts up when it is set true a second time after the delay.... but delaying within the chime rule itself didn't work as noted in the first edit.
Clearly this is probably a bug and not intended behavior, so I'll keep an eye on updates so I can remove my hack to my rule once its fixed and hopefully the description of the work around could help others if they are having the same sort of problems in the mean time (now I can keep using my alarm and it won't go off randomly because of this).
Also note, in my title I said local variable originally, but this is for a HUB variable... not a local variable. That might matter. I haven't used local variables for a lot because I usually don't find them useful for modular rules that don't have to be individually complicated.
As I explained above... the trigger event fires but the while loop does not get to see the correct variable value because it probably didn't actually get written BEFORE the event triggers.. I have to write the value twice so that it triggers twice in order to make this work. First time it exits, and then the 2nd trigger works because by that time the value is written (and as I said, this is new behavior, I've had this rule for a long time and only became broken recently).
There is no lag between an event of a variable being set to a value and that value being "written". The new value is stored in the database, and that generates the event.
Yes thats what I looked at and I could see the event come in triggering the rule and then immediately exit the loop because the value was still false when the while looked at it.... so there is definitely some race condition happening.
Here you can clearly see it get the event... fail out of the loop, get a second event and then succeed. Nothing else is changing the variable in between. It should have been true in the first attempt to enter the loop but it wasn't.
Happens every single time. Never used to do this ... no idea which firmware update broke it, but I'm on 2.3.4.153 and at least the last couple versions were doing it but I didn't notice it immediately so I'm not sure which version it last behaved correctly.
If you're certain the code writes to the DB before firing the event, I dunno what its using under the hood, but maybe if it is somehow transactional, it has not done a commit or a flush to storage yet.
I saw there was a change note in a firmware release that mentioned fixing possible delayed updates of hub variables. Going to try updating to latest and see if the behavior changes.... will report back... perhaps not until tomorrow since I'm busy working too.
