Startup takes up to 70 Minutes - Raspberry Pi 3 Model B

None of that makes sense if you only clone your SD card.
Start by reinstalling as I already advised.

I absolutely treasure your advice and knowledge, honestly. And reinstalling is definitly on my Wish-List. But for my understanding, if clonig the whole SD (inclusive boot partition and debian partition) and usage afterwards in a second same raspberry model is solving the delay, the problem can not be the whole OS. (Except if there a problems with the USB drivers in combination with the NanoCUL. If so, I expect a change in step 3)

Reinstalling will not really give me an answers, why its working on one device and not on another one.

In cloning your SDcard and running it on another raspberry you would only eliminate hardware issues. Markus gave the advice to eliminate issues that stem from (e.g.) suboptimal configuration changes that might happen due to numerous updates on OS level. With a fresh install you may detect that easily and will have a responsive system again.
For comparison: my boot time (OH only) is around 5 minutes. That is on a RasPi 4 running on a mSATA disk instead of SDcard (which gives the system a noticable performance boost), no changes in the ZWave network. Normally app. 2 minutes after restarting the system I can use the openHAB App again.

1 Like

Interesting thread.

I just updated my openHAB installation and it takes ages until it’s up again.
After a short diagnosis it turned out that apt needs half an eternity to download packages…

Maybe you also install some extra packages?

Good hint. Yes if you have configured your system to download all bindings rather than to use a local .kar file that download phase can be annyoingly long.
But generally speaking, you should take a systematic approach rather than search for the needle in the haystack and look after ideas of various people that don’t know your setup.
That’s why FIRST, you should create/move to a starting point that is well-known to work, hence my advice to reinstall.
Then SECOND you should ramp up Karaf logging to debug levels. This will give you hints what stage(s) of startup are lame. The binding download is a prime candidate you’ll spot quickly.
But there’s others such as rules compilation or ever-ongoing restarts of modules.
Once again, the reinstall step is crucial because it resets your system to avoid at least quite some bad settings that can cause this that you might have introduced yourself (eventually without knowing).

Glaad for every hint that could give me answers! But I am not exactly sure:

What you mean by

How can apt need an eternity if I am not running it manually by funning “apt-get upgrade”?

I have installed the bindings by PaperUI, I have never saw an option to use binding by downloading it every time? I thought installing them by PaperUI will download them.

Regarding starting point, here is the updated: I am still working on it daily, but almost everything was getting complicated. First I installed openhabian and just used .cfg, .thing, .items, .rules, .persistance files to transfer everything. Made some bigger steps since I assumed everthing will work out. Openhab was not loading all rules files and I was not able finding out why. Then i started again from the scratch and was approaching in little steps. (Funny fact: Shelly Binding is running perfectly on “debian openhab” and throwing massive errors on “openhabian openhab” but same version of everything. Maybe Java)
The Problem is, to walk in little steps costs a hell lot of time is neccesarry.
Starting Openhab is now about 4-7 Minutes. I am still not done. Right now I will try to figure out, why is openhab again not loading all rules and needs 7 instead of 4 minutes to start, depending of one specific rule which is existing or not. I will let you know. But I am still not done, many steps are missing.

Depends on the install method you initially chose (expert, standard, …).
With proper Karaf debugging, watch startup closely and you’ll quickly see if it starts downloading.

Why don’t you use openHABian ? It’s right there to relieve you of all those steps.

2 Likes

I am not sure anymore, did it by PaperUi long time ago. I was not able to find it in karaf, but:
cat /var/lib/openhab2/config/org/openhab/addons.config
gives me standard:

:org.apache.felix.configadmin.revision:=L"12"
binding=“astro,chromecast,expire1,homematic,mail,mqtt,network,openweathermap,shelly,miio”
felix.fileinstall.filename=“file:/var/lib/openhab2/etc/org.openhab.addons.cfg”
legacy=B"false"
misc=",openhabcloud,ruleengine"
package=“standard”
persistence=“influxdb”
remote=B"true"
service.pid=“org.openhab.addons”
ui=“basic,paper,classic,habpanel,habmin”
voice=“voicerss”

So i guess my bindings are all fully downloaded and I don’t need .kar files?

I will, but I will need to study how to properly debug first. I will report.

To be hones, I have installed Debian and Openhab long time ago. As the system was working perfectly (except for the startup delay lately), I never had a reason (or time) to change the OS.

Since then I configured some stuff by PaperUi and some stuff by files (.cfg, services, .things, etc.). But I always wanted a “just files setup”. I prefer to control openhab totaly or backup everything easily by samba. So those steps are wanted to move PaperUI set-ups to files (.cfg, services, etc).

The “B” is wrong. This is the setting about downloading bindings.

