Skip to content
This repository has been archived by the owner on May 7, 2020. It is now read-only.

Circular reference detected #870

Closed
lolodomo opened this issue Jan 16, 2016 · 53 comments · Fixed by #1810
Closed

Circular reference detected #870

lolodomo opened this issue Jan 16, 2016 · 53 comments · Fixed by #1810

Comments

@lolodomo
Copy link
Contributor

I don't know if it is important or not, but when I start openHAB2 beta 1, the first message I get in the logs is:

13:06:14.339 [ERROR] [org.eclipse.smarthome.core.transform] - [org.eclipse.smarthome.action.transformation.action(73)] Circular reference detected, getService returning null

@kaikreuzer
Copy link
Contributor

Definitely something to look at.

@hardoverflow
Copy link

The same issue here.

[ERROR] [org.eclipse.smarthome.core.transform] - [org.eclipse.smarthome.action.transformation.action(72)] Circular reference detected, getService returning null

logfile.txt

@kaikreuzer
Copy link
Contributor

I just caught a full exception that could help us in the analysis:

18:39:47.419 [DEBUG] [org.eclipse.smarthome.core.transform] - BundleEvent STARTING - org.eclipse.smarthome.core.transform
18:39:47.420 [DEBUG] [orm.internal.TransformationActivator] - Transformation Service has been started.
18:39:47.424 [DEBUG] [org.eclipse.smarthome.model.script  ] - BundleEvent STARTING - org.eclipse.smarthome.model.script
18:39:47.425 [ERROR] [org.eclipse.smarthome.core.transform] - [org.eclipse.smarthome.action.transformation.action(78)] Circular reference detected, getService returning null
18:39:47.493 [DEBUG] [org.eclipse.smarthome.core.transform] - FrameworkEvent WARNING - org.eclipse.smarthome.core.transform
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:496)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:619)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.osgi.util.tracker.ServiceTracker.addingService(ServiceTracker.java:414)[org.osgi.core-6.0.0.jar:]
    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.model.script.internal.ScriptActivator.start(ScriptActivator.java:38)
    at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:771)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_40]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:764)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:721)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:936)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:319)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]
    at org.eclipse.osgi.container.Module.doStart(Module.java:571)[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_40]
    at java.lang.ClassLoader.defineClass1(Native Method)[:1.8.0_40]
    at java.lang.ClassLoader.defineClass(ClassLoader.java:760)[:1.8.0_40]
    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_40]
    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)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:980)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:812)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:774)[28: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_40]
    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)[12:com.eclipsesource.jaxrs.publisher:5.3.0.201512270850]
    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)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:857)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:915)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:715)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:399)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.config.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:676)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:360)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator.access$000(Activator.java:53)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:260)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:259)[28:org.apache.felix.scr:2.0.2]
    at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:232)[28: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:]
18:39:47.494 [DEBUG] [org.eclipse.smarthome.model.script  ] - BundleEvent STARTED - org.eclipse.smarthome.model.script
18:39:47.501 [DEBUG] [org.eclipse.smarthome.core.transform] - ServiceEvent REGISTERED - {org.eclipse.smarthome.model.script.engine.action.ActionService}={component.name=org.eclipse.smarthome.action.transformation.action, component.id=78, service.id=168, service.bundleid=96, service.scope=bundle} - org.eclipse.smarthome.core.transform

The culprit might be the ScriptActivator as it appears in the middle of the stacktrace.

@dvanherbergen
Copy link
Contributor

This is what appears to be happening:

The bundle org.eclipse.smarthome.core.transform is being started. This bundle provides a service which implements org.eclipse.smarthome.model.script.engine.action.ActionService. That interface class is located in the bundle org.eclipse.smarthome.model.script, which has been configured to start when one of its classes are loaded, so the loading of this interface class triggers the start of the org.eclipse.smarthome.model.script bundle.
In the activator of this bundle, it tries to open a service tracker on ActionService services, but this returns null, probably because the service org.eclipse.smarthome.core.transform is still being started.

The issue also seems to occur in other places:

2016-01-27 14:09:00.544 [DEBUG] [org.eclipse.smarthome.config.core   ] - BundleEvent STARTING - org.eclipse.smarthome.config.core
2016-01-27 14:09:00.550 [ERROR] [org.eclipse.smarthome.config.core   ] - [ConfigDescriptionRegistry(0)] Circular reference detected, getService returning null
2016-01-27 14:09:00.629 [DEBUG] [org.eclipse.smarthome.config.core   ] - FrameworkEvent WARNING - org.eclipse.smarthome.config.core
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.common.osgi.ServiceBinder$1.addingService(ServiceBinder.java:110)
  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.common.osgi.ServiceBinder.open(ServiceBinder.java:146)
  at org.eclipse.smarthome.config.core.internal.Activator.start(Activator.java:45)

Some potential ways to work around this...

  1. delay the opening of the service tracker until first use
  2. remove 'the start bundle when classes are loaded' flag
  3. replace servicetrackers with DS (annotations?)

Personally, I'm not a big fan of service trackers in an activator, so option 3 would have my preference.
Any other suggestions?

@kaikreuzer
Copy link
Contributor

@maggu2810 Already introduced DS-controlled activators for the model.runtime bundles, so in general option 3 make sense (as long as the services are immediately activated). We might need to add some null checks to e.g. the static methods in BusEvents etc.

@maggu2810 Was there any reason why you left the Activator in place for the model.script bundle or do you think it is safe to change as well?

@dvanherbergen
Copy link
Contributor

Besides the activators, the issue also occurs in the ServiceBinder class (see my stacktrace above). I'm not sure I understand the purpose of this class. Why not use standard DS and keep everything consistent or move to DS annotations rather than reinventing the wheel?

@kaikreuzer
Copy link
Contributor

Question: If there are circular dependencies between services, DS cannot help us either, can it?

@dvanherbergen
Copy link
Contributor

It will depend on the cardinality/policy used. If there is a static policy on both ends of a circular dependency, then in my opinion some refactoring is due...

@kaikreuzer
Copy link
Contributor

Can you figure out which case we have here before spending to much effort on refactoring towards DS?

@dvanherbergen
Copy link
Contributor

For the issue with the org.eclipse.smarthome.action.transformation.action, there is no circular dependencies between services, but between a bundle and a service. In this case, using a dynamic 0..n policy in the org.eclipse.smarthome.model.script should work just fine.

@kaikreuzer
Copy link
Contributor

You mean specifically for the dependency to ActionService, yes. The other three are 1..1 dependencies though.
So I would be fine with extracting this into a DS component.
Wrt the ServiceBinder, let us discuss this separately afterwards, ok?

@dvanherbergen
Copy link
Contributor

The other three are 1..1 dependencies though.

Yes, so those should be static.

So I would be fine with extracting this into a DS component.

I will try to work on this tomorrow.

Wrt the ServiceBinder, let us discuss this separately afterwards, ok?

OK.

@dvanherbergen
Copy link
Contributor

I'm a bit stuck getting this to work. After the refactoring, the ScriptEngineOSGiTest is failing on a script parse error.

Running org.eclipse.smarthome.model.script.tests.scriptengine.ScriptEngineOSGiTest
Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.833 sec <<< FAILURE! - in org.eclipse.smarthome.model.script.tests.scriptengine.ScriptEngineOSGiTest
testInterpreter(org.eclipse.smarthome.model.script.tests.scriptengine.ScriptEngineOSGiTest)  Time elapsed: 0.649 sec  <<< ERROR!
org.eclipse.smarthome.model.script.engine.ScriptParsingException: 
            S ___ witch1.state = ON
            Switch1.state = OFF
            Switch1.state = ON

            Switch1.state

   1. Couldn't resolve reference to JvmIdentifiableElement 'Switch1'.; line 2, column 4, length 7
   2. Couldn't resolve reference to JvmIdentifiableElement 'Switch1'.; line 3, column 26, length 7
   3. Couldn't resolve reference to JvmIdentifiableElement 'Switch1'.; line 4, column 49, length 7
   4. Couldn't resolve reference to JvmIdentifiableElement 'Switch1'.; line 6, column 72, length 7
    at org.eclipse.smarthome.model.script.runtime.internal.engine.ScriptEngineImpl.parseScriptIntoXTextEObject(ScriptEngineImpl.java:129)
    at org.eclipse.smarthome.model.script.runtime.internal.engine.ScriptEngineImpl.newScriptFromString(ScriptEngineImpl.java:84)
    at org.eclipse.smarthome.model.script.engine.ScriptEngine$newScriptFromString.call(Unknown Source)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
    at org.eclipse.smarthome.model.script.tests.scriptengine.ScriptEngineOSGiTest.testInterpreter(ScriptEngineOSGiTest.groovy:60)

