Cleaning up the startup process / renaming rules (windows possible)

Yes, I’m on snapshot

Just reviving this topic, as newly relevant to me.
Running OH on a Windows laptop, I had not really been troubled by the “file load order” issue until recently.
OH 2.5 obviously changed some timings, and gave me really inconsistent loads. Sometimes Items missing, sometimes system ‘constants’ like ON, etc.

Applying the level tweaks as per @glhopital has chased it all away for me, thanks!

For me this works perfectly well on 2.5 - the numbers behind the bundles mean at what load level should the binding be loaded - ie. the rule engine at 98%.

/var/lib/openhab2/etc/scripts/startup.script

bundle:start-level org.openhab.core.model.thing 83
bundle:start-level org.openhab.core.model.thing.ide 83
bundle:start-level org.openhab.core.model.thing.runtime 83
bundle:start-level org.openhab.core.persistence 85
bundle:start-level org.openhab.core.model.item 90
bundle:start-level org.openhab.core.model.item.ide 90
bundle:start-level org.openhab.core.model.item.runtime 90
bundle:start-level org.openhab.core.model.sitemap 91
bundle:start-level org.openhab.core.model.sitemap.ide 91
bundle:start-level org.openhab.core.model.sitemap.runtime 91
bundle:start-level org.openhab.core.model.rule 98
bundle:start-level org.openhab.core.model.rule.ide 98
bundle:start-level org.openhab.core.model.rule.runtime 98

Nevertheless, there still might be some items which are not updated yet when your rules are triggered and they contain items which are not yet initialized/updated (thus are still NULL) - this can still cause error messages, but those ones can be avoided with this fix:

Item:
Switch SystemStarting

Rule:
var Timer startedTimer
rule “Start-Up”
when System started
then
SystemStarting.sendCommand(ON)
startedTimer = createTimer(now.plusMinutes(15)) [|
SystemStarting.sendCommand(OFF)
]

Start other rules which have caused error messages with ie.
Rule “Example”
when Item Example changed
then
if (SystemStarting.state == OFF)
{
// your code here
}
end

Shouldn’t mapdb persistence take care of that ?

A possibly silly question: is it sufficient to create the script to have this be a permanent solution?
How and when is it executed ?

That’s not always appropriate if you want to rely on a recent update from a device/service, rather than some historic record. It takes a finite time to get e.g weather data.

It can be complicated; in theory a binding starts up and could update Items before rules are ready. So relying on a rule triggered by update/change could miss the first update of the day.
On the other hand, triggering from System started could be premature, if the update is slow.

I’ve some rules that trigger from both … but deal gracefully with NULL states.

Hello,
I also tried the startup.script trick but I am getting the following error:

Command not found: bundle:start-level

I checked my user.properties file against this thread with no success. Running OH 2.5.4 on Windows 10. Any suggestion is appreciated :slight_smile:

I think you have to generate the script, e.g. with this command

sudo nano /var/lib/openhab2/etc/scripts/startup.script
and there you add there you add the wished order, e.g.

bundle:start-level org.openhab.core.model.thing 83
bundle:start-level org.openhab.core.model.thing.ide 83
bundle:start-level org.openhab.core.model.thing.runtime 83
bundle:start-level org.openhab.core.persistence 85
bundle:start-level org.openhab.core.model.item 90
bundle:start-level org.openhab.core.model.item.ide 90
bundle:start-level org.openhab.core.model.item.runtime 90
bundle:start-level org.openhab.core.model.sitemap 91
bundle:start-level org.openhab.core.model.sitemap.ide 91
bundle:start-level org.openhab.core.model.sitemap.runtime 91
bundle:start-level org.openhab.core.model.rule 98
bundle:start-level org.openhab.core.model.rule.ide 98
bundle:start-level org.openhab.core.model.rule.runtime 98

I tried the method as written above in my message here as well as the option from message #1 with sudo systemctl edit openhab2.service and read this thread.
There seems to be pro and con.

I have several things, item and rules (10-20 each) and started to run into booting issues with OH 2.5.4 on openhabian. I am wondering why normal user-s have to care about this.

What is the preferred way of doing? Both solutions still cause error messages while booting.

The rules renaming works fine if you implement it correctly. It’s also already built into openHABian.

FWIW, I suggested adding that to openhab-core but Kai refused. OSGi start levels according to him cause all sorts of problems.

What do you mean be with built into OpenHABian? I found the 44 command “Delay rules load”. What is it doing compared to the suggested option in this threat? I activated it but my rules where activated very fast just after items and things.

Attached the loading order and times when using the openhabian 44 option and no additional modification:

2020-05-17 18:14:47.507 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘general.items’

2020-05-17 18:14:47.596 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘anwesenheit.items’

2020-05-17 18:14:47.677 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘systeminfo.items’

2020-05-17 18:14:47.756 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘hue.items’

2020-05-17 18:14:48.003 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘zigbee2mqtt.items’

