Binding not starting consistently since 6/19 build

This time I started with a completely clean installation.

  • Deleted everything in openhab directory
  • Unzipped the nightly snapshot
  • copied HABmin jar into addons
  • copied my items, rules, sitemap, etc files into conf directory
  • started up openhab - wait for bundles to be loaded
  • configure zwave port
  • shutdown openhab
  • started up openhab

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…