Hi @m3tatai, does this keep happening with the latest snapshot? I thought this would have been improved after #1103.
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.
Is this with a apt or manual install? It would be good to investigate this further.
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.
And are you using the openhab2-addons* packages?
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.baseExcellent, 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?
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…
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.
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.
This might have been your java process was also updated? But yes please, any information you can give me so that I can look into it will be great.
As a tip, if the service isn’t working, then you can view the logfile for the service with:
sudo journalctl -u openhab2.service -b
Useful to know. My fat fingers just had me remove the /usr/ dir, so if my OS wasnt broken before, it is now.
Clean OS (Raspbian Stretch Lite), fiddling to get Oracle Java installed and then running the apt-get on the unstable, has me with a working OpenHab instance.
Now just to reconfigure it all :s
1 Like
There was no java update, it was only:
Upgrade: raspi-config:armhf (20171127, 20171201), openhab2:armhf (2.2.0~20171203035709-1, 2.2.0~20171204165516-1)
The service itself was running ok in terms of stop/start, openhab.log was reflecting requests, just not sure why a reboot worked as I have run Linux servers for long enough that I generally know when I should reboot and to me this didn’t deserve it. But as it was enough for now I can’t reproduce so I’ll progress on testing 2.1 migration and see if it plays ball. Thanks.
1 Like
My OH install is also no longer starting up. Unsure what could have caused it with only doing a stop of OH2 and then a reboot of Ubunut
This is what I see:
- Logs begin at Mon 2017-12-04 18:42:48 EST, end at Mon 2017-12-04 19:05:10 EST. --
Dec 04 18:43:08 OpenHab2 systemd[1]: Started openHAB 2 - empowering the smart home.
Dec 04 18:43:18 OpenHab2 karaf[1137]: There is a Root instance already running with name openhab and pid 113
Dec 04 18:43:18 OpenHab2 systemd[1]: openhab2.service: Main process exited, code=exited, status=1/FAILURE
Dec 04 18:43:24 OpenHab2 karaf[1496]: Can't connect to the container. The container is not running.
Dec 04 18:43:24 OpenHab2 systemd[1]: openhab2.service: Control process exited, code=exited status=1
Dec 04 18:43:24 OpenHab2 systemd[1]: openhab2.service: Unit entered failed state.
Dec 04 18:43:24 OpenHab2 systemd[1]: openhab2.service: Failed with result 'exit-code'.
Dec 04 18:43:29 OpenHab2 systemd[1]: openhab2.service: Service hold-off time over, scheduling restart.
Dec 04 18:43:29 OpenHab2 systemd[1]: Stopped openHAB 2 - empowering the smart home.
Dec 04 18:43:29 OpenHab2 systemd[1]: Started openHAB 2 - empowering the smart home.
Dec 04 18:43:30 OpenHab2 karaf[1747]: There is a Root instance already running with name openhab and pid 113
Dec 04 18:43:30 OpenHab2 systemd[1]: openhab2.service: Main process exited, code=exited, status=1/FAILURE
Dec 04 18:43:30 OpenHab2 karaf[1878]: Can't connect to the container. The container is not running.
Dec 04 18:43:30 OpenHab2 systemd[1]: openhab2.service: Control process exited, code=exited status=1
Dec 04 18:43:30 OpenHab2 systemd[1]: openhab2.service: Unit entered failed state.
Dec 04 18:43:30 OpenHab2 systemd[1]: openhab2.service: Failed with result 'exit-code'.
Dec 04 18:43:35 OpenHab2 systemd[1]: openhab2.service: Service hold-off time over, scheduling restart.
Dec 04 18:43:35 OpenHab2 systemd[1]: Stopped openHAB 2 - empowering the smart home.
Dec 04 18:43:35 OpenHab2 systemd[1]: Started openHAB 2 - empowering the smart home.
Dec 04 18:43:35 OpenHab2 karaf[2027]: There is a Root instance already running with name openhab and pid 113
Dec 04 18:43:35 OpenHab2 systemd[1]: openhab2.service: Main process exited, code=exited, status=1/FAILURE
Dec 04 18:43:36 OpenHab2 karaf[2158]: Can't connect to the container. The container is not running.
Dec 04 18:43:36 OpenHab2 systemd[1]: openhab2.service: Control process exited, code=exited status=1
Dec 04 18:43:36 OpenHab2 systemd[1]: openhab2.service: Unit entered failed state.
Dec 04 18:43:36 OpenHab2 systemd[1]: openhab2.service: Failed with result 'exit-code'.EDIT. Did a reinstall of OH2 with and that got the service started, but then same issues with the UIs not loading and the above error I mentioned up above.
sudo apt-get install --reinstall openhab2Okay, that’s interesting. This particular line:
Dec 04 18:43:30 OpenHab2 karaf[1747]: There is a Root instance already running with name openhab and pid 113
Says that openHAB is already running. Are you up and running with:
sudo kill -9 113
sudo systemctl daemon-reload
sudo systemctl enable openhab2.service
sudo systemctl start openhab2.service
Replied before seeing you edit, will reply with more info too.
@ptmuldoon, would you be able to temporarily disable the three bindings in your addons folder? I’m curious to see if this is still the root cause of the issue?
OK. I removed all 3 bindings from the Addon’s folder, and that did appear to get rid of the earlier errors of felix.fileinstall, but after Stop and Start of OH2, did get this weird error, although the Uis did load
2017-12-04 19:38:24.947 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2017-12-04 19:38:24.996 [ERROR] [org.apache.felix.scr ] - Circular reference detected trying to get service {org.openhab.ui.dashboard.DashboardTile}={component.name=org.openhab.ui.basicui.dashboardtile, component.id=194, service.id=299, service.bundleid=213, service.scope=bundle}
stack of references: ServiceReference: {org.openhab.ui.dashboard.DashboardTile}={component.name=org.openhab.ui.basicui.dashboardtile, component.id=194, service.id=299, service.bundleid=213, service.scope=bundle}
ServiceReference: {org.openhab.ui.dashboard.internal.DashboardService}={component.name=org.openhab.dashboard, component.id=195, service.id=300, service.bundleid=191, service.scope=bundle}
java.lang.Exception: stack trace
at org.apache.felix.scr.impl.ComponentRegistry.enterCreate(ComponentRegistry.java:510) ~[?:?]
at org.apache.felix.scr.impl.BundleComponentActivator.enterCreate(BundleComponentActivator.java:809) ~[?:?]
at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:817) ~[?:?]
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) ~[?:?]
.....
..... Alot moreAnd then after a separate OH2 stop and system restart, that error is gone and things look good.
I then stopped OH2 again, put the bindings back into the AddOns folder, and another system restart and I am not seeing that felix.fileinstall, error this time. Although I am seeing a bunch of Hue binding errors.
2017-12-04 19:59:38.782 [WARN ] [ome.core.thing.internal.ThingManager] - Initializing handler for thing 'hue:0210:00178824e7e9:1' takes more than 5000ms.
2017-12-04 19:59:38.829 [WARN ] [nal.common.AbstractInvocationHandler] - Timeout of 5000ms exceeded while calling method 'ThingHandler.initialize()' on 'org.eclipse.smarthome.binding.hue.handler.HueLightHandler@1945d42'. Thread 'safeCall-8' (254) is in state 'WAITING'
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at org.eclipse.smarthome.core.thing.internal.ThingManager.thingUpdated(ThingManager.java:406)
at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTrackers(ThingRegistryImpl.java:222)
at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:145)
at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:1)
at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(AbstractRegistry.java:188)
at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(AbstractRegistry.java:1)
at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:62)
at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListenersAboutUpdatedElement(AbstractProvider.java:86)
at org.eclipse.smarthome.core.common.registry.AbstractManagedProvider.update(AbstractManagedProvider.java:132)
at org.eclipse.smarthome.core.thing.internal.ThingManager$1$1.run(ThingManager.java:233)
at org.eclipse.smarthome.core.thing.internal.ThingManager$1$1.run(ThingManager.java:1)
at java.security.AccessController.doPrivileged(Native Method)
...And the after 1 more OH2 stop and start (no reboot), the Circular error is back. And then after yet another Stop and Start, no errors this time.
So OH2 appears to be currently running, but am getting those strange errors.
Almost like clockwork, OH2 froze up again at 6:30am here for me again with the Blacklist Error. And I did delete the cache and tmp directories about 2 days ago.
Currently on Build 1112
017-12-05 06:29:54.858 [WARN ] [org.apache.karaf.services.eventadmin] - EventAdmin: Blacklisting ServiceReference [{org.osgi.service.event.EventHandler, org.eclipse.smarthome.core.events.EventPublisher}={event.topics=smarthome, component.name=org.eclipse.smarthome.core.internal.events.OSGiEventManager, component.id=49, service.id=147, service.bundleid=111, service.scope=bundle} | Bundle(org.eclipse.smarthome.core_0.9.0.201712011551 [111])] due to timeout!
2017-12-05 06:29:55.511 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread HTTP Refresh Service
java.lang.NullPointerException: null
2017-12-05 06:29:56.511 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread HTTP Refresh Service
java.lang.NullPointerException: null
2017-12-05 06:29:56.557 [WARN ] [org.apache.karaf.services.eventadmin] - EventAdmin: Blacklisting ServiceReference [{org.osgi.service.event.EventHandler, org.eclipse.smarthome.core.events.EventPublisher}={event.topics=smarthome, component.name=org.eclipse.smarthome.core.internal.events.OSGiEventManager, component.id=49, service.id=147, service.bundleid=111, service.scope=bundle} | Bundle(org.eclipse.smarthome.core_0.9.0.201712011551 [111])] due to timeout!
2017-12-05 06:29:57.381 [WARN ] [org.apache.karaf.services.eventadmin] - EventAdmin: Blacklisting ServiceReference [{org.osgi.service.event.EventHandler, org.eclipse.smarthome.core.events.EventPublisher}={event.topics=smarthome, component.name=org.eclipse.smarthome.core.internal.events.OSGiEventManager, component.id=49, service.id=147, service.bundleid=111, service.scope=bundle} | Bundle(org.eclipse.smarthome.core_0.9.0.201712011551 [111])] due to timeout!
2017-12-05 06:29:57.512 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread HTTP Refresh Service
java.lang.NullPointerException: null
2017-12-05 06:29:57.584 [WARN ] [org.apache.karaf.services.eventadmin] - EventAdmin: Blacklisting ServiceReference [{org.osgi.service.event.EventHandler, org.eclipse.smarthome.core.events.EventPublisher}={event.topics=smarthome, component.name=org.eclipse.smarthome.core.internal.events.OSGiEventManager, component.id=49, service.id=147, service.bundleid=111, service.scope=bundle} | Bundle(org.eclipse.smarthome.core_0.9.0.201712011551 [111])] due to timeout!
2017-12-05 06:29:58.616 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread HTTP Refresh Service
java.lang.NullPointerException: null
2017-12-05 06:30:02.251 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread HTTP Refresh Service
java.lang.NullPointerException: null
2017-12-05 06:30:02.256 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 5e173177-a9ee-47cc-a2bb-ec0f655ee0f8, base URL = http://localhost:8080)I’m using the latest build and still got this problems.