2020-05-17 18:14:48.293 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘schlafen.items’

2020-05-17 18:14:48.355 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘chromecast.items’

2020-05-17 18:14:48.478 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘tueren_fenster.items’

2020-05-17 18:14:48.494 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘nerdstuff.items’

2020-05-17 18:14:48.502 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘tasker.items’

2020-05-17 18:14:48.513 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘warnings.items’

2020-05-17 18:14:48.520 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘test.items’

2020-05-17 18:14:48.534 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘speedtest.items’

2020-05-17 18:14:48.559 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘shelly.items’

2020-05-17 18:14:48.615 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘kodi.items’

2020-05-17 18:14:48.646 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘timeoftheday.items’

2020-05-17 18:14:48.663 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘szenen.items’

2020-05-17 18:14:48.715 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘network.items’

2020-05-17 18:14:48.805 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘ui.items’

2020-05-17 18:14:48.882 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘sonos.items’

2020-05-17 18:14:49.100 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘sonoff.items’

2020-05-17 18:14:49.160 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘roborock.items’

2020-05-17 18:14:49.241 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘astro.items’

2020-05-17 18:14:49.591 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘influxdb.persist’

2020-05-17 18:14:50.166 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘default.sitemap’

2020-05-17 18:14:50.621 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘hue.things’

2020-05-17 18:14:50.632 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘mqtt.things’

2020-05-17 18:14:50.653 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘network.things’

2020-05-17 18:14:50.667 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘mail.things’

2020-05-17 18:14:50.693 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘nodemcu.things’

2020-05-17 18:14:50.715 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘sonos.things’

2020-05-17 18:14:50.731 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘sonoff.things’

2020-05-17 18:14:50.755 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘shelly.things’

2020-05-17 18:14:50.772 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘roborock.things’

2020-05-17 18:14:50.814 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘zigbee2mqtt.things’

2020-05-17 18:14:50.848 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘systeminfo.things’

2020-05-17 18:14:50.856 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘astro.things’

2020-05-17 18:14:54.871 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘sonoff.rules’

2020-05-17 18:15:03.628 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘licht.rules’

2020-05-17 18:15:07.170 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘motionsensor.rules’

2020-05-17 18:15:11.226 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘warnings_luftfeuchtigkeit.rules’

2020-05-17 18:15:11.621 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘weihnachtsbeleuchtung.rules’

2020-05-17 18:15:19.137 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘schlafen.rules’

2020-05-17 18:15:19.930 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘warnung.rules’

2020-05-17 18:15:20.957 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘timeoftheday.rules’

2020-05-17 18:15:22.708 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘tueren_fenster.rules’

2020-05-17 18:15:34.692 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘sonos.rules’

2020-05-17 18:15:36.437 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘warning_systeminfo.rules’

2020-05-17 18:15:39.820 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘warnings_temperatur.rules’

2020-05-17 18:15:40.440 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘roborock_szenen.rules’

2020-05-17 18:15:42.255 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘speedtest.rules’

2020-05-17 18:15:48.361 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘zigbee.rules’

2020-05-17 18:15:48.701 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘networkhealt.rules’

2020-05-17 18:15:50.279 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘ui.rules’

2020-05-17 18:15:54.277 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘hue.rules’

2020-05-17 18:16:00.948 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘roborock.rules’

2020-05-17 18:16:01.526 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘vacation.rules’

2020-05-17 18:16:07.672 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘statistik.rules’

2020-05-17 18:16:13.005 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘anwesenheit.rules’

2020-05-17 18:16:14.076 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘googlehome.rules’

2020-05-17 18:16:19.132 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘szenen.rules’

2020-05-17 18:16:23.315 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘rollo_szenen.rules’

2020-05-17 18:16:23.599 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘rollo_automatik.rules’

2020-05-17 18:16:26.571 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘schalter.rules’

2020-05-17 18:16:33.904 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model ‘rollo_shelly.rules’

It implements the solution this thread was about in the first place (move rules away and back after 2 mins). If it does so after items that’s all you need.

I tried to change to the following commands:

[Service]
ExecStartPre=-/bin/bash -c ‘/usr/bin/find ${OPENHAB_CONF} -name “.rules" -exec /usr/bin/rename.ul .rules .rules_away {} \;’
ExecStartPre=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.script” -exec /usr/bin/rename.ul .script .script_away {} \;’
ExecStartPost=/bin/sleep 240
ExecStartPost=-/bin/bash -c ‘/usr/bin/find ${OPENHAB_CONF} -name “.script_away" -exec /usr/bin/rename.ul .script_away .script {} \;’
ExecStartPost=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.rules_away” -exec /usr/bin/rename.ul .rules_away .rules {} \;’
TimeoutStartSec=360

Watching the filenames on the raspberry I could not see any renaming happening. In addition I observed that watching the log during boot is active much later. Any explanation? I run openhabian 2.5.4 on RP 4.

Thanks and best
Matthias

where

why

