You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomee.apache.org by jdiaz <jd...@generalsw.com> on 2010/07/20 20:14:32 UTC
Error at @PreDestroy Singleton in OpenEJB 3.1.2 Tomcat shutdown
Hello,
I have the following singleton:
@Singleton
@Startup
public class Workflow implements WorkflowIF {
private static Logger logger =
Logger.getLogger(Workflow.class.getName());
//some code here
@PreDestroy
public void cerrar(){
System.out.println("Gestor de Workflows parado");
logger.info("Gestor de Workflows parado");
}
Singleton works ok at @PostConstruct, but when doing shutdown in tomcat, it
gets a nullpointerexception in logger.info line of @PreDestroy. After that,
it also appear other errors...
2010-07-20 18:11:43,053 ERROR [main] "OpenEJB": Singleton shutdown failed:
Workflow
java.lang.NullPointerException
at es.jdiaz.util.Logger.info(Logger.java:56)
at es.jdiaz.workflow.Workflow.cerrar(Workflow.java:115)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:158)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext$LifecycleInvocation.invoke(ReflectionInvocationContext.java:189)
at
org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:141)
at
org.apache.openejb.core.interceptor.InterceptorStack.invoke(InterceptorStack.java:122)
at
org.apache.openejb.core.singleton.SingletonInstanceManager.freeInstance(SingletonInstanceManager.java:316)
at
org.apache.openejb.core.singleton.SingletonContainer.undeploy(SingletonContainer.java:146)
at
org.apache.openejb.core.singleton.SingletonContainer.undeploy(SingletonContainer.java:139)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:844)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:785)
at
org.apache.openejb.tomcat.catalina.TomcatWebAppBuilder.afterStop(TomcatWebAppBuilder.java:403)
at
org.apache.openejb.tomcat.catalina.GlobalListenerSupport.lifecycleEvent(GlobalListenerSupport.java:66)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.StandardContext.stop(StandardContext.java:4427)
at
org.apache.catalina.core.ContainerBase.removeChild(ContainerBase.java:893)
at
org.apache.catalina.startup.HostConfig.undeployApps(HostConfig.java:1180)
at org.apache.catalina.startup.HostConfig.stop(HostConfig.java:1151)
at
org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:313)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1055)
at
org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1067)
at
org.apache.catalina.core.StandardEngine.stop(StandardEngine.java:448)
at
org.apache.catalina.core.StandardService.stop(StandardService.java:510)
at
org.apache.catalina.core.StandardServer.stop(StandardServer.java:734)
at org.apache.catalina.startup.Catalina.stop(Catalina.java:602)
at org.apache.catalina.startup.Catalina.start(Catalina.java:577)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:295)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:433)
2010-07-20 18:11:43,079 DEBUG [main] "OpenEJB": Destroying classLoaders for
application /opt/tomcat-instances/TEST/webapps/ROOT
2010-07-20 18:11:43,080 DEBUG [main] "OpenEJB": Releasing URLs for
application /opt/tomcat-instances/TEST/webapps/ROOT
2010-07-20 18:11:43,080 DEBUG [main] "OpenEJB": Clearing Sun JarFileFactory
cache for directory /opt/tomcat-instances/TEST/webapps/ROOT
2010-07-20 18:11:43,082 ERROR [main] "OpenEJB": Unable to clear Sun
JarFileFactory cache
java.lang.ClassCastException: java.lang.String cannot be cast to
java.net.URL
at
org.apache.openejb.ClassLoaderUtil.clearSunJarFileFactoryCache(ClassLoaderUtil.java:173)
at
org.apache.openejb.ClassLoaderUtil.destroyClassLoader(ClassLoaderUtil.java:130)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:918)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:785)
at
org.apache.openejb.tomcat.catalina.TomcatWebAppBuilder.afterStop(TomcatWebAppBuilder.java:403)
at
org.apache.openejb.tomcat.catalina.GlobalListenerSupport.lifecycleEvent(GlobalListenerSupport.java:66)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.StandardContext.stop(StandardContext.java:4427)
at
org.apache.catalina.core.ContainerBase.removeChild(ContainerBase.java:893)
at
org.apache.catalina.startup.HostConfig.undeployApps(HostConfig.java:1180)
at org.apache.catalina.startup.HostConfig.stop(HostConfig.java:1151)
at
org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:313)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1055)
at
org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1067)
at
org.apache.catalina.core.StandardEngine.stop(StandardEngine.java:448)
at
org.apache.catalina.core.StandardService.stop(StandardService.java:510)
at
org.apache.catalina.core.StandardServer.stop(StandardServer.java:734)
at org.apache.catalina.startup.Catalina.stop(Catalina.java:602)
at org.apache.catalina.startup.Catalina.start(Catalina.java:577)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:295)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:433)
2010-07-20 18:11:43,085 DEBUG [main] "OpenEJB.startup": Undeployed app:
/opt/tomcat-instances/TEST/webapps/ROOT
2010-07-20 18:11:43,327 INFO [main] "OpenEJB.startup": Undeploying app:
/opt/tomcat-instances/TEST/webapps/openejb
2010-07-20 18:11:43,327 DEBUG [main] "OpenEJB.startup": App Destroyed Event:
CxfService: /opt/tomcat-instances/TEST/webapps/openejb
2010-07-20 18:11:43,332 DEBUG [main] "OpenEJB": Destroying classLoaders for
application /opt/tomcat-instances/TEST/webapps/openejb
2010-07-20 18:11:43,333 DEBUG [main] "OpenEJB": Releasing URLs for
application /opt/tomcat-instances/TEST/webapps/openejb
2010-07-20 18:11:43,333 DEBUG [main] "OpenEJB": Clearing Sun JarFileFactory
cache for directory /opt/tomcat-instances/TEST/webapps/openejb
2010-07-20 18:11:43,334 ERROR [main] "OpenEJB": Unable to clear Sun
JarFileFactory cache
java.lang.ClassCastException: java.lang.String cannot be cast to
java.net.URL
at
org.apache.openejb.ClassLoaderUtil.clearSunJarFileFactoryCache(ClassLoaderUtil.java:173)
at
org.apache.openejb.ClassLoaderUtil.destroyClassLoader(ClassLoaderUtil.java:130)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:918)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:785)
at
org.apache.openejb.tomcat.catalina.TomcatWebAppBuilder.afterStop(TomcatWebAppBuilder.java:403)
at
org.apache.openejb.tomcat.catalina.GlobalListenerSupport.lifecycleEvent(GlobalListenerSupport.java:66)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.StandardContext.stop(StandardContext.java:4427)
at
org.apache.catalina.core.ContainerBase.removeChild(ContainerBase.java:893)
at
org.apache.catalina.startup.HostConfig.undeployApps(HostConfig.java:1180)
at org.apache.catalina.startup.HostConfig.stop(HostConfig.java:1151)
at
org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:313)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1055)
at
org.apache.catalina.core.ContainerBase.stop(ContainerBase.java:1067)
at
org.apache.catalina.core.StandardEngine.stop(StandardEngine.java:448)
at
org.apache.catalina.core.StandardService.stop(StandardService.java:510)
at
org.apache.catalina.core.StandardServer.stop(StandardServer.java:734)
at org.apache.catalina.startup.Catalina.stop(Catalina.java:602)
at org.apache.catalina.startup.Catalina.start(Catalina.java:577)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:295)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:433)
2010-07-20 18:11:43,336 DEBUG [main] "OpenEJB.startup": Undeployed app:
/opt/tomcat-instances/TEST/webapps/openejb
2010-07-20 18:11:43,477 DEBUG [main] "OpenEJB.startup": Undeploying
Applications
2010-07-20 18:11:43,478 INFO [main] "OpenEJB.startup": Undeploying app:
classpath.ear
2010-07-20 18:11:43,478 DEBUG [main] "OpenEJB.startup": App Destroyed Event:
CxfService: classpath.ear
2010-07-20 18:11:43,499 DEBUG [main] "OpenEJB": Destroying classLoaders for
application classpath.ear
2010-07-20 18:11:43,500 DEBUG [main] "OpenEJB": Destroying classLoader
URLClassLoader@22764575
2010-07-20 18:11:43,504 DEBUG [main] "OpenEJB": Releasing URLs for
application classpath.ear
2010-07-20 18:11:43,505 DEBUG [main] "OpenEJB": Clearing Sun JarFileFactory
cache for directory classpath.ear
2010-07-20 18:11:43,505 ERROR [main] "OpenEJB": Unable to clear Sun
JarFileFactory cache
java.lang.ClassCastException: java.lang.String cannot be cast to
java.net.URL
at
org.apache.openejb.ClassLoaderUtil.clearSunJarFileFactoryCache(ClassLoaderUtil.java:173)
at
org.apache.openejb.ClassLoaderUtil.destroyClassLoader(ClassLoaderUtil.java:130)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:918)
at
org.apache.openejb.assembler.classic.Assembler.destroyApplication(Assembler.java:785)
at
org.apache.openejb.assembler.classic.Assembler.destroy(Assembler.java:746)
at org.apache.openejb.OpenEJB.destroy(OpenEJB.java:250)
at
org.apache.openejb.tomcat.catalina.TomcatLoader.destroy(TomcatLoader.java:183)
at
org.apache.openejb.tomcat.catalina.TomcatLoader$1.lifecycleEvent(TomcatLoader.java:162)
at
org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:120)
at
org.apache.catalina.core.StandardServer.stop(StandardServer.java:738)
at org.apache.catalina.startup.Catalina.stop(Catalina.java:602)
at org.apache.catalina.startup.Catalina.start(Catalina.java:577)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:295)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:433)
2010-07-20 18:11:43,511 DEBUG [main] "OpenEJB.startup": Undeployed app:
classpath.ear
2010-07-20 18:11:43,546 INFO [main] "OpenEJB.startup": Stopping
ResourceAdapter: GRM_JMS_RA
2010-07-20 18:12:01,730 DEBUG [main] "OpenEJB.options": Using default
'openejb.validation.skip=false'
2010-07-20 18:12:01,802 DEBUG [main] "OpenEJB.options": Using default
'openejb.deploymentId.format={ejbName}'
2010-07-20 18:12:01,845 DEBUG [main] "OpenEJB.options": Using default
'openejb.debuggable-vm-hackery=false'
2010-07-20 18:12:01,845 DEBUG [main] "OpenEJB.options": Using default
'openejb.webservices.enabled=true'
2010-07-20 18:12:02,175 DEBUG [main] "OpenEJB.options": Using default
'openejb.vendor.config=ALL' Possible values are: geronimo, glassfish,
jboss, weblogic or NONE or ALL
2010-07-20 18:12:03,262 DEBUG [main] "OpenEJB.options": Using default
'openejb.nobanner=true'
2010-07-20 18:12:03,284 INFO [main] "OpenEJB":
--
View this message in context: http://openejb.979440.n4.nabble.com/Error-at-PreDestroy-Singleton-in-OpenEJB-3-1-2-Tomcat-shutdown-tp2295992p2295992.html
Sent from the OpenEJB User mailing list archive at Nabble.com.
Re: Error at @PreDestroy Singleton in OpenEJB 3.1.2 Tomcat shutdown
Posted by David Blevins <da...@visi.com>.
On Jul 22, 2010, at 12:16 AM, jdiaz wrote:
>
> I have detected that when I move my jar with the web application that
> contains the singleton and the rest of the classes used from my webapp
> classloader to the shared loader (
> http://tomcat.apache.org/tomcat-5.5-doc/class-loader-howto.html#Overview
> here you can see tomcat 5.5 classloaders), it works ok.
>
> I think this is a bit strange, because when I have my classes in the webapp
> classloader, openejb loads ok the singleton, and executes the @Postconstruct
> method, so in my opinion it seems before predestroy is done something that
> should be done after @Predestroy in order to have the same behaviour in this
> operation as in postconstruct.
I tracked down the code in Tomcat which does the aggressive nulling of your variable:
http://svn.apache.org/repos/asf/tomcat/tc5.5.x/tags/TOMCAT_5_5_24/container/catalina/src/share/org/apache/catalina/loader/WebappClassLoader.java
http://svn.apache.org/repos/asf/tomcat/tc6.0.x/tags/TOMCAT_6_0_3/java/org/apache/catalina/loader/WebappClassLoader.java
In either of the links above see the code comment "// Null out any static or final fields from loaded classes,"
That would explain why moving the class to the Tomcat lib directory "fixes" the problem as then Tomcat will not have it listed in the WepAppClassLoader and will not modify your variables.
It seems as of versions 5.5.24 and 6.0.3, they added this system property which you can use to shut off the stripping of static/final variables:
-Dorg.apache.catalina.loader.WebappClassLoader.ENABLE_CLEAR_REFERENCES=false
-David
Re: Error at @PreDestroy Singleton in OpenEJB 3.1.2 Tomcat shutdown
Posted by jdiaz <jd...@generalsw.com>.
I have detected that when I move my jar with the web application that
contains the singleton and the rest of the classes used from my webapp
classloader to the shared loader (
http://tomcat.apache.org/tomcat-5.5-doc/class-loader-howto.html#Overview
here you can see tomcat 5.5 classloaders), it works ok.
I think this is a bit strange, because when I have my classes in the webapp
classloader, openejb loads ok the singleton, and executes the @Postconstruct
method, so in my opinion it seems before predestroy is done something that
should be done after @Predestroy in order to have the same behaviour in this
operation as in postconstruct.
--
View this message in context: http://openejb.979440.n4.nabble.com/Error-at-PreDestroy-Singleton-in-OpenEJB-3-1-2-Tomcat-shutdown-tp2295992p2298231.html
Sent from the OpenEJB User mailing list archive at Nabble.com.
Re: Error at @PreDestroy Singleton in OpenEJB 3.1.2 Tomcat shutdown
Posted by jdiaz <jd...@generalsw.com>.
Thanks, it works perfectly with that property in 5.5.25.
--
View this message in context: http://openejb.979440.n4.nabble.com/Error-at-PreDestroy-Singleton-in-OpenEJB-3-1-2-Tomcat-shutdown-tp2295992p2300184.html
Sent from the OpenEJB User mailing list archive at Nabble.com.
Re: Error at @PreDestroy Singleton in OpenEJB 3.1.2 Tomcat shutdown
Posted by jdiaz <jd...@generalsw.com>.
Hello David,
thank you for replying.
I also tested with final and it also failed. In fact, I posted the wrong
stack. I'll put each case:
With: private static Logger logger =
Logger.getLogger(Workflow.class.getName());
2010-07-20 17:31:43,869 ERROR [main] "OpenEJB": Singleton shutdown failed:
Workflow
java.lang.NullPointerException
at es.tid.jdiaz.workflow.Workflow.cerrar(Workflow.java:115)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
With: private static final Logger logger =
Logger.getLogger(Workflow.class.getName());
2010-07-20 18:11:43,053 ERROR [main] "OpenEJB": Singleton shutdown failed:
Workflow
java.lang.NullPointerException
at es.jdiaz.util.Logger.info(Logger.java:56)
at es.jdiaz.workflow.Workflow.cerrar(Workflow.java:115)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Line 56 of Logger.java is:
logger.info(message);
where logger is defined when created Logger, so it is strange it becomes
null (or it is something about classloading I don't know).
private org.apache.log4j.Logger logger = null;
public static Logger getLogger(String loggerName){
return new
Logger(org.apache.log4j.Logger.getLogger(loggerName));
}
private Logger(org.apache.log4j.Logger logger){
this.loggerSimpleName =
logger.getName().substring(logger.getName().lastIndexOf(".")+1);
this.logger = logger;
}
The version of tomcat we are using is 5.5.25.
--
View this message in context: http://openejb.979440.n4.nabble.com/Error-at-PreDestroy-Singleton-in-OpenEJB-3-1-2-Tomcat-shutdown-tp2295992p2296713.html
Sent from the OpenEJB User mailing list archive at Nabble.com.
Re: Error at @PreDestroy Singleton in OpenEJB 3.1.2 Tomcat shutdown
Posted by David Blevins <da...@visi.com>.
On Jul 20, 2010, at 11:14 AM, jdiaz wrote:
>
> Hello,
>
> I have the following singleton:
>
> @Singleton
> @Startup
>
> public class Workflow implements WorkflowIF {
>
> private static Logger logger =
> Logger.getLogger(Workflow.class.getName());
>
> //some code here
>
> @PreDestroy
> public void cerrar(){
> System.out.println("Gestor de Workflows parado");
> logger.info("Gestor de Workflows parado");
> }
>
> Singleton works ok at @PostConstruct, but when doing shutdown in tomcat, it
> gets a nullpointerexception in logger.info line of @PreDestroy. After that,
> it also appear other errors...
>
> 2010-07-20 18:11:43,053 ERROR [main] "OpenEJB": Singleton shutdown failed:
> Workflow
> java.lang.NullPointerException
> at es.jdiaz.util.Logger.info(Logger.java:56)
> at es.jdiaz.workflow.Workflow.cerrar(Workflow.java:115)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Looks like it's the static that's going null. This vaguely makes me remember of some code in the Tomcat classloader that aggressively grabs all the static fields of all the classes it has loaded and sets them to null.
Try making your logger a 'static final' and see if that doesn't prevent it from going null.
-David