Referencing service disables web app

[ulsa]

I have two bundles: 'service' and 'web'. The 'web' bundle is using Spring MVC. The 'service' bundle is exporting a service, which is imported in MANIFEST and referenced by applicationContext.xml in 'web', but otherwise not yet used.

Problem:
Tomcat gave me a blank page regardless of what I entered in the address bar. No error messages or stack traces.

Apparent Cause:
The service reference. If I comment out the service, like this:



<!-- comment out this bean to get the web app working
<osgi:reference id="myExampleBean"
interface="se.jayway.labs.spring.osgi.service.ExampleBean" />
-->


then the web app works.

If I enable the service, like this:



<!-- comment out this bean to get the web app working
-->
<osgi:reference id="myExampleBean"
interface="se.jayway.labs.spring.osgi.service.ExampleBean" />


then I get blank pages and no errors.

Any ideas?

The last few lines when the service is enabled and the web app fails:



[Timer-1] DEBUG org.springframework.beans.factory.support.DefaultL istableBeanFactory - Invoking afterPropertiesSet() on bean with name 'myExampleBean'
[Timer-1] TRACE org.springframework.osgi.service.importer.support. AbstractOsgiServiceImportFactoryBean - Unified classes={interface se.jayway.labs.spring.osgi.service.ExampleBean} and filter=[null] in=[(objectClass=se.jayway.labs.spring.osgi.service.Ex ampleBean)]
[Timer-1] TRACE org.springframework.osgi.service.importer.support. AbstractOsgiServiceImportFactoryBean - Unified serviceBeanName [null] and filter=[(objectClass=se.jayway.labs.spring.osgi.service.Ex ampleBean)] in=[(objectClass=se.jayway.labs.spring.osgi.service.Ex ampleBean)]
[Timer-1] DEBUG org.springframework.beans.factory.support.DefaultL istableBeanFactory - Finished creating instance of bean 'myExampleBean'
[Timer-1] DEBUG org.springframework.beans.factory.support.DefaultL istableBeanFactory - Returning cached instance of singleton bean 'myExampleBean'
[Timer-1] DEBUG org.springframework.osgi.service.importer.support. OsgiServiceProxyFactoryBean - creating a single service proxy ...
[Timer-1] TRACE org.springframework.osgi.service.importer.support. AbstractServiceProxyCreator - CLIENT TCCL used for invoking ServiceReference [null] null={}
[Timer-1] TRACE org.springframework.core.CollectionFactory - Creating [java.util.concurrent.ConcurrentHashMap]
[Timer-1] DEBUG org.springframework.aop.framework.JdkDynamicAopPro xy - Creating JDK dynamic proxy: target source is EmptyTargetSource: no target class, static
[Timer-1] DEBUG org.springframework.osgi.service.importer.internal .aop.ServiceDynamicInterceptor - Adding osgi mandatoryListeners for services matching [(objectClass=se.jayway.labs.spring.osgi.service.Ex ampleBean)]
[Timer-1] TRACE org.springframework.osgi.util.OsgiListenerUtils - Calling listener for already registered services: null
[Timer-1] DEBUG org.springframework.osgi.service.importer.internal .aop.ServiceDynamicInterceptor - 1..x cardinality - looking for service [(objectClass=se.jayway.labs.spring.osgi.service.Ex ampleBean)] at startup...


These are the last few lines when everything works:



[Timer-1] DEBUG org.springframework.web.servlet.DispatcherServlet - Published WebApplicationContext of servlet 'sampleBankingServlet' as ServletContext attribute with name [org.springframework.web.servlet.FrameworkServlet.C ONTEXT.sampleBankingServlet]
[Timer-1] INFO org.springframework.web.servlet.DispatcherServlet - FrameworkServlet 'sampleBankingServlet': initialization completed in 967 ms
[Timer-1] DEBUG org.springframework.web.servlet.DispatcherServlet - Servlet 'sampleBankingServlet' configured successfully
[Timer-1] TRACE org.springframework.osgi.util.DebugUtils - Could not find class [org.apache.jasper.servlet.JspServlet] required by [se.jayway.labs.spring.osgi.web(se.jayway.labs.spri ng.osgi.web)] scanning available bundles
[Timer-1] DEBUG org.apache.jasper.compiler.JspRuntimeContext - Parent class loader is: java.net.FactoryURLClassLoader@33872a
[Timer-1] DEBUG org.apache.jasper.compiler.JspRuntimeContext - Compilation classpath initialized: /tmp/spring.dm.tld.17887.jar:/Users/ulrik/Source/testing-osgi/t/myapp/runner/work/Catalina/127.0.0.1/hello:null
[Timer-1] DEBUG org.apache.jasper.servlet.JspServlet - Scratch dir for the JSP engine is: /Users/ulrik/Source/testing-osgi/t/myapp/runner/work/Catalina/127.0.0.1/hello
[Timer-1] DEBUG org.apache.jasper.servlet.JspServlet - IMPORTANT: Do not modify the generated servlets
[Timer-1] INFO org.springframework.osgi.web.deployer.tomcat.Tomca tWarDeployer - Successfully deployed bundle [se.jayway.labs.spring.osgi.web (se.jayway.labs.spring.osgi.web)] at [/hello] on server org.apache.catalina.startup.Embedded/1.0


