[Old issue] Memory leak after stop web application in Tomcat

classic Classic list List threaded Threaded
10 messages Options
Reply | Threaded
Open this post in threaded view
|

[Old issue] Memory leak after stop web application in Tomcat

liny
Hi,

It's old issue, but I still can't or find any solution so far.
After stop my web application, Tomcat told me some memory leak.
I use VisualVM to check, and yes, below caused memory leak.
Does anyone find any solutions?
Can ActiveMQ team try to solve it?
Thank you for any advice.
SEVERE: The web application [/iKPI2] appears to have started a thread named [InactivityMonitor ReadCheck] but has failed to stop it. This is very likely to create a memory leak.
Jul 13, 2012 3:51:21 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/iKPI2] appears to have started a thread named [InactivityMonitor WriteCheck] but has failed to stop it. This is very likely to create a memory leak.
Jul 13, 2012 3:51:21 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/iKPI2] appears to have started a thread named [ActiveMQ Transport: tcp://server/15.87.146.93:61616] but has failed to stop it.
This is very likely to create a memory leak.
Jul 13, 2012 3:51:21 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/iKPI2] appears to have started a thread named [InactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@ab3777
[State = 0, empty queue]] but has failed to stop it. This is very likely to create a memory leak.
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

gtully
This is https://issues.apache.org/jira/browse/AMQ-3451
can you validate that the problem is the same with a current
5.7-SNAPSHOT and that you are calling the static shutdown methods as
outlined in that jira.

If I want to quickly reproduce, what steps should I follow?

On 13 July 2012 09:09, liny <[hidden email]> wrote:

> Hi,
>
> It's old issue, but I still can't or find any solution so far.
> After stop my web application, Tomcat told me some memory leak.
> I use VisualVM to check, and yes, below caused memory leak.
> Does anyone find any solutions?
> Can ActiveMQ team try to solve it?
> Thank you for any advice.
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Old-issue-Memory-leak-after-stop-web-application-in-Tomcat-tp4653959.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



--
http://fusesource.com
http://blog.garytully.com
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

liny
Hi gtully:

I made a war with source code to reproduce the problem, please download it from My GoogleDoc.
The Tomcat version is 6.0.33 or above, but I use Tomcat 7.0.28.
Before starting this web app, you need to setup a broker TCP address in WEB-INF\classes\jms-spring-client.xml:
<value>failover:(tcp://foo.com:61616?closeAsync=false)?...
Change foo.com:61616 to your own broker.
After web app is started, you can see below main page:


And live threads are:


The reproduce steps are:
1. Click [Start getting text msg from topic], it will start listening msg from simpleTopic topic. And some ActiveMQ threads are shown as below:


2. You can go to ActiveMQ web console to send fake msg into simpleTopic. (optional) Like below:


3. Click [Stop getting text msg from topic] will do below methods (in stop() of \WEB-INF\classes\com\foo\MainApplication.java):
        subscriber.close();
        jmsSession.close();
        conn.close();
        DefaultThreadPools.getDefaultTaskRunnerFactory().shutdown();
        DefaultThreadPools.shutdown();

4. Go to Tomcat manager to stop this web app. Tomcat will show some logs like below:
17:41:26.120 [http-bio-8080-exec-4] INFO  o.s.w.c.s.XmlWebApplicationContext - Closing Root WebApplicationContext: startup date [Mon Jul 16 16:06:04 CST 2012];
root of context hierarchy
17:41:26.120 [http-bio-8080-exec-4] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'lifecycleProcessor'
17:41:26.120 [http-bio-8080-exec-4] INFO  o.s.b.f.s.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultLista
bleBeanFactory@48ad1: defining beans [jmsFactory,pooledJmsFactory,simpleTopic]; root of factory hierarchy
17:41:26.120 [http-bio-8080-exec-4] DEBUG o.s.b.f.s.DisposableBeanAdapter - Invoking destroy method 'stop' on bean with name 'pooledJmsFactory'
17:41:26.120 [http-bio-8080-exec-4] DEBUG o.a.a.pool.PooledConnectionFactory - Stop the PooledConnectionFactory, number of connections in cache: 1
Jul 16, 2012 5:41:26 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor ReadCheck] but has failed to stop it. This is very likely to create a memory leak.
Jul 16, 2012 5:41:26 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor WriteCheck] but has failed to stop it. This is very likely to create a memory leak.
Jul 16, 2012 5:41:26 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [ActiveMQ Transport: tcp://taxsrv01/157.87.146.93:61616] but has failed to stop it. This is very likely to create a memory leak.
Jul 16, 2012 5:41:26 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@
1ea9dde[State = 0, empty queue]] but has failed to stop it. This is very likely to create a memory leak.

