openhab / openhab1-addons

Add-ons for openHAB 1.x
Eclipse Public License 2.0
3.43k stars 1.71k forks source link

[mail (and possibly other bindings)] Circular reference error at startup #4604

Closed mhilbush closed 7 years ago

mhilbush commented 7 years ago

I'm seeing this error during consistently during startup of OH2 for the OH1 mail binding. I'm not sure if this should be posted here, or in another repo, since it's unclear where the root cause is.

2016-08-23 17:30:43.553 [ERROR] [org.openhab.action.mail             ] - [org.openhab.action.mail.action(0)] Circular reference detected, getService returning null
2016-08-23 17:30:43.599 [WARN ] [org.openhab.action.mail             ] - FrameworkEvent WARNING - org.openhab.action.mail
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:]

It was resulting in this error when calling sendMail from within a rule.

2016-08-25 15:22:02.289 [ERROR] [.script.engine.ScriptExecutionThread] - Rule 'xxxxxxxx': An error occured during the script execution: The name 'sendMail(<XFeatureCallImplCustom>,<XFeatureCallImplCustom>,<XFeatureCallImplCustom>)' cannot be resolved to an item or type.

At least one other occurrence has been reported here: https://community.openhab.org/t/circular-reference-within-1x-bindings

This started to occur around OH2 build 454.

I have the following bindings installed:

package = minimal

# A comma-separated list of bindings to install (e.g. "sonos,knx,zwave")
binding = astro,http,ntp,squeezebox,systeminfo,weather,zwave

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

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

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

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

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

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

Oddly, after doing an uninstall/install of the MAP transformation, sendMail started working again.

pabloNZ commented 7 years ago

I've had this happen with the compat1x too.

2016-08-25 22:31:10.878 [ERROR] [org.openhab.core.compat1x ] - [org.openhab.core.compat1x.eventbridge(8)] Circular reference detected, getService returning null 2016-08-25 22:31:10.969 [WARN ] [org.openhab.core.compat1x ] - FrameworkEvent WARNING - org.openhab.core.compat1x

Latest snapshot build installed after deleting the cache and tmp folders.

mhilbush commented 7 years ago

Including a full stack trace.

2016-08-23 17:30:43.553 [ERROR] [org.openhab.action.mail             ] - [org.openhab.action.mail.action(0)] Circular reference detected, getService returning null
2016-08-23 17:30:43.599 [WARN ] [org.openhab.action.mail             ] - FrameworkEvent WARNING - org.openhab.action.mail
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.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:72)
    at org.apache.felix.scr.impl.helper.BindMethod.getServiceObject(BindMethod.java:646)
    at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2137)
    at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.prebind(DependencyManager.java:389)
    at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1457)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:983)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:812)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:724)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:399)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.config.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:676)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:360)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.access$000(Activator.java:53)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:260)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:259)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:232)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.addingBundle(AbstractExtender.java:192)[32:org.apache.felix.scr:2.0.2]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:469)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:415)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:902)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:165)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:75)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:67)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:102)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.publishEvent(Module.java:466)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.doStart(Module.java:538)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.start(Module.java:439)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:454)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.hooks.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:107)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:531)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:324)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:320)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:395)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:345)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:337)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:160)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at java.lang.ClassLoader.loadClass(ClassLoader.java:357)[:1.8.0_91]
    at org.eclipse.osgi.internal.framework.EquinoxBundle.loadClass(EquinoxBundle.java:568)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.initDependencyManagers(AbstractComponentManager.java:952)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:980)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:812)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[32:org.apache.felix.scr:2.0.2]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_91]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210)[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.apache.felix.metatype.internal.ManagedServiceTracker.addingService(ManagedServiceTracker.java:52)[2:org.apache.felix.metatype:1.1.2]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:399)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.config.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:676)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:360)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.access$000(Activator.java:53)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:260)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:259)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:232)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.addingBundle(AbstractExtender.java:192)[32:org.apache.felix.scr:2.0.2]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:469)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:415)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:902)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:165)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:75)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:67)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:102)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.publishEvent(Module.java:466)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.start(Module.java:457)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1582)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1561)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1533)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1476)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
otbe commented 7 years ago

Same here :/

mhilbush commented 7 years ago

I pared down my bindings to just mail, then turned on ESH debugging. This is the full log from startup until it starts loading items, rules, etc.