We’re every time getting back to my initial recommendation:
You have bad settings somewhere in your system so instead of searching everything setup again, from scratch.

openHABian is Debian/Raspbian, too so no change actually.
But you have to upgrade at times anyway.

That has nothing to do with openHABian, it works both ways. Samba included, too.

You can take the chance to configure everything from scratch to get files-only, however check out https://www.openhab.org/docs/configuration/#versatility first.

1 Like

How did the B came in? I never edited this file manually. Same char at legacy! So true means all bindings are downloaded? When? On every start? Where to change it, what to do about the char B?

I know, but as the Debian installation is still my first installation and I wanted to start from scratch and configure everythings by files this time. All good, I do as I told me, just want to clean up too.

Update: The openhabian installation is driving me nuts!!!

I’ve got pretty far by adding things, items, bindings. Then I went to copying rules. I copied first 18 rules at once. Measured the boot time by stopwatch. About 4 Minutes. After I added additional few rules, time went up to 7 Minutes. So I erased the last added rules. 4 Minutes again.

I wrote a shell script which is starting by cron @reboot.
It saves the OS boot timestamp. After that it sends ON to an item (boot_input) by REST api frequently (every 5 seconds) and see if bootTestRule is working and boot_output has changed from NULL to ON. After that the script writes the difference between the OS boot timestamp and now timestamp into that file, waits 30 seconds, stops openhab service, reboots the OS and starts again.
That is done 10 times. So I have time measurements of startup time of 10 startups without any changes by me. So i can compare startup time with every change I will further do.

rule
	"bootTestRule"
when
	Item boot_input changed
then
	boot_output.sendCommand( ON )
end

This is the startup duration time until the the bootTestRule worked out with 18 rules:
5:25 Minutes
4:36 Minutes
5:54 Minutes
6:14 Minutes
4:53 Minutes
4:41 Minutes
4:44 Minutes
4:34 Minutes
4:31 Minutes

After that I added another rule and startes the script again (automatically 10 times). Not so complicated rule to me.
5:18 Minutes
6:09 Minutes
6:48 Minutes
5:29 Minutes
5:24 Minutes
6:56 Minutes
5:23 Minutes
5:13 Minutes
5:07 Minutes

Rule which added almost a minute of startup time:

rule
	"regelStatusHelligkeitAenderung"
when
	Item Bewegungsmelder1_helligkeit changed