Your file is wrong. You need a * in front of .rules.
And you must not duplicate lines.
You also said you enabled openHABian delayed rules option, but your file (which ?) would not look like that if it did originate from openHABian.

I was following the original threat.

I used the command as follows as I am on stretch-based Linux using openhabian 2.5.4

sudo systemctl edit openhab2.service
and modified from

ExecStartPre=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name “.rules" -exec$
ExecStartPost=-/bin/sleep 120
ExecStartPost=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.x” -exec /u$
TimeoutStartSec=240

to

#[Service]
ExecStartPre=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name “.rules" -exe$
ExecStartPre=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.script” -ex$
ExecStartPost=/bin/sleep 240
ExecStartPost=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name ".script_awa$
ExecStartPost=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.rules_away$
TimeoutStartSec=360

as mentioned here.

Why: Because my rules are loaded immediately, especially before things are initialized and before values are restored by persistance. This causes several rule failures as well as multiple load of rules.

The following file does not exist or has been generated as I expect the steps above are correct for my OS:

/etc/systemd/system/openhab2.service.d/override.conf

EDIT:
I just checked my version and it seems to be buster:

cat /etc/os-release
PRETTY_NAME=“Raspbian GNU/Linux 10 (buster)”
NAME=“Raspbian GNU/Linux”
VERSION_ID=“10”
VERSION=“10 (buster)”
VERSION_CODENAME=buster
ID=raspbian
ID_LIKE=debian
HOME_URL=“http://www.raspbian.org/
SUPPORT_URL=“http://www.raspbian.org/RaspbianForums
BUG_REPORT_URL=“http://www.raspbian.org/RaspbianBugs

You have not been careful in reading.
If you literally entered what you cited that cannot work.
Your lines are incomplete. And a # before [Section] is no good idea.

And there was no need for that change, the previous version was mostly fine (except that your lines are cutoff there, too).

There has been more commented lines and a non-commented [Service] at the top.

Interestingly I just checked the file after rebooting and it was empty - so maybe something was wrong anyhow.

The current full (!) file looks like this:

[Service]
ExecStartPre=-/bin/bash -c ‘/usr/bin/find ${OPENHAB_CONF} -name “.rules" -exec /usr/bin/rename.ul .rules .rules_away {} \;’
ExecStartPre=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.script” -exec /usr/bin/rename.ul .script .script_away {} \;’
ExecStartPost=/bin/sleep 240
ExecStartPost=-/bin/bash -c ‘/usr/bin/find ${OPENHAB_CONF} -name “.script_away" -exec /usr/bin/rename.ul .script_away .script {} \;’
ExecStartPost=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.rules_away” -exec /usr/bin/rename.ul .rules_away .rules {} \;’
TimeoutStartSec=360

Same problems:

  • Rules are loaded very early
  • Log output is quite late
  • Rules are fired several times
  • Watching the files I can not observe any renaming happening

Obviously I am still doing something wrong.

Can be anything like an unspotted typo or file permissions or whatever.
I don’t understand anyway why you do not use the delayed rules option since you’re on openHABian.
It’s right there to save you from this trouble.

I am fine with the delayed rules option with openhabian and already activated it several times with no effect. What should I observe? What is changed?

I believe you must somehow have messed up your system because it works on a default oepnHABian installation.

Actually multiple rule firings at the startup seems to be a known issue - that’s why I ended up trying to clean this behavior with this threat.
Does anybody know what the built in delay rules of openhabian is doing?

I did an upgrade to openhabian 2.5.5.-1:

  • After the update the file sudo systemctl edit openhab2.service was empty.
  • Logs during booting are shown as expected (starting with timezone etc.).

I played with openhabian-config:

  • Option Default order Reset config load order to default (random) empties whatever has been modified via sudo systemctl edit openhab2.service
  • Option 44 | Delay rules load Delay loading rules to speed up overall startup adds the following to sudo systemctl edit openhab2.service:

[Service]
ExecStartPre=-/bin/bash -c ‘/usr/bin/find ${OPENHAB_CONF} -name “.rules" -exec /usr/bin/rename.ul .rules .x {} \;’
ExecStartPost=-/bin/sleep 120
ExecStartPost=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.x” -exec /usr/bin/rename.ul .x .rules {} \;’
TimeoutStartSec=240

This shows what the built-in openhabian option is doing. Nevertheless applying this optimization results in delayed log-output and no observed renaming.

I thought about removing the second renaming to just see the script works:

[Service]
ExecStartPre=-/bin/bash -c ‘/usr/bin/find ${OPENHAB_CONF} -name “.rules" -exec /usr/bin/rename.ul .rules .x {} \;’
ExecStartPost=-/bin/sleep 120
#ExecStartPost=-/bin/bash -c '/usr/bin/find ${OPENHAB_CONF} -name "
.x” -exec /usr/bin/rename.ul .x .rules {} \;’
TimeoutStartSec=240

Interestingly the rules still are named rules instead of x.
So again: Something is wrong here!?