[
https://issues.apache.org/jira/browse/AMQ-6602?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15880128#comment-15880128
]
Mykola Markov commented on AMQ-6602:
------------------------------------
To show how it can impact, I had updated TaskRunnerFactory init function in
this manner:
{code}
public void init() {
int threadId = Thread.currentThread().hashCode();
try {
LOG.debug("before init TaskRunnerFactory[{}-0x{}],
executor:{}", name, Integer.toHexString(threadId), executor);
// initLock.lock();
// LOG.debug("after lock TaskRunnerFactory[{}-0x{}], executor:{}",
name, Integer.toHexString(threadId), executor);
if (initDone.compareAndSet(false, true)) {
// If your OS/JVM combination has a good thread model,
you may want to
// avoid using a thread pool to run tasks and use a
DedicatedTaskRunner instead.
if (dedicatedTaskRunner ||
"true".equalsIgnoreCase(System.getProperty("org.apache.activemq.UseDedicatedTaskRunner")))
{
executor = null;
} else if (executor == null) {
executor = createDefaultExecutor();
}
LOG.debug("Initialized TaskRunnerFactory[{}-0x{}] using
ExecutorService: {}", name, Integer.toHexString(threadId), executor);
}
} finally {
// initLock.unlock();
LOG.debug("after unlock TaskRunnerFactory[{}-0x{}],
executor:{}", name, Integer.toHexString(threadId), executor);
}
}
{code}
Initialization log
{code}
2017-02-15 17:02:57.614 [DEBUG] [colContainer-1] o.a.a.t.TaskRunnerFactory -
before init TaskRunnerFactory[ActiveMQ Session Task-0x2bef0d82], executor:null
2017-02-15 17:02:57.615 [DEBUG] [clContainer-1] o.a.a.t.TaskRunnerFactory -
before init TaskRunnerFactory[ActiveMQ Session Task-0x4b0e0ec5], executor:null
2017-02-15 17:02:57.615 [DEBUG] [clContainer-1] o.a.a.t.TaskRunnerFactory -
after unlock TaskRunnerFactory[ActiveMQ Session Task-0x4b0e0ec5], executor:null
2017-02-15 17:02:57.615 [DEBUG] [rlContainer-1] o.a.a.t.TaskRunnerFactory -
before init TaskRunnerFactory[ActiveMQ Session Task-0x28aeb65f], executor:null
2017-02-15 17:02:57.615 [DEBUG] [rlContainer-1] o.a.a.t.TaskRunnerFactory -
after unlock TaskRunnerFactory[ActiveMQ Session Task-0x28aeb65f], executor:null
2017-02-15 17:02:57.615 [DEBUG] [polContainer-1] o.a.a.t.TaskRunnerFactory -
before init TaskRunnerFactory[ActiveMQ Session Task-0x6e32598d], executor:null
2017-02-15 17:02:57.615 [DEBUG] [polContainer-1] o.a.a.t.TaskRunnerFactory -
after unlock TaskRunnerFactory[ActiveMQ Session Task-0x6e32598d], executor:null
2017-02-15 17:02:57.621 [DEBUG] [rolContainer-1] o.a.a.t.TaskRunnerFactory -
before init TaskRunnerFactory[ActiveMQ Session Task-0x75aef312], executor:null
2017-02-15 17:02:57.621 [DEBUG] [rolContainer-1] o.a.a.t.TaskRunnerFactory -
after unlock TaskRunnerFactory[ActiveMQ Session Task-0x75aef312], executor:null
2017-02-15 17:02:57.621 [DEBUG]
[org.springframework.jms.listener.DefaultMessageListenerContainer#0-1]
o.a.a.t.TaskRunnerFactory - before init TaskRunnerFactory[ActiveMQ Session
Task-0x20a020d9], executor:null
2017-02-15 17:02:57.621 [DEBUG]
[org.springframework.jms.listener.DefaultMessageListenerContainer#0-1]
o.a.a.t.TaskRunnerFactory - after unlock TaskRunnerFactory[ActiveMQ Session
Task-0x20a020d9], executor:null
2017-02-15 17:02:57.636 [TRACE] [ActiveMQ Session:
ID:comp-49411-1487206976940-1:1:1] o.a.a.t.DedicatedTaskRunner - Running task
org.apache.activemq.ActiveMQSessionExecutor@7d4182f8
2017-02-15 17:02:57.637 [TRACE] [ActiveMQ Session:
ID:comp-49411-1487206976940-1:1:6] o.a.a.t.DedicatedTaskRunner - Running task
org.apache.activemq.ActiveMQSessionExecutor@1d3f4670
2017-02-15 17:02:57.639 [TRACE] [ActiveMQ Session:
ID:comp-49411-1487206976940-1:1:2] o.a.a.t.DedicatedTaskRunner - Running task
org.apache.activemq.ActiveMQSessionExecutor@51aef7dd
2017-02-15 17:02:57.641 [TRACE] [ActiveMQ Session:
ID:comp-49411-1487206976940-1:1:5] o.a.a.t.DedicatedTaskRunner - Running task
org.apache.activemq.ActiveMQSessionExecutor@2cd032c6
2017-02-15 17:02:57.642 [TRACE] [ActiveMQ Session:
ID:comp-49411-1487206976940-1:1:12] o.a.a.t.DedicatedTaskRunner - Running task
org.apache.activemq.ActiveMQSessionExecutor@6ab678f8
2017-02-15 17:02:57.649 [DEBUG] [colContainer-1] o.a.a.t.TaskRunnerFactory -
Initialized TaskRunnerFactory[ActiveMQ Session Task-0x2bef0d82] using
ExecutorService: java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool
size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
2017-02-15 17:02:57.650 [DEBUG] [colContainer-1] o.a.a.t.TaskRunnerFactory -
after unlock TaskRunnerFactory[ActiveMQ Session Task-0x2bef0d82],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
0, active threads = 0, queued tasks = 0, completed tasks = 0]
2017-02-15 17:02:57.660 [TRACE] [colContainer-1] o.a.a.t.TaskRunnerFactory -
Created thread[ActiveMQ Session Task-1]: Thread[ActiveMQ Session Task-1,7,main]
2017-02-15 17:02:57.813 [DEBUG] [DefaultMessageListenerContainer-2]
o.a.a.t.TaskRunnerFactory - before init TaskRunnerFactory[ActiveMQ Session
Task-0x789e8e89],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 1]
2017-02-15 17:02:57.814 [DEBUG] [DefaultMessageListenerContainer-2]
o.a.a.t.TaskRunnerFactory - after unlock TaskRunnerFactory[ActiveMQ Session
Task-0x789e8e89],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 1]
2017-02-15 17:02:57.815 [DEBUG] [DefaultMessageListenerContainer-3]
o.a.a.t.TaskRunnerFactory - before init TaskRunnerFactory[ActiveMQ Session
Task-0x5c3aee6b],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 2]
2017-02-15 17:02:57.816 [DEBUG] [DefaultMessageListenerContainer-3]
o.a.a.t.TaskRunnerFactory - after unlock TaskRunnerFactory[ActiveMQ Session
Task-0x5c3aee6b],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 2]
2017-02-15 17:02:57.815 [DEBUG] [DefaultMessageListenerContainer-4]
o.a.a.t.TaskRunnerFactory - before init TaskRunnerFactory[ActiveMQ Session
Task-0x11da4ceb],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 2]
2017-02-15 17:02:57.817 [DEBUG] [DefaultMessageListenerContainer-4]
o.a.a.t.TaskRunnerFactory - after unlock TaskRunnerFactory[ActiveMQ Session
Task-0x11da4ceb],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 3]
2017-02-15 17:02:57.813 [DEBUG] [DefaultMessageListenerContainer-5]
o.a.a.t.TaskRunnerFactory - before init TaskRunnerFactory[ActiveMQ Session
Task-0x5da5b756],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 1, queued tasks = 0, completed tasks = 2]
2017-02-15 17:02:57.815 [DEBUG] [klContainer-1] o.a.a.t.TaskRunnerFactory -
before init TaskRunnerFactory[ActiveMQ Session Task-0x36ebc2a0],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 3]
2017-02-15 17:02:57.817 [DEBUG] [klContainer-1] o.a.a.t.TaskRunnerFactory -
after unlock TaskRunnerFactory[ActiveMQ Session Task-0x36ebc2a0],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 1, queued tasks = 0, completed tasks = 3]
2017-02-15 17:02:57.817 [TRACE] [klContainer-1] o.a.a.t.TaskRunnerFactory -
Created thread[ActiveMQ Session Task-2]: Thread[ActiveMQ Session Task-2,7,main]
2017-02-15 17:02:57.817 [DEBUG] [DefaultMessageListenerContainer-1]
o.a.a.t.TaskRunnerFactory - before init TaskRunnerFactory[ActiveMQ Session
Task-0x62922916],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
1, active threads = 0, queued tasks = 0, completed tasks = 3]
2017-02-15 17:02:57.818 [DEBUG] [DefaultMessageListenerContainer-1]
o.a.a.t.TaskRunnerFactory - after unlock TaskRunnerFactory[ActiveMQ Session
Task-0x62922916],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
2, active threads = 1, queued tasks = 0, completed tasks = 4]
2017-02-15 17:02:57.818 [DEBUG] [DefaultMessageListenerContainer-5]
o.a.a.t.TaskRunnerFactory - after unlock TaskRunnerFactory[ActiveMQ Session
Task-0x5da5b756],
executor:java.util.concurrent.ThreadPoolExecutor@5b724860[Running, pool size =
2, active threads = 0, queued tasks = 0, completed tasks = 6]
{code}
Sample configuration:
{code}
<bean id="jmsFactory"
class="org.apache.activemq.pool.PooledConnectionFactory"
destroy-method="stop">
<property name="connectionFactory">
<bean
class="org.apache.activemq.ActiveMQConnectionFactory" p:trustAllPackages="true">
<property name="brokerURL">
<value>${jms.host}</value>
</property>
</bean>
</property>
</bean>
.............
I have containers defined like this one
<bean id="polContainer"
class="org.springframework.jms.listener.DefaultMessageListenerContainer">
<property name="connectionFactory" ref="jmsFactory" />
<property name="destination" ref="poQueue" />
<property name="messageListener" ref="psReceiver" />
<property name="concurrentConsumers" value="1" />
</bean>
{code}
The problem is initDone.compareAndSet(false, true) set TRUE (Thread [
colContainer-1 ]), but executor still null when next Thread ( [ clContainer-1
]) try to use this shared connection.
In my box it takes 30ms to create Executor after this all works fine.
> Memory leak when undeploying webapp with ActiveMQ client
> --------------------------------------------------------
>
> Key: AMQ-6602
> URL: https://issues.apache.org/jira/browse/AMQ-6602
> Project: ActiveMQ
> Issue Type: Bug
> Components: JMS client
> Affects Versions: 5.14.3
> Reporter: Mykola Markov
> Priority: Minor
> Labels: leak
> Attachments: AMQ-6602.patch
>
>
> I have a web app with an ActiveMQ client. When undeploying the app, Tomcat
> logs the following messages.
> {code}
> 15-Feb-2017 17:53:31.760 WARNING [localhost-startStop-2]
> org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
> web application [Engine] appears to have started a thread named [ActiveMQ
> Session: ID:comp-41144-1487186920452-1:1:3] but has failed to stop it. This
> is very likely to create a memory leak. Stack trace of thread:
> java.lang.Object.wait(Native Method)
> java.lang.Object.wait(Object.java:502)
>
> org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:119)
>
> org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> 15-Feb-2017 17:53:31.761 WARNING [localhost-startStop-2]
> org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
> web application [Engine] appears to have started a thread named [ActiveMQ
> Session: ID:comp-41144-1487186920452-1:1:2] but has failed to stop it. This
> is very likely to create a memory leak. Stack trace of thread:
> java.lang.Object.wait(Native Method)
> java.lang.Object.wait(Object.java:502)
>
> org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:119)
>
> org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> 15-Feb-2017 17:53:31.762 WARNING [localhost-startStop-2]
> org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
> web application [Engine] appears to have started a thread named [ActiveMQ
> Session: ID:comp-41144-1487186920452-1:1:4] but has failed to stop it. This
> is very likely to create a memory leak. Stack trace of thread:
> java.lang.Object.wait(Native Method)
> java.lang.Object.wait(Object.java:502)
>
> org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:119)
>
> org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> 15-Feb-2017 17:53:31.762 WARNING [localhost-startStop-2]
> org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
> web application [Engine] appears to have started a thread named [ActiveMQ
> Session: ID:comp-41144-1487186920452-1:1:10] but has failed to stop it. This
> is very likely to create a memory leak. Stack trace of thread:
> java.lang.Object.wait(Native Method)
> java.lang.Object.wait(Object.java:502)
>
> org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:119)
>
> org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> 15-Feb-2017 17:53:31.763 WARNING [localhost-startStop-2]
> org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The
> web application [Engine] appears to have started a thread named [ActiveMQ
> Session: ID:comp-41144-1487186920452-1:1:6] but has failed to stop it. This
> is very likely to create a memory leak. Stack trace of thread:
> java.lang.Object.wait(Native Method)
> java.lang.Object.wait(Object.java:502)
>
> org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:119)
>
> org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> Feb 15, 2017 5:53:31 PM org.apache.catalina.core.ApplicationContext log
> INFO: Closing Spring root WebApplicationContext
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
