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

could somebody explain to me what is going on here?
how does this work and what does it do?

1 Like

could somebody explain to me what is going on here?
how does this work and what does it do?

From my guessing it is like this:

On startup different things are done. Bindings are started, rules are loaded. You can see everything with its startup level by doing

bundle:list

For me it outputs stuff like:

 ID │ State    │ Lvl │ Version                │ Name
────┼──────────┼─────┼────────────────────────┼───────────────────────────────────────────
[...]
129 │ Active   │  80 │ 0.10.0.oh240           │ Eclipse SmartHome Item Model
130 │ Active   │  80 │ 0.10.0.oh240           │ Eclipse SmartHome Item Model IDE
131 │ Active   │  80 │ 0.10.0.oh240           │ Eclipse SmartHome Item Model Runtime
[...]
160 │ Active   │  80 │ 2.14.0.v20180522-1629  │ Xbase Runtime Library
175 │ Active   │  80 │ 1.9.6                  │ MIME streaming extension
177 │ Active   │  80 │ 6.2.0                  │ org.objectweb.asm
178 │ Active   │  80 │ 6.2.0                  │ org.objectweb.asm.commons
179 │ Active   │  80 │ 6.2.0                  │ org.objectweb.asm.tree
180 │ Active   │  90 │ 2.4.0                  │ openHAB Core
181 │ Active   │  80 │ 2.4.0                  │ openHAB Karaf Integration
183 │ Resolved │  80 │ 2.4.0                  │ openHAB Sound Support, Hosts: 116
184 │ Active   │  80 │ 2.4.0                  │ openHAB Dashboard UI
[...]

There you can see most things have a level of 80, including bindings. Without the above change, rules also have a startup level of 80:

bundle:start-level org.eclipse.smarthome.model.rule
Level 80

What I assume is that everything with the same startup level is started at the same time. So when the startup level reaches 80, everything with startup level 80 is loaded at the same time. By increasing the level of rules, rules are loaded after everything in startup level 80 (like things or bindings) are loaded. Effectively delaying rule loading after everything else is loaded.


I even got a step further by loading things, items, etc. step by step by doing:

bundle:start-level org.eclipse.smarthome.model.thing 83
bundle:start-level org.eclipse.smarthome.model.thing.ide  83
bundle:start-level org.eclipse.smarthome.model.thing.runtime   83
bundle:start-level org.eclipse.smarthome.model.item 85
bundle:start-level org.eclipse.smarthome.model.item.ide 85
bundle:start-level org.eclipse.smarthome.model.item.runtime 85
bundle:start-level org.eclipse.smarthome.model.sitemap   88
bundle:start-level org.eclipse.smarthome.model.sitemap.ide    88
bundle:start-level org.eclipse.smarthome.model.sitemap.runtime     88
bundle:start-level org.eclipse.smarthome.model.rule 90
bundle:start-level org.eclipse.smarthome.model.rule.ide 90
bundle:start-level org.eclipse.smarthome.model.rule.runtime 90

So first things are loaded (after everything else in level 80 like bindings), then items, then sitemaps and finally rules. I’d guess they depend on each other in this order (e.g. items need things and sitemaps need items etc.).

This is just my guessing - I didn’t take a look at the code or so. If somebody from the devs could confirm this I’d be grateful.

2 Likes

To be confirmed by experience but it does not seem that bad.
I created a custom.script in /var/lib/openhab2/etc/scripts and adapted your proposal to last snapshot module names :

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.model.item 85
bundle:start-level org.openhab.core.model.item.ide 85
bundle:start-level org.openhab.core.model.item.runtime 85
bundle:start-level org.openhab.core.model.sitemap   88
bundle:start-level org.openhab.core.model.sitemap.ide    88
bundle:start-level org.openhab.core.model.sitemap.runtime     88
bundle:start-level org.openhab.core.model.rule 90
bundle:start-level org.openhab.core.model.rule.ide 90
bundle:start-level org.openhab.core.model.rule.runtime 90

@kai, @maggu2810, or @wborn, are start-levels something users should be meddling with? IIRC, this discussion has come up before and the advice was not to do it.

Should we bring ESH #1896 over to openhab-core (if it has, I couldn’t find it)?

No, start levels should not be touched by users.
And yes, the startup issue is still open, definitely worth to address.

4 Likes

I definitevely agree that touching start levels should not be in end user scope, but while this subject is not addressed at framework level, this can be a way to clean and clear startup process. I hate seeing warnings or errors when I browse my log files. Every time I wonder what’s the reason behind, is it a real failing or just a temporary error

I’ve implemented the workaround from this thread in openHABian so at least the major pain point (evaluate rules last) is adressed.
However I also prefer a complete start level based solution and we shouldn’t care if that’s user or developer level if it works. But that’s the question - does it ? If so, can anyone create a PR ?

This is giving me

Error in initialization script: /var/lib/openhab2/etc/scripts/startup.script: Bundle org.openhab.core.model.item does not match any bundle

on every console start so I doubt it’s right.
(running 2.5M1 - have the bundle names changed since and you used the new ones ?)

Thank you Gael, it seems to work well for me.
PS: I created a start-level.script in userdata/etc/scripts

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