Since upgrading to unstable 1104/1106 OH2.2.0 doesnt run

Vini · December 3, 2017, 11:25pm

I’m a Pi3 user running the apt-get instance of the unstable version of 2.2.0.

In 2.2.0 1102 I was noticing my Z-Wave would drop occasionally (roughly after 24 hours). The Zwave controller (Aeon ZStick Gen2) would remain initialised but all nodes would be offline/uninitialised.

In my previous occurrence when this happened, I simply updated Openhab and the problem went away for a while longer. It happened again on Friday so I upgraded my OH2 platform to at the time 1104. This took me further from the solution, in that OH2 wouldn’t even run then.

When upgrading, I stop the service, clear /cache/ and /tmp/, and perform an apt-get install --reinstall on both openhab2 and openhab2-addons. This generally, hasn’t caused me any grief, until 1104.

Thinking 1104 might be fundamentally broken, I’ve done the same again tonight, this time I’ve received 1106, but still getting the same issue.

OH2 ‘does run’ but sits at “Please stand by while UIs are being installed. This can take several minutes.” no matter how long I leave it, it sits there.

Any ideas of how I could troubleshoot this? What log options should I change? I tend not to use Karaf, but instead, monitor openhab.log in a log viewer. In org.ops4j.pax.logging.cfg I have changed the OpenHAB and Smarthome from INFO to TRACE… is there any other’s I could change/investigate?

openHAB specific logger configuration

log4j2.logger.openhab.name = org.openhab
log4j2.logger.openhab.level = TRACE

log4j2.logger.smarthome.name = org.eclipse.smarthome
log4j2.logger.smarthome.level = TRACE

Benjy · December 4, 2017, 12:07am

To clarify openHAB does start but doesn’t get past the installing UIs stage?

There should be errors (not just info’s or traces) printed in openhab.log for a problem like this. Are there any?

One issue that comes to mind is one that the unstable builds have had recently but is now fixed. Could you check the contents of /var/lib/openhab2/etc/org.openhab.addons.cfg to see if it contains quote marks? It shouldn’t so if there is, then these should be removed. For example:

package = standard
ui = basic,paper,habpanel,habmin
binding = amazondashbutton,hue,zwave,ntp,astro,systeminfo
transformation =
persistence = mapdb,influxdb
remote = true
misc = restdocs,lsp,ruleengine

You should also be aware that using the addons packages can stop the latest snapshots from working. There is an issue being worked on to resolve this.

Vini · December 4, 2017, 12:50pm

OH2 service runs, but it sits at “Loading UIs”… I left it overnight, 13 hours or so, and woke to the same message. I have experienced the same issue you mention above, my org.openhab.addons.cfg looks “clean”.

I even removed that file and hoped addons.cfg would re-populate it. To no avail.

I’ve just done a very granular clean down, and short of uninstalling, I don’t know what else I can do now.

I’m now running #1109. But still facing the same issues. It’s been sat loading UI for an hour.

Vini · December 4, 2017, 2:12pm

Had no joy, uninstalled. Nuked all directories, reinstalled from apt-get, still not having much luck.

Dries · December 4, 2017, 3:15pm

Do you see anything strange in openhab.log?

Vini · December 4, 2017, 3:35pm

Clearly got myself in an OH2 pickle again. This is a completely clean install (clean, as in uninstalled, nuked dirs)…

openhab.log now just reads;

Dec 04, 2017 3:28:00 PM org.apache.karaf.main.Main launch
INFO: Installing and starting initial bundles
Dec 04, 2017 3:28:04 PM org.apache.karaf.main.Main launch
INFO: All initial bundles installed and set to start
Dec 04, 2017 3:28:04 PM org.apache.karaf.main.lock.SimpleFileLock lock
INFO: Trying to lock /var/lib/openhab2/tmp/lock
Dec 04, 2017 3:28:04 PM org.apache.karaf.main.lock.SimpleFileLock lock
INFO: Lock acquired
Dec 04, 2017 3:28:04 PM org.apache.karaf.main.Main$KarafLockCallback lockAquired
INFO: Lock acquired. Setting startlevel to 100