After web app is stopped, these 4 ActiveMQ threads are still running:


Hope these can help analysis.
Let me know if any!
Thank you very much.
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

liny
In reply to this post by gtully
I also caught some logs, doesn't know whether it's related or not.
2012-07-13 15:10:04,737 ERROR o.a.a.transport.tcp.TcpTransport - Could not stop service: tcp://foo.com/15.87.14.93:61616. Reason: java.util.concurrent.RejectedExecutionException: Task org.apache.activemq.transport.tcp.TcpTransport$1@1bed75e rejected from java.util.concurrent.ThreadPoolExecutor@2d9cd0[T
erminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 3]
java.util.concurrent.RejectedExecutionException: Task org.apache.activemq.transport.tcp.TcpTransport$1@1bed75e rejected from java.util.concurrent.ThreadPoolExec
utor@2d9cd0[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 3]
        at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2013) ~[na:1.7.0_04]
        at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:816) [na:1.7.0_04]
        at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1337) [na:1.7.0_04]
        at org.apache.activemq.thread.TaskRunnerFactory.execute(TaskRunnerFactory.java:99) ~[activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.thread.TaskRunnerFactory.execute(TaskRunnerFactory.java:93) ~[activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.tcp.TcpTransport.doStop(TcpTransport.java:539) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.util.ServiceSupport.stop(ServiceSupport.java:70) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.tcp.TcpTransport.stop(TcpTransport.java:575) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.AbstractInactivityMonitor.stop(AbstractInactivityMonitor.java:127) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.TransportFilter.stop(TransportFilter.java:65) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.WireFormatNegotiator.stop(WireFormatNegotiator.java:91) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.failover.FailoverTransport.stop(FailoverTransport.java:369) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.TransportFilter.stop(TransportFilter.java:65) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.TransportFilter.stop(TransportFilter.java:65) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.transport.ResponseCorrelator.stop(ResponseCorrelator.java:132) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.util.ServiceSupport.dispose(ServiceSupport.java:43) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.ActiveMQConnection.close(ActiveMQConnection.java:692) [activemq-core-5.6.0.jar:5.6.0]
        at org.apache.activemq.pool.ConnectionPool.close(ConnectionPool.java:139) [activemq-pool-5.6.0.jar:5.6.0]
        at org.apache.activemq.pool.PooledConnectionFactory.stop(PooledConnectionFactory.java:164) [activemq-pool-5.6.0.jar:5.6.0]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_04]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_04]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_04]
        at java.lang.reflect.Method.invoke(Method.java:601) ~[na:1.7.0_04]
        at org.springframework.beans.factory.support.DisposableBeanAdapter.invokeCustomDestroyMethod(DisposableBeanAdapter.java:300) [org.springframework.beans-
3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:226) [org.springframework.beans-3.1.1.RELEASE.jar:
3.1.1.RELEASE]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:498) [org.springframework.beans-
3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:474) [org.springframework.b
eans-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:442) [org.springframework.
beans-3.1.1.RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1066) [org.springframework.context-3.1.1.
RELEASE.jar:3.1.1.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1040) [org.springframework.context-3.1.1.RELEA
SE.jar:3.1.1.RELEASE]
        at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:988) [org.springframework.context-3.1.1.RELEASE.
jar:3.1.1.RELEASE]
        at org.springframework.web.context.ContextLoader.closeWebApplicationContext(ContextLoader.java:556) [org.springframework.web-3.1.1.RELEASE.jar:3.1.1.REL
EASE]
        at org.springframework.web.context.ContextLoaderListener.contextDestroyed(ContextLoaderListener.java:142) [org.springframework.web-3.1.1.RELEASE.jar:3.1
.1.RELEASE]
        at org.apache.catalina.core.StandardContext.listenerStop(StandardContext.java:4830) [catalina.jar:7.0.28]
        at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5477) [catalina.jar:7.0.28]
        at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:232) [catalina.jar:7.0.28]
        at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1611) [catalina.jar:7.0.28]
        at org.apache.catalina.core.ContainerBase$StopChild.call(ContainerBase.java:1600) [catalina.jar:7.0.28]
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [na:1.7.0_04]
        at java.util.concurrent.FutureTask.run(FutureTask.java:166) [na:1.7.0_04]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [na:1.7.0_04]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [na:1.7.0_04]
        at java.lang.Thread.run(Thread.java:722) [na:1.7.0_04]