@kaikreuzer Any thoughts on what change(s) might've introduced this?

circ-ref.txt

kaikreuzer commented 7 years ago

@mhilbush Can you say since when you experience this? I don't have any clear idea what change could have caused this. The closest change to this was https://github.com/eclipse/smarthome/pull/1810 early July, which actually fixed circular deps issues, but maybe it introduced a new one in the compat layer... I'll have to investigate this in detail. Will do when I am back from holidays next week!

mhilbush commented 7 years ago

@kaikreuzer Thanks.

For me it started in OH2 build 454, which I think is the build that picked up the new ESH stable? I suppose this could be just a coincidence.

I had installed numerous builds prior to 454, none of which exhibited this problem.

The first forum post was Aug 24, which also seems to align with build 454. https://community.openhab.org/t/circular-reference-within-1x-bindings

Didn't builds prior to 454 have the ESH build from 8/3? If so, wouldn't that ESH build have had the 1810 fix?

otbe commented 7 years ago

This error happens more often if I want to use multiple 1x compat bindings. So all seems to work well if I use only 2.0 ready bindings but it starts failing if I use 1x compat bindings. But that's only my feeling :) Thanks for checking this out!!

kaikreuzer commented 7 years ago

Didn't builds prior to 454 have the ESH build from 8/3? If so, wouldn't that ESH build have had the 1810 fix?

Yes, they should have had this fix already. So it is probably unrelated and some other change must have caused this. Let's hope that I first find the time and then find the cause and a fix!

JueBag commented 7 years ago

I'm seeing this error in my new setup (#456) using bindings intertechno and HTTP. I do not see it in m old installation, don't know the build # (it wasn't stated by karaf back then) but the runtime files date from July'25 03:39

mhilbush commented 7 years ago

Full stack trace that refers to eventbridge.

2016-08-22 12:15:05.674 [ERROR] [org.openhab.core.compat1x           ] - [org.openhab.core.compat1x.eventbridge(9)] Circular reference detected, getService returning null
2016-08-22 12:15:05.721 [WARN ] [org.openhab.core.compat1x           ] - FrameworkEvent WARNING - org.openhab.core.compat1x
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.eclipse.smarthome.core.internal.events.OSGiEventManager$EventSubscriberServiceTracker.addingService(OSGiEventManager.java:67)
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.smarthome.core.internal.events.OSGiEventManager.activate(OSGiEventManager.java:96)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_91]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_91]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_91]
    at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_91]
    at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:222)
    at org.apache.felix.scr.impl.helper.BaseMethod.access$500(BaseMethod.java:37)
    at org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:615)
    at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:499)
    at org.apache.felix.scr.impl.helper.ActivateMethod.invoke(ActivateMethod.java:295)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:302)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:113)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:866)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:833)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[32:org.apache.felix.scr:2.0.2]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_91]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210)[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.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:72)
    at org.apache.felix.scr.impl.helper.BindMethod.getServiceObject(BindMethod.java:646)
    at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2137)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.prebind(DependencyManager.java:1048)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1457)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:983)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:812)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[32:org.apache.felix.scr:2.0.2]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_91]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210)[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 com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39)[11:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:954)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:915)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1215)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1136)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:945)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:881)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1167)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:120)[32:org.apache.felix.scr:2.0.2]
    at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:399)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.config.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:676)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:360)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.access$000(Activator.java:53)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:260)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:259)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:232)[32:org.apache.felix.scr:2.0.2]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:902)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:165)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:75)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:67)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:102)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.publishEvent(Module.java:466)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.start(Module.java:457)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1582)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1562)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1533)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1476)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
kaikreuzer commented 7 years ago

As the problem occurs throughout any addon that uses the compat layer, the most likely reason is a problem in the compat1x bundle then. From the timing, I would assume that it is due to https://github.com/kaikreuzer/openhab-core/pull/53.

As the exceptions really do not tell much about which services create the circular dependency, I have created https://github.com/kaikreuzer/openhab-core/pull/58 as a wild guess - this was a service that implemented an interface of the compat layer, while requiring an ESH service. With my change, it now only refers to ESH services/interfaces. Let's touch wood and see if it makes a difference... Tomorrows distro should contain this PR already.

mhilbush commented 7 years ago

Very good. I'll install tonight's build in the morning and report back results.

kaikreuzer commented 7 years ago

