[SOLVED] Active rules re-set upon docker restart

[3rdStng]

Sorry for the long post.

A couple of versions back I started noticing some of my lights would start to turn off and then immediately come back on when ever I would restart my docker. I've been migrating all my devices off Vera and into HE, (moved my final device last night), so I've been restarting the docker a lot recently.

Without knowing what the exact issue is, the best thing I can think of is some sort of race condition upon the start up. I have LED's on the back of my monitor and a lamp on my desk. I have a rule using a lux level reading. If the light level is low, or it's after sunset, the LED's and lamp turn on. Upon my docker starting up, the lights will start to dim down as if the Reset Action was triggered. Then a second later they would brighten back up. Yesterday, I noticed that my roller shades were closed when they shouldn't be. Upon looking at the rule, 2 of the 3 triggers were met and the unmet trigger was a time span between midnight and 4 AM. (The below image is as of right now. At the time, it was after astronomical dusk.) Thinking a little more about this. Is the time of the docker off until it syncs with the host? Perhaps it is being set to midnight, or something else, as the docker is being started?

For a more recent test. I changed my LUX level to something that force the lights on. Stopped my docker and nothing happened. As I restarted it, the lights dimmed and brightened back up a second or two after I started the docker. However my roller shade was still open. Making me think this has something to do with time?

EDIT: This may be related to having a Mode trigger within the rule? If I remove the Mode trigger, the lights to not dim down and up, and the SET since time does not update. In the below screenshot, the SET time is 3:32 for the Office - Lamp rule. I restarted my docker at 3:34, as noted with the Office - Monitor LEDs rule. Only my Monitor LEDs dimmed down and back up.

Perhaps why I didn't start seeing this until recently was that many of my rules had both a Vera Home Mode and Hubitat Home Mode. This doesn't explain the roller shade being closed though.

One final test, I changed the Office - Monitor LEDs rule to == "Home" instead of "home", both with and without the Ignore Case option checked. Both restarts caused the LEDs to dim down and back up. So the case in the rule isn't the issue.

[toggledbits]

Good sleuthing on the house mode. I have a suspicion on what that might be, so I'm building now with a fix on my hunch. Let's see if that does it.

Remember, please include your platform (you said docker, but didn't say Synology, Pi, etc., and you may have told me yesterday and every other day this week but I speak to so many people I can't remember such things), and of course, always give your Reactor version number.

[3rdStng]

Oops. So Sorry. I run my docker containers on my unRAID server. It has a GUI front end that does all the docker pull commands and run config parameters. It's basically a Linux server, as they all are. I don't recall where it started, if it truly is due to only have my HE house mode defined. I can add in a Vera Home mode to my rule tomorrow and test.
MSR version is latest-21306-f17d2eb. But I started noticing it at least 2 releases ago.

[toggledbits]

@3rdstng Try 21307?

[3rdStng]

@toggledbits said in Active rules re-set upon docker restart:

@3rdstng Try 21307?

Just did. My tests were:

Included both Vera and HE Mode in my rule. (Lights dimmed and restored.)
Just Vera Mode. (Lights did not change.)
Just HE Mode. Just to be sure the issue was still there. (Lights dimmed.)
Updated to 21307-1746e27
Just HE Mode. (Lights did not dim.)

Looks like you nailed it. Thank you!

[toggledbits]

Whew! Lucky guess.

The problem was a "race condition." On the startup of the (pre-21307) HubitatController, it would first query Maker API for the list of devices, set up all the device-related entities, and then launch separate asynchronous queries for HSM and system mode.

The problem was that the report of the controller being ready came as soon as the HSM and mode queries were made, not after they were completed. So, it was possible for the HubitatController to report "online and ready" before HSM state and system mode were actually ready.

When the Engine sees all controllers ready, it does a startup evaluation of the rules. At this point, it was possible for the evaluation of the rule containing your mode test condition to run, and if the mode query hadn't yet completed, HubitatController's entity for the mode would be null. Some number of milliseconds later, when the mode query completed, the mode entity would be updated, the rule would be notified of the change, and would update the state. So the mode actually did go through a state transition, it was just from whatever state through null and back to the original state.

Since you reported it as a startup issue, it was reasonable to assume the above. The fix for such a "race" condition (two processes trying to finish first) is to simply synchronize them, which is what I did for the fix for 21307.

And we're on our way...

[3rdStng]

WOW! Thank you for the great explanation and I'm glad it was an easy one for you. I'm betting that the condition doesn't exist with Vera because...well...it's like a sloth. (And I don't think I can get banned here for saying that.)

My final step to be able to pull the plug out on my Vera Plus is a Dashboard. Preferably with an API capability to blank the screen when my mode is <> Home. For now I have a few virtual devices on the Vera that is acting like a bridge for my Imperihome to keep limping along.