then
	var helligkeit = Bewegungsmelder1_helligkeit .state
	
	var leicht = 175
	var mittel = 149
	var dunkel = 122
	var voll = 10
	var rollo_mittel = 70
	var rollo_sehr = 20

	if (helligkeit < voll && st_helligkeit_dunkel_voll.state != ON) st_helligkeit_dunkel_voll.sendCommand(ON)
	else if (helligkeit > (voll + 20) && st_helligkeit_dunkel_voll.state != OFF) st_helligkeit_dunkel_voll.sendCommand(OFF)
	
	
	if ( helligkeit < dunkel || ( helligkeit < (dunkel + 10) && st_helligkeit_dunkel_sehr.state != OFF ) ) {
	
		if ( st_helligkeit_dunkel_sehr.state != ON ) logInfo("st_helligkeit.rules", "regelStatusHelligkeitAenderung: jetzt dunkel.")
		if ( st_helligkeit_dunkel_sehr.state != ON ) st_helligkeit_dunkel_sehr.sendCommand(ON)
		if ( st_helligkeit_dunkel_mittel.state != OFF ) st_helligkeit_dunkel_mittel.sendCommand(OFF)
		if ( st_helligkeit_dunkel_leicht.state != OFF ) st_helligkeit_dunkel_leicht.sendCommand(OFF)
		if ( st_helligkeit_dunkel_aus.state != OFF ) st_helligkeit_dunkel_aus.sendCommand(OFF)


	} else if (helligkeit < mittel || ( helligkeit < (mittel + 10) && st_helligkeit_dunkel_mittel.state != OFF )) {
		
		if ( st_helligkeit_dunkel_mittel.state != ON ) logInfo("st_helligkeit.rules", "regelStatusHelligkeitAenderung: jetzt mittel.")
		if ( st_helligkeit_dunkel_sehr.state != OFF ) st_helligkeit_dunkel_sehr.sendCommand(OFF)
		if ( st_helligkeit_dunkel_mittel.state != ON ) st_helligkeit_dunkel_mittel.sendCommand(ON)
		if ( st_helligkeit_dunkel_leicht.state != OFF ) st_helligkeit_dunkel_leicht.sendCommand(OFF)
		if ( st_helligkeit_dunkel_aus.state != OFF ) st_helligkeit_dunkel_aus.sendCommand(OFF)


	} else if (helligkeit < leicht || ( helligkeit < (leicht + 10) && st_helligkeit_dunkel_leicht.state != OFF )) {
		
		if ( st_helligkeit_dunkel_leicht.state != ON ) logInfo("st_helligkeit.rules", "regelStatusHelligkeitAenderung: jetzt leicht.")
		if ( st_helligkeit_dunkel_sehr.state != OFF ) st_helligkeit_dunkel_sehr.sendCommand(OFF)
		if ( st_helligkeit_dunkel_mittel.state != OFF ) st_helligkeit_dunkel_mittel.sendCommand(OFF)
		if ( st_helligkeit_dunkel_leicht.state != ON ) st_helligkeit_dunkel_leicht.sendCommand(ON)
		if ( st_helligkeit_dunkel_aus.state != OFF ) st_helligkeit_dunkel_aus.sendCommand(OFF)
		
		
	} else {
		if ( st_helligkeit_dunkel_aus.state != ON  )logInfo("st_helligkeit.rules", "regelStatusHelligkeitAenderung: jetzt hell.")
		if ( st_helligkeit_dunkel_sehr.state != OFF ) st_helligkeit_dunkel_sehr.sendCommand(OFF)
		if ( st_helligkeit_dunkel_mittel.state != OFF ) st_helligkeit_dunkel_mittel.sendCommand(OFF)
		if ( st_helligkeit_dunkel_leicht.state != OFF ) st_helligkeit_dunkel_leicht.sendCommand(OFF)
		if ( st_helligkeit_dunkel_aus.state != ON ) st_helligkeit_dunkel_aus.sendCommand(ON)
		
		
	}
	
	
	
	
	
	
	
	if ( helligkeit < rollo_sehr || ( helligkeit < ( rollo_sehr + 5) && st_helligkeit_rollo_sehr.state != OFF ) ) {
		
		if ( st_helligkeit_rollo_sehr.state != ON ) logInfo("st_helligkeit.rules", "regelStatusHelligkeitAenderung: Rollo jetzt sehr.")
		if ( st_helligkeit_rollo_sehr.state != ON )  st_helligkeit_rollo_sehr.sendCommand(ON)
		if ( st_helligkeit_rollo_mittel.state != OFF ) st_helligkeit_rollo_mittel.sendCommand(OFF)
		if ( st_helligkeit_rollo_aus.state != OFF ) st_helligkeit_rollo_aus.sendCommand(OFF)
		
		
	} else if (helligkeit < rollo_mittel || ( helligkeit < ( rollo_mittel + 5) && st_helligkeit_rollo_mittel.state != OFF )) {
		
		if ( st_helligkeit_rollo_mittel.state != ON ) logInfo("st_helligkeit.rules", "regelStatusHelligkeitAenderung: Rollo jetzt mittel.")
		if ( st_helligkeit_rollo_sehr.state != OFF )  st_helligkeit_rollo_sehr.sendCommand(OFF)
		if ( st_helligkeit_rollo_mittel.state != ON ) st_helligkeit_rollo_mittel.sendCommand(ON)
		if ( st_helligkeit_rollo_aus.state != OFF ) st_helligkeit_rollo_aus.sendCommand(OFF)
		
		
	} else {
		if ( st_helligkeit_rollo_aus.state != ON  )logInfo("st_helligkeit.rules", "regelStatusHelligkeitAenderung: Rollo jetzt hell.")
		if ( st_helligkeit_rollo_sehr.state != OFF )  st_helligkeit_rollo_sehr.sendCommand(OFF)
		if ( st_helligkeit_rollo_mittel.state != OFF ) st_helligkeit_rollo_mittel.sendCommand(OFF)
		if ( st_helligkeit_rollo_aus.state != ON ) st_helligkeit_rollo_aus.sendCommand(ON)
		
		
	}
end

After that, I have tried to add all missing rules (another 14) at once to see what startup time will turn to. My srcipt run endlessly. After checking what happend, I found out that not all rules were loaded. Even after hours of running. The bootTestRule, which worked before and was not touched since than, was not loaded anymore. I can reboot as often or wait as long as I want, rules are not loaded. Files are there, permissions and ownership are equal, filesystem is fine.

What is going on? Why are not all rules loaded? Why is adding one rule so much time to startup. Where to seach? I try so hard with karaf, but I don’t know where to look at.

Please - it’s openHAB to drive you nuts, not openHABian. That’s completely different things (and people to blame :wink: )

The load times you show are somewhat normal (btw to get specific log output set e.g.
log:set debug org.eclipse.smarthome.model.script.st_helligkeit.rules)

Some code constructions are known to be deadly for compilation times, Java math primitives like those I quoted for example. Try eliminating these ( ‘10.0’ instead of ‘10’ or better introduce Number variables instead at the beginning of a file).

2 Likes