Everything looks fine and dandy:


id State Bundle
0 ACTIVE org.eclipse.osgi_3.3.2.R33x_v20080105
1 ACTIVE org.eclipse.osgi.util_3.1.200.v20070605
2 ACTIVE org.eclipse.osgi.services_3.1.200.v20070605
3 ACTIVE org.ops4j.pax.logging.pax-logging-api_1.1.0
4 ACTIVE org.ops4j.pax.logging.pax-logging-service_1.1.0
5 ACTIVE org.springframework.osgi.aopalliance.osgi_1.0.0.SN APSHOT
6 ACTIVE org.springframework.osgi.servlet-api.osgi_2.5.0.SNAPSHOT
7 ACTIVE org.springframework.osgi.jasper.osgi_5.5.23.SNAPSH OT
8 ACTIVE org.springframework.osgi.commons-el.osgi_1.0.0.SNAPSHOT
9 ACTIVE org.springframework.osgi.jsp-api.osgi_2.0.0.SNAPSHOT
10 ACTIVE org.springframework.osgi.jstl.osgi_1.1.2.SNAPSHOT
11 ACTIVE org.springframework.osgi.catalina.osgi_6.0.16.SNAP SHOT
12 ACTIVE org.springframework.osgi.catalina.start.osgi_6.0.1 6.SNAPSHOT
13 ACTIVE org.springframework.bundle.spring.core_2.5.4
14 ACTIVE org.springframework.bundle.spring.beans_2.5.4
15 ACTIVE org.springframework.bundle.spring.context_2.5.4
16 ACTIVE org.springframework.bundle.spring.aop_2.5.4
17 ACTIVE org.springframework.bundle.osgi.core_1.1.0.rc1-SNAPSHOT
18 ACTIVE org.springframework.bundle.osgi.io_1.1.0.rc1-SNAPSHOT
19 ACTIVE org.springframework.bundle.osgi.extender_1.1.0.rc1-SNAPSHOT
20 ACTIVE org.springframework.bundle.osgi.web_1.1.0.rc1-SNAPSHOT
21 ACTIVE org.springframework.bundle.osgi.web.extender_1.1.0 .rc1-SNAPSHOT
22 ACTIVE org.springframework.bundle.spring.web_2.5.4
23 ACTIVE org.springframework.bundle.spring.webmvc_2.5.4
24 ACTIVE se.jayway.labs.spring.osgi.service_1.0.0.SNAPSHOT
25 ACTIVE se.jayway.labs.spring.osgi.web_1.0.0.SNAPSHOT

osgi> diag 24 25
initial@reference:file:se.jayway.labs.spring.osgi. service_1.0.0.SNAPSHOT.jar/ [24]
No unresolved constraints.
initial@reference:file:se.jayway.labs.spring.osgi. web_1.0.0.SNAPSHOT.jar/ [25]
No unresolved constraints.

[Costin Leau]

It's likely that the mandatory dependency is doing its default waiting for the target service to appear and thus all requests to tomcat are probably placed on hold. Try minimizing the timeout (either directly on the reference or globally) and see whether that makes a difference.

Cheers,

[ulsa]

I set the timeout to 300 and, sure enough, I got a stack trace that showed me I had defined the bean but forgotten to export the service from the 'service' bundle.

I was under the impression that no timeout and no service-unavailable-handlers would cause a ServiceUnavailableException...?

[Costin Leau]

If you don't specify a timeout, the default one (5 minutes) will apply. And there is no "service-unavailable-handlers" at least in the version of Spring-DM that I have locally :).

[ulsa]

Yes, I was looking in some old docs. In the latest reference guide, it's clear that it will block until the service becomes available, unless a timeout is specified.

Thanks for putting me on the right track. Why didn't I have the patience to just wait for five minutes? :)

[Costin Leau]

You might be interested in OSGI-472 which, if resolved, will provide a dedicated extender property which can specify the default timeout.