Jul 13, 2012 3:10:04 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/iKPI2] appears to have started a thread named [InactivityMonitor ReadCheck] but has failed to stop it. This is very likely to crea
te a memory leak.
Jul 13, 2012 3:10:04 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/iKPI2] appears to have started a thread named [InactivityMonitor WriteCheck] but has failed to stop it. This is very likely to cre
ate a memory leak.
Jul 13, 2012 3:10:04 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/iKPI2] appears to have started a thread named [ActiveMQ Transport: tcp://taxsrv01/157.87.146.93:61616] but has failed to stop it.
This is very likely to create a memory leak.
Jul 13, 2012 3:10:04 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/iKPI2] appears to have started a thread named [InactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@17329a
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

liny
In reply to this post by gtully
Hi, gtully:

Thanks for reply.
The solution that is suggested at AMQ-3451 can't solve the problem.
I did specify "destroy-method" in my WEB-INF/classes/jms-spring-client.xml as below:
  <bean id="pooledJmsFactory" class="org.apache.activemq.pool.PooledConnectionFactory"
        destroy-method="stop" lazy-init="true">

And after stop web application by Tomcat manager, spring did call "stop" of PooledConnectionFactory as below:
18:40:57.449 [http-bio-8080-exec-7] DEBUG o.a.a.pool.PooledConnectionFactory - Stop the PooledConnectionFactory, number of connections in cache: 1
18:40:57.527 [http-bio-8080-exec-7] DEBUG o.a.a.t.failover.FailoverTransport - Stopped tcp://foo.com:61616?closeAsync=false
18:40:57.527 [http-bio-8080-exec-7] DEBUG o.a.a.transport.tcp.TcpTransport - Stopping transport tcp://foo.com/15.87.14.93:61616

And "InactivityMonitor" is still running in the background.
These logs can be found in tomcat_log.TXT.

Really appreciated.
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

gtully
hmm, I gave your war a whirl with 5.7-SNAPSHOT (current trunk) and it
worked and undeployed once I added the call to stop the pool before
the calls to shutdown the executors in com.foo.MainApplication#stop

Really the correct place for the calls to shutdown is when the spring
context is destroyed, so after the call to stop the pool from the
destroy-method. In that way they cannot interfere with normal
connection close etc.

There may be some change on trunk that resolved this issue. Can you do
some validation with a 5.7-SNAPSHOT.

On 17 July 2012 12:06, liny <[hidden email]> wrote:

> Hi, gtully:
>
> Thanks for reply.
> The solution that is suggested at
> https://issues.apache.org/jira/browse/AMQ-3451?focusedCommentId=13416044&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-13416044
> AMQ-3451  can't solve the problem.
> I did specify "destroy-method" in my WEB-INF/classes/jms-spring-client.xml
> as below:
>
>
> And after stop web application by Tomcat manager, spring did call "stop" of
> PooledConnectionFactory as below:
>
>
> And "InactivityMonitor" is still running in the background.
> These logs can be found in
> http://activemq.2283324.n4.nabble.com/file/n4654084/tomcat_log.TXT
> tomcat_log.TXT .
>
> Really appreciated.
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Old-issue-Memory-leak-after-stop-web-application-in-Tomcat-tp4653959p4654084.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



--
http://fusesource.com
http://blog.garytully.com
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

liny
Hi gtully:

I changed to use 5.7-SNAPSHOT and did below in com.foo.MainApplication#stop:
        subscriber.close();
        jmsSession.close();
        conn.stop();
        conn.close();
        ((PooledConnectionFactory) springHelper.getBean("pooledJmsFactory")).stop();
        DefaultThreadPools.getDefaultTaskRunnerFactory().shutdown();
        DefaultThreadPools.shutdown();

But still not work for me.
Did ActiveMQ call AbstractInactivityMonitor#stopMonitorThreads while Connection#close?
Or anything missing?
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

gtully
Two suggestions:

introduce a DisposableBean to call the static shutdown methods on amq
so that they don't occur too early. Calling them from the main app
stop is too early as they will stop a close from being successful.

something like:
public class Shutdown implements DisposableBean {
    private static final Logger log = LoggerFactory.getLogger(Shutdown.class);

    @Override
    public void destroy() throws Exception {
        log.info("Doing amq static shutdown");
        try {
            DefaultThreadPools.getDefaultTaskRunnerFactory().shutdown();
        } finally {
            DefaultThreadPools.shutdown();
        }
    }
}

and add to your context like: <bean id="shutdown" class="com.foo.Shutdown" />

Also ensure that every call to getConnection has a corresponding call
to close, even if the call to connection pool stop has this covered,
it may be that some interaction causes a close from pool.stop to clash
and fail. But in that case I would expect to see something to that
effect in the log.

On 18 July 2012 06:32, liny <[hidden email]> wrote:

> Hi gtully:
>
> I changed to use 5.7-SNAPSHOT and did below in com.foo.MainApplication#stop:
>
>
> But still not work for me.
> Did ActiveMQ call AbstractInactivityMonitor#stopMonitorThreads while
> Connection#close?
> Or anything missing?
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Old-issue-Memory-leak-after-stop-web-application-in-Tomcat-tp4653959p4654109.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



--
http://fusesource.com
http://blog.garytully.com
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

liny
Thanks, Gary.

I created a bean like you said:
-------------------------START-------------------------------------
public class MyDisposableBean implements DisposableBean
{
  private static final Logger log = LoggerFactory.getLogger(MyDisposableBean.class);
  
  @Override
  public void destroy() throws Exception
  {
    log.info("Doing amq static shutdown.");
    try
    {
      DefaultThreadPools.getDefaultTaskRunnerFactory().shutdown();
    }
    finally
    {
      DefaultThreadPools.shutdown();
      log.info("Finally call amq static shutdown."); 
    }
  }
}
-------------------------END---------------------------------------
And added it to context xml:
-------------------------START-------------------------------------
<bean id="shutdown" class="com.foo.MyDisposableBean" />
-------------------------END---------------------------------------

If I don't call static shutdown() in  MainApplication#stop(), like below:
-------------------------START-------------------------------------
  private void stop()
  {
    try
    {
      if(conn != null)
      {
        subscriber.close();
        jmsSession.close();
        conn.stop();
        conn.close();
        ((PooledConnectionFactory) springHelper.getBean("pooledJmsFactory")).stop();
        log.debug("All clean?");
      }
    }
    catch (JMSException e)
    {
      log.error("Stop exception", e);
    }
  }
-------------------------END---------------------------------------

After manual stop web app from Tomcat web manager, the memory leaks still are there. Logs as below:
-------------------------START-------------------------------------
09:59:51.836 [http-bio-8080-exec-2] INFO  o.s.w.c.s.XmlWebApplicationContext - Closing Root WebApplicationContext: startup date [Fri Jul 20 09:58:20 CST 2012];
root of context hierarchy
09:59:51.836 [http-bio-8080-exec-2] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'lifecycleProcessor'
09:59:51.836 [http-bio-8080-exec-2] INFO  o.s.b.f.s.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultLista
bleBeanFactory@4abe67: defining beans [jmsFactory,pooledJmsFactory,simpleTopic,shutdown]; root of factory hierarchy
09:59:51.836 [http-bio-8080-exec-2] DEBUG o.s.b.f.s.DisposableBeanAdapter - Invoking destroy method 'stop' on bean with name 'pooledJmsFactory'
09:59:51.836 [http-bio-8080-exec-2] DEBUG o.a.a.pool.PooledConnectionFactory - Stop the PooledConnectionFactory, number of connections in cache: 0
09:59:51.836 [http-bio-8080-exec-2] DEBUG o.s.b.f.s.DisposableBeanAdapter - Invoking destroy() on bean with name 'shutdown'
09:59:51.836 [http-bio-8080-exec-2] INFO  com.foo.MyDisposableBean - Doing amq static shutdown.
09:59:51.836 [http-bio-8080-exec-2] INFO  com.foo.MyDisposableBean - Finally call amq static shutdown.
Jul 20, 2012 9:59:51 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor ReadCheck] but has failed to stop it. This is very likely t
o create a memory leak.
Jul 20, 2012 9:59:51 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor WriteCheck] but has failed to stop it. This is very likely
to create a memory leak.
Jul 20, 2012 9:59:51 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [ActiveMQ Transport: tcp://foo/15.87.14.93:61616] but has failed to sto
p it. This is very likely to create a memory leak.
Jul 20, 2012 9:59:51 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@
131324d[State = 0, empty queue]] but has failed to stop it. This is very likely to create a memory leak.
09:59:59.617 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10000 ms
 elapsed since last write check.
10:00:09.617 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10000 ms
 elapsed since last write check.
10:00:19.617 [InactivityMonitor ReadCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - 30000 ms elapsed since last read check.
10:00:19.617 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10000 ms
 elapsed since last write check.
10:00:29.617 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10000 ms
 elapsed since last write check.
10:00:39.618 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10001 ms
 elapsed since last write check.
10:00:49.618 [InactivityMonitor ReadCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - 30001 ms elapsed since last read check.
10:00:49.618 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10000 ms
 elapsed since last write check.
10:00:59.618 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10000 ms
 elapsed since last write check.
10:01:09.618 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@1b60bad 10000 ms
 elapsed since last write check.
10:01:19.618 [InactivityMonitor ReadCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - 30000 ms elapsed since last read check.
-------------------------END---------------------------------------
you can see the AbstractInactivityMonitor is still running.

If I call static shutdown() in MainApplication#stop(), and also in MyDisposableBean, logs look different:
-------------------------START-------------------------------------
10:05:54.013 [http-bio-8080-exec-4] INFO  o.s.w.c.s.XmlWebApplicationContext - Closing Root WebApplicationContext: startup date [Fri Jul 20 10:05:23 CST 2012];
root of context hierarchy
10:05:54.013 [http-bio-8080-exec-4] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'lifecycleProcessor'
10:05:54.013 [http-bio-8080-exec-4] INFO  o.s.b.f.s.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultLista
bleBeanFactory@eb4627: defining beans [jmsFactory,pooledJmsFactory,simpleTopic,shutdown]; root of factory hierarchy
10:05:54.013 [http-bio-8080-exec-4] DEBUG o.s.b.f.s.DisposableBeanAdapter - Invoking destroy method 'stop' on bean with name 'pooledJmsFactory'
10:05:54.013 [http-bio-8080-exec-4] DEBUG o.a.a.pool.PooledConnectionFactory - Stop the PooledConnectionFactory, number of connections in cache: 0
10:05:54.013 [http-bio-8080-exec-4] DEBUG o.s.b.f.s.DisposableBeanAdapter - Invoking destroy() on bean with name 'shutdown'
10:05:54.013 [http-bio-8080-exec-4] INFO  com.foo.MyDisposableBean - Doing amq static shutdown.
10:05:54.013 [http-bio-8080-exec-4] INFO  com.foo.MyDisposableBean - Finally call amq static shutdown.
Jul 20, 2012 10:05:54 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor ReadCheck] but has failed to stop it. This is very likely t
o create a memory leak.
Jul 20, 2012 10:05:54 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [InactivityMonitor WriteCheck] but has failed to stop it. This is very likely
to create a memory leak.
Jul 20, 2012 10:05:54 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/Vaadin_test] appears to have started a thread named [ActiveMQ Transport: tcp://foo/15.87.14.93:61616] but has failed to sto
p it. This is very likely to create a memory leak.
10:05:54.138 [InactivityMonitor WriteCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - org.apache.activemq.transport.AbstractInactivityMonitor$2@76264f 10000 ms
elapsed since last write check.
Jul 20, 2012 10:05:54 AM org.apache.catalina.loader.WebappClassLoader loadClass
INFO: Illegal access: this web application instance has been stopped already.  Could not load org.apache.activemq.transport.AbstractInactivityMonitor$3.  The ev
entual 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.
java.lang.IllegalStateException
        at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1597)
        at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1556)
        at org.apache.activemq.transport.AbstractInactivityMonitor.writeCheck(AbstractInactivityMonitor.java:142)
        at org.apache.activemq.transport.AbstractInactivityMonitor$2.run(AbstractInactivityMonitor.java:111)
        at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
        at java.util.TimerThread.mainLoop(Timer.java:555)
        at java.util.TimerThread.run(Timer.java:505)

Exception in thread "InactivityMonitor WriteCheck" java.lang.NoClassDefFoundError: org/apache/activemq/transport/AbstractInactivityMonitor$3
        at org.apache.activemq.transport.AbstractInactivityMonitor.writeCheck(AbstractInactivityMonitor.java:142)
        at org.apache.activemq.transport.AbstractInactivityMonitor$2.run(AbstractInactivityMonitor.java:111)
        at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
        at java.util.TimerThread.mainLoop(Timer.java:555)
        at java.util.TimerThread.run(Timer.java:505)
Caused by: java.lang.ClassNotFoundException: org.apache.activemq.transport.AbstractInactivityMonitor$3
        at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1711)
        at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1556)
        ... 5 more
