Openhab unstable after upgrade to 2.5

Hi,

After upgrading to 2.5 stable, my openhab rules are periodically reloading.

  • Platform information:
    • Hardware: Rapsberry pi 3b+
    • OS: Raspbian GNU/Linux 9 (stretch)
    • Java Runtime Environment: openjdk version “1.8.0_222”
    • openHAB version: 2.5.0.1

This behaviour started between 2.5 M5 and M6. I reported this here.

I had to downgrade to M5 to get Openhab usuable again. As RC1 had a MQTT bug, I was unable to test RC1. Now in 2.5 stable the problem is back.

What I am seeing is the same behaviour as when an item definition is changed, i.e by editing an items file. If that happens - as far as I can tell - rule files that are relevant to that item get reloaded. However, I am not touching my items in any way.

Note that the reloading of rules as a result of editing an item is something different from a change to a rules file itself. If that happens you get a corresponding line in your log file. This does not happen when a rule reloads as a result of edits to an item.

The reason that I know that my rules are being reloaded is that all my rule files have code similar to the following:

rule "System started Rule radiators"
when
        System started 
then
       	logInfo("System started Rule", "radiators done")
	Radiator_RulesActivated.postUpdate(ON)
end

What I am seeing is my rules get reloaded for no apparent reason. It might be that this is affecting other people as well, however, I am assuming most people won’t have the above code in their rule files. What they would probably see is cpu usage periodically spiking as openhab reloads rules and/or lags.

After downgrading to 2.5 M5, the behaviour is gone again. Does anybody have an idea what is going on, or how to debug this?

Check addons.cfg and addons.config for any bad addon entries or syntax errors. That can cause addons to reload constantly. That may also trigger System started rules.

Thank you. addons.cfg seems to be all commented out with #marks. I looked at addons.config. That is harder to judge. The file is below, but I do not know what I am looking for. I’m not seeing addons that I’m not using.

:org.apache.felix.configadmin.revision:=L"43"
binding=“buienradar,max,samsungtv,expire1,weather1,openweathermap,exec,astro,systeminfo,http1,hdpowerview,chromecast,zwave,enocean,mqtt,network,squeezebox,wifiled”
misc=“market,openhabcloud”
package=“standard”
persistence=“influxdb,mapdb”
service.pid=“org.openhab.addons”
transformation=“jsonpath,map,javascript,exec,bin2json,jinja,xpath,xslt,scale,regex”
ui=“basic,paper,habpanel,homebuilder,habmin,classic,restdocs”
voice=“marytts,mactts,picotts,voicerss”

Since upgrading have you tried stopping OH, cleaning the cache and rebooting?

sudo systemctl stop openhab2

sudo openhab-cli clean-cache

sudo reboot

After OH has fully restarted and everything has loaded you may need to stop OH and reboot a second time.

3 Likes

Do you anything on the definition of the item or does the .state of the item change?

Item changes state or you modify the definition of an Item?

Not for no apparent reason, reloaded because an Item changed. It’s still not clear what “changed” means though. We need more precise information.

Yes I have, mulitiple times.

I agree, it wasn’t clear, What I mean is my rules reloading as a result of the definition of an item being edited. However, the rules are reloading while I am not touching the system in any way.

I will edit my initial post to clarify.

An alternative interpretation based on the evidence - not reloading
(you are missing the logs that might produce), but simply triggering System started, as detected by your rules.
It’s a subtle difference but leads to possibly different causes.

I do think my rules are reloading, as i see the cpu going up to roughly 100%. The same as when my rules are loading when openhab starts. However, I agree, the only think I know for sure is that a System started event is triggered.

To make things weirder, not all rules have the System started event triggered. I am looking into what the rules that have their System started event triggered and those that don’t have in common or how they differ. For the moment, I dont see a pattern.

Probably silly question. Is your Java 8 version reasonably up to date? There was another user with a 2 year old version that had the cpu issue.

I assume so. I am on openhabian. I am fully updated. This is the result of java -version

