You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@felix.apache.org by "David Jencks (JIRA)" <ji...@apache.org> on 2012/09/05 23:33:08 UTC

[jira] [Resolved] (FELIX-3639) SCR "need write lock" assertion error

     [ https://issues.apache.org/jira/browse/FELIX-3639?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

David Jencks resolved FELIX-3639.
---------------------------------

    Resolution: Fixed
    
> SCR "need write lock" assertion error
> -------------------------------------
>
>                 Key: FELIX-3639
>                 URL: https://issues.apache.org/jira/browse/FELIX-3639
>             Project: Felix
>          Issue Type: Bug
>          Components: Declarative Services (SCR)
>         Environment: openjdk version "1.6.0-OpenSCG-Build-24", on Red Hat Enterprise Linux Server release 5.4 (Tikanga)
>            Reporter: Pierre De Rop
>            Assignee: David Jencks
>             Fix For: scr-1.8.0
>
>         Attachments: NeedWriteLock.log
>
>
> This issue is related to the post http://www.mail-archive.com/dev@felix.apache.org/msg26360.html.
> Initially, the post was about an apparent deadlock, where SCR can't obtain its state lock timely.
> But after having added some tracking code in SCR, we came across another (probably different) problem,
> where the "need write lock (createComponent)" assertion fails from the ImmediateComponentManager.createComponent() method.
> In order to see the full stacktrace, I have modified the ImmediateComponentManager.createComponent method with a log, like this:
>     protected boolean createComponent()
>     {
>         if ( !isWriteLocked() )
>         {
>             log(LogService.LOG_ERROR, "need write lock (createComponent)", new Object[0], new Exception("stacktrace")); throw new IllegalStateException( "need write lock (createComponent)" );
>         }
>         ...
> (I just added a log with a "stacktrace" exception, just before throwing the illegal state).
> I have attached the full log to this issue, with ds.loglevel set to DEBUG.
> Please take a look at line line 8143, where the assertion fails.
> It's difficult to explain the whole context, but I will try to give a quick overview:
> 1- the "sipagent" component is declared like this (we are using bnd DS annotations):
> @Component(name="sipagent",provide={com.nextenso.mux.MuxHandler.class,SipAgent.class},properties=("protocol=sip"),configurationPolicy=ConfigurationPolicy.require,factory="composite.sip")
> public class SipAgentActivator extends SipAgent implements ServiceListener {
> ...
> }
> Here, the SipAgentActivator class actually extends SipAgent, which extends the MuxHandler abstract class, and the MuxHandler abstract class is provided as an OSGi service, using a "protocol=sip" service property.
> The "sipagent" component is also declared as a factory component (with name="composite.sip"), and another manager is in charge of instantiating the "sipagent" component instances (using ComponentFactory.newInstance() method). When the sip message load increases, more sipagent component instances are created.
> 2- when one "sipagent" component instance is created, there is another tracking "agent" component, which has a Reference on the MuxHandler interface, provided by the "sipagent" component. We use a ServiceReference. Here is how the "agent" component defines its reference:
> @Component(name = "agent",  configurationPolicy = ConfigurationPolicy.require)
> public class Agent {
>   @Reference(service = MuxHandler.class, type = '*', unbind = "unbindMuxHandler")
>   public void bindMuxHandler(final ServiceReference<?> muxHandler) {
>     _logger.info("bound mux handler (protocol=%s)", muxHandler.getProperty("protocol"));
>     _serial.execute(new Runnable() {
>       public void run() {
>         if (!_started) {
>           _pendingMuxHandlers.add(muxHandler);
>         } else {
>            ...
> Here, the "agent" is tracking every mux handlers, but if the "agent" component is not yet started, then the mux handler is simply stored in the "pendingMuxHandlers" temporary list. The _serial object is a serial executor, used to avoid synchronized methods.
> 3- The "agent" component also have a Reference on a "SessionManager" service, and when this service is injected, then then the "agent" component decides to handle the sip MuxHandler stored in the pendingMuxHandlers temporary list. At this point, the "agent" gets the MuxHandler ServiceReference from the temporary list, and directly calls BundleContext.getService(ServiceReference), in order to get the pointer to the actual MuxHandler object.
> But the BundleContext.getService method returns null, and internally, the ImmediateComponentManager.createComponent has throws an IllegalStateException because the writelock has not been aquired.
> See stacktrace, starting from line 8143 (it is the log I have added in the ImmediateComponentManager.createComponent method):
> 2012-08-27 13:07:45,909 Processing-ThreadPool-10 ERROR osgi  - [sipagent] need write lock (createComponent)
> java.lang.Exception: stacktrace
> 	at org.apache.felix.scr.impl.manager.ImmediateComponentManager.createComponent(ImmediateComponentManager.java:123)
> 	at org.apache.felix.scr.impl.manager.AbstractComponentManager$FactoryInstance.getService(AbstractComponentManager.java:1570)
> 	at org.apache.felix.scr.impl.manager.ImmediateComponentManager.getService(ImmediateComponentManager.java:632)
> 	at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:308)
> 	at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:219)
> 	at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:310)
> 	at org.apache.felix.framework.Felix.getService(Felix.java:3420)
> 	at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:468)
> 	at com.nextenso.agent.Agent$9.run(Agent.java:427)
> 	at com.alcatel.as.service.concurrent.SerialExecutor.execute(SerialExecutor.java:41)
> 	at com.nextenso.agent.Agent.bindSessionManager(Agent.java:362)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:616)
> 	at org.apache.felix.scr.impl.helper.BaseMethod.invokeMethod(BaseMethod.java:226)
> 	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:603)
> 	at org.apache.felix.scr.impl.helper.BaseMethod$NotResolved.invoke(BaseMethod.java:560)
> 	at org.apache.felix.scr.impl.helper.BaseMethod.invoke(BaseMethod.java:484)
> 	at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1086)
> 	at org.apache.felix.scr.impl.manager.DependencyManager.serviceAdded(DependencyManager.java:328)
> 	at org.apache.felix.scr.impl.manager.DependencyManager.serviceChanged(DependencyManager.java:170)
> 	at org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCallback(EventDispatcher.java:932)
> 	at org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(EventDispatcher.java:793)
> 	at org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDispatcher.java:543)
> 	at org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:4260)
> 	at org.apache.felix.framework.Felix.registerService(Felix.java:3275)
> 	at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:346)
> 	at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:320)
> 	at com.alcatel.as.util.osgi.DependencyActivatorHelper.registerService(DependencyActivatorHelper.java:209)
> 	at com.alcatel.as.session.distributed.mgr.Engine$7.run(Engine.java:1383)
> 	at com.alcatel.as.service.concurrent.impl.Helper.runTask(Helper.java:54)
> 	at com.alcatel.as.service.concurrent.impl.QueueExecutor$1.run(QueueExecutor.java:165)
> 	at com.alcatel.as.service.concurrent.impl.SerialQueue.run(SerialQueue.java:80)
> 	at alcatel.tess.hometop.gateways.concurrent.ThreadPool$3.run(ThreadPool.java:286)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> 	at java.lang.Thread.run(Thread.java:679)
> Is the attached log enough with ds.loglevel=DEBUG, or do you need some more informations ?

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira