I'm having an issue with tomcat not stopping when requested from time to time and I have to kill the process manually.. I'm using a standard spring stack (JPA, MVC). This does not always happen, just about 70% of the time.. I have seen this on both Windows, OSX & Linux platforms...
Any thoughts why this may be happening.. In the below log, you will see 2 SERVERE log entries but from this question: To prevent a memory leak, the JDBC Driver has been forcibly unregistered seems to say that is not an issue with Tomcat so it leaves the soft reference..
Any thoughts why this could stop tomcat shutting down?
EDIT: On further Advice & Analysis - it looks like the apache HTTP client is using the DateUtils class, which in turns creates a ThreadLocal instance.. Our code uses the HTTP Client to class an external service... Surely this should be a very common problem if it resides in Apache HTTP Client as using this to call an external HTTP Endpoint isn't uncommon??
Threaddump below log output
Thanks,
Ian.
-2013-01-04 09:18:33,189 DEBUG [http-bio-9999-exec-8] view.InternalResourceView (InternalResourceView.java:236) - Forwarding to resource [/WEB-INF/views/auth/login.jsp] in InternalResourceView 'auth/login'
2013-01-04 09:18:33,191 DEBUG [http-bio-9999-exec-8] servlet.FrameworkServlet (FrameworkServlet.java:913) - Successfully completed request
Jan 04, 2013 9:18:33 AM org.apache.catalina.core.StandardServer await
INFO: A valid shutdown command was received via the shutdown port. Stopping the Server instance.
Jan 04, 2013 9:18:33 AM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-9999"]
Jan 04, 2013 9:18:33 AM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["ajp-bio-8009"]
Jan 04, 2013 9:18:33 AM org.apache.catalina.core.StandardService stopInternal
INFO: Stopping service Catalina
2013-01-04 09:18:33,409 INFO [localhost-startStop-2] support.AbstractApplicationContext (AbstractApplicationContext.java:1025) - Closing WebApplicationContext for namespace 'test-servlet': startup date [Thu Jan 03 17:56:22 GMT 2013]; parent: Root WebApplicationContext
2013-01-04 09:18:33,409 DEBUG [localhost-startStop-2] support.AbstractBeanFactory (AbstractBeanFactory.java:245) - Returning cached instance of singleton bean 'org.springframework.context.annotation.internalScheduledAnnotationProcessor'
2013-01-04 09:18:33,410 DEBUG [localhost-startStop-2] support.AbstractBeanFactory (AbstractBeanFactory.java:245) - Returning cached instance of singleton bean 'lifecycleProcessor'
2013-01-04 09:18:33,410 INFO [localhost-startStop-2] support.DefaultSingletonBeanRegistry (DefaultSingletonBeanRegistry.java:433) - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@37f293d3: defining beans []; parent: org.springframework.beans.factory.support.DefaultListableBeanFactory@2f701b4e
log4j:WARN No appenders could be found for logger (org.springframework.web.context.support.AnnotationConfigWebApplicationContext).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
Jan 04, 2013 9:18:33 AM org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SEVERE: The web application [] registered the JDBC driver [com.mysql.jdbc.Driver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
Jan 04, 2013 9:18:33 AM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [] created a ThreadLocal with key of type [org.apache.http.impl.cookie.DateUtils$DateFormatHolder$1] (value [org.apache.http.impl.cookie.DateUtils$DateFormatHolder$1@3f94bcde]) and a value of type [java.lang.ref.SoftReference] (value [java.lang.ref.SoftReference@3dfbb36e]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
Jan 04, 2013 9:18:33 AM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["http-bio-9999"]
Jan 04, 2013 9:18:33 AM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["ajp-bio-8009"]
Jan 04, 2013 9:18:33 AM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["http-bio-9999"]
Jan 04, 2013 9:18:33 AM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["ajp-bio-8009"]
--Thread Dump-------
at org.apache.http.impl.cookie.DateUtils$DateFormatHolder$1.initialValue(DateUtils.java:220) at org.apache.http.impl.cookie.DateUtils$DateFormatHolder$1.initialValue(DateUtils.java:219) at java.lang.ThreadLocal.setInitialValue(ThreadLocal.java:160)
at java.lang.ThreadLocal.get(ThreadLocal.java:150) at org.apache.http.impl.cookie.DateUtils$DateFormatHolder.formatFor(DateUtils.java:239) at org.apache.http.impl.cookie.DateUtils.parseDate(DateUtils.java:156)
at org.apache.http.impl.cookie.DateUtils.parseDate(DateUtils.java:114) at org.apache.http.impl.cookie.BasicExpiresHandler.parse(BasicExpiresHandler.java:61) at org.apache.http.impl.cookie.CookieSpecBase.parse(CookieSpecBase.java:93) at org.apache.http.impl.cookie.BestMatchSpec.parse(BestMatchSpec.java:135) at org.apache.http.client.protocol.ResponseProcessCookies.processCookies(ResponseProcessCookies.java:114) at org.apache.http.client.protocol.ResponseProcessCookies.process(ResponseProcessCookies.java:95) at org.apache.http.protocol.ImmutableHttpProcessor.process(ImmutableHttpProcessor.java:116) at org.apache.http.protocol.HttpRequestExecutor.postProcess(HttpRequestExecutor.java:342) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:462) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732)