Extender startup exception

[dlaidlaw]

I was playing around with Spring DM and a minimal OSGi container setup. For startup I decided to try the fileinstall bundle that Peter Kriens has on his blog pages. It works great - it may not be good for production ready things, but it is a good way to start and stop bundles merely by dropping them in or deleting them from a directory.

But starting Spring DM 1.1.2 this way is not working, and I don't understand why. First, I started off with a set of bundles that all start normally, leaving out the extender bundle. This is the list:

[ see attached status.txt]

Bundle 1 is the fileinstall bundle, and it gets started with the config.ini as follows:

osgi.bundles=fileinstall-1.3.4.jar@3:start
eclipse.ignoreApp=true
osgi.noShutdown=true
aQute.fileinstall.dir=./plugins

The other 40 bundles are in the plugins directory. So far so good, everything starts normally with no problems.

Now dropping the extender bundle (org.springframework.bundle.osgi.extender_1.1.2) into the plugins folder causes the fileinstall bundle to attempt to install it, resolve it and start it. But it fails to start. It logs messages like this over and over:

TRACE 2008-11-10 14:36:40,115 [{aQute.fileinstall.dir=./plugins}] org.springframework.core.CollectionFactory - Creating [java.util.concurrent.ConcurrentHashMap]
INFO 2008-11-10 14:36:40,118 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.activat or.ContextLoaderListener - Starting [org.springframework.bundle.osgi.extender] bundle v.[1.1.2]
DEBUG 2008-11-10 14:36:40,124 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.activat or.ContextLoaderListener - Spring-DM v.[1.1.2] is wired to Spring core bundle org.springframework.bundle.spring.core version [2.5.5]
TRACE 2008-11-10 14:36:40,129 [{aQute.fileinstall.dir=./plugins}] org.springframework.core.CollectionFactory - Creating [java.util.concurrent.ConcurrentHashMap]
WARN 2008-11-10 14:36:40,150 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Bundle spring-jms (org.springframework.bundle.spring.jms) cannot see class [org.springframework.beans.factory.xml.NamespaceHan dlerResolver]; ignoring its namespace handlers
DEBUG 2008-11-10 14:36:40,150 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Bundle [spring-jms (org.springframework.bundle.spring.jms)] declares namespace handlers but is not compatible with extender [org.springframework.bundle.osgi.extender|1.1.2]; ignoring...
DEBUG 2008-11-10 14:36:40,162 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Adding namespace handler resolver for spring-osgi-core (org.springframework.bundle.osgi.core)
DEBUG 2008-11-10 14:36:40,163 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespacePlugins - Adding as handler spring-osgi-core (org.springframework.bundle.osgi.core)
WARN 2008-11-10 14:36:40,186 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Bundle spring-aop (org.springframework.bundle.spring.aop) cannot see class [org.springframework.beans.factory.xml.NamespaceHan dlerResolver]; ignoring its namespace handlers
DEBUG 2008-11-10 14:36:40,186 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Bundle [spring-aop (org.springframework.bundle.spring.aop)] declares namespace handlers but is not compatible with extender [org.springframework.bundle.osgi.extender|1.1.2]; ignoring...
WARN 2008-11-10 14:36:40,190 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Bundle spring-tx (org.springframework.bundle.spring.tx) cannot see class [org.springframework.beans.factory.xml.NamespaceHan dlerResolver]; ignoring its namespace handlers
DEBUG 2008-11-10 14:36:40,192 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Bundle [spring-tx (org.springframework.bundle.spring.tx)] declares namespace handlers but is not compatible with extender [org.springframework.bundle.osgi.extender|1.1.2]; ignoring...
DEBUG 2008-11-10 14:36:40,210 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Adding namespace handler resolver for spring-context (org.springframework.bundle.spring.context)
DEBUG 2008-11-10 14:36:40,211 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespacePlugins - Adding as handler spring-context (org.springframework.bundle.spring.context)
DEBUG 2008-11-10 14:36:40,214 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Adding namespace handler resolver for spring-beans (org.springframework.bundle.spring.beans)
DEBUG 2008-11-10 14:36:40,214 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespacePlugins - Adding as handler spring-beans (org.springframework.bundle.spring.beans)
DEBUG 2008-11-10 14:36:40,215 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .NamespaceManager - Registering Spring NamespaceHandlerResolver and EntityResolver...
INFO 2008-11-10 14:36:40,230 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .ExtenderConfiguration - No custom extender configuration detected; using defaults...
INFO 2008-11-10 14:36:40,236 [{aQute.fileinstall.dir=./plugins}] org.springframework.scheduling.timer.TimerTaskExec utor - Initializing Timer
DEBUG 2008-11-10 14:36:40,243 [{aQute.fileinstall.dir=./plugins}] org.springframework.osgi.extender.internal.support .ExtenderConfiguration - Spring-DM annotation processing disabled; [org.springframework.osgi.extensions.annotation.Ser viceReferenceDependencyBeanFactoryPostProcessor] not loaded

Since the fileinstall bundle attempts to restart the spring extender every 2 seconds this message is repeated. So I stop the fileinstall bundle and the extender is left in a RESOLVED state. Now attempting to start the extender with:

start 42

yields more errors like this:

[see attached exception.txt]

Any idea why this is happening?

Thanks!
-Don

[Costin Leau]