Should be in build https://openhab.ci.cloudbees.com/job/openHAB-Distribution/460/ once it is through.

pabloNZ commented 7 years ago

Unfortunately, I still have errors. (Note the time stamp is wrong, for some reason my logs are 12 hours behind the actual time. It's always been this way and i've never bothered to look into fixing it)

 2016-08-29 22:46:52.987 [ERROR] [org.openhab.core.compat1x           ] - [org.openhab.core.compat1x.eventbridge(8)] Circular reference detected, getService returning null
2016-08-29 22:46:53.033 [WARN ] [org.openhab.core.compat1x           ] - FrameworkEvent WARNING - org.openhab.core.compat1x
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.eclipse.smarthome.core.internal.events.OSGiEventManager$EventSubscriberServiceTracker.addingService(OSGiEventManager.java:67)
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.smarthome.core.internal.events.OSGiEventManager.activate(OSGiEventManager.java:96)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_101]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_101]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_101]
    at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_101]
    at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:222)
    at org.apache.felix.scr.impl.helper.BaseMethod.access$500(BaseMethod.java:37)
    at org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:615)
    at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:499)
    at org.apache.felix.scr.impl.helper.ActivateMethod.invoke(ActivateMethod.java:295)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:302)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:113)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:866)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:833)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[32:org.apache.felix.scr:2.0.2]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_101]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210)[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.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:72)
    at org.apache.felix.scr.impl.helper.BindMethod.getServiceObject(BindMethod.java:646)
    at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2137)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.prebind(DependencyManager.java:1048)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1457)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:983)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:812)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[32:org.apache.felix.scr:2.0.2]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_101]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210)[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 com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39)[11:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:954)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:915)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1215)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1136)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:945)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:881)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1167)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:120)[32:org.apache.felix.scr:2.0.2]
    at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:399)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.config.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:676)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:360)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.access$000(Activator.java:53)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:260)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:259)[32:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:232)[32:org.apache.felix.scr:2.0.2]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232)[org.osgi.core-6.0.0.jar:]
    at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444)[org.osgi.core-6.0.0.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:902)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:165)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:75)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:67)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:102)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.publishEvent(Module.java:466)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.start(Module.java:457)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1582)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1562)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1533)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1476)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
kaikreuzer commented 7 years ago

What exactly do I have to do to reproduce it?

sehroriginell commented 7 years ago

I've had the same problems with "Circular reference detected". Build 460 solved my problems. For now at least. I'll keep my eyes open.

mhilbush commented 7 years ago

I installed build 460. I install the build by first removing openhab/runtime, openhab/userdata/cache, and openhab/userdata/tmp, then laying down the new distro.

The behavior has changed. It's still complaining about the circ ref for mail. But it's now throwing other exceptions.

My config is very simple. I have an addons.cfg containing the following. I've reduced this down to the most minimal configuration.

# The base installation package of this openHAB instance (default is "standard")
# Valid options:
#   - minimal  : Installation only with dashboard, but no UIs or other addons
#   - standard : Typical installation with all standards UIs
#   - demo     : A demo setup which includes UIs, a few bindings, config files etc.
package = minimal

# A comma-separated list of bindings to install (e.g. "sonos,knx,zwave")
binding = 

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

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

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

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

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

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

There are no items, rules, persistence, etc. files.

I have ESH at DEBUG log level.

Attached is the log file showing startup and shutdown. openhab.txt

And here is the list of installed bundles. bundles.txt

If there's something else I can do or provide, let me know.

kaikreuzer commented 7 years ago

Pity, it seems to have been a too wild guess then...

I can reproduce it, will try to further analyse it.

mhilbush commented 7 years ago

As soon as build 461 finishes building, I'll try it out and report back.

@kaikreuzer Thanks!

kaikreuzer commented 7 years ago

Don't thank me as long as it isn't fixed...

I now get a

15:59:00.355 [ERROR] [g.eclipse.smarthome.config.discovery] - [org.eclipse.smarthome.config.discovery.inbox.Inbox(66)] Circular reference detected, getService returning null
15:59:00.389 [WARN ] [g.eclipse.smarthome.config.discovery] - FrameworkEvent WARNING - org.eclipse.smarthome.config.discovery
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:]

