[2.2.0-SNAPSHOT] UI and services not installed as defined in addons.cfg

[zarusz]

Hello,

I have switched my openHAB installation from stable build (2.1.0-1) to snapshot releases (2.2.0~20170920221851-1 - openHAB 2.2.0 Build #1044). This was done using the debian package manager (apt-get update, apt-get upgrade).

Here is the list of issues that I am seeing on latest snapshot builds:

• The UIs and services declared in addons.cfg are not respected and nothing gets auto installed. There is nothing interesting in the openhab.log (see below).
• Clearing /var/lib/openhab/tmp (and cache) folders and doing openhab2.service restart helps until next reboot. Yet the UI, does not load my _default.sitemap.
• After reboot and openning the browsers http://<host>:8080/ the message gets displayed forever: Please stand by while UIs are being installed. This can take several minutes.. Manual page refresh after some time (1h) indicate no progress.

Now, reverting the openHAB version to stable 2.1.0-1 (having the same configs and addons.cfg) fixes all of the above symptoms. Therefore, I suspect this is a platform issue in the latest snapshots (2.2.0~X-1).

The issue is also described on the community topic.

Here is my addons.cfg:

package = minimal

# Access Remote Add-on Repository
# Defines whether the remote openHAB add-on repository should be used for browsing and installing add-ons.
# This not only makes latest snapshots of add-ons available, it is also required for the installation of
# any legacy 1.x add-on. (default is true)
#
remote = true

# Include legacy 1.x bindings. If set to true, it also allows the installation of 1.x bindings for which there is 
# already a 2.x version available (requires remote repo access, see above). (default is false)
#
legacy = true

# A comma-separated list of bindings to install (e.g. "sonos,knx,zwave")
binding = yamahareceiver,mqtt1,xbmc1,mqttitude1,yahooweather,weather1

# A comma-separated list of UIs to install (e.g. "basic,paper")
ui = basic,paper,habpanel

# A comma-separated list of persistence services to install (e.g. "rrd4j,jpa")
persistence = rrd4j

# A comma-separated list of actions to install (e.g. "mail,pushover")
#action = xbmc

# A comma-separated list of transformation services to install (e.g. "map,jsonpath")
transformation = map

# A comma-separated list of voice services to install (e.g. "marytts,freetts")
#voice = 

# A comma-separated list of miscellaneous services to install (e.g. "myopenhab")
#misc = 

Here is the openhab.log soon after starting openhab2.service:

2017-09-20 23:00:20.795 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.action.ActionService}={component.name=org.eclipse.smarthome.action.audio, component.id=117, service.id=675, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:20.847 [DEBUG] [org.eclipse.smarthome.model.script  ] - BundleEvent STARTING - org.eclipse.smarthome.model.script
2017-09-20 23:00:20.862 [DEBUG] [org.eclipse.smarthome.model.script  ] - BundleEvent STARTED - org.eclipse.smarthome.model.script
2017-09-20 23:00:20.911 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.action.ActionService}={component.name=org.eclipse.smarthome.action.persistence.action, component.id=119, service.id=679, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:20.933 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.voice.text.HumanLanguageInterpreter}={service.pid=org.eclipse.smarthome.rulehli, service.config.category=voice, service.config.label=Rule Voice Interpreter, component.name=org.eclipse.smarthome.rulehli, component.id=120, service.config.description.uri=voice:rulehli, service.id=680, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:20.967 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.jvmmodel.ScriptItemRefresher}={component.name=org.eclipse.smarthome.model.script.jvmmodel.scriptitemrefresher, component.id=121, service.id=681, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:21.021 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.ScriptServiceUtil}={component.name=org.eclipse.smarthome.model.script.ScriptServiceUtil, component.id=122, service.id=682, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:21.044 [DEBUG] [thome.model.script.ScriptServiceUtil] - ScriptServiceUtil started
2017-09-20 23:00:21.058 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.action.ActionService}={component.name=org.eclipse.smarthome.action.thing.action, component.id=123, service.id=683, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:21.079 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.action.ActionService}={component.name=org.eclipse.smarthome.action.transformation.action, component.id=124, service.id=684, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:21.098 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.action.ActionService}={component.name=org.eclipse.smarthome.action.voice, component.id=125, service.id=685, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:00:21.120 [DEBUG] [org.eclipse.smarthome.model.script  ] - BundleEvent [unknown:512] - org.eclipse.smarthome.model.script
2017-09-20 23:01:09.445 [DEBUG] [lipse.smarthome.model.script.runtime] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.ScriptEngine, org.eclipse.smarthome.model.core.ModelParser}={component.name=org.eclipse.smarthome.model.script, component.id=129, service.id=699, service.bundleid=131, service.scope=bundle} - org.eclipse.smarthome.model.script.runtime
2017-09-20 23:01:12.647 [DEBUG] [ime.internal.engine.ScriptEngineImpl] - Registered 'script' configuration parser
2017-09-20 23:01:13.312 [DEBUG] [org.eclipse.smarthome.model.script  ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.io.console.extensions.ConsoleCommandExtension}={component.name=org.eclipse.smarthome.model.script.engine.consolecommandextension, component.id=118, service.id=701, service.bundleid=130, service.scope=bundle} - org.eclipse.smarthome.model.script
2017-09-20 23:01:13.337 [DEBUG] [lipse.smarthome.model.script.runtime] - BundleEvent STARTING - org.eclipse.smarthome.model.script.runtime
2017-09-20 23:01:13.358 [DEBUG] [lipse.smarthome.model.script.runtime] - BundleEvent STARTED - org.eclipse.smarthome.model.script.runtime