openjdk version "1.8.0_222"
OpenJDK Runtime Environment (Zulu8.40.0.178-CA-linux_aarch32hf) (build 1.8.0_222-b178)
OpenJDK Client VM (Zulu8.40.0.178-CA-linux_aarch32hf) (build 25.222-b178, mixed mode, Evaluation)

Monitor the timestamps on all your xxx.rules files.

I do not suppose for one moment that they are being touched by something else, because you see no log.

I have made a log of them and will report if something changes, However, I do not think they are changing for the reason you state. As far as I can tell the last edit was made on December 12. That corresponds to the timestamps that I see in the daily backups of my openhab configuration.

Careful - some backup tools do touch files. I forgot to say that you should also check xxx.items files timestamps, an expected cause of “system started” trigger without rules loaded logs, and you may as well complete the set with any xxx.things files.

It’s not entirely clear if you have seen this problem since that ‘current’ timestamp of 12/12, but I presume so since you could not have updated to 2.5 release at that date.

When does your daily backup run, any connection?

Hi, thanks for all the help. The reloads are quite frequent. In fact the latest reload just started 10 minutes ago. I do not think there is a connection with the daily backup process. BTW I use the openhab backup script.

I can see reloads at:

  • 2019-12-17 21:24:25
  • 2019-12-17 19:25:05
  • 2019-12-17 17:24:27
  • 2019-12-17 15:24:45
  • 2019-12-17 13:24:21

Looking at this list the reloads seem to trigger every 2 hours. Is there a something in openhab running every two hours? I have checked

  • my cron jobs, nothing with a two hour trigger
  • all my rule files for cron triggers, nothing with a two hour trigger.
  • exec binding things, nothing that runs automatically
  • OpenWeatherMap, runs on a 10 minute cycle
  • Buienradar binding (rain forcast in the Netherlands), runs on a 5 minute cycle
  • Systeminfo binding (60 minutes)

What could explain the 2 hour cycle? BTW I see that when I previously reported the problem, there also was a 2 hour cycle. However, back then the minute the cycle started was not roughly 24 like today, but roughly 11. This makes me think that it is either linked to openhab or linux starting.

There’s nothing like that in OH by default unless you coded something yourself like a timer.

I’d suggest to install openHABian from scratch to another SD card and copy your config over. That may or may not show the same behavior but that way you can be sure it’s not some obscure part of the OS to cause that.

Most likely derived from hours after system boot time. Deeply weird, I have no useful suggestion. Confident you have set up no external service posting active REST calls in, like edits?

I will do that, however since updating to 2.5 I downgraded to 2.5 M5 a couple of times. If I do that, the problem goes away. If I upgrade to 2.5 stable the problem reappears like clockwork. As I said, I will give it a try if only to exclude possibilities.

Well, I do have tasker which uses rest calls. However, nothing on a 2 hour cycle, purely event driven. In addition my router posts a mqtt message when a phone connects to it. Other than that, I have a few cron jobs, posting the results to a REST call, however, that is not anywhere as often as on a two hour cycle.

Hi,

I recently upgraded to Openhab 2.5 and i have similar issues! Every some hours my load goes up and the system gets unresponsive (one openhab process using up 100 percent)
Here is my addons.config:

:org.apache.felix.configadmin.revision:=L"8"
action=“mail,pushbullet”
binding=“hue,network,nest,zwave,astro,expire1,miio,openweathermap,bosesoundtouch,mqtt1,systeminfo”
legacy=B"true"
misc=“market,ruleengine”
package=“standard”
persistence=“influxdb,rrd4j”
remote=B"true"
service.pid=“org.openhab.addons”
transformation=“jsonpath,javascript,regex,map”
ui=“basic,paper,habpanel,classic,habmin,habot,restdocs”
voice=“marytts,voicerss,googletts”

I dont see any Loading model messages after the initial loading on startup, but from the behaviour it feels like openhab would internally reload them or doing some other weird stuff every other hour. A threads --list gave me only some pool thread 5 as the one with the most cpu time…

Is there any way to dig deeper? I’d be happy to do so, but I don’t know the commands…

Thank you so much!

Mail action at least has changed for 2.5 ?