[ 
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

Reply via email to