10:06:14.138 [InactivityMonitor ReadCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - 30000 ms elapsed since last read check.
10:06:44.139 [InactivityMonitor ReadCheck] DEBUG o.a.a.t.AbstractInactivityMonitor - 30001 ms elapsed since last read check.
10:06:44.170 [ActiveMQ Transport: tcp://foo/15.87.14.93:61616] DEBUG o.a.a.t.failover.FailoverTransport - Reconnect was triggered but transport is not st
arted yet. Wait for start to connect the transport.
-------------------------END---------------------------------------

After double call static shutdown(),
thread [writeCheck] is gone after "java.lang.ClassNotFoundException: org.apache.activemq.transport.AbstractInactivityMonitor$3".
Thread [InactivityMonitor ReadCheck] and [ActiveMQ Transport: tcp://foo/15.87.14.93:61616] are still there, but after few seconds, they are gone around 10:06:44.170 finally.
At the end, FailoverTransport even tried to reconnect...weird.

I hope there is better solution on this issue.
Thank you again, Gary.
Reply | Threaded
Open this post in threaded view
|

Re: [Old issue] Memory leak after stop web application in Tomcat

gtully
connection pool stop needs to be called before the static shutdown methods.
Because stop is called via a destroy-method, you must only call the
static shutdowns from your shutdown bean, and only after the
connection pool has stopped. So there should be a depends-on relation
between the beans (shutdown depends on pool). I think they will be
stopped in reverse order.

Every call to close results in a call to stop on the inactivity
monitor which tracks the inactivity monitor executor and calls
shutdown when the reference count drops.
Looking at it now, it may be that it needs to call
java.util.concurrent.ThreadPoolExecutor#shutdownNow for that case
where some tasks are executing.

On 20 July 2012 03:41, liny <[hidden email]> wrote:

> Thanks, Gary.
>
> I created a bean like you said:
>
> And added it to context xml:
>
>
> If I don't call static shutdown() in  MainApplication#stop(), like below:
>
>
> After manual stop web app from Tomcat web manager, the memory leaks still
> are there. Logs as below:
>
> you can see the AbstractInactivityMonitor is still running.
>
> If I call static shutdown() in MainApplication#stop(), and also in
> MyDisposableBean, logs look different:
>
>
> After double call static shutdown(),
> thread [writeCheck] is gone after "java.lang.ClassNotFoundException:
> org.apache.activemq.transport.AbstractInactivityMonitor$3".
> Thread [InactivityMonitor ReadCheck] and [ActiveMQ Transport:
> tcp://foo/15.87.14.93:61616] are still there, but after few seconds, they
> are gone around 10:06:44.170 finally.
> At the end, FailoverTransport even tried to reconnect...weird.
>
> I hope there is better solution on this issue.
> Thank you again, Gary.
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Old-issue-Memory-leak-after-stop-web-application-in-Tomcat-tp4653959p4654187.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.



--
http://fusesource.com
http://blog.garytully.com