I’ve even elected to go back to an earlier build (2.2.0~20171125131803-1) and am facing the same thing.

The service is starting, but thats about it;

vini@openhab2:~ $ sudo systemctl status openhab2.service
[sudo] password for vini:
● openhab2.service - openHAB 2 - empowering the smart home
Loaded: loaded (/usr/lib/systemd/system/openhab2.service; enabled; vendor preset: enabled)
Active: active (running) since Mon 2017-12-04 15:27:51 UTC; 3min 49s ago
Docs: http://docs.openhab.org
https://community.openhab.org
Main PID: 469 (java)
CGroup: /system.slice/openhab2.service
└─469 /usr/bin/java -Dopenhab.home=/usr/share/openhab2 -Dopenhab.conf=/etc/openhab2 -Dopenhab.runtime=/usr/share/openhab2/runtime -Dopenhab.userdata=/var/lib/openhab2 -Dopenhab.logdir=/var/log/openhab2 -Dfelix.cm.dir=/var/lib/
Dec 04 15:27:51 openhab2 systemd[1]: Started openHAB 2 - empowering the smart home.

netstat doesn’t even show a port as being opened…

m3tatai · December 4, 2017, 5:47pm

Same problems here. After fixing the problem in addons.cfg , everything is fine. After another update / restart the problem is back again.

EDIT: Even after restarting the service,

package = expert
ui = "paper,basic"
transformation = map,regex,xslt,exec,javascript,scale,xpath,jsonpath
remote = true
binding = homematic,milight,wol1,network
misc = restdocs
is back again.

RayMYP · December 4, 2017, 6:17pm

Could be related to one of the issues that seems to have been on going for a while with snapshots where by installation of openhab2-addons gets things messed up on restarts. Only just started dabbling in snapshots myself this week and got very frustrated with trying to get a clean snapshot install (based on the documentation) running on a clean machine and eventually nailed it to this lot:

So I’ve now got a clean OH snapshot running without doing the apt-get for the addons and I’m testing migration of my OH2.1 version stuff. Basically the addons are available from the online repos so you can live without them offline.

Not sure if the latest and greatest snapshot should now have a proper fix (or is in the build pipeline) as the maintainers are talking about prerparing for a 2.2 release.

Vini · December 4, 2017, 7:03pm

I can’t even get the Stable to run - the HTTP server suggests its running, but just gives Error 404. Jetty not found.

I’m gonna blow my OS, grrrr

Dec 04, 2017 6:51:27 PM org.apache.karaf.main.Main launch
INFO: Installing and starting initial bundles
Dec 04, 2017 6:51:28 PM org.apache.karaf.main.Main launch
INFO: All initial bundles installed and set to start
Dec 04, 2017 6:51:28 PM org.apache.karaf.main.lock.SimpleFileLock lock
INFO: Trying to lock /var/lib/openhab2/tmp/lock
Dec 04, 2017 6:51:28 PM org.apache.karaf.main.lock.SimpleFileLock lock
INFO: Lock acquired
Dec 04, 2017 6:51:28 PM org.apache.karaf.main.Main$KarafLockCallback lockAquired
INFO: Lock acquired. Setting startlevel to 100
2017-12-04 18:52:58.529 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.11:8181
2017-12-04 18:52:58.536 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.11:8443
2017-12-04 18:57:31.186 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
Dec 04, 2017 6:58:15 PM org.apache.karaf.main.lock.SimpleFileLock lock
INFO: Trying to lock /var/lib/openhab2/tmp/lock
Dec 04, 2017 6:58:15 PM org.apache.karaf.main.lock.SimpleFileLock lock
INFO: Lock acquired
Dec 04, 2017 6:58:15 PM org.apache.karaf.main.Main$KarafLockCallback lockAquired
INFO: Lock acquired. Setting startlevel to 100
2017-12-04 18:58:59.598 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.11:8181
2017-12-04 18:58:59.644 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.11:8443

