Uploaded image for project: 'ActiveMQ'
  1. ActiveMQ
  2. AMQ-6602

Memory leak when undeploying webapp with ActiveMQ client

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 5.14.3
    • Fix Version/s: 5.15.0, 5.14.4
    • Component/s: JMS client
    • Labels:

      Description

      I have a web app with an ActiveMQ client. When undeploying the app, Tomcat logs the following messages.

      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
      
      1. AMQ-6602.patch
        2 kB
        Mykola Markov

        Issue Links

          Activity

          Hide
          mykolamarkov Mykola Markov added a comment -

          Can be fixed with AMQ-6602.patch

          Show
          mykolamarkov Mykola Markov added a comment - Can be fixed with AMQ-6602 .patch
          Hide
          cshannon Christopher L. Shannon added a comment -

          From the stack trace it looks like a deadlock occurred on shutdown and after taking a quick glance at this I'm a little confused as to how adding that lock solves this issue. There is an AtomicBoolean that gets checked to prevent the initialization from happening more than once. Can you elaborate more? One issue I do see is that the executor should probably be volatile or an AtomicReference when it is set so that it is visible to all threads on init.

          Show
          cshannon Christopher L. Shannon added a comment - From the stack trace it looks like a deadlock occurred on shutdown and after taking a quick glance at this I'm a little confused as to how adding that lock solves this issue. There is an AtomicBoolean that gets checked to prevent the initialization from happening more than once. Can you elaborate more? One issue I do see is that the executor should probably be volatile or an AtomicReference when it is set so that it is visible to all threads on init.
          Hide
          mykolamarkov Mykola Markov added a comment -

          To show how it can impact, I had updated TaskRunnerFactory init function in this manner:

              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);
              	}
              }
          

          Initialization log

          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]
          

          Sample configuration:

          	<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>
          
          

          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.

          Show
          mykolamarkov Mykola Markov added a comment - To show how it can impact, I had updated TaskRunnerFactory init function in this manner: 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); } } Initialization log 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] Sample configuration: <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> 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.
          Hide
          cshannon Christopher L. Shannon added a comment -

          Ah, I see the issue now, good catch. I forgot that the init() method is invoked each time createTaskRunner() and execute() is called leading to this race condition where multiple TaskRunners get started when they shouldn't. I will take a closer look at this for a fix, some variation of your patch will probably be the fix.

          Show
          cshannon Christopher L. Shannon added a comment - Ah, I see the issue now, good catch. I forgot that the init() method is invoked each time createTaskRunner() and execute() is called leading to this race condition where multiple TaskRunners get started when they shouldn't. I will take a closer look at this for a fix, some variation of your patch will probably be the fix.
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit fe5164a404ebcb0879c1b769e16c00f475320419 in activemq's branch refs/heads/master from Christopher L. Shannon
          [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=fe5164a ]

          AMQ-6602: Fix race condition in TaskRunnerFactory

          Fixing a race condition in TaskRunnerFactory where if multiple threads
          call createTaskRunner() at the same time some threads might see the
          executor as null (if it hasn't finished initializing) leading to the
          creation of extra DedicatedTaskRunner objects instead of sharing a
          PooledTaskRunner.

          Show
          jira-bot ASF subversion and git services added a comment - Commit fe5164a404ebcb0879c1b769e16c00f475320419 in activemq's branch refs/heads/master from Christopher L. Shannon [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=fe5164a ] AMQ-6602 : Fix race condition in TaskRunnerFactory Fixing a race condition in TaskRunnerFactory where if multiple threads call createTaskRunner() at the same time some threads might see the executor as null (if it hasn't finished initializing) leading to the creation of extra DedicatedTaskRunner objects instead of sharing a PooledTaskRunner.
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit b6a8c188ff07a795399067ef6f6598a2f623a002 in activemq's branch refs/heads/activemq-5.14.x from Christopher L. Shannon
          [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=b6a8c18 ]

          AMQ-6602: Fix race condition in TaskRunnerFactory

          Fixing a race condition in TaskRunnerFactory where if multiple threads
          call createTaskRunner() at the same time some threads might see the
          executor as null (if it hasn't finished initializing) leading to the
          creation of extra DedicatedTaskRunner objects instead of sharing a
          PooledTaskRunner.

          (cherry picked from commit fe5164a404ebcb0879c1b769e16c00f475320419)

          Show
          jira-bot ASF subversion and git services added a comment - Commit b6a8c188ff07a795399067ef6f6598a2f623a002 in activemq's branch refs/heads/activemq-5.14.x from Christopher L. Shannon [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=b6a8c18 ] AMQ-6602 : Fix race condition in TaskRunnerFactory Fixing a race condition in TaskRunnerFactory where if multiple threads call createTaskRunner() at the same time some threads might see the executor as null (if it hasn't finished initializing) leading to the creation of extra DedicatedTaskRunner objects instead of sharing a PooledTaskRunner. (cherry picked from commit fe5164a404ebcb0879c1b769e16c00f475320419)
          Hide
          cshannon Christopher L. Shannon added a comment -

          Resolved the issue by using a variation of double checked locking so that the synchronized penalty only occurs when initialization is first needed. After initialization is complete threads will no longer need to synchronize every init() call.

          Show
          cshannon Christopher L. Shannon added a comment - Resolved the issue by using a variation of double checked locking so that the synchronized penalty only occurs when initialization is first needed. After initialization is complete threads will no longer need to synchronize every init() call.
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit 1f53b124bcdc41e6241c811f6854c42855deaf6a in activemq's branch refs/heads/master from Christopher L. Shannon
          [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=1f53b12 ]

          AMQ-6602 - Removing lambdas for java 7 compatibility

          Show
          jira-bot ASF subversion and git services added a comment - Commit 1f53b124bcdc41e6241c811f6854c42855deaf6a in activemq's branch refs/heads/master from Christopher L. Shannon [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=1f53b12 ] AMQ-6602 - Removing lambdas for java 7 compatibility
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit 789f82b34bd4103448e25ae16f53d95946619809 in activemq's branch refs/heads/activemq-5.14.x from Christopher L. Shannon
          [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=789f82b ]

          AMQ-6602 - Removing lambdas for java 7 compatibility

          (cherry picked from commit 1f53b124bcdc41e6241c811f6854c42855deaf6a)

          Show
          jira-bot ASF subversion and git services added a comment - Commit 789f82b34bd4103448e25ae16f53d95946619809 in activemq's branch refs/heads/activemq-5.14.x from Christopher L. Shannon [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=789f82b ] AMQ-6602 - Removing lambdas for java 7 compatibility (cherry picked from commit 1f53b124bcdc41e6241c811f6854c42855deaf6a)
          Hide
          mykolamarkov Mykola Markov added a comment - - edited

          Thanks Christopher for quick patch!

          Show
          mykolamarkov Mykola Markov added a comment - - edited Thanks Christopher for quick patch!
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit 0cf64783d2cbae684f6d2d3e6c46801070f7fd77 in activemq's branch refs/heads/master from Christopher L. Shannon
          [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=0cf6478 ]

          AMQ-6602 - fix java 7 incompatibility

          Show
          jira-bot ASF subversion and git services added a comment - Commit 0cf64783d2cbae684f6d2d3e6c46801070f7fd77 in activemq's branch refs/heads/master from Christopher L. Shannon [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=0cf6478 ] AMQ-6602 - fix java 7 incompatibility
          Hide
          jira-bot ASF subversion and git services added a comment -

          Commit e5751570936e335a59dfa7f124623f4b257be03d in activemq's branch refs/heads/activemq-5.14.x from Christopher L. Shannon
          [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=e575157 ]

          AMQ-6602 - fix java 7 incompatibility

          (cherry picked from commit 0cf64783d2cbae684f6d2d3e6c46801070f7fd77)

          Show
          jira-bot ASF subversion and git services added a comment - Commit e5751570936e335a59dfa7f124623f4b257be03d in activemq's branch refs/heads/activemq-5.14.x from Christopher L. Shannon [ https://git-wip-us.apache.org/repos/asf?p=activemq.git;h=e575157 ] AMQ-6602 - fix java 7 incompatibility (cherry picked from commit 0cf64783d2cbae684f6d2d3e6c46801070f7fd77)

            People

            • Assignee:
              cshannon Christopher L. Shannon
              Reporter:
              mykolamarkov Mykola Markov
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development