Different than before, but still not perfect :-(

mhilbush commented 7 years ago

I'm still seeing a bunch of these, too.

2016-08-30 09:58:17.060 [ERROR] [org.eclipse.smarthome.io.javasound  ] - [org.eclipse.smarthome.io.javasoundsource(55)] Error during instantiation of the implementation object
java.lang.RuntimeException: Error creating the AudioSource
        at org.eclipse.smarthome.io.javasound.internal.JavaSoundAudioSource.<init>(JavaSoundAudioSource.java:69)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)[:1.8.0_91]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)[:1.8.0_91]
2016-08-30 09:58:17.067 [ERROR] [org.eclipse.smarthome.io.javasound  ] - [org.eclipse.smarthome.io.javasoundsource(55)] Failed creating the component instance; see log for reason
2016-08-30 09:58:17.068 [WARN ] [org.eclipse.smarthome.io.javasound  ] - FrameworkEvent WARNING - org.eclipse.smarthome.io.javasound
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:]
2016-08-30 09:58:17.075 [ERROR] [org.eclipse.smarthome.io.javasound  ] - [org.eclipse.smarthome.io.javasoundsource(55)] Error during instantiation of the implementation object
java.lang.RuntimeException: Error creating the AudioSource
        at org.eclipse.smarthome.io.javasound.internal.JavaSoundAudioSource.<init>(JavaSoundAudioSource.java:69)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)[:1.8.0_91]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)[:1.8.0_91]
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)[:1.8.0_91]
2016-08-30 09:58:17.079 [ERROR] [org.eclipse.smarthome.io.javasound  ] - [org.eclipse.smarthome.io.javasoundsource(55)] Failed creating the component instance; see log for reason
2016-08-30 09:58:17.079 [WARN ] [org.eclipse.smarthome.io.javasound  ] - FrameworkEvent WARNING - org.eclipse.smarthome.io.javasound
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:]
kaikreuzer commented 7 years ago

These are unrelated, but good to know as well. Are you running on Linux?

kaikreuzer commented 7 years ago

Your javasound messages will disappear with https://github.com/kaikreuzer/openhab-core/pull/60 again.

I did a couple of restarts and now it all looks good on my end. Do you still see any circular dependency problems?

mhilbush commented 7 years ago

Yes. Ubuntu 16.04 LTS.

kaikreuzer commented 7 years ago

Latest build 462 does not show the javasound exceptions anymore. And I would claim that the circular dependency issue is solved:

Launching the openHAB runtime...

                          __  _____    ____      
  ____  ____  ___  ____  / / / /   |  / __ )     
 / __ \/ __ \/ _ \/ __ \/ /_/ / /| | / __  | 
/ /_/ / /_/ /  __/ / / / __  / ___ |/ /_/ /      
\____/ .___/\___/_/ /_/_/ /_/_/  |_/_____/     
    /_/                        2.0.0-SNAPSHOT
                               Build #462   

Hit '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
Hit '<ctrl-d>' or type 'system:shutdown' or 'logout' to shutdown openHAB.

openhab> log:tail
17:53:57.959 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
17:53:57.974 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
17:53:58.019 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
17:53:58.113 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
17:53:58.212 [INFO ] [core.karaf.internal.FeatureInstaller] - Installed 'openhab-package-standard'
17:53:59.392 [INFO ] [core.karaf.internal.FeatureInstaller] - Installed 'openhab-action-mail'

Can anyone else confirm?

mhilbush commented 7 years ago

Confirmed on my minimal configuration. I'll test on a more robust config in my test environment next.

otbe commented 7 years ago

Seems to work for me :) 5 (re)starts and no DI errors 👍

I installed another binding (caldav-command) and get this:

