[
https://issues.apache.org/jira/browse/FELIX-3345?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
David Jencks updated FELIX-3345:
--------------------------------
Attachment: FELIX-3345-3.diff
I've finally managed to reproduce a similar problem in a test. The attached
includes a lot of logging additions to scr, ignores the existing integration
tests, and adds one that demonstrates a similar problem. It also always fails
for unrelated reasons. The interesting stack trace is
java.lang.NullPointerException: No log service
at
org.apache.felix.scr.impl.BundleComponentActivator.log(BundleComponentActivator.java:623)
at
org.apache.felix.scr.impl.BundleComponentActivator.log(BundleComponentActivator.java:594)
at
org.apache.felix.scr.impl.manager.AbstractComponentManager.log(AbstractComponentManager.java:635)
at
org.apache.felix.scr.impl.helper.BaseMethod$Resolved.invoke(BaseMethod.java:596)
at
org.apache.felix.scr.impl.helper.BaseMethod$NotResolved.invoke(BaseMethod.java:552)
at
org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:476)
at
org.apache.felix.scr.impl.helper.BindMethod.invoke(BindMethod.java:36)
at
org.apache.felix.scr.impl.manager.DependencyManager.invokeUnbindMethod(DependencyManager.java:1142)
at
org.apache.felix.scr.impl.manager.DependencyManager.unbind(DependencyManager.java:999)
at
org.apache.felix.scr.impl.manager.DependencyManager.close(DependencyManager.java:886)
at
org.apache.felix.scr.impl.manager.ImmediateComponentManager.disposeImplementationObject(ImmediateComponentManager.java:269)
at
org.apache.felix.scr.impl.manager.ImmediateComponentManager.deleteComponent(ImmediateComponentManager.java:135)
at
org.apache.felix.scr.impl.manager.AbstractComponentManager$Satisfied.deactivate(AbstractComponentManager.java:1225)
at
org.apache.felix.scr.impl.manager.AbstractComponentManager.deactivateInternal(AbstractComponentManager.java:339)
at
org.apache.felix.scr.impl.manager.DependencyManager.serviceRemoved(DependencyManager.java:346)
at
org.apache.felix.scr.impl.manager.DependencyManager.serviceChanged(DependencyManager.java:253)
at
org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:104)
at
org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:861)
at
org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)
at
org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)
at
org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:819)
at
org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:771)
at
org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:225)
at
org.apache.felix.scr.impl.manager.AbstractComponentManager.unregisterComponentService(AbstractComponentManager.java:567)
at
org.apache.felix.scr.impl.manager.AbstractComponentManager$Satisfied.deactivate(AbstractComponentManager.java:1224)
at
org.apache.felix.scr.impl.manager.AbstractComponentManager.disposeInternal(AbstractComponentManager.java:360)
at
org.apache.felix.scr.impl.manager.AbstractComponentManager.dispose(AbstractComponentManager.java:197)
at
org.apache.felix.scr.impl.config.ImmediateComponentHolder.disposeComponents(ImmediateComponentHolder.java:356)
at
org.apache.felix.scr.impl.BundleComponentActivator.dispose(BundleComponentActivator.java:312)
at
org.apache.felix.scr.impl.Activator.disposeComponents(Activator.java:333)
at org.apache.felix.scr.impl.Activator.bundleChanged(Activator.java:198)
at
org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:847)
at
org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)
at
org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)
at
org.eclipse.osgi.framework.internal.core.Framework.publishBundleEventPrivileged(Framework.java:1523)
at
org.eclipse.osgi.framework.internal.core.Framework.publishBundleEvent(Framework.java:1459)
at
org.eclipse.osgi.framework.internal.core.Framework.publishBundleEvent(Framework.java:1454)
at
org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:506)
at
org.eclipse.osgi.framework.internal.core.AbstractBundle.stop(AbstractBundle.java:464)
at
org.eclipse.osgi.framework.internal.core.AbstractBundle.stop(AbstractBundle.java:456)
at
org.apache.felix.scr.integration.concurrency.ConcurrentShutdownTest$Worker.run(ConcurrentShutdownTest.java:185)
at java.lang.Thread.run(Thread.java:680)
By messing with the timing I've gotten into a state where we're trying to log
on a BundleComponentActivator that has been shut down. The activity being
logged is different, but the NPE is the same. Admittedly I added the log
statement in question....
The basic scenario is two threads shutting stuff down concurrently, and an
unbind method that takes a long time to return.
bundle A has a service s1
bundle B has a service s2 with a reference to s1, and an unbind method that
takes a long time.
Stop A in thread 1; the thread gets stuck in unbind of s2.
Stop B in thread 2; this shuts down B so it's BundleComponentActivator no
longer can log (the NPE).
If the unbind method in thread 1 now returns, it will try to log in B's BCA
which has no log service tracker.
If you comment out my added logging statement you get a different NPE.
> Concurrency problems in SCR
> ---------------------------
>
> Key: FELIX-3345
> URL: https://issues.apache.org/jira/browse/FELIX-3345
> Project: Felix
> Issue Type: Bug
> Components: Declarative Services (SCR)
> Affects Versions: scr-1.6.0
> Reporter: David Jencks
> Attachments: FELIX-3345-2.diff, FELIX-3345-3.diff, FELIX-3345.diff
>
>
> We've been encountering several exceptions thrown intermittently from DS.
> They generally look like ungetting service on a disposed-of SCR
> BundleComponentActivator, ComponentManager, or DependencyManager. There may
> be two threads trying to shut down the same bundles at the same time. I'm
> not sure how to investigate the root cause or if this kind of behavior is
> expected. The SCR code generally doesn't look very thread safe. It's easy
> to "fix" the specific problems we see by adding more checks to the SCR code
> so the NPEs are avoided, or attempted use of closed bundle contexts are
> caught and ignored. I'd be happy to keep looking into this but could use
> some hints about what should be happening. Unless someone can come up with a
> better explanation and fix it would be great meanwhile to patch the code to
> avoid throwing the exceptions.
> Here are some of the typical stack traces we see:
> Stack Dump = org.osgi.framework.ServiceException: Exception in
> org.apache.felix.scr.impl.manager.DelayedComponentManager.ungetService()
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceUse.releaseService(ServiceUse.java:287)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.releaseService(ServiceRegistrationImpl.java:562)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.releaseServicesInUse(ServiceRegistry.java:665)
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.close(BundleContextImpl.java:91)
> at
> org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:514)
> at
> org.eclipse.osgi.framework.internal.core.AbstractBundle.suspend(AbstractBundle.java:565)
> at
> org.eclipse.osgi.framework.internal.core.Framework.suspendBundle(Framework.java:1161)
> at
> org.eclipse.osgi.framework.internal.core.StartLevelManager.decFWSL(StartLevelManager.java:595)
> at
> org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:257)
> at
> org.eclipse.osgi.framework.internal.core.StartLevelManager.shutdown(StartLevelManager.java:215)
> at
> org.eclipse.osgi.framework.internal.core.InternalSystemBundle.suspend(InternalSystemBundle.java:284)
> at
> org.eclipse.osgi.framework.internal.core.Framework.shutdown(Framework.java:691)
> at
> org.eclipse.osgi.framework.internal.core.Framework.close(Framework.java:598)
> at
> org.eclipse.osgi.framework.internal.core.InternalSystemBundle$1.run(InternalSystemBundle.java:261)
> at java.lang.Thread.run(Thread.java:680)
> Caused by: java.lang.NullPointerException
> at
> org.apache.felix.scr.impl.BundleComponentActivator.log(BundleComponentActivator.java:614)
> at
> org.apache.felix.scr.impl.BundleComponentActivator.log(BundleComponentActivator.java:589)
> at
> org.apache.felix.scr.impl.manager.AbstractComponentManager.log(AbstractComponentManager.java:633)
> at
> org.apache.felix.scr.impl.manager.AbstractComponentManager$State.log(AbstractComponentManager.java:1000)
> at
> org.apache.felix.scr.impl.manager.AbstractComponentManager$State.ungetService(AbstractComponentManager.java:964)
> at
> org.apache.felix.scr.impl.manager.DelayedComponentManager.ungetService(DelayedComponentManager.java:114)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceUse$3.run(ServiceUse.java:277)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceUse.releaseService(ServiceUse.java:275)
> ... 14 more
> Stack Dump = org.osgi.framework.ServiceException: Exception in
> org.apache.felix.scr.impl.manager.DelayedComponentManager.ungetService()
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceUse.releaseService(ServiceUse.java:287)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.releaseService(ServiceRegistrationImpl.java:562)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.unregister(ServiceRegistrationImpl.java:245)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.unregisterServices(ServiceRegistry.java:635)
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.close(BundleContextImpl.java:88)
> at
> org.eclipse.osgi.framework.internal.core.BundleHost.stopWorker(BundleHost.java:514)
> at
> org.eclipse.osgi.framework.internal.core.AbstractBundle.suspend(AbstractBundle.java:565)
> at
> org.eclipse.osgi.framework.internal.core.Framework.suspendBundle(Framework.java:1161)
> at
> org.eclipse.osgi.framework.internal.core.StartLevelManager.decFWSL(StartLevelManager.java:595)
> at
> org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:257)
> at
> org.eclipse.osgi.framework.internal.core.StartLevelManager.shutdown(StartLevelManager.java:215)
> at
> org.eclipse.osgi.framework.internal.core.InternalSystemBundle.suspend(InternalSystemBundle.java:284)
> at
> org.eclipse.osgi.framework.internal.core.Framework.shutdown(Framework.java:691)
> at
> org.eclipse.osgi.framework.internal.core.Framework.close(Framework.java:598)
> at
> org.eclipse.osgi.framework.internal.core.InternalSystemBundle$1.run(InternalSystemBundle.java:261)
> at java.lang.Thread.run(Thread.java:680)
> Caused by: java.lang.IllegalStateException: BundleContext is no longer valid
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.checkValid(BundleContextImpl.java:931)
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.ungetService(BundleContextImpl.java:634)
> at
> org.apache.felix.scr.impl.manager.DependencyManager.ungetService(DependencyManager.java:819)
> at
> org.apache.felix.scr.impl.manager.DependencyManager.unbind(DependencyManager.java:1000)
> at
> org.apache.felix.scr.impl.manager.DependencyManager.close(DependencyManager.java:880)
> at
> org.apache.felix.scr.impl.manager.ImmediateComponentManager.disposeImplementationObject(ImmediateComponentManager.java:268)
> at
> org.apache.felix.scr.impl.manager.ImmediateComponentManager.deleteComponent(ImmediateComponentManager.java:135)
> at
> org.apache.felix.scr.impl.manager.DelayedComponentManager.deleteComponent(DelayedComponentManager.java:67)
> at
> org.apache.felix.scr.impl.manager.AbstractComponentManager$Active.ungetService(AbstractComponentManager.java:1266)
> at
> org.apache.felix.scr.impl.manager.DelayedComponentManager.ungetService(DelayedComponentManager.java:114)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceUse$3.run(ServiceUse.java:277)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceUse.releaseService(ServiceUse.java:275)
> ... 15 more
> -------
> This one is from FELIX-3307:
> java.lang.NullPointerException
> at
> org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1028)
>
> at
> org.apache.felix.scr.impl.manager.DependencyManager.serviceAdded(DependencyManager.java:308)
>
> at
> org.apache.felix.scr.impl.manager.DependencyManager.serviceChanged(DependencyManager.java:170)
>
> at
> org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:104)
>
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.dispatchEvent(BundleContextImpl.java:861)
>
> at
> org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230)
>
> at
> org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148)
>
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:819)
>
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:771)
>
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:130)
>
> at
> org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:214)
>
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.registerService(BundleContextImpl.java:433)
>
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.registerService(BundleContextImpl.java:451)
>
> at
> org.eclipse.osgi.framework.internal.core.BundleContextImpl.registerService(BundleContextImpl.java:950)
>
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