JDK version is latest for my Raspbian Stretch distro:

java version "1.8.0_65"
Java(TM) SE Runtime Environment (build 1.8.0_65-b17)
Java HotSpot(TM) Client VM (build 25.65-b01, mixed mode)

[mstormi]

There's quite a number of possible reasons under the hood for long startup times.
I have a similar problem.

One of these reasons is that you want or need OH to fetch legacy bindings from a remote repo. See if you can disable that (i.e. remote = false in addons.cfg).
Also, you should definitely upgrade your Java. There ARE newer versions available (I'm running 1.8.0_u144, and I'm still on jessie !), please google for how to obtain that.

[kaikreuzer]

@zarusz This might be related to openhab/openhab-distro#519.
If you take a plain installation, the addon installation works smoothly.

It would be good if you could figure out a way to reproduce it with a normal installation - otherwise I do not see any chance to analyse what might be the issue as the logs are not really helpful.

[zarusz]

@kaikreuzer what do you mean by a "normal installation"? :) Should I install from scratch rather than via an upgrade process?

@mstormi I did upgrade to latest JDK yesterday, however I am still on stable OH2.1 release. Today I plan to upgrade to latest snapshot again and check if the issue got resolved.
Also to be clear, my issue was not slow install of addons and rather the addon installation getting stuck entirely for no reason.

[zarusz]

I have installed latest JDK 8 (see below) and upgraded to latest OH snapshot (2.2.0~20170928165715-1). This did not resolve the issue. It pretty much misbehaves in the same way as I described earlier.

java version "1.8.0_144"
Java(TM) SE Runtime Environment (build 1.8.0_144-b01)
Java HotSpot(TM) Client VM (build 25.144-b01, mixed mode)

My next step is to wipe out the existing OH install and setup everything from scratch. 😕

[zarusz]

Alright, I performed a clean install of snapshot 2.2 (openHAB 2.2.0 Build #1051).

Here are the steps to reproduce:

1. First start of OH service after install (none of my configs yet) -> Fine.
2. Customize addons.cfg (see file content above) and drop my other items/sitemaps -> Fine.
3. Restart OH service -> Fail (no addons installed, no UIs).
4. Stop OH service, delete /var/lib/tmp and /var/lib/cache, start OH service -> Fine.

So basically, I am at a stage where it works unless I restart my RaspberryPi or OH.

Can anyone else reproduce this?

[hreichert]

Yes, same problem here.
Sometimes a double-restart resolves the problem for me.
But sometimes I need to follow the procedure that @zarusz mentioned.

Also I get other errors that are maybe related to https://github.com/openhab/openhab-distro/pull/538/files

@zarusz Do you use online or offline repo?

[kaikreuzer]

@zarusz Do you use online or offline repo?

Note that if it is "offline", this behavior is the known bug I mentioned above (see also openhab/openhab-distro#538 (comment)).

"offline" meaning here that you have placed the kar file in the addons folder. Are you sure that you have those issues even without a kar? In that case, there should be really something helpful in your logs.

[hreichert]

Ok, so MY problem would be 538 as I use the addons .kar file.
Haven't tried it with online repo yet.

[zarusz]

@kaikreuzer and @hreichert I did not put anything manually in my addons folder. I followed the Linux install instructions here which pulls the addons using apt-get. I think this is the online install. Does this help?

Soon, I will also check the addons folder content, check if anything interesting in the logs and let you know again.

[zarusz]

@zarusz This might be related to openhab/openhab-distro#519.
If you take a plain installation, the addon installation works smoothly.

@kaikreuzer I double checked and indeed I had an addons JAR already present in the addons folder. Once I deleted the JAR, consequent restarts work without having to delete cache/tmp.

I am closing this ticket as it is a duplicate of /openhab-distro/issues/519