felix-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Pierre De Rop (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (FELIX-3661) Scr sometimes does not invoke Reference bind method
Date Fri, 14 Sep 2012 08:34:07 GMT

    [ https://issues.apache.org/jira/browse/FELIX-3661?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13455669#comment-13455669
] 

Pierre De Rop commented on FELIX-3661:
--------------------------------------

Actually it's not a testcase, but a big application I am trying to start, and I don't have
knowledge about every dependencies, that's why it's difficult for now to find out the cycles.
I would appreciate if you could take a look again at the msg.log I will attach after this
message, because if I can find out the remaining cycles (I guess there are still some), then
I will be able to
proceed with the validation of FELIX-3645 "could not obtain lock in 5000 ms" issue (I'm actually
stuck about these cycles ...).

Regarding the logs, I think that in the future, it might be very helpful to plan to add some
warnings in SCR (and the specification also recommends to log an error when some cycles are
detected).

Now, in the log, the remaining problem is at 2012-09-14 10:13:54,344: here, the "agent" component
is expected to be injected with the MuxHandler service, but we then see the log: 

2012-09-14 10:13:54,344 ProxyAppReporter-FastCacheListener DEBUG osgi  - [agent] Dependency
Manager: Adding Service com.nextenso.mux.MuxHandler/597
2012-09-14 10:13:54,344 ProxyAppReporter-FastCacheListener DEBUG osgi  - [agent] DependencyManager
: component not yet created, assuming bind method call succeeded

This MuxHandler service is provided by the ["sipagent"] component. So, I suspect that there
is a cycle inside the "sipagent" component.

thanks again.

                
> Scr sometimes does not invoke Reference bind method
> ---------------------------------------------------
>
>                 Key: FELIX-3661
>                 URL: https://issues.apache.org/jira/browse/FELIX-3661
>             Project: Felix
>          Issue Type: Bug
>          Components: Declarative Services (SCR)
>            Reporter: Pierre De Rop
>            Assignee: David Jencks
>         Attachments: msg2.log, msg.log, msg.log
>
>
> With scr from trunk: sometimes, a satisfied Reference bind method is not invoked.
> I'm not sure, but this might be related to the FELIX-3659 issue and/or when Reference
types are org.osgi.service.ComponentFactory types.
> The use case is the following:
> - I have a DS component (name="agent"), which depends on the CompositeFactory service
(ref is dynamic, optional, cardinality=0..N).
> - the "agent" component is started (at this point), the CompositeFactory is not yet available
> - next, the implementation bundle for the CompositeFactory service starts and registers
the service, using bundleContext.registerService.
> - but the "agent" component is not invoked in its bindCompositeFactory(CompositeFactory)
method.
> I have attached a logfile which illustrates the problem.
> 1) Line 8491: the '"agent" component is being created, and some bind method are successfully
invoked, except the "bindCompositeFactory" method (but this is normal since the service is
optional, and not yet available):
> 2012-09-11 23:09:21,147 ProxyAppReporter-FastCacheListener DEBUG osgi  - [agent] For
dependency loggerRepository, optional: false; to bind: {[org.apache.log4j.spi.LoggerRepository]=org.apache.felix.scr.impl.manager.AbstractComponentManager$RefPair@1b7a875}
> 2012-09-11 23:09:21,147 ProxyAppReporter-FastCacheListener DEBUG osgi  - [agent] invoking
bind: bindLoggerRepository
> 2012-09-11 23:09:21,147 ProxyAppReporter-FastCacheListener DEBUG osgi  - [agent] For
dependency compositeFactory, optional: true; to bind: {}
> (here the bind for loggerRepository is invoked, but not for compositeFactory ... normal
behavior for now.
> 2) at line 8644, the CompositeFactory service is being registered, but we see the "component
not yet created, assuming bind method call succeeded" log and the bindCompositeFactory method
on the "agent" component is not invoked. 
> However, another "com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand"
DS component is succesfully bound with the CompositeFactory, but this component depends on
the CompositeService, using a ServiceReference type, instead of the actual CompositeFactory
type, in the bind method signature ...
> 2012-09-11 23:09:21,222 ProxyAppReporter-FastCacheListener WARN  com.alcatel_lucent.as.service.composite.impl.CompositeFactoryImpl
 - Registering CompositeFactory ...
> 2012-09-11 23:09:21,222 ProxyAppReporter-FastCacheListener DEBUG osgi  - [agent] Dependency
Manager: Adding Service com.alcatel_lucent.as.service.composite.CompositeFactory/565
> 2012-09-11 23:09:21,222 ProxyAppReporter-FastCacheListener DEBUG osgi  - [agent] DependencyManager
: component not yet created, assuming bind method call succeeded
> 2012-09-11 23:09:21,223 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.GogoCompositeCommand]
Dependency Manager: Adding Service com.alcatel_lucent.as.service.composite.CompositeFactory/565
> 2012-09-11 23:09:21,223 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.GogoCompositeCommand]
DependencyManager : component not yet created, assuming bind method call succeeded
> 2012-09-11 23:09:21,223 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand]
Dependency Manager: Adding Service com.alcatel_lucent.as.service.composite.CompositeFactory/565
> 2012-09-11 23:09:21,223 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand]
getting bind: bindCompositeFactory
> 2012-09-11 23:09:21,224 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand]
Locating method bindCompositeFactory in class com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand
> 2012-09-11 23:09:21,224 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand]
doFindMethod: Looking for method com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand.bindCompositeFactory
> 2012-09-11 23:09:21,224 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand]
doFindMethod: Found Method public void com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand.bindCompositeFactory(org.osgi.framework.ServiceReference)
> 2012-09-11 23:09:21,224 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand]
Found bind method: public void com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand.bindCompositeFactory(org.osgi.framework.ServiceReference)
> 2012-09-11 23:09:21,224 ProxyAppReporter-FastCacheListener DEBUG osgi  - [com.alcatel_lucent.as.service.composite.impl.shell.FelixCompositeCommand]
invoking bind: bindCompositeFactory
> 2012-09-11 23:09:21,224 ProxyAppReporter-FastCacheListener INFO  osgi.event.service 
- Service registered by bundle com.alcatel_lucent.as.service.composite.impl(1.1100.01)
>  {objectClass=[com.alcatel_lucent.as.service.composite.CompositeFactory],service.id=565}
> Hope that the log file will be enough to understand the issue ?

--
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

Mime
View raw message