I'm not sure what the problem is - the stracktrace indicates that a class definition cannot be loaded though I'm not sure why that is. Try starting with a minimal setup, just Spring DM and dependencies and make sure you start equinox with a clean cache (-clean). See this entry in the FAQ, it might help you.

[dlaidlaw]

The FAQ on PDE did not help, since I am not using PDE at all. All this is from the unix command shell of my MacBook. I am not even starting eclipse.

But I did go to the minimal set of bundles and had some success, but only after replacing the three slf4j jars with an older set. I got the older set of slf4j jars from the Spring DM 1.0.2 release and replaced the newer jars from the 1.1.2 release.

After this the minimal OSGi setup starts and runs normally! I think there must be some packaging error in the new set of slf4j jars in the lib directory of the 1.1.2 release. These are the files in my minimal install:

-rw-r--r--@ 1 dlaidlaw dlaidlaw 4608 Oct 3 10:39 com.springsource.org.aopalliance-1.0.0.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 396742 Nov 10 14:15 com.springsource.org.apache.log4j-1.2.15.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 15435 Mar 24 2008 jcl104-over-slf4j-1.4.3.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 399088 Mar 24 2008 log4j.osgi-1.2.15-SNAPSHOT.jar
-rw-r--r-- 1 dlaidlaw dlaidlaw 92736 Mar 17 2008 org.eclipse.equinox.common_3.3.0.v20070426.jar
-rw-r--r-- 1 dlaidlaw dlaidlaw 63704 Mar 17 2008 org.eclipse.osgi.services_3.1.200.v20070605.jar
-rw-r--r-- 1 dlaidlaw dlaidlaw 22755 Sep 23 03:51 org.eclipse.osgi.util_3.1.300.v20080303.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 15345 Mar 24 2008 slf4j-api-1.4.3.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 8601 Mar 24 2008 slf4j-log4j12-1.4.3.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 326392 Oct 3 10:39 spring-aop-2.5.5.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 485785 Oct 3 10:39 spring-beans-2.5.5.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 473406 Oct 3 10:39 spring-context-2.5.5.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 287288 Oct 3 10:39 spring-core-2.5.5.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 302545 Oct 3 10:41 spring-osgi-core-1.1.2.jar
-rw-r--r-- 1 dlaidlaw dlaidlaw 92682 Oct 3 10:41 spring-osgi-extender-1.1.2.jar
-rw-r--r--@ 1 dlaidlaw dlaidlaw 31298 Oct 3 10:41 spring-osgi-io-1.1.2.jar

These work well.

Thanks for the pointers. I can have some fun from here

-Don

[dlaidlaw]

Well, after experimenting, this solution actually causes some problems later on.

The problem is that the old version of the slf4j libs export org.apache.commons.logging at version "0.0.0". Some other spring-packaged bundles import org.commons.logging at [1.1.1,2.0.0). So the other things (like commons beanutils) the Spring packages do not work well.

However, I am absolutely unable to get the extender to start with the version of slf4j packaged by spring that exports version 1.1.1 of org.apache.commons.logging. Why that is I am not sure, but the exception is very consistent:

[Framework Event Dispatcher] INFO org.springframework.bundle.osgi.extender - FrameworkEvent ERROR
org.osgi.framework.BundleException: Exception in org.springframework.osgi.extender.internal.activat or.ContextLoaderListener.start() of bundle org.springframework.bundle.osgi.extender.
at org.eclipse.osgi.framework.internal.core.BundleCon textImpl.startActivator(BundleContextImpl.java:101 8)
at org.eclipse.osgi.framework.internal.core.BundleCon textImpl.start(BundleContextImpl.java:974)
at org.eclipse.osgi.framework.internal.core.BundleHos t.startWorker(BundleHost.java:346)
at org.eclipse.osgi.framework.internal.core.AbstractB undle.resume(AbstractBundle.java:350)
at org.eclipse.osgi.framework.internal.core.Framework .resumeBundle(Framework.java:1118)
at org.eclipse.osgi.framework.internal.core.PackageAd minImpl.resumeBundles(PackageAdminImpl.java:266)
at org.eclipse.osgi.framework.internal.core.PackageAd minImpl.doResolveBundles(PackageAdminImpl.java:234 )
at org.eclipse.osgi.framework.internal.core.PackageAd minImpl$1.run(PackageAdminImpl.java:164)
at java.lang.Thread.run(Thread.java:613)
Caused by: java.lang.NoClassDefFoundError
at org.springframework.osgi.service.importer.support. AbstractServiceImporterProxyFactoryBean.setBeanCla ssLoader(AbstractServiceImporterProxyFactoryBean.j ava:158)
at org.springframework.osgi.extender.internal.activat or.ContextLoaderListener.createListenersList(Conte xtLoaderListener.java:844)
at org.springframework.osgi.extender.internal.activat or.ContextLoaderListener.initListenerService(Conte xtLoaderListener.java:826)
at org.springframework.osgi.extender.internal.activat or.ContextLoaderListener.start(ContextLoaderListen er.java:394)
at org.eclipse.osgi.framework.internal.core.BundleCon textImpl$2.run(BundleContextImpl.java:999)
at java.security.AccessController.doPrivileged(Native Method)
at org.eclipse.osgi.framework.internal.core.BundleCon textImpl.startActivator(BundleContextImpl.java:993 )
... 8 more