I know, I know :rofl: I just use those two terms to differe between my old server (installed debian and openhab by apt, which took 70 Minutes to boot) and new server (openhabian image).

Optimizing rules is definitely on my todo list to, as I never analyzed it before. Thanks for the hints.

But more important to me is: what do I need to debug in karaf, when not all rules are loaded. What is hapening there? Every single rules is loaded on the debian server. But debian and openhabian server have both the same openhab and bindings versions.
I could expand my script to also check if all rules are loaded by reading the openhab.log automatically anjd compare it to the folder. Add on rule after another and see when problems starting. But I am not sure if one of the rules is the reason why not all are loaded. Especially when working fine on the debian server and no error eintries in openhab.log

You should be seeing an error like
2020-10-06 19:41:04.722 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'Test.rules' has errors, therefore ignoring it: [392,1]: extraneous input 'xxxx' expecting EOF

1 Like

There are no errors. But in the end the code constructions were the problem. In some rules I used massivly Java math primitives. I don’t know why, but all these rules active at once lead to massive problems. As I mentioned, not all rules were loaded, took very much time to startup, and so on.

I cleaned up as far as I could and deactivated all heavy mathematical rules. Now the startup time is about 10 Minutes which is fine for me. So many many thanks to all of you, for help me finding the cause. I will try to add those heavy rules automatically after startup is done.

May I ask for some help regarding this problem?

  1. Is there a topic or HowTo regarding optimization of rules? Especially wen working with var and calculationg code. I have searched a lot, but keywords like “optimization” or “compiling” lead to a lot of topics which are not general or in a different context.
  2. Is there a Chance to get the exact time the compiler need to compile the rule? Going just by karaf log wallclock doesnt seem to be really accurate.
  3. Is there a way to get autmatically the names/array of the already loaded rules? Reading the openhab.log is pretty unfortunate. If you reboot mutliple times or change a rule while running, you have multiple entries.

The best solution is to rewrite these rules to the new rule engine in either jython or Javascript as that doesn’t have the compilation problem.

1 Like

Xtend, the language upon which Rules DSL is built, is a loosely typed language. It expects to not have to worry about the types of things until runtime. But it’s not a typeless language. When you do specify type, and most especially when you specify the type to be a primitive, the loader must do a lot more work at load time in order to check those types. And it’s really bad at this checking. Not bad in that it gets it wrong, but bad in that it looks like it’s using an exponential algorithm to do the job. Consequently it doesn’t take more than a few primitives to add minutes to your .rules files loading times.

  1. Several but most of the content is buried in replies to posts like this one. The tl;dr though is to follow these rules of thumb:

    • Never specify the type unless absolutely necessary.
    • When it is necessary to specify the type, don’t do so until the last possible moment. For example, if you are calculating how long a Timer needs to be set for, don’t convert the number to an int until the actual call to now.plusSeconds(somenumber.intValue). Leave it as a Number up to that point.
    • The result of all calculations and the type of all numbers (when a type is not provided) is BigDecimal which itself is of type Number. When a calculation doesn’t work because you are using the state of an Item, cast that state to Number. When defining a constant don’t provide a type and it will be a BigDecimal (e.g. var MY_CONSTANT = 7)

That’s all there is to it really. Avoid forcing the parser to look at type at load time and let it manage the type at runtime where it has way more information and can more efficiently handle it.

  1. Not that I know of. Maybe you can put the rule engine into debug mode and see when it starts to load the rule if it logs that.

  2. Not with Rules DSL.

I’ll also second Hilbrand’s suggestion (I was going to anyway but he beat me to it). None of these are problems with the new rule engine using Jython, JavaScript, or Groovy. I don’t know if they are problems with Rules DSL on the new rule engine in OH 3 or not. These languages have no similar problems with long load times. They also appear in PaperUI under Rules where they can be manually run (for testing), enabled, and disabled and you can see when they are running. And events get put into events.log when the rules are loaded and when they are running. All of these provide way more capability and information about the running of your rules than is possible with the default OH 2 rules engine.

It’s worth noting that the NGRE in OH 2 is just “the rules engine” in OH 3. And Rules DSL language is one of the supported languages. So even with .rules files some of the above advantages will come to .rules files too.

1 Like

Gut instinct was on the money there.

2 Likes

You guys are amazing! Speaking of instinct, you always meantion Jython first, than JavaScript and Groovy. As my time is pretty limited, which of those three would you prefer to choose? I kind of can’t find an overview of Pros and Conts comparing those three. I don’t care about the complexity, just about posibilities and future-proof.

Jython it is.

1 Like

Frustrating. Not even by openhab console? If not, it seems like I will need to acomplish it by a bash script and crontab and updating by REST Api by scanning the rules folder and greping openhab.log. I will post the final script, i guess some people could use that too.