0

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)

Community
  • 1
  • 1
Mannie
  • 1,608
  • 1
  • 21
  • 33
  • what about this: http://stackoverflow.com/questions/10415113/threadlocal-memory-leak-in-threadpool – burna Jan 04 '13 at 14:26

1 Answers1

0

It seems that your code uses [org.apache.http.impl.cookie.DateUtils$DateFormatHolder$] at some point. This old question tells that HttpClient may be issueing the reference.

So you need to look for code, that is using HttpClient - and be sure to cleanup any Thread or HttpClient related resources on contextDestroy.

Look at threads in your application, that use HttpClient, you should verify that these threads get stopped properly on shutdown.

Community
  • 1
  • 1
burna
  • 2,932
  • 18
  • 27
  • Thanks - Looking at the class it does create a threadlocal however I'm not using this class, a 3rd party library is; how can I clean this up so tomcat will shutdown gracefully? – Mannie Jan 04 '13 at 18:56
  • You told that a 3rd party library is using HttpClient. But based on your previous comment it look too much like that it's actually *yourself* who is using it. Note that the answerer has already told that it's HttpClient who is causing this problem. – BalusC Jan 04 '13 at 19:44
  • I think you should also look to threads you started in your app, these should be stopped properly. (yes its not in the log, but maybe) – burna Jan 04 '13 at 20:20
  • Thanks I'm thinking of moving from HttpClient - When you say "Stopped Properly" - I'm not starting any threads per-se, tomcat is though.. – Mannie Jan 04 '13 at 20:54
  • maybe httpclient needs to be update? dunno if its a bug. You could ask further on the httpclient userlist: http://hc.apache.org/mail-lists.html – burna Jan 04 '13 at 21:13