It looks to me that the error message is not correct, but as I don't know Groovy or xtend, I'm hitting a brick wall here...

@dvanherbergen
Copy link
Contributor

Just to clarify: the code changes in the pull request do work when used in openHAB. It's only the test case which is failing.

@kaikreuzer
Copy link
Contributor

Groovy and Xtend stuff in tests are indeed ugly to analyze... I'll have a try to find out what is going on there. Thanks for the PR!

@maggu2810
Copy link
Contributor

@maggu2810 Was there any reason why you left the Activator in place for the model.script bundle or do you think it is safe to change as well?

Have to look at the code, but after a very short look at #947 we have to check that the order is still strict.
The activator's activate function is finished in front of any DS calls / usage.
Using DS, we do not know the order of the activation etc.
Perhaps some classes are now used in front of the activation of the service factory DS.
I am still not familiar with that Xtext stuff, so I don't know at which time the usage of the objects that calling ServiceFactory.get... is started. But as long we are using static methods to access the references the DS gets injected, we do not know if the DS (ServiceFactory) has been started as all.

@kaikreuzer
Copy link
Contributor

I just had a look at the classes that use these trackers - a few are instantiated by Guice, which is now started up by the script.runtime component that @maggu2810 has created. So maybe we should introduce a dependency of the runtime.xml to the new service factory component - this way, we should be sure that the startup order is as required.

@dvanherbergen
Copy link
Contributor

OK, I can add that. I don't think that will fix the test case though. I tried the same test case in plain Java to make sure the sequence was correct:

@Test
    public void testInterpreter() throws Exception {

        ServiceFactory factory = new ServiceFactory();
        ScriptRuntimeStandaloneSetup.doSetup();
        ScriptEngine engine = new ScriptEngineImpl();

        String parsedScript = "Switch1.state = ON\n" +
            "Switch1.state = OFF\n" +
            "Switch1.state = ON\n" +
            "\n" +
            "Switch1.state\n";

        Script script = engine.newScriptFromString(parsedScript);
        Object switch1State = script.execute();

        Assert.assertNotNull(switch1State);
        Assert.assertEquals("org.eclipse.smarthome.core.library.types.OnOffType", switch1State.getClass().getName());
        Assert.assertEquals("ON", switch1State.toString());

    }

It results in the same script parsing error in xtend as above. Not sure where to look next.

@kaikreuzer
Copy link
Contributor

What you are missing in your plain Java test case is the definition of the item "Switch1" - this might be the same problem for the failing test above.
The error is "Couldn't resolve reference to JvmIdentifiableElement 'Switch1'" - so it simply does not know what Switch1 is as it does not seem to find it in the ItemRegistry.

@dvanherbergen
Copy link
Contributor

Thanks for the pointer. It's building without test errors now. I still need to add the runtime.xml dependency.

@kaikreuzer
Copy link
Contributor

It's building without test errors now.

That's good news!

I still need to add the runtime.xml dependency.

If you manage to do it before tonight, we would be able to still get it into the OH2 beta2, which I want to build tonight.

@dvanherbergen
Copy link
Contributor

Tonight won't be feasible, I gave it a go, but adding the runtime.xml dependency is not working and I have a plane to catch.

I'm experiencing some weird sequencing issue in the build process. For example I get the following compilation error:

[ERROR] Failed to execute goal org.eclipse.tycho:tycho-compiler-plugin:0.23.1:compile (default-compile) on project org.eclipse.smarthome.model.script: Compilation failure: Compilation failure:
[ERROR] /Users/davy/openhab/git/smarthome/bundles/model/org.eclipse.smarthome.model.script/src-gen/org/eclipse/smarthome/model/script/ScriptStandaloneSetupGenerated.java:[28]
[ERROR] return Guice.createInjector(new org.eclipse.smarthome.model.script.ScriptRuntimeModule());
[ERROR] ^^^^^^^^^^^^^^
[ERROR] The method createInjector(Module...) in the type Guice is not applicable for the arguments (ScriptRuntimeModule)
[ERROR] 1 problem (1 error)

After this, I don't make any changes, but just restart the build again from the failure point:

mvn clean install -rf :org.eclipse.smarthome.model.script

and now, it magically compiles and continues the build until it reaches the ScriptEngineOSGiTest which has test failures.

There is very little useful information shown, it looks like something (guice?) is swallowing exceptions, which makes this hard to troubleshoot.

