Ah - ok, sorry, I didn’t realise that. So we were referring to different versions of the same log…
In any case, I think the root of the problem is the Circular reference detected error so I don’t think there’s too much else to look at. Looking at the log you emailed (since I’m home now) it looks fine once the binding starts - ie after this error.
Ok. If the circular reference is the cause, I’ll keep an eye on that and, when fixed, I’ll verify that the intermittent behavior on startup also goes away.
Thanks, and sorry for the confusion.
So, I tried to update last week-end, as well as today, and I had to go back to an early june snapshot both times, to get things working again.
Is this what is expected? I think I read somewhere that the “circular problem” could be avoided by trying to restart, but I am not successful in this. The zwave binding starts, but I get lots of (timeout-, sending-, can-) errors, and everything is unusable.
So I’m getting (trunkated headlines);
16:52:51.322 [ERROR] [org.eclipse.smarthome.model.script ] - [org.eclipse.smarthome.action.transformation.action(85)] Circular reference detected, getService returning null
16:52:51.341 [WARN ] [org.eclipse.smarthome.model.script ] - FrameworkEvent WARNING - org.eclipse.smarthome.model.script
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
And:-
16:52:54.020 [ERROR] [ui.habmin.internal.servlet.HABminApp] - Error during HABmin servlet startup
org.osgi.service.http.NamespaceException: alias: '/habmin' is already in use in this or another context
at org.ops4j.pax.web.service.spi.model.ServerModel.addServletModel(ServerModel.java:130)
at org.ops4j.pax.web.service.internal.HttpServiceStarted.registerServlet(HttpServiceStarted.java:207)
at org.ops4j.pax.web.service.internal.HttpServiceStarted.registerResources(HttpServiceStarted.java:258)
at org.ops4j.pax.web.service.internal.HttpServiceProxy.registerResources(HttpServiceProxy.java:71)
at org.openhab.ui.habmin.internal.servlet.HABminApp.activate(HABminApp.java:30)
And
16:52:54.382 [ERROR] [org.glassfish.jersey.internal.Errors] - Following issues have been detected:
WARNING: A resource model has ambiguous (sub-)resource method for HTTP method GET and input mime-types as defined by"@Consumes" and "@Produces" annotations at Java methods public javax.ws.rs.core.Response org.openhab.ui.habmin.internal.services.dashboard.DashboardResource.httpGetDashboards(javax.ws.rs.core.HttpHeaders) and public javax.ws.rs.core.Response org.openhab.ui.habmin.internal.services.dashboard.DashboardResource.httpGetDashboards(javax.ws.rs.core.HttpHeaders) at matching regular expression /habmin/dashboards. These two methods produces and consumes exactly the same mime-types and therefore their invocation as a resource methods will always fail.None of these errors seem to be related to ZWave… Maybe it’s worth commenting on the Github issue as I suspect given the title of this thread, you might not otherwise get an answer…
Good suggestion, @chris, @Kai . As a first step, I’m retitling this thread, removing the zwave tag, and summarizing the behavior that I’m seeing.
This behavior started with the 6/19 build, and continues through the most current build. At the time I was installing builds on almost a daily basis. This behavior did not occur in the 6/17 and prior builds (I think I skipped installing the 6/18 build, so I don’t know about that one).
Here’s the summary of what I’m seeing:
2016-06-20 10:38:43.635 [WARN ] [org.eclipse.smarthome.model.script ] - FrameworkEvent WARNING - org.eclipse.smarthome.model.script
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
> 2016-06-20 10:38:47.723 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'zwave:device:1556e3ab04f:node3' has been added. > 2016-06-20 10:38:47.800 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'zwave:device:1556e3ab04f:node6' has been added. > 2016-06-20 10:38:47.807 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'zwave:serial_zstick:1556e3ab04f' has been added. > 2016-06-20 10:38:47.870 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_device_1556e3ab04f_node3_scene_number' has been added. > 2016-06-20 10:38:47.872 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_device_1556e3ab04f_node3_scene_number-zwave:device:1556e3ab04f:node3:scene_number' has been added. > 2016-06-20 10:38:47.875 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_device_1556e3ab04f_node6_scene_number' has been added. > 2016-06-20 10:38:47.878 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_device_1556e3ab04f_node6_scene_number-zwave:device:1556e3ab04f:node6:scene_number' has been added. > 2016-06-20 10:38:47.886 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_device_1556e3ab04f_node6_switch_dimmer' has been added. > 2016-06-20 10:38:47.889 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_device_1556e3ab04f_node6_switch_dimmer-zwave:device:1556e3ab04f:node6:switch_dimmer' has been added. > 2016-06-20 10:38:47.894 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_1556e3ab04f_serial_ack' has been added. > 2016-06-20 10:38:47.896 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_1556e3ab04f_serial_ack-zwave:serial_zstick:1556e3ab04f:serial_ack' has been added. > 2016-06-20 10:38:47.902 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_1556e3ab04f_serial_can' has been added. > 2016-06-20 10:38:47.908 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_1556e3ab04f_serial_can-zwave:serial_zstick:1556e3ab04f:serial_can' has been added. > 2016-06-20 10:38:47.917 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_1556e3ab04f_serial_nak' has been added. > 2016-06-20 10:38:47.921 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_1556e3ab04f_serial_nak-zwave:serial_zstick:1556e3ab04f:serial_nak' has been added. > 2016-06-20 10:38:47.932 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_1556e3ab04f_serial_oof' has been added. > 2016-06-20 10:38:47.934 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_1556e3ab04f_serial_oof-zwave:serial_zstick:1556e3ab04f:serial_oof' has been added. > 2016-06-20 10:38:47.936 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_1556e3ab04f_serial_sof' has been added. > 2016-06-20 10:38:47.938 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_1556e3ab04f_serial_sof-zwave:serial_zstick:1556e3ab04f:serial_sof' has been added. > 2016-06-20 10:38:50.530 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui > 2016-06-20 10:38:50.744 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start > 2016-06-20 10:38:50.755 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTING - org.openhab.binding.zwave > 2016-06-20 10:38:50.760 [DEBUG] [inding.zwave.internal.ZWaveActivator] - ZWave binding started. Version 2.0.0.201606200830 > 2016-06-20 10:38:51.019 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.ConfigOptionProvider, org.eclipse.smarthome.config.core.ConfigDescriptionProvider}={component.name=org.openhab.binding.zwave.ConfigDescription, component.id=156, service.id=274, service.bundleid=188, service.scope=bundle} - org.openhab.binding.zwave > 2016-06-20 10:38:51.029 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.zwave.internal.ZWaveHandlerFactory, component.id=157, service.id=275, service.bundleid=188, service.scope=bundle} - org.openhab.binding.zwave > 2016-06-20 10:38:51.094 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:aeon_dsa03202_00_000, thing.id=zwave:device:1556e3ab04f:node3, service.id=276, service.bundleid=188, service.scope=singleton} - org.openhab.binding.zwave > 2016-06-20 10:38:51.106 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:1556e3ab04f:node3' changed from UNINITIALIZED to INITIALIZING > 2016-06-20 10:38:51.118 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=277, service.bundleid=188, service.scope=singleton} - org.openhab.binding.zwave > 2016-06-20 10:38:51.147 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:leviton_vrp03_00_000, thing.id=zwave:device:1556e3ab04f:node6, service.id=278, service.bundleid=188, service.scope=singleton} - org.openhab.binding.zwave > 2016-06-20 10:38:51.153 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=279, service.bundleid=188, service.scope=singleton} - org.openhab.binding.zwave > 2016-06-20 10:38:51.158 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:1556e3ab04f:node6' changed from UNINITIALIZED to INITIALIZING > 2016-06-20 10:38:51.195 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:serial_zstick, thing.id=zwave:serial_zstick:1556e3ab04f, service.id=280, service.bundleid=188, service.scope=singleton} - org.openhab.binding.zwave > 2016-06-20 10:38:51.213 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTED - org.openhab.binding.zwave > 2016-06-20 10:38:51.215 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:1556e3ab04f' changed from UNINITIALIZED to INITIALIZING
After that there’s nothing. Initialization of the stick and nodes never starts.
When things start normally I would see messages like this.
2016-06-20 09:35:30.622 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler.
2016-06-20 09:35:30.631 [INFO ] [me.event.ThingStatusInfoChangedEvent] - ‘zwave:device:1556de5cdb3:node3’ changed from INITIALIZING to OFFLINE
2016-06-20 09:35:30.633 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller initialised.
@Override public void initialize() { logger.debug("Initializing ZWave thing handler.");
Any help on this would be much appreciated.
Strangely, having changed nothing in my system over the past couple of days, I’m now also seeing this…
If I stop/start the binding on the console, then I only see the service registration messages -:
21:36:30.104 [DEBUG] [inding.zwave.internal.ZWaveActivator] - ZWave binding stopped.
21:36:30.105 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STOPPED - org.openhab.binding.zwave
21:36:33.416 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTING - org.openhab.binding.zwave
21:36:33.417 [DEBUG] [inding.zwave.internal.ZWaveActivator] - Z-Wave binding started. Version 2.0.0.201607020102
21:36:33.422 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTED - org.openhab.binding.zwave
21:36:33.430 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.zwave.internal.ZWaveHandlerFactory, component.id=219, service.id=380, service.bundleid=201, service.scope=bundle} - org.openhab.binding.zwave
21:36:33.433 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:qubino_zmnhba_00_000, thing.id=zwave:device:1531045fdae:node12, service.id=381, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.435 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=382, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.437 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:tkb_tz88_00_000, thing.id=zwave:device:1531045fdae:node13, service.id=383, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.440 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=384, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.443 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:fibaro_fgd211_00_000, thing.id=zwave:device:1531045fdae:node2, service.id=385, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.445 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=386, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.448 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:fibaro_fgd211_00_000, thing.id=zwave:device:1531045fdae:node4, service.id=387, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.453 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=388, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.455 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:serial_zstick, thing.id=zwave:serial_zstick:1531045fdae, service.id=389, service.bundleid=201, service.scope=singleton} - org.openhab.binding.zwave
21:36:33.462 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.ConfigOptionProvider, org.eclipse.smarthome.config.core.ConfigDescriptionProvider}={component.name=org.openhab.binding.zwave.ConfigDescription, component.id=220, service.id=390, service.bundleid=201, service.scope=bundle} - org.openhab.binding.zwave
The next thing I guess should be the framework reading the XML files, and the binding itself doesn’t actually get started until all the files have been read (in theory!). This doesn’t seem to be happening under Karaf (ie I don’t see the loading XML messages at all), and if I run the system in the IDE, it all works ok, but I’ve just noticed that the XML files are now being loaded AFTER the things are initialised, so it looks like this is now broken.
I suspect this isn’t the problem, but it is known to cause other problems, so also needs to be fixed.
I’ve also tried upgrading to the latest version of everything, and that doesn’t work either, although I do get errors about “no callback” in various places -:
21:43:07.634 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=zwave:tkb_tz88_00_000, thing.id=zwave:device:1531045fdae:node13, service.id=394, service.bundleid=203, service.scope=singleton} - org.openhab.binding.zwave
21:43:07.633 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler.
21:43:07.643 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while initializing handler of thing 'zwave:device:1531045fdae:node4': java.lang.IllegalStateException: Could not update status, because callback is missing
java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Could not update status, because callback is missing
As I understand what’s meant to happen is the service gets added, and the ThingManager should find the thing and add the callback. Looking at the code, there should be a debug message Thing handler for thing '{}' added when the service is registered, but I don’t see this although the framework is saying the service is registered. I would guess this is pointing to something bad in the framework with registering services, but maybe @kai or @maggu2810 can comment?
Yeah, it’s very strange, isn’t it? You got a bit further than me in troubleshooting. That’s good. Hopefully, this will lead to a root cause and solution.
Looks like I might have the same startup issues. I was used to having to start openHAB 2 twice for the RFXCOM binding to start, but following my update to the latest build as of yesterday I also noticed that the zwave binding was not starting reliably every time.
Extract of the log file follows:
2016-07-02 17:09:36.408 [WARN ] [g.dispatch.internal.ConfigDispatcher] - Could not parse line 'paper,basic,rest,classic'
2016-07-02 17:09:36.408 [WARN ] [g.dispatch.internal.ConfigDispatcher] - Could not parse line 'restdocs'
2016-07-02 17:09:36.455 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2016-07-02 17:09:37.656 [ERROR] [org.eclipse.smarthome.model.script ] - [org.eclipse.smarthome.action.transformation.action(89)] Circular reference detected, getService returning null
2016-07-02 17:09:37.687 [WARN ] [org.eclipse.smarthome.model.script ] - FrameworkEvent WARNING - org.eclipse.smarthome.model.script
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:496)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:619)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
at org.osgi.util.tracker.ServiceTracker.addingService(ServiceTracker.java:414)[org.osgi.core-6.0.0.jar:]
This problem is very repeatable if debug log info is required.
What other bindings are you running? Is it just ZWave that doesn’t start, or are others unreliable as well?
I’m trying to ascertain if this is a ZWave problem, or the framework - I’m reasonably sure it’s ESH, but it seems a bit funny if it’s only ZWave that has a problem. I went through all the recent changes to ZWave last night and can’t see anything that can cause this. I even created a version of ZWave that reverted a number of changes going back to the 19th June when @mhilbush reckons this started, and it didn’t help.
Currently in my production system I can’t start the ZWave binding at all since I “upgraded” last night (it’s currently the only binding installed) - it runs fine in the IDE though.
i have rfxcom, astro, mqtt, ntp, zwave running.
Pretty sure that I have the same issue with rfxcom.
I will go and do a few restarts and report back shortly
I also cannot say what is going wrong, I will need time to analyze things in detail.
Messages like
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
are due to this issue. As this has pretty weird implications, I could imagine that your problems might also be (partially) related to it. So my first priority would be to solve this (again).
I just restarted a couple of times. 2 x fail, 1 x OK.
In the fail situation, MQTT and Astro are working but both zwave and RFXCOM are not.
I then restarted again. MQTT, RFXCOM and zwave are working but this time Astro:Moon is not.
5th restart and everything seems to be working OK. I don’t think the issue is with the zwave binding.
Hope this helps.
Mike
Thanks.
I’ve restarted 6 times this morning, and haven’t had the system start properly at all (ie the ZWave binding, which is the only binding in my main system, hasn’t started each time)…
If it is really caused by the circular reference, then I would give it a try to use Apache Felix instead of Eclipse Equinox. Can you test it @chris ? It is not my personal intention to change the used OSGi framework, but I realized that the “circular reference” does not occur if the other one is used. As long as we do not know the root cause, you can give it a try.
If this solves the problem for you, it should be resolved for Equinox as soon as the circular reference could be removed.
I’d be happy to try it, as well. What needs to be changed to enable Felix? Is it as simple as commenting out this line in runtime/karaf/etc/custom.properties?
karaf.framework=equinox
Would the steps be:
Commenting out that lines should be enough.
You can also add:
karaf.framework=felix
to the file (if comment out is not enough – but it should)
Normally if you change the OSGi framework all bundles will be reinstalled but it would perhaps me a cleaner approach to start a clean one (delete the old karaf data folder).
Ok, sounds good. I saw that the default (Felix) was specified in config.properties, so I figured commenting out the entry in custom.properties would be enough.
I have an installation on three separate systems, two of which are “production”, and the other one is used for testing. I can use my test system to start with a clean install. I’ll also make a backup of my current test setup, which currently is exhibiting the startup issue.
Thanks for the help.
Thanks for the help.
Perhaps nothing will be changed.
Thanks for testing and I am waiting eagerly for the result. 
Result: I continued to see initialization not working consistently. Sometimes it would start up normally, sometimes not.
Here’s what I did:
The Circular reference exception no longer occurred, but I did see several NPEs right at startup – perhaps something looking for equinox things that are no longer there??
> 2016-07-04 11:15:16.553 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin > 2016-07-04 11:15:16.667 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1241)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 11:15:16.674 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1244)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 11:15:16.829 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1244)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 11:15:16.830 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1241)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 11:15:16.838 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui > 2016-07-04 11:15:16.919 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start > 2016-07-04 11:15:17.026 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent RESOLVED - org.openhab.binding.zwave > 2016-07-04 11:15:17.028 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTING - org.openhab.binding.zwave > 2016-07-04 11:15:17.030 [DEBUG] [inding.zwave.internal.ZWaveActivator] - Z-Wave binding started. Version 2.0.0.201607030102 > 2016-07-04 11:15:17.031 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTED - org.openhab.binding.zwave > 2016-07-04 11:15:17.037 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.config.core.ConfigOptionProvider, org.eclipse.smarthome.config.core.ConfigDescriptionProvider] - org.openhab.binding.zwave > 2016-07-04 11:15:17.076 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory] - org.openhab.binding.zwave > 2016-07-04 11:15:17.084 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.core.thing.binding.ThingHandler] - org.openhab.binding.zwave > 2016-07-04 11:15:17.087 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.config.core.status.ConfigStatusProvider] - org.openhab.binding.zwave > 2016-07-04 11:15:17.089 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.core.thing.binding.ThingHandler] - org.openhab.binding.zwave > 2016-07-04 11:15:17.090 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.config.core.status.ConfigStatusProvider] - org.openhab.binding.zwave > 2016-07-04 11:15:17.094 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.core.thing.binding.ThingHandler] - org.openhab.binding.zwave > 2016-07-04 11:15:17.648 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app > 2016-07-04 11:15:17.654 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app > 2016-07-04 11:15:17.707 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap' > 2016-07-04 11:15:17.771 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist' > 2016-07-04 11:15:17.810 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysql.persist' > 2016-07-04 11:15:17.824 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.rules' > 2016-07-04 11:15:17.987 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'systeminfo.items' > 2016-07-04 11:15:18.143 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.items' > 2016-07-04 11:15:18.155 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node3:sensor_binary --> REFRESH > 2016-07-04 11:15:18.155 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.156 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node3:sensor_temperature --> REFRESH > 2016-07-04 11:15:18.156 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.157 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node3:sensor_relhumidity --> REFRESH > 2016-07-04 11:15:18.158 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.159 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node3:sensor_luminance --> REFRESH > 2016-07-04 11:15:18.159 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.160 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node3:sensor_ultraviolet --> REFRESH > 2016-07-04 11:15:18.160 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.161 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node3:battery-level --> REFRESH > 2016-07-04 11:15:18.161 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.163 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node3:alarm_general --> REFRESH > 2016-07-04 11:15:18.163 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.164 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node4:sensor_binary --> REFRESH > 2016-07-04 11:15:18.164 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.165 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node4:sensor_temperature --> REFRESH > 2016-07-04 11:15:18.165 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.166 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node4:sensor_seismicintensity --> REFRESH > 2016-07-04 11:15:18.166 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.167 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node4:sensor_luminance --> REFRESH > 2016-07-04 11:15:18.167 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.168 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node4:battery-level --> REFRESH > 2016-07-04 11:15:18.168 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.169 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node4:alarm_general --> REFRESH > 2016-07-04 11:15:18.170 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.171 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 0: Command received zwave:device:15573c1286e:node4:alarm_burglar --> REFRESH > 2016-07-04 11:15:18.171 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - Controller handler not found. Cannot handle command without ZWave controller. > 2016-07-04 11:15:18.753 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.items' > 2016-07-04 11:15:21.998 [WARN ] [thome.binding.ntp.handler.NtpHandler] - ntp:ntp:local couldn't establish network connection [host '0.ubuntu.pool.ntp.org'] -> returning current sytem time instead.
As an aside, I’m not sure what’s going on with the ntp errors. If I run ntpdate, it seems to be taking >8 seconds to return. I see the NTP binding has a 5 second timeout on the transaction, so that’s probably what’s happening.
I probably should try a complete from-scratch install next.
This time I started with a completely clean installation.
I’m still seeing the same NPEs on startup, but not the circular reference exception.
> 2016-07-04 12:22:44.323 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin > 2016-07-04 12:22:44.520 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1244)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 12:22:44.533 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1241)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 12:22:44.692 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1244)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 12:22:44.707 [ERROR] [org.eclipse.equinox.registry ] - FrameworkEvent ERROR - org.eclipse.equinox.registry > java.lang.NullPointerException > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFiles(EclipseBundleListener.java:217)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.checkForNLSFragment(EclipseBundleListener.java:198)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.addBundle(EclipseBundleListener.java:154)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.eclipse.core.internal.registry.osgi.EclipseBundleListener.bundleChanged(EclipseBundleListener.java:79)[66:org.eclipse.equinox.registry:3.6.0.v20150318-1503] > at org.apache.felix.framework.util.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:916)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:835)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:517)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4541)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.fireResolvedEvents(StatefulResolver.java:1241)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.StatefulResolver.resolve(StatefulResolver.java:465)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4106)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.startBundle(Felix.java:2117)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1371)[org.apache.felix.framework-5.4.0.jar:] > at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)[org.apache.felix.framework-5.4.0.jar:] > at java.lang.Thread.run(Thread.java:745)[:1.8.0_91] > 2016-07-04 12:22:44.708 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui > 2016-07-04 12:22:44.806 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start > 2016-07-04 12:22:44.881 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent RESOLVED - org.openhab.binding.zwave > 2016-07-04 12:22:44.882 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTING - org.openhab.binding.zwave > 2016-07-04 12:22:44.886 [DEBUG] [inding.zwave.internal.ZWaveActivator] - Z-Wave binding started. Version 2.0.0.201607030102 > 2016-07-04 12:22:44.912 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.config.core.ConfigOptionProvider, org.eclipse.smarthome.config.core.ConfigDescriptionProvider] - org.openhab.binding.zwave > 2016-07-04 12:22:44.914 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory] - org.openhab.binding.zwave > 2016-07-04 12:22:44.923 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.core.thing.binding.ThingHandler] - org.openhab.binding.zwave > 2016-07-04 12:22:44.925 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.config.core.status.ConfigStatusProvider] - org.openhab.binding.zwave > 2016-07-04 12:22:44.953 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - [org.eclipse.smarthome.core.thing.binding.ThingHandler] - org.openhab.binding.zwave > 2016-07-04 12:22:44.954 [DEBUG] [org.openhab.binding.zwave ] - BundleEvent STARTED - org.openhab.binding.zwave > 2016-07-04 12:22:45.393 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap' > 2016-07-04 12:22:45.461 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist' > 2016-07-04 12:22:45.500 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysql.persist' > 2016-07-04 12:22:45.513 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.rules' > 2016-07-04 12:22:45.514 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app > 2016-07-04 12:22:45.520 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app > 2016-07-04 12:22:45.696 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'systeminfo.items' > 2016-07-04 12:22:45.745 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.items' > 2016-07-04 12:22:45.790 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.items'
And, I still see the intermittent startup behavior. Not sure where this leaves us…