Benjy · December 4, 2017, 7:54pm

I’m curious as to how you uninstalled. By “nuke directories”, do you mean manually deleted directories, then APT would have seen this as a user configuration, and would not have repopulated items when you reinstalled.

To completely wipe openHAB’s directories (move anything important away first):

sudo apt purge openhab2* && sudo apt install openhab2

Then try starting again to see if this works, if not then there’s definately something wrong with your OS configuration.

Benjy · December 4, 2017, 7:58pm

Hi @m3tatai, does this keep happening with the latest snapshot? I thought this would have been improved after #1103.

ptmuldoon · December 4, 2017, 8:11pm

I’m still seeing these issues on the current 1112 build. After upgrading today, I am also getting stuck on the installing UIs.

I can often get back up and running with a manual stop and start of OH2, or a Stop OH2 and the reboot of the server.

Benjy · December 4, 2017, 8:13pm

Is this with a apt or manual install? It would be good to investigate this further.

ptmuldoon · December 4, 2017, 8:16pm

I am on Ubuntu 16 Server running as a VM with ESXi server and using apt-get install and upgrades. Just had the stuck at UIs earlier today after the upgrade to 1112. But can typically get it going with a reboot.

Benjy · December 4, 2017, 8:17pm

And are you using the openhab2-addons* packages?

ptmuldoon · December 4, 2017, 8:21pm

Yes, and I think that is where the problem is occurring. I have 3 addons in my \usr\share\openhab2\addons directory, They are the test security zwave binding, osram lightify, and myq addons. And in the logs, I can see those 3 bindings are getting an error with an uresolved requirement of com.google.common.base

2017-12-04 13:48:30.509 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zwave-2.2.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zwave [11]
  Unresolved requirement: Import-Package: com.google.common.collect

	at org.eclipse.osgi.container.Module.start(Module.java:444) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) [?:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1253) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1225) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:512) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:361) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:312) [8:org.apache.felix.fileinstall:3.5.8]
2017-12-04 13:48:30.523 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.myq-1.10.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.myq [12]
  Unresolved requirement: Import-Package: com.google.common.base

	at org.eclipse.osgi.container.Module.start(Module.java:444) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) [?:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1253) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1225) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:512) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:361) [8:org.apache.felix.fileinstall:3.5.8]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:312) [8:org.apache.felix.fileinstall:3.5.8]
2017-12-04 13:48:30.527 [WARN ] [org.apache.felix.fileinstall        ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.osramlightify-2.2.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.osramlightify [10]
  Unresolved requirement: Import-Package: com.google.common.base

Benjy · December 4, 2017, 8:23pm

Excellent, that might be a good place to start. @Kai, I recognise felix.fileinstall as a cause for a hanging start up. What’s your take on this?

Vini · December 4, 2017, 10:14pm

Hi Benji,

I did apt-get remove openhab2* and then manually removed the leftover files in the dirs…

Followed by an apt-get install openhab2…

RayMYP · December 4, 2017, 10:28pm

I just did an ‘apt-get update’ to the latest #1112 and it killed startup of my simple test installation, wouldn’t load the UIs. Before the update it was apt-get installed without addons as previously said, plenty of reinstalls with purges to get it running. Wouldn’t usually consider a server reboot for this sort of software but did give it a shot and it worked?! That would suggest the service management wasn’t or isn’t stop/starting properly although only did the documented method. I’ll pay a little more attention the services and processes if it shows again.

Benjy · December 4, 2017, 10:31pm

Yes, that wouldn’t have worked, because configurable system files won’t replace themselves. To do this without a purge you must specify:

sudo apt-get -o Dpkg::Options::="--force-confmiss" install openhab2

This isn’t just for openHAB however, this is the same for anything apt installed. To clean everything related to a program you must use apt-get purge. If you manually delete things without purging, the things set as “configurable” won’t replace themselves because apt assumes that deleting the file was a choice you made.