2016-08-30 18:51:15.753 [ERROR] [org.openhab.io.myopenhab            ] - [org.openhab.myopenhab(0)] Circular reference detected, getService returning null
2016-08-30 18:51:15.851 [WARN ] [org.openhab.io.myopenhab            ] - FrameworkEvent WARNING - org.openhab.io.myopenhab
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.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:72)
        at org.apache.felix.scr.impl.helper.BindMethod.getServiceObject(BindMethod.java:646)
        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2137)
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.prebind(DependencyManager.java:389)
        at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1457)
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:983)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:812)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[32:org.apache.felix.scr:2.0.2]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_101]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210)[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 com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39)[11:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901)[org.osgi.core-6.0.0.jar:]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:399)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.config.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:676)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:360)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.Activator.access$000(Activator.java:53)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:260)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:259)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:232)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.utils.extender.AbstractExtender.addingBundle(AbstractExtender.java:192)[32:org.apache.felix.scr:2.0.2]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:469)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerAdding(BundleTracker.java:415)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444)[org.osgi.core-6.0.0.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:902)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:165)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:75)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:67)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:102)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:466)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.Module.doStart(Module.java:538)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.Module.start(Module.java:439)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:454)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.hooks.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:107)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:531)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:324)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:320)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.sources.SingleSourcePackage.loadClass(SingleSourcePackage.java:36)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:379)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:345)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:337)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:160)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)[:1.8.0_101]
        at java.lang.ClassLoader.defineClass1(Native Method)[:1.8.0_101]
        at java.lang.ClassLoader.defineClass(ClassLoader.java:763)[:1.8.0_101]
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.defineClass(ModuleClassLoader.java:272)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.defineClass(ClasspathManager.java:632)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findClassImpl(ClasspathManager.java:588)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClassImpl(ClasspathManager.java:540)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:527)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:324)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:320)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:395)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:345)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:337)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:160)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)[:1.8.0_101]
        at org.eclipse.osgi.internal.framework.EquinoxBundle.loadClass(EquinoxBundle.java:568)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.initDependencyManagers(AbstractComponentManager.java:952)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:980)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:812)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[32:org.apache.felix.scr:2.0.2]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_101]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210)[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 com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39)[11:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901)[org.osgi.core-6.0.0.jar:]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleDynamicCustomizer.addedService(DependencyManager.java:753)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleDynamicCustomizer.addedService(DependencyManager.java:700)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1215)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1136)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:945)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:881)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1167)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:120)[32:org.apache.felix.scr:2.0.2]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:869)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:399)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.config.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:676)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:360)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.Activator.access$000(Activator.java:53)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:260)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:259)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:232)[32:org.apache.felix.scr:2.0.2]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232)[org.osgi.core-6.0.0.jar:]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444)[org.osgi.core-6.0.0.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:902)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:165)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:75)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:67)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:102)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:466)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.Module.start(Module.java:457)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1582)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1562)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1533)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1476)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]

EDIT: Maybe this is related to another problem. After some restarts with caldav binding I dont see this error again. On the other hand the caldav binding does nothing. :/ No log output, nothing.

Woutch commented 7 years ago

I have strange behaviour also, started the same time as this problems. You saw my thread here: https://community.openhab.org/t/circular-reference-compability-layer-zwave/13662/3 There is all info on my setup.

I now get 1 error:

2016-08-30 19:23:39.587 [ERROR] [nding.AbstractGenericBindingProvider] - Binding org.openhab.binding.weather.internal.bus.WeatherBinding threw an exception:
java.lang.IllegalStateException: Task already scheduled or cancelled

with a whole stacktrace. No other errors, but only some work. zwave and systeminfo are downloaded and installed from previous run. And in paperui showing installed. But on this run, nothing indicates it is starting or running. No channels, items, or info warnings from these bindings.

If you want more info, please ask.

JueBag commented 7 years ago

Installed build #462 In a setup with bindings Intertechno and Http, the error did show again during most startups. After removing the Http-binding I did not see the error during 4 consecutive startups. Before the update I did see the error even if only Intertechno-binding was used.

Woutch commented 7 years ago

When trying to use only zwave it gives the following errors on first install:

20:17:34.965 [WARN ] [ig.xml.osgi.XmlDocumentBundleTracker] - The XML document '/ESH-INF/thing/horstmann_hrt4zw_0_0.xml' in module 'org.openhab.binding.zwave' could not be parsed:  : ParseError at [row,col]:[140,3]
Message: Stream closed :  : ParseError at [row,col]:[140,3]
Message: Stream closed
---- Debugging information ----
message             :  : ParseError at [row,col]:[140,3]
Message: Stream closed
cause-exception     : com.thoughtworks.xstream.io.StreamException
cause-message       :  : ParseError at [row,col]:[140,3]
Message: Stream closed
class               : java.util.ArrayList
required-type       : java.util.ArrayList
converter-type      : com.thoughtworks.xstream.converters.collections.CollectionConverter
path                : /thing-descriptions
line number         : 140
class[1]            : org.eclipse.smarthome.core.thing.xml.internal.ThingDescriptionList
converter-type[1]   : org.eclipse.smarthome.core.thing.xml.internal.ThingDescriptionConverter
version             : 1.4.7
-------------------------------
com.thoughtworks.xstream.converters.ConversionException:  : ParseError at [row,col]:[140,3]
Message: Stream closed :  : ParseError at [row,col]:[140,3]
Message: Stream closed
---- Debugging information ----
message             :  : ParseError at [row,col]:[140,3]
Message: Stream closed
cause-exception     : com.thoughtworks.xstream.io.StreamException
cause-message       :  : ParseError at [row,col]:[140,3]
Message: Stream closed
class               : java.util.ArrayList
required-type       : java.util.ArrayList
converter-type      : com.thoughtworks.xstream.converters.collections.CollectionConverter
path                : /thing-descriptions
line number         : 140
class[1]            : org.eclipse.smarthome.core.thing.xml.internal.ThingDescriptionList
converter-type[1]   : org.eclipse.smarthome.core.thing.xml.internal.ThingDescriptionConverter
version             : 1.4.7
-------------------------------
        at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:79)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:65)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at org.eclipse.smarthome.core.thing.xml.internal.ThingDescriptionConverter.unmarshal(ThingDescriptionConverter.java:48)[102:org.eclipse.smarthome.core.thing.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:65)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1185)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1169)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1115)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1062)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at org.eclipse.smarthome.config.xml.util.XmlDocumentReader.readFromXML(XmlDocumentReader.java:82)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$1.processBundle(XmlDocumentBundleTracker.java:129)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at org.eclipse.smarthome.config.xml.osgi.AbstractAsyncBundleProcessor$1.run(AbstractAsyncBundleProcessor.java:231)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at java.lang.Thread.run(Thread.java:745)[:1.8.0_101]
Caused by: com.thoughtworks.xstream.io.StreamException:  : ParseError at [row,col]:[140,3]
Message: Stream closed
        at com.thoughtworks.xstream.io.xml.StaxReader.pullNextEvent(StaxReader.java:73)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.io.xml.AbstractPullReader.readRealEvent(AbstractPullReader.java:148)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.io.xml.AbstractPullReader.readEvent(AbstractPullReader.java:135)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.io.xml.AbstractPullReader.hasMoreChildren(AbstractPullReader.java:87)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.io.ReaderWrapper.hasMoreChildren(ReaderWrapper.java:32)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.io.ReaderWrapper.hasMoreChildren(ReaderWrapper.java:32)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.converters.collections.CollectionConverter.populateCollection(CollectionConverter.java:89)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.converters.collections.CollectionConverter.populateCollection(CollectionConverter.java:85)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.converters.collections.CollectionConverter.unmarshal(CollectionConverter.java:80)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        ... 18 more
Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[140,3]
Message: Stream closed
        at com.sun.org.apache.xerces.internal.impl.XMLStreamReaderImpl.next(XMLStreamReaderImpl.java:591)[:1.8.0_101]
        at com.thoughtworks.xstream.io.xml.StaxReader.pullNextEvent(StaxReader.java:58)[94:org.eclipse.smarthome.config.xml:0.9.0.201608291700]
        ... 27 more

On the next run, I see nothing anymore from zwave in the logs...

PS: this error seems to repeat for every zwave device xml file embedded in the binding.

mhilbush commented 7 years ago

I'm running build 462 in two environments -- my test environment and one of my prod environments. Both are running well with no presence of any of the previous errors.

That zwave error, assuming you're running the 2.0 version of the zwave binding, may be unrelated. You might want to open that as an issue in the zwave repo, or post on the forum, for Chris to assess.

As for the error in the weather binding, I wonder if that is an error in the weather binding itself, which might be manifesting itself now because bindingChanged() in WeatherBinding.java is being called now when it wasn't before. This is just a guess on my part. You might want to open that as a separate issue, as well.

@kaikreuzer Your call on when you want to close this issue.

Woutch commented 7 years ago

@kaikreuzer Apparently the internal database was wiped... I need to configure all again. But at least the binding is working again. Maybe going to config them all in the items file now, easier to backup :-)

otbe commented 7 years ago

Mh I think something is still broken.

Before build 46x I was able to get the caldav binding to work if I use only this specific binding. If I added another binding (exec) I got the circular ref error from this issue. But as of now it stops working at all. It doesn't matter if it is used standalone or alongside other bindings. It disappears completely from the logs.

My test environment is cleaned by

#!/bin/bash

USER_DATA=/var/lib/openhab2
RUNTIME=/usr/share/openhab2/runtime

rm -rf $RUNTIME
rm -r $USER_DATA/tmp/*
rm -r $USER_DATA/cache/*

reinstalled via apt-get upgrade and reconfigured by config files on every try. What else to do?

mhilbush commented 7 years ago

So, it would seem this is not fully sorted out yet.

2016-08-30 14:23:26.798 [INFO ] [eather.internal.common.WeatherConfig] - ProviderConfig[providerName=WUNDERGROUND,apiKey=XXXXXXXXX]
2016-08-30 14:23:26.803 [INFO ] [eather.internal.common.WeatherConfig] - LocationConfig[providerName=WUNDERGROUND,language=en,updateInterval=15,latitude=XX>XXXXXX,longitude=-YY.YYYY,woeid=<null>,locationId=hom
e,name=home]
2016-08-30 14:23:26.817 [ERROR] [nding.AbstractGenericBindingProvider] - Binding org.openhab.binding.weather.internal.bus.WeatherBinding threw an exception: 
java.lang.IllegalStateException: Task already scheduled or cancelled
        at java.util.Timer.sched(Timer.java:401)[:1.8.0_91]
        at java.util.Timer.schedule(Timer.java:193)[:1.8.0_91]
        at org.openhab.binding.weather.internal.utils.DelayedExecutor.schedule(DelayedExecutor.java:44)
        at org.openhab.binding.weather.internal.scheduler.WeatherJobScheduler.restart(WeatherJobScheduler.java:65)
        at org.openhab.binding.weather.internal.bus.WeatherBinding.bindingChanged(WeatherBinding.java:130)
        at org.openhab.model.item.binding.AbstractGenericBindingProvider.notifyListeners(AbstractGenericBindingProvider.java:124)
        at org.openhab.model.item.binding.AbstractGenericBindingProvider.addBindingConfig(AbstractGenericBindingProvider.java:118)
        at org.openhab.binding.weather.internal.bus.WeatherGenericBindingProvider.processBindingConfiguration(WeatherGenericBindingProvider.java:58)
        at org.openhab.core.binding.internal.BindingConfigReaderDelegate.processBindingConfiguration(BindingConfigReaderDelegate.java:48)
        at org.eclipse.smarthome.model.item.internal.GenericItemProvider.internalDispatchBindings(GenericItemProvider.java:312)
        at org.eclipse.smarthome.model.item.internal.GenericItemProvider.dispatchBindingsPerType(GenericItemProvider.java:268)
        at org.eclipse.smarthome.model.item.internal.GenericItemProvider.addBindingConfigReader(GenericItemProvider.java:102)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_91]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_91]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_91]
        at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_91]
        at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:222)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BaseMethod.access$500(BaseMethod.java:37)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:615)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:499)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BindMethod.invoke(BindMethod.java:41)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1660)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1636)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:370)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:319)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:295)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1215)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1136)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:945)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:881)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1167)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:120)[32:org.apache.felix.scr:2.0.2]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:914)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:482)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:998)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
        at org.openhab.core.binding.internal.BindingConfigReaderFactory.registerDelegateService(BindingConfigReaderFactory.java:69)
        at org.openhab.core.binding.internal.BindingConfigReaderFactory.addBindingConfigReader(BindingConfigReaderFactory.java:52)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_91]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_91]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_91]
        at java.lang.reflect.Method.invoke(Method.java:498)[:1.8.0_91]
        at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:222)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BaseMethod.access$500(BaseMethod.java:37)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:615)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:499)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.helper.BindMethod.invoke(BindMethod.java:41)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1660)[32:org.apache.felix.scr:2.0.2]
        at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1636)[32:org.apache.felix.scr:2.0.2]
kaikreuzer commented 7 years ago

Thank you all for testing. From what I read is that the circular dependency issue seems to be solved - all other issues are likely to be something else and should be analysed individually (in their own issue).

otbe commented 7 years ago

It seems to me that this fix is related to all other issues, because before 46x this bindings sometimes work (if there were no circular ref error), but after 46x they don't work at all. Maybe this fix introduced another bug!?

kaikreuzer commented 7 years ago

Maybe this fix introduced another bug!?

No, because this fix only reverted a previous change that caused the circular dependency issue.