@maggu2810
Copy link
Contributor

@dvanherbergen You shouldn't use Maven as long as the Eclipse IDE is running (and automatically build is enabled).

@maggu2810
Copy link
Contributor

@dvanherbergen
Copy link
Contributor

@maggu2810, thanks for the tip. I will give that a go...

@dvanherbergen
Copy link
Contributor

ThingSetupManager is the main one. It is used by others like SetupConsoleCommandExtension, which looks like it should be deprecated.

@kaikreuzer
Copy link
Contributor

Yes. I am in the process of having it deprecated, but we are not there yet - the Paper UI also has many dependencies on it.

@kaikreuzer
Copy link
Contributor

ThingType uses the ChannelTypeRegistry

Through the TypeResolver, indeed. This is not nice and should indeed be refactored. I have created #1012 for this.

@kaikreuzer
Copy link
Contributor

@dvanherbergen & @maggu2810 I lost this issue a bit out of sight, but this is still an annoying startup problem of OH2.
So if I get the situation right, #947 does not fully solve the issue and must not be merged.
What can we do to move forward? Should we try to address the ServiceBinder and refactor it to SCR or is there any less-risky option?

@dvanherbergen
Copy link
Contributor

#947 indeed only solves the first occurrence of the circular reference. By removing that issue, it revealed the other one in the ServiceBinder. As an alternative to #947, you could disable the 'activate plugin when classes loaded' as mentioned in this comment.
Maybe something similar can be done to avoid the circular reference for the service binder.

@maggu2810
Copy link
Contributor

I think we should drop "activate plugin when classes loaded" and move to DS (at the moment for all involved bundles).
But this is no grant that there is no circular reference anymore. But IMHO this is then much more easy to solve as we can set a 1..1 reference to 0..1 then etc.

@maggu2810
Copy link
Contributor

The initial reported circular reference could be solved by:
#1395

@kaikreuzer
Copy link
Contributor

That's what I had hoped as well, but I am still seeing the very same exception in the latest OH2 distro :-(

@maggu2810
Copy link
Contributor

@kaikreuzer Could you test the linked distribution at #1407

@kaikreuzer
Copy link
Contributor

As mentioned in #1393 (comment), this looks good!

@kaikreuzer
Copy link
Contributor

Finally fixed by #1407 - many thanks, @maggu2810!

@kaikreuzer
Copy link
Contributor

Actually not - parts of #1407 had to be reverted, because they broke the Designer; it is simply required to start the bundles before any of their classes are used. So this issue is back and I think we should have a closer look at #947.

@kaikreuzer kaikreuzer reopened this Jun 20, 2016
@maggu2810
Copy link
Contributor

Would like to add this link, I think it is very an interesting (and related) discussion: https://bugs.eclipse.org/bugs/show_bug.cgi?id=490062#c12

@kaikreuzer
Copy link
Contributor

Interesting discussion indeed. But their statement "it means that BAPL has no impact in plain OSGi when all bundles are automatically activated" somehow does not seem to be true if I look at our issue here?

@maggu2810
Copy link
Contributor

The guys are much more familiar about the OSGi framework, but after reading the "Technical Solution" here (https://www.osgi.org/developer/design/lazy-start/), I can't believe that it has no impact at all.

@kaikreuzer
Copy link
Contributor

So shall we challenge them?

@maggu2810
Copy link
Contributor

@kaikreuzer FYI: Using equinox install the most ESH features results in a circular reference detected message. If I install the same features using felix, I don't get this error.

@kaikreuzer
Copy link
Contributor

Are you silently suggesting me to switch OH to Felix...?

@maggu2810
Copy link
Contributor

No, this has not been my intention. I just want to inform you about my observations.

I think it would be a good start to use DS instead of the Activator (#947), so we can have a good dependency chain.

@kgoderis
Copy link
Contributor

I can confirm the problem, and in addition to that, the following (partly copied) is thrown as well:

2016-06-28 18:05:21.540 [WARN ] [org.eclipse.smarthome.model.script  ] - FrameworkEvent WARNING - org.eclipse.smarthome.model.script
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232)[org.eclipse.osgi-3.10.2.v20150203-1939.jar:]

@maggu2810
Copy link
Contributor

Thanks @kgoderis. The message you given is the result of the circular reference. One part of the circular reference chain cannot get the service. It will be disappear as soon as the circular reference is resolved.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants