Community
Participate
Working Groups
Build Identifier: When our webbundle is redeployed to virgo, it is cleanly shut down, but fails to start again: 8<--------------------------------------------- [2011-06-24 11:36:55.615] INFO TCP Connection(23)-127.0.0.1 org.eclipse.virgo.medic.eventlog.default DE0004I Starting bundle 'net.junisphere.eranger.ui.web' version '0.0.1.BUILD-SNAPSHOT'. [2011-06-24 11:36:55.616] INFO TCP Connection(23)-127.0.0.1 org.eclipse.virgo.kernel.core.internal.BundleStartTracker Non-Spring DM powered bundle 'net.junisphere.eranger.ui.web_0.0.1.BUILD-SNAPSHOT [172]' has started. Driving signals '[org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact$StateMonitorSignal@5e436fcd]'. [2011-06-24 11:36:55.616] DEBUG TCP Connection(23)-127.0.0.1 org.apache.camel.impl.osgi.Activator Bundle started: net.junisphere.eranger.ui.web 8<--------------------------------------------- It seems as if it is not recognized as a spring dm powered bundle anymore. What follows is a very long list of exceptions like this one (with different classes that could not be loaded); 8<--------------------------------------------- [2011-06-24 11:36:55.617] ERROR TCP Connection(23)-127.0.0.1 System.err 24.06.2011 11:36:55 org.eclipse.gemini.web.tomcat.internal.loading.BundleWebappClassLoader loadClass [2011-06-24 11:36:55.617] ERROR TCP Connection(23)-127.0.0.1 System.err INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.camel .spi.Language. The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact. [2011-06-24 11:36:55.617] ERROR TCP Connection(23)-127.0.0.1 System.err java.lang.IllegalStateException [2011-06-24 11:36:55.617] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.gemini.web.tomcat.internal.loading.BundleWebappClassLoader.loadClass(BundleWebappClassLoader.j ava:269) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at java.lang.ClassLoader.loadClass(ClassLoader.java:248) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.virgo.web.core.internal.WebAppClassLoaderDelegateHook.postFindClass(WebAppClassLoaderDelegateH ook.java:64) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.virgo.osgi.extensions.equinox.hooks.PluggableDelegatingClassLoaderDelegateHook.postFindClass(P luggableDelegatingClassLoaderDelegateHook.java:58) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.osgi.internal.loader.BundleLoader.searchHooks(BundleLoader.java:528) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:493) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:429) [2011-06-24 11:36:55.618] INFO start-signalling-5 org.eclipse.virgo.medic.eventlog.default WE0000I Starting web bundle 'net.junisphere.eranger.ui.web' version '0.0.1.BUILD-SNAPSHOT' with context path '/ er'. [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:417) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.osgi.internal.baseadaptor.DefaultClassLoader.loadClass(DefaultClassLoader.java:107) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.virgo.kernel.userregion.internal.equinox.KernelBundleClassLoader.loadClass(KernelBundleClassLo ader.java:134) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at java.lang.ClassLoader.loadClass(ClassLoader.java:248) [2011-06-24 11:36:55.618] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.osgi.internal.loader.BundleLoader.loadClass(BundleLoader.java:345) ... [2011-06-24 11:36:55.625] ERROR TCP Connection(23)-127.0.0.1 System.err 24.06.2011 11:36:55 org.eclipse.gemini.web.tomcat.internal.loading.BundleWebappClassLoader loadClass [2011-06-24 11:36:55.625] ERROR TCP Connection(23)-127.0.0.1 System.err INFO: Illegal access: this web application instance has been stopped already. Could not load org.apache.camel .spi.DataFormat. The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact. [2011-06-24 11:36:55.625] ERROR TCP Connection(23)-127.0.0.1 System.err java.lang.IllegalStateException [2011-06-24 11:36:55.625] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.gemini.web.tomcat.internal.loading.BundleWebappClassLoader.loadClass(BundleWebappClassLoader.j ava:269) [2011-06-24 11:36:55.625] ERROR TCP Connection(23)-127.0.0.1 System.err at java.lang.ClassLoader.loadClass(ClassLoader.java:248) [2011-06-24 11:36:55.625] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.virgo.web.core.internal.WebAppClassLoaderDelegateHook.postFindClass(WebAppClassLoaderDelegateH ook.java:64) [2011-06-24 11:36:55.625] ERROR TCP Connection(23)-127.0.0.1 System.err at org.eclipse.virgo.osgi.extensions.equinox.hooks.PluggableDelegatingClassLoaderDelegateHook.postFindClass(P luggableDelegatingClassLoaderDelegateHook.java:58) ... [2011-06-24 11:36:56.168] ERROR start-signalling-5 System.err SCHWERWIEGEND: Error listenerStart [2011-06-24 11:36:56.169] ERROR start-signalling-5 System.err 24.06.2011 11:36:56 org.apache.catalina.core.StandardContext startInternal [2011-06-24 11:36:56.169] ERROR start-signalling-5 System.err SCHWERWIEGEND: Context [/er] startup failed due to previous errors [2011-06-24 11:36:56.169] ERROR start-signalling-5 System.err 24.06.2011 11:36:56 org.apache.catalina.core.ApplicationContext log [2011-06-24 11:36:56.169] ERROR start-signalling-5 System.err INFO: Closing Spring root WebApplicationContext [2011-06-24 11:36:56.173] ERROR start-signalling-5 org.eclipse.gemini.web.internal.StandardWebApplication Failed to start web application at bundleContext path '/er' org.eclipse.gemini.web.core.spi.ServletContainerException: Web application at '/er' failed to start. Check the logs for more details. at org.eclipse.gemini.web.tomcat.internal.TomcatServletContainer.startWebApplication(TomcatServletContainer.java:125) at org.eclipse.gemini.web.internal.StandardWebApplication.start(StandardWebApplication.java:91) at org.eclipse.virgo.web.core.internal.WebBundleLifecycleListener.onStarted(WebBundleLifecycleListener.java:122) at org.eclipse.virgo.kernel.install.artifact.internal.StandardArtifactStateMonitor.onStarted(StandardArtifactStateMonitor.java:247) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.asyncStartSucceeded(AbstractInstallArtifact.java:294) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact.access$0(AbstractInstallArtifact.java:291) at org.eclipse.virgo.kernel.install.artifact.internal.AbstractInstallArtifact$StateMonitorSignal.signalSuccessfulCompletion(AbstractInstallArtifact.java:229) at org.eclipse.virgo.kernel.core.internal.BundleStartTracker$1.run(BundleStartTracker.java:143) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) 8<--------------------------------------------- Then when I try to redeploy the webapp again, I get the same errors, but this time the web bundle gets uninstalled in the end. And finally the next attempt to redeploy the webapp works again! So after every code change I have to redeploy the web bundle three times to start it again. This also happens when I put the war file in the pickup directory and touch the file file to redeploy it, so it seems a bug in virgo and not in the virgo tooling. We are using Virgo 3.0.0.M05 at the moment, but it also happened on M03. Reproducible: Always Steps to Reproduce: 1. Deploy a web bundle with STS to a virgo instance 2. Redeploy it
Please find the full log file here: http://dl.dropbox.com/u/11739559/redeploy_fails.log It's > 2000 KB, so I could not upload it here.
I tried to reproduce this with a Spring powered Web Application Bundle, but the refresh worked ok: [2011-06-27 15:54:22.107] fs-watcher <HD0001I> Hot deployer processing 'MODIFIED' event for file 'org.eclipse.virgo.apps.admin.web-3.0.0.M05.jar'. [2011-06-27 15:54:23.641] fs-watcher <DE0007I> Refreshing bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05'. [2011-06-27 15:54:24.358] fs-watcher <WE0002I> Stopping web bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05' with context path '/admin'. [2011-06-27 15:54:24.441] fs-watcher <WE0003I> Stopped web bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05' with context path '/admin'. [2011-06-27 15:54:24.443] fs-watcher <DE0010I> Stopping bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05'. [2011-06-27 15:54:24.447] fs-watcher <DE0011I> Stopped bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05'. [2011-06-27 15:54:24.533] fs-watcher <DE0004I> Starting bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05'. [2011-06-27 15:54:24.541] start-signalling-4 <WE0000I> Starting web bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05' with context path '/admin'. [2011-06-27 15:54:24.923] start-signalling-4 <WE0001I> Started web bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05' with context path '/admin'. [2011-06-27 15:54:24.924] start-signalling-4 <DE0005I> Started bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05'. [2011-06-27 15:54:24.925] fs-watcher <DE0008I> Refreshed bundle 'org.eclipse.virgo.apps.admin.web' version '3.0.0.M05'. Note: I replaced the admin console plan in pickup with the admin console web bundle in order to try to mirror your instructions closely. Please could you attach a small web app that reproduces the problem?
A vanilla spring based web app seems to be redeployable. I'll try to strip down our web bundle so that I can show this behaviour.
That would be excellent. By the way, in Comment 1, you refer to a web bundle in the context of STS and a war in the context of the pickup directory. So please could you clarify: do you see the problem with web application bundles, wars, or both?
Created attachment 198713 [details] Web bundle that cannot be redeployed The attached web bundle can be deployed by copying it to the pickup directory of virgo. When touching the war, virgo tries to redeploy it, which fails. The only way to restart the web bundle is to delete it and copy it again so that it gets uninstalled and reinstalled. This behaviour showed up, after I added the camel dependencies, so it seems as if camel is not playing nice here. The source code can be found here: https://bitbucket.org/ractive/jsp-compilation "mvn package" generates a directory jsp-compilation-0.0.1.BUILD-SNAPSHOT-dependencies where (hopefully) all dependent bundles for virgo will be assembled. The content of this dir can be copied to virgo's repository/usr folder. The target dir also contains the war to be deployed to the pickup dir.
Thanks very much for the attachment. To get the dependencies, I tried to build the bitbucket project, but the build failed after many messages like this (whichI suppose do not matter since they are INFOs, but they *look* pretty serious): Downloading: http://repository.springsource.com/maven/bundles/release/org/springframework/spring-jms/3.0.5.RELEASE/spring-jms-3.0.5.RELEASE.jar [INFO] Unable to find resource 'org.springframework:spring-jms:jar:3.0.5.RELEASE' in repository spring-ebr (http://repository.springsource.com/maven/bundles/release) and then: [INFO] [compiler:compile {execution: default-compile}] [INFO] Compiling 2 source files to /Users/glynnormington/bugs/350404/ractive-jsp-compilation-2a10f12a21e6/target/classes [INFO] ------------------------------------------------------------------------ [ERROR] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Compilation failure /Users/glynnormington/bugs/350404/ractive-jsp-compilation-2a10f12a21e6/src/main/java/com/example/web/internal/AccessDeniedHandler.java:[34,5] annotations are not supported in -source 1.3 (use -source 5 or higher to enable annotations) @Override /Users/glynnormington/bugs/350404/ractive-jsp-compilation-2a10f12a21e6/src/main/java/com/example/web/internal/CollectorController.java:[12,1] annotations are not supported in -source 1.3 (use -source 5 or higher to enable annotations) @Controller I added the following to pom.xml, to set the source to 5: <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-compiler-plugin</artifactId> <configuration> <source>1.5</source> <target>1.5</target> </configuration> </plugin> but I'm confused why the project should build for you, Jean-Pierre, and not me. Anyway, I now have BUILD SUCCESSFUL, so I'll press on.
Thankfully the test application now deploys successfully and when I "touch" the war, the problem reproduces.
The logs show: java.lang.ClassNotFoundException: org.apache.camel.spring.handler.CamelNamespaceHandler so the next step is to examine the wiring and class loading before and after the refresh.
I'm also having no idea, why it builds here without setting the source to java 5. I just tried this at home and could build the project from the command line right away. But anyway, I'll updated the pom.xml to include the compiler plugin config. But I'm glad that you can now compile it and reproduce this behaviour. Good luck finding the bug... :-P Tell me if you need further support.
Thanks. I spent several hours staring at a debugger yesterday and plan to do the same today...
(In reply to comment #10) > Thanks. I spent several hours staring at a debugger yesterday and plan to do > the same today... Thank you for your help and your commitment! And don't forget to blink, while staring at the debugger. ;-)
I keep blinking, but I still can't see the precise problem. ;-) I'm far from being a Spring/web expert, but the nub of the problem seems to be that, on refresh, we get a DefaultNamespaceHandlerResolver for the BundleDelegatingClassloader which has a mapping for the camel namespace and this class loader cannot load the camel namespace handler. On initial deployment of the web app, the DefaultNamespaceHandlerResolver for the BundleDelegatingClassloader has an empty mapping and so DelegatingNamespaceHandlerResolver delegates to the NamespacePlugins namespace handler resolver which is associated with a class loader which *can* load camel's namespace handler. So I *think* there may be a problem in the application as it seems to be building two application contexts. I saw this by putting a VM breakpoint in DefaultNamespaceHandlerResolver line 160. The relevant stack traces during initial deployment are: Daemon Thread [Thread-33] (Suspended (breakpoint at line 160 in DefaultNamespaceHandlerResolver)) DefaultNamespaceHandlerResolver.getHandlerMappings() line: 160 DefaultNamespaceHandlerResolver.resolve(String) line: 113 DelegatedNamespaceHandlerResolver.resolve(String) line: 56 BeanDefinitionParserDelegate.parseCustomElement(Element, BeanDefinition) line: 1330 BeanDefinitionParserDelegate.parseCustomElement(Element) line: 1325 DefaultBeanDefinitionDocumentReader.parseBeanDefinitions(Element, BeanDefinitionParserDelegate) line: 135 DefaultBeanDefinitionDocumentReader.registerBeanDefinitions(Document, XmlReaderContext) line: 93 XmlBeanDefinitionReader.registerBeanDefinitions(Document, Resource) line: 493 XmlBeanDefinitionReader.doLoadBeanDefinitions(InputSource, Resource) line: 390 XmlBeanDefinitionReader.loadBeanDefinitions(EncodedResource) line: 334 XmlBeanDefinitionReader.loadBeanDefinitions(Resource) line: 302 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(Resource...) line: 143 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(String, Set<Resource>) line: 178 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(String) line: 149 ServerOsgiBundleXmlWebApplicationContext(OsgiBundleXmlApplicationContext).loadBeanDefinitions(XmlBeanDefinitionReader) line: 164 ServerOsgiBundleXmlWebApplicationContext(OsgiBundleXmlApplicationContext).loadBeanDefinitions(DefaultListableBeanFactory) line: 136 ServerOsgiBundleXmlWebApplicationContext(AbstractRefreshableApplicationContext).refreshBeanFactory() line: 130 ServerOsgiBundleXmlWebApplicationContext(AbstractApplicationContext).obtainFreshBeanFactory() line: 467 ServerOsgiBundleXmlWebApplicationContext(AbstractApplicationContext).refresh() line: 397 AbstractDelegatedExecutionApplicationContext.access$301(AbstractDelegatedExecutionApplicationContext) line: 69 AbstractDelegatedExecutionApplicationContext$1.run() line: 186 PrivilegedUtils.executeWithCustomTCCL(ClassLoader, PrivilegedUtils$UnprivilegedExecution) line: 85 ServerOsgiBundleXmlWebApplicationContext(AbstractDelegatedExecutionApplicationContext).normalRefresh() line: 182 AbstractDelegatedExecutionApplicationContext$NoDependenciesWaitRefreshExecutor.refresh() line: 89 ServerOsgiBundleXmlWebApplicationContext(AbstractDelegatedExecutionApplicationContext).refresh() line: 175 ContextLoaderListener(ContextLoader).createWebApplicationContext(ServletContext, ApplicationContext) line: 276 ContextLoaderListener(ContextLoader).initWebApplicationContext(ServletContext) line: 197 ContextLoaderListener.contextInitialized(ServletContextEvent) line: 47 OsgiAwareEmbeddedTomcat$ExtendedStandardContext(StandardContext).listenerStart() line: 4701 StandardContext$1.call() line: 5204 StandardContext$1.call() line: 5199 FutureTask$Sync.innerRun() line: 303 FutureTask<V>.run() line: 138 ThreadPoolExecutor$Worker.runTask(Runnable) line: 886 ThreadPoolExecutor$Worker.run() line: 908 Thread.run() line: 680 with the following variables in the top stack frame: this DefaultNamespaceHandlerResolver (id=117) classLoader BundleDelegatingClassLoader (id=146) handlerMappings ConcurrentHashMap<K,V> (id=160) handlerMappingsLocation "META-INF/spring.handlers" (id=148) logger SLF4JLocationAwareLog (id=152) mappings Properties (id=135) handlerMappings ConcurrentHashMap<K,V> (id=134) // this is empty {} and: Daemon Thread [Thread-33] (Suspended (breakpoint at line 160 in DefaultNamespaceHandlerResolver)) DefaultNamespaceHandlerResolver.getHandlerMappings() line: 160 DefaultNamespaceHandlerResolver.resolve(String) line: 113 BeanDefinitionParserDelegate.parseCustomElement(Element, BeanDefinition) line: 1330 BeanDefinitionParserDelegate.parseCustomElement(Element) line: 1325 DefaultBeanDefinitionDocumentReader.parseBeanDefinitions(Element, BeanDefinitionParserDelegate) line: 135 DefaultBeanDefinitionDocumentReader.registerBeanDefinitions(Document, XmlReaderContext) line: 93 XmlBeanDefinitionReader.registerBeanDefinitions(Document, Resource) line: 493 XmlBeanDefinitionReader.doLoadBeanDefinitions(InputSource, Resource) line: 390 XmlBeanDefinitionReader.loadBeanDefinitions(EncodedResource) line: 334 XmlBeanDefinitionReader.loadBeanDefinitions(Resource) line: 302 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(Resource...) line: 143 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(String, Set<Resource>) line: 178 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(String) line: 149 XmlWebApplicationContext.loadBeanDefinitions(XmlBeanDefinitionReader) line: 124 XmlWebApplicationContext.loadBeanDefinitions(DefaultListableBeanFactory) line: 93 XmlWebApplicationContext(AbstractRefreshableApplicationContext).refreshBeanFactory() line: 130 XmlWebApplicationContext(AbstractApplicationContext).obtainFreshBeanFactory() line: 467 XmlWebApplicationContext(AbstractApplicationContext).refresh() line: 397 DispatcherServlet(FrameworkServlet).createWebApplicationContext(ApplicationContext) line: 442 DispatcherServlet(FrameworkServlet).createWebApplicationContext(WebApplicationContext) line: 458 DispatcherServlet(FrameworkServlet).initWebApplicationContext() line: 339 DispatcherServlet(FrameworkServlet).initServletBean() line: 306 DispatcherServlet(HttpServletBean).init() line: 127 DispatcherServlet(GenericServlet).init(ServletConfig) line: 244 StandardWrapper.initServlet(Servlet) line: 1189 StandardWrapper.loadServlet() line: 1103 StandardWrapper.load() line: 1010 OsgiAwareEmbeddedTomcat$ExtendedStandardContext(StandardContext).loadOnStartup(Container[]) line: 4935 StandardContext$3.call() line: 5262 StandardContext$3.call() line: 5257 FutureTask$Sync.innerRun() line: 303 FutureTask<V>.run() line: 138 ThreadPoolExecutor$Worker.runTask(Runnable) line: 886 ThreadPoolExecutor$Worker.run() line: 908 Thread.run() line: 680 with the following variables in the top stack frame: this DefaultNamespaceHandlerResolver (id=259) classLoader BundleWebappClassLoader (id=262) handlerMappings ConcurrentHashMap<K,V> (id=284) handlerMappingsLocation "META-INF/spring.handlers" (id=148) logger SLF4JLocationAwareLog (id=152) mappings Properties (id=260) handlerMappings ConcurrentHashMap<K,V> (id=261) // this is {http://www.springframework.org/schema/jdbc=org.springframework.jdbc.config.JdbcNamespaceHandler, http://www.springframework.org/schema/osgi-compendium=org.springframework.osgi.compendium.config.CompendiumNamespaceHandler, http://www.springframework.org/schema/oxm=org.springframework.oxm.config.OxmNamespaceHandler, http://activemq.apache.org/schema/core=org.apache.xbean.spring.context.v2.XBeanNamespaceHandler, http://camel.apache.org/schema/spring=org.apache.camel.spring.handler.CamelNamespaceHandler, http://www.springframework.org/schema/osgi=org.springframework.osgi.config.OsgiNamespaceHandler, http://camel.apache.org/schema/spring/v2.7=org.apache.camel.spring.handler.CamelNamespaceHandler, http://www.springframework.org/schema/aop=org.springframework.aop.config.AopNamespaceHandler, http://www.springframework.org/schema/mvc=org.springframework.web.servlet.config.MvcNamespaceHandler, http://www.springframework.org/schema/util=org.springframework.beans.factory.xml.UtilNamespaceHandler, http://www.springframework.org/schema/jms=org.springframework.jms.config.JmsNamespaceHandler, http://www.springframework.org/schema/p=org.springframework.beans.factory.xml.SimplePropertyNamespaceHandler, http://www.springframework.org/schema/tx=org.springframework.transaction.config.TxNamespaceHandler, http://camel.apache.org/schema/osgi=org.apache.camel.osgi.CamelNamespaceHandler, http://www.springframework.org/schema/lang=org.springframework.scripting.config.LangNamespaceHandler, http://www.springframework.org/schema/task=org.springframework.scheduling.config.TaskNamespaceHandler, http://www.springframework.org/schema/context=org.springframework.context.config.ContextNamespaceHandler, http://www.springframework.org/schema/security=org.springframework.security.config.SecurityNamespaceHandler, http://www.springframework.org/schema/jee=org.springframework.ejb.config.JeeNamespaceHandler} On refresh of the bundle, there breakpoint only fires once for the the relevant paths: Daemon Thread [Thread-35] (Suspended (breakpoint at line 160 in DefaultNamespaceHandlerResolver)) DefaultNamespaceHandlerResolver.getHandlerMappings() line: 160 DefaultNamespaceHandlerResolver.resolve(String) line: 113 DelegatedNamespaceHandlerResolver.resolve(String) line: 56 BeanDefinitionParserDelegate.parseCustomElement(Element, BeanDefinition) line: 1330 BeanDefinitionParserDelegate.parseCustomElement(Element) line: 1325 DefaultBeanDefinitionDocumentReader.parseBeanDefinitions(Element, BeanDefinitionParserDelegate) line: 135 DefaultBeanDefinitionDocumentReader.registerBeanDefinitions(Document, XmlReaderContext) line: 93 XmlBeanDefinitionReader.registerBeanDefinitions(Document, Resource) line: 493 XmlBeanDefinitionReader.doLoadBeanDefinitions(InputSource, Resource) line: 390 XmlBeanDefinitionReader.loadBeanDefinitions(EncodedResource) line: 334 XmlBeanDefinitionReader.loadBeanDefinitions(Resource) line: 302 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(Resource...) line: 143 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(String, Set<Resource>) line: 178 XmlBeanDefinitionReader(AbstractBeanDefinitionReader).loadBeanDefinitions(String) line: 149 ServerOsgiBundleXmlWebApplicationContext(OsgiBundleXmlApplicationContext).loadBeanDefinitions(XmlBeanDefinitionReader) line: 164 ServerOsgiBundleXmlWebApplicationContext(OsgiBundleXmlApplicationContext).loadBeanDefinitions(DefaultListableBeanFactory) line: 136 ServerOsgiBundleXmlWebApplicationContext(AbstractRefreshableApplicationContext).refreshBeanFactory() line: 130 ServerOsgiBundleXmlWebApplicationContext(AbstractApplicationContext).obtainFreshBeanFactory() line: 467 ServerOsgiBundleXmlWebApplicationContext(AbstractApplicationContext).refresh() line: 397 AbstractDelegatedExecutionApplicationContext.access$301(AbstractDelegatedExecutionApplicationContext) line: 69 AbstractDelegatedExecutionApplicationContext$1.run() line: 186 PrivilegedUtils.executeWithCustomTCCL(ClassLoader, PrivilegedUtils$UnprivilegedExecution) line: 85 ServerOsgiBundleXmlWebApplicationContext(AbstractDelegatedExecutionApplicationContext).normalRefresh() line: 182 AbstractDelegatedExecutionApplicationContext$NoDependenciesWaitRefreshExecutor.refresh() line: 89 ServerOsgiBundleXmlWebApplicationContext(AbstractDelegatedExecutionApplicationContext).refresh() line: 175 ContextLoaderListener(ContextLoader).createWebApplicationContext(ServletContext, ApplicationContext) line: 276 ContextLoaderListener(ContextLoader).initWebApplicationContext(ServletContext) line: 197 ContextLoaderListener.contextInitialized(ServletContextEvent) line: 47 OsgiAwareEmbeddedTomcat$ExtendedStandardContext(StandardContext).listenerStart() line: 4701 StandardContext$1.call() line: 5204 StandardContext$1.call() line: 5199 FutureTask$Sync.innerRun() line: 303 FutureTask<V>.run() line: 138 ThreadPoolExecutor$Worker.runTask(Runnable) line: 886 ThreadPoolExecutor$Worker.run() line: 908 Thread.run() line: 680 with the following variables in the top stack frame: this DefaultNamespaceHandlerResolver (id=740) classLoader BundleDelegatingClassLoader (id=744) handlerMappings ConcurrentHashMap<K,V> (id=761) handlerMappingsLocation "META-INF/spring.handlers" (id=148) logger SLF4JLocationAwareLog (id=152) mappings Properties (id=741) handlerMappings ConcurrentHashMap<K,V> (id=742) // this is {http://www.springframework.org/schema/jdbc=org.springframework.jdbc.config.JdbcNamespaceHandler, http://activemq.apache.org/schema/core=org.apache.xbean.spring.context.v2.XBeanNamespaceHandler, http://www.springframework.org/schema/oxm=org.springframework.oxm.config.OxmNamespaceHandler, http://camel.apache.org/schema/spring=org.apache.camel.spring.handler.CamelNamespaceHandler, http://camel.apache.org/schema/spring/v2.7=org.apache.camel.spring.handler.CamelNamespaceHandler, http://www.springframework.org/schema/aop=org.springframework.aop.config.AopNamespaceHandler, http://www.springframework.org/schema/util=org.springframework.beans.factory.xml.UtilNamespaceHandler, http://www.springframework.org/schema/mvc=org.springframework.web.servlet.config.MvcNamespaceHandler, http://www.springframework.org/schema/jms=org.springframework.jms.config.JmsNamespaceHandler, http://www.springframework.org/schema/p=org.springframework.beans.factory.xml.SimplePropertyNamespaceHandler, http://www.springframework.org/schema/tx=org.springframework.transaction.config.TxNamespaceHandler, http://camel.apache.org/schema/osgi=org.apache.camel.osgi.CamelNamespaceHandler, http://www.springframework.org/schema/task=org.springframework.scheduling.config.TaskNamespaceHandler, http://www.springframework.org/schema/lang=org.springframework.scripting.config.LangNamespaceHandler, http://www.springframework.org/schema/context=org.springframework.context.config.ContextNamespaceHandler, http://www.springframework.org/schema/security=org.springframework.security.config.SecurityNamespaceHandler, http://www.springframework.org/schema/jee=org.springframework.ejb.config.JeeNamespaceHandler}
Further clues. On initial deployment the following application context classes appear to be driven: this ServerOsgiBundleXmlWebApplicationContext (id=1062) and: this XmlWebApplicationContext (id=1071) whereas on refresh we get: this ServerOsgiBundleXmlWebApplicationContext (id=1081) and: this ServerOsgiBundleXmlWebApplicationContext (id=1093)
More clues. The same problem occurs if the admin console is used to stop the web app and then start it again, so this is not a refresh-specific problem.
It turned out that stopping a web application was not performed antisymmetrically to starting a web application. Start associates the web app's bundle with the web app class loader and stop did not disossiate them, so a stop followed by a start (or, equivalently a refresh) resulted in the start executing with a stale association to the web app class loader and producing invalid application contexts and namespace handler resolvers. Furthermore, the actions to start a web application were not performed in the reverse order when stoppingthe web application. The changes to the stop processing are in commit 7f666cb8f2ddcc2a951d5c9a0878277d2f864250 in the Virgo web repository and fix the problem.
(In reply to comment #15) ... > The changes to the stop processing are in commit > 7f666cb8f2ddcc2a951d5c9a0878277d2f864250 in the Virgo web repository and fix > the problem. Thank you and congrats for finding a fix for this bug! We are looking forward to M06.
I can confirm that our WAB can properly be restarted with M06. Thanks.
Thanks for confirming.
