org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable

Spring JIRA | Oleg Zhurakousky | 8 years ago
  1. 0

    Problem: Web Extender fails to start if it's Activator start(..) method (WarLoaderListener.start(..)) is called before Catalina service, which means that it doesn't happen all the time (only if the sequence of bundle startups is aligned in the order where Web extender is started before Web Container). To replicate this problem consistently set the Start Level for Web Extender bundle to (3). Stack Trace: ================================================================================= 12:40:03,682 ERROR (org.springframework.osgi.web.deployer.tomcat.TomcatWarDeployer:95) - No Catalina Service found, bailing out org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable at org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.getTarget(ServiceDynamicInterceptor.java:395) at org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.afterPropertiesSet(ServiceDynamicInterceptor.java:455) at org.springframework.osgi.service.importer.support.OsgiServiceProxyFactoryBean.createProxy(OsgiServiceProxyFactoryBean.java:191) at org.springframework.osgi.service.importer.support.AbstractServiceImporterProxyFactoryBean.getObject(AbstractServiceImporterProxyFactoryBean.java:75) at org.springframework.osgi.service.importer.support.OsgiServiceProxyFactoryBean.getObject(OsgiServiceProxyFactoryBean.java:140) at org.springframework.osgi.web.deployer.internal.util.Utils.createServerServiceProxy(Utils.java:117) at org.springframework.osgi.web.deployer.tomcat.TomcatWarDeployer.afterPropertiesSet(TomcatWarDeployer.java:90) at org.springframework.osgi.web.extender.internal.activator.WarListenerConfiguration.createDefaultWarDeployer(WarListenerConfiguration.java:191) at org.springframework.osgi.web.extender.internal.activator.WarListenerConfiguration.<init>(WarListenerConfiguration.java:102) at org.springframework.osgi.web.extender.internal.activator.WarLoaderListener.start(WarLoaderListener.java:339) at org.eclipse.osgi.framework.internal.core.BundleContextImpl$2.run(BundleContextImpl.java:1009) at java.security.AccessController.doPrivileged(Native Method) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:1003) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:984) at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:346) at org.eclipse.osgi.framework.internal.core.AbstractBundle.resume(AbstractBundle.java:355) at org.eclipse.osgi.framework.internal.core.Framework.resumeBundle(Framework.java:1074) at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:616) at org.eclipse.osgi.framework.internal.core.StartLevelManager.incFWSL(StartLevelManager.java:508) at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:299) at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:489) at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:211) at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:321) 12:40:03,704 INFO (org.springframework.osgi.web.tomcat.internal.Activator:85) - Starting Apache Tomcat/6.0.16 ... 12:40:03,705 INFO (org.springframework.osgi.web.tomcat.internal.Activator:167) - Using default XML configuration bundleresource://215/conf/default-server.xml 12:40:03,770 INFO (org.springframework.osgi.extender.internal.activator.ContextLoaderListener:361) - Starting [org.springframework.bundle.osgi.extender] bundle v.[1.2.0.m1-SNAPSHOT] 12:40:03,800 INFO (org.apache.catalina.startup.ClusterRuleSetFactory:68) - Unable to find a cluster rule set in the classpath. Will load the default rule set. 12:40:03,801 INFO (org.apache.catalina.startup.ClusterRuleSetFactory:68) - Unable to find a cluster rule set in the classpath. Will load the default rule set. 12:40:04,230 INFO (org.apache.coyote.http11.Http11Protocol:182) - Initializing Coyote HTTP/1.1 on http-8080 ================================================================================= Details: The quick and dirty one is to change the start level of Web Extender bundle from the default one (4) to one up (5), but I don't think it really addresses the problem. The problem is with the way bundles are started. OSGi platform (Equinox in my case) starts bundles sequentially one at the time, which means if Web Extender start(..) was initiated, no other bundles will be started until the start(..) method of Web Extender Activator will return. That is really the core of the problem, since Web Extender is looking for the actual Catalina Service which will not be started until Web Extender start(..) exits. Catalina Service is warped into a proxy (see OsgiServiceProxyFactoryBean) to address OSGi service dynamics (loss and rediscovery of service itself), which means target (service itself - Catalina) will not always be available. To address service rediscovery, one of the Service's Dynamics interceptor uses RetryTemplate to discover the service and set it as a target of the proxy, but since during startup Catalina service is not always available the retry logic of Retry Template will always fail (regardless of how many tries) if Web Extender is started before Catalina. More (as you can see form the stack trace) after it fails and OSGi proceeds and Catalina Service is started successfully, Web Extender remains in the RESOLVED state until started manually, which mean service dynamics aren't working properly anyway. Looking at the code it seem like the main reason for wrapping Catalina service into a proxy is because it might not always be available and that is why OsgiSrviceProxyFactoryBean.createProxy() does return Proxy object, however inside of that method it locks on lookupAdvice.afterPropertiesSet(); while retrying to locate the actual service, which obviously will never appear since OSGi is waiting for this bundle to start, before it will attempt to start another one. Possible solution: Execute Web Extender's Activator start(..) method asynchronously - Not the best approach as it would violate some if the best practices of OSGi Bundle Activation Better solution would be to wrap lookupAdvice.afterPropertiesSet(); into ASYNC invocation Example: new Thread(new Runnable(){ public void run() { lookupAdvice.afterPropertiesSet(); } }).start(); However, there would still be an issue inside of TomcatWarDeployer.afterPropertySet() while executing log.info("Found service " + service.getName()); which attempts to locate the actual service to get it's name. Commenting it will do the job. Obviously it is not a straight forward issue and few other things could have been suggested, but I think it's enough to get started.

    Spring JIRA | 8 years ago | Oleg Zhurakousky
    org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable
  2. 0

    Problem: Web Extender fails to start if it's Activator start(..) method (WarLoaderListener.start(..)) is called before Catalina service, which means that it doesn't happen all the time (only if the sequence of bundle startups is aligned in the order where Web extender is started before Web Container). To replicate this problem consistently set the Start Level for Web Extender bundle to (3). Stack Trace: ================================================================================= 12:40:03,682 ERROR (org.springframework.osgi.web.deployer.tomcat.TomcatWarDeployer:95) - No Catalina Service found, bailing out org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable at org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.getTarget(ServiceDynamicInterceptor.java:395) at org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.afterPropertiesSet(ServiceDynamicInterceptor.java:455) at org.springframework.osgi.service.importer.support.OsgiServiceProxyFactoryBean.createProxy(OsgiServiceProxyFactoryBean.java:191) at org.springframework.osgi.service.importer.support.AbstractServiceImporterProxyFactoryBean.getObject(AbstractServiceImporterProxyFactoryBean.java:75) at org.springframework.osgi.service.importer.support.OsgiServiceProxyFactoryBean.getObject(OsgiServiceProxyFactoryBean.java:140) at org.springframework.osgi.web.deployer.internal.util.Utils.createServerServiceProxy(Utils.java:117) at org.springframework.osgi.web.deployer.tomcat.TomcatWarDeployer.afterPropertiesSet(TomcatWarDeployer.java:90) at org.springframework.osgi.web.extender.internal.activator.WarListenerConfiguration.createDefaultWarDeployer(WarListenerConfiguration.java:191) at org.springframework.osgi.web.extender.internal.activator.WarListenerConfiguration.<init>(WarListenerConfiguration.java:102) at org.springframework.osgi.web.extender.internal.activator.WarLoaderListener.start(WarLoaderListener.java:339) at org.eclipse.osgi.framework.internal.core.BundleContextImpl$2.run(BundleContextImpl.java:1009) at java.security.AccessController.doPrivileged(Native Method) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:1003) at org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:984) at org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:346) at org.eclipse.osgi.framework.internal.core.AbstractBundle.resume(AbstractBundle.java:355) at org.eclipse.osgi.framework.internal.core.Framework.resumeBundle(Framework.java:1074) at org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:616) at org.eclipse.osgi.framework.internal.core.StartLevelManager.incFWSL(StartLevelManager.java:508) at org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:299) at org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:489) at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:211) at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:321) 12:40:03,704 INFO (org.springframework.osgi.web.tomcat.internal.Activator:85) - Starting Apache Tomcat/6.0.16 ... 12:40:03,705 INFO (org.springframework.osgi.web.tomcat.internal.Activator:167) - Using default XML configuration bundleresource://215/conf/default-server.xml 12:40:03,770 INFO (org.springframework.osgi.extender.internal.activator.ContextLoaderListener:361) - Starting [org.springframework.bundle.osgi.extender] bundle v.[1.2.0.m1-SNAPSHOT] 12:40:03,800 INFO (org.apache.catalina.startup.ClusterRuleSetFactory:68) - Unable to find a cluster rule set in the classpath. Will load the default rule set. 12:40:03,801 INFO (org.apache.catalina.startup.ClusterRuleSetFactory:68) - Unable to find a cluster rule set in the classpath. Will load the default rule set. 12:40:04,230 INFO (org.apache.coyote.http11.Http11Protocol:182) - Initializing Coyote HTTP/1.1 on http-8080 ================================================================================= Details: The quick and dirty one is to change the start level of Web Extender bundle from the default one (4) to one up (5), but I don't think it really addresses the problem. The problem is with the way bundles are started. OSGi platform (Equinox in my case) starts bundles sequentially one at the time, which means if Web Extender start(..) was initiated, no other bundles will be started until the start(..) method of Web Extender Activator will return. That is really the core of the problem, since Web Extender is looking for the actual Catalina Service which will not be started until Web Extender start(..) exits. Catalina Service is warped into a proxy (see OsgiServiceProxyFactoryBean) to address OSGi service dynamics (loss and rediscovery of service itself), which means target (service itself - Catalina) will not always be available. To address service rediscovery, one of the Service's Dynamics interceptor uses RetryTemplate to discover the service and set it as a target of the proxy, but since during startup Catalina service is not always available the retry logic of Retry Template will always fail (regardless of how many tries) if Web Extender is started before Catalina. More (as you can see form the stack trace) after it fails and OSGi proceeds and Catalina Service is started successfully, Web Extender remains in the RESOLVED state until started manually, which mean service dynamics aren't working properly anyway. Looking at the code it seem like the main reason for wrapping Catalina service into a proxy is because it might not always be available and that is why OsgiSrviceProxyFactoryBean.createProxy() does return Proxy object, however inside of that method it locks on lookupAdvice.afterPropertiesSet(); while retrying to locate the actual service, which obviously will never appear since OSGi is waiting for this bundle to start, before it will attempt to start another one. Possible solution: Execute Web Extender's Activator start(..) method asynchronously - Not the best approach as it would violate some if the best practices of OSGi Bundle Activation Better solution would be to wrap lookupAdvice.afterPropertiesSet(); into ASYNC invocation Example: new Thread(new Runnable(){ public void run() { lookupAdvice.afterPropertiesSet(); } }).start(); However, there would still be an issue inside of TomcatWarDeployer.afterPropertySet() while executing log.info("Found service " + service.getName()); which attempts to locate the actual service to get it's name. Commenting it will do the job. Obviously it is not a straight forward issue and few other things could have been suggested, but I think it's enough to get started.

    Spring JIRA | 8 years ago | Oleg Zhurakousky
    org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable
  3. 0

    vCloud Director could not display the Webside | VMware Communities

    vmware.com | 8 months ago
    org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'com.vmware.vcloud.common.configuration.ModuleConfiguration#0' defined in URL [bundleentry://170.fwk197731637/META-INF/spring/config-wizard-context.xml]: Cannot resolve reference to bean 'configurationService' while setting bean property 'configurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'configurationService': FactoryBean threw exception on object creation; nested exception is org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=com.vmware.vcloud.common.configuration.ConfigurationService)] unavailable
  4. Speed up your debug routine!

    Automated exception search integrated into your IDE

  5. 0

    After setting up an HTTPS Connector with Tomcat config file server.xml, the Web Extender consistently fails to start. This only happens when HTTPS Connector is being used on Linux 6. I've tried this on RHEL 5 and it works just fine with the default start level. Stack Trace: org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1420) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456) at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:291) at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:288) at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:190) at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:580) at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:895) at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:425) at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.access$301(AbstractDelegatedExecutionApplicationContext.java:62) at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext$1.run(AbstractDelegatedExecutionApplicationContext.java:170) at org.springframework.osgi.util.internal.PrivilegedUtils.executeWithCustomTCCL(PrivilegedUtils.java:87) at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.normalRefresh(AbstractDelegatedExecutionApplicationContext.java:166) at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext$NoDependenciesWaitRefreshExecutor.refresh(AbstractDelegatedExecutionApplicationContext.java:80) at org.springframework.osgi.context.support.AbstractDelegatedExecutionApplicationContext.refresh(AbstractDelegatedExecutionApplicationContext.java:159) at org.springframework.osgi.web.extender.internal.activator.WarListenerConfiguration.<init>(WarListenerConfiguration.java:115) at org.springframework.osgi.web.extender.internal.activator.WarLoaderListener$1.run(WarLoaderListener.java:366) at java.lang.Thread.run(Thread.java:662) Caused by: org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable at org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.getTarget(ServiceDynamicInterceptor.java:406) at org.springframework.osgi.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:62) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.osgi.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:59) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131) at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) at $Proxy2.getName(Unknown Source) at org.springframework.osgi.web.deployer.tomcat.TomcatWarDeployer.afterPropertiesSet(TomcatWarDeployer.java:91) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1477) at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1417) ... 18 more

    Spring JIRA | 3 years ago | Nicholas M
    org.springframework.osgi.service.ServiceUnavailableException: service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable

    Not finding the right solution?
    Take a tour to get the most out of Samebug.

    Tired of useless tips?

    Automated exception search integrated into your IDE

    Root Cause Analysis

    1. org.springframework.osgi.service.ServiceUnavailableException

      service matching filter=[(objectClass=org.apache.catalina.Service)] unavailable

      at org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.getTarget()
    2. Spring OSGi Core
      OsgiServiceProxyFactoryBean.getObject
      1. org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.getTarget(ServiceDynamicInterceptor.java:395)
      2. org.springframework.osgi.service.importer.support.internal.aop.ServiceDynamicInterceptor.afterPropertiesSet(ServiceDynamicInterceptor.java:455)
      3. org.springframework.osgi.service.importer.support.OsgiServiceProxyFactoryBean.createProxy(OsgiServiceProxyFactoryBean.java:191)
      4. org.springframework.osgi.service.importer.support.AbstractServiceImporterProxyFactoryBean.getObject(AbstractServiceImporterProxyFactoryBean.java:75)
      5. org.springframework.osgi.service.importer.support.OsgiServiceProxyFactoryBean.getObject(OsgiServiceProxyFactoryBean.java:140)
      5 frames
    3. org.springframework.osgi
      WarLoaderListener.start
      1. org.springframework.osgi.web.deployer.internal.util.Utils.createServerServiceProxy(Utils.java:117)
      2. org.springframework.osgi.web.deployer.tomcat.TomcatWarDeployer.afterPropertiesSet(TomcatWarDeployer.java:90)
      3. org.springframework.osgi.web.extender.internal.activator.WarListenerConfiguration.createDefaultWarDeployer(WarListenerConfiguration.java:191)
      4. org.springframework.osgi.web.extender.internal.activator.WarListenerConfiguration.<init>(WarListenerConfiguration.java:102)
      5. org.springframework.osgi.web.extender.internal.activator.WarLoaderListener.start(WarLoaderListener.java:339)
      5 frames
    4. Eclipse OSGi
      BundleContextImpl$2.run
      1. org.eclipse.osgi.framework.internal.core.BundleContextImpl$2.run(BundleContextImpl.java:1009)
      1 frame
    5. Java RT
      AccessController.doPrivileged
      1. java.security.AccessController.doPrivileged(Native Method)
      1 frame
    6. Eclipse OSGi
      StartLevelManager.dispatchEvent
      1. org.eclipse.osgi.framework.internal.core.BundleContextImpl.startActivator(BundleContextImpl.java:1003)
      2. org.eclipse.osgi.framework.internal.core.BundleContextImpl.start(BundleContextImpl.java:984)
      3. org.eclipse.osgi.framework.internal.core.BundleHost.startWorker(BundleHost.java:346)
      4. org.eclipse.osgi.framework.internal.core.AbstractBundle.resume(AbstractBundle.java:355)
      5. org.eclipse.osgi.framework.internal.core.Framework.resumeBundle(Framework.java:1074)
      6. org.eclipse.osgi.framework.internal.core.StartLevelManager.resumeBundles(StartLevelManager.java:616)
      7. org.eclipse.osgi.framework.internal.core.StartLevelManager.incFWSL(StartLevelManager.java:508)
      8. org.eclipse.osgi.framework.internal.core.StartLevelManager.doSetStartLevel(StartLevelManager.java:299)
      9. org.eclipse.osgi.framework.internal.core.StartLevelManager.dispatchEvent(StartLevelManager.java:489)
      9 frames
    7. Eclipse OSGi
      EventManager$EventThread.run
      1. org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:211)
      2. org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:321)
      2 frames