Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-11516

Start of Artemis may hang if JDBC store is used

XMLWordPrintable

    • Regression, Blocks Testing
    • Hide 
      git clone git://git.app.eng.bos.redhat.com/jbossqe/eap-tests-hornetq.git
cd eap-tests-hornetq/scripts/
git checkout 6cde621dc29f4313e3b00bc323d62bd1ac007f62
groovy -DEAP_VERSION=7.1.0.ER1 PrepareServers7.groovy
export WORKSPACE=$PWD
export JBOSS_HOME_1=$WORKSPACE/server1/jboss-eap
export JBOSS_HOME_2=$WORKSPACE/server2/jboss-eap
export JBOSS_HOME_3=$WORKSPACE/server3/jboss-eap
export JBOSS_HOME_4=$WORKSPACE/server4/jboss-eap

cd ../jboss-hornetq-testsuite/

mvn clean test -Dtest=JDBCTestCase#killServerDuringSendingLargeMessage -DfailIfNoTests=false -Deap=7x -Dprepare.param.DATABASE=oracle12c -Dprepare.param.JDBC_STORE=true | tee log
      Show
      git clone git: //git.app.eng.bos.redhat.com/jbossqe/eap-tests-hornetq.git cd eap-tests-hornetq/scripts/ git checkout 6cde621dc29f4313e3b00bc323d62bd1ac007f62 groovy -DEAP_VERSION=7.1.0.ER1 PrepareServers7.groovy export WORKSPACE=$PWD export JBOSS_HOME_1=$WORKSPACE/server1/jboss-eap export JBOSS_HOME_2=$WORKSPACE/server2/jboss-eap export JBOSS_HOME_3=$WORKSPACE/server3/jboss-eap export JBOSS_HOME_4=$WORKSPACE/server4/jboss-eap cd ../jboss-hornetq-testsuite/ mvn clean test -Dtest=JDBCTestCase#killServerDuringSendingLargeMessage -DfailIfNoTests= false -Deap=7x -Dprepare.param.DATABASE=oracle12c -Dprepare.param.JDBC_STORE= true | tee log

      If Artemis with JDBC store is used, it may get into deadlock situation during start up phase. See details below.

      Customer impact: Start up phase of EAP may hang. Starting of EAP is standard operation so the issue may be hit by customers in production. It affects user experience and it may have negative impact on availability of service.

      This is regression against 7.1.0.DR19.

      The start of EAP is blocked by thread [1] which loads the journal. It waits until all tasks are executed on executor. However the task [2] is blocked by lock held by the thread [1] so it never finishes.

      [1]

      "ServerService Thread Pool -- 74" #123 prio=5 os_prio=0 tid=0x00007f09040c4000 nid=0x7907 waiting on condition [0x00007f095120e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000d1b43240> (a java.util.concurrent.CountDownLatch$Sync)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
        at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:277)
        at org.apache.activemq.artemis.core.journal.impl.SimpleWaitIOCallback.waitCompletion(SimpleWaitIOCallback.java:61)
        at org.apache.activemq.artemis.jdbc.store.file.JDBCSequentialFile.sync(JDBCSequentialFile.java:295)
        at org.apache.activemq.artemis.jdbc.store.file.JDBCSequentialFile.close(JDBCSequentialFile.java:285)
        at org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.releaseResources(LargeServerMessageImpl.java:243)
        - locked <0x00000000d1bfb5b8> (a org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl)
        at org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.deleteFile(LargeServerMessageImpl.java:219)
        - locked <0x00000000d1bfb5b8> (a org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl)
        at org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.checkDelete(LargeServerMessageImpl.java:190)
        at org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.decrementRefCount(LargeServerMessageImpl.java:205)
        - locked <0x00000000d1bfb5b8> (a org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl)
        at org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.decrementDelayDeletionCount(LargeServerMessageImpl.java:170)
        - locked <0x00000000d1bfb5b8> (a org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl)
        at org.apache.activemq.artemis.core.persistence.impl.journal.LargeMessageTXFailureCallback.failedTransaction(LargeMessageTXFailureCallback.java:56)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalLoaderCallback.failedTransaction(JDBCJournalLoaderCallback.java:94)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalReaderCallback.checkPreparedTx(JDBCJournalReaderCallback.java:133)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl.load(JDBCJournalImpl.java:849)
        - locked <0x00000000d13efd78> (a org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl.load(JDBCJournalImpl.java:887)
        - locked <0x00000000d13efd78> (a org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl.load(JDBCJournalImpl.java:879)
        at org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.loadMessageJournal(AbstractJournalStorageManager.java:837)
        at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.loadJournals(ActiveMQServerImpl.java:2218)
        at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.initialisePart2(ActiveMQServerImpl.java:2072)
        - locked <0x00000000d135c4f0> (a org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl)
        at org.apache.activemq.artemis.core.server.impl.LiveOnlyActivation.run(LiveOnlyActivation.java:64)
        at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.internalStart(ActiveMQServerImpl.java:518)
        at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.start(ActiveMQServerImpl.java:466)
        - locked <0x00000000d135c4f0> (a org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl)
        at org.apache.activemq.artemis.jms.server.impl.JMSServerManagerImpl.start(JMSServerManagerImpl.java:413)
        - locked <0x00000000d16015f0> (a org.apache.activemq.artemis.jms.server.impl.JMSServerManagerImpl)
        at org.wildfly.extension.messaging.activemq.jms.JMSService.doStart(JMSService.java:205)
        - locked <0x00000000d1601570> (a org.wildfly.extension.messaging.activemq.jms.JMSService)
        at org.wildfly.extension.messaging.activemq.jms.JMSService.access$000(JMSService.java:64)
        at org.wildfly.extension.messaging.activemq.jms.JMSService$1.run(JMSService.java:99)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
        at org.jboss.threads.JBossThread.run(JBossThread.java:320)

   Locked ownable synchronizers:
        - <0x00000000d0c4fcc8> (a java.util.concurrent.ThreadPoolExecutor$Worker)

      [2]

      "Thread-0 (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$3@7335e558)" #157 prio=5 os_prio=0 tid=0x00007f08602d3000 nid=0x792d waiting for monitor entry [0x00007f09493c4000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl.sync(JDBCJournalImpl.java:166)
        - waiting to lock <0x00000000d13efd78> (a org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl)
        at org.apache.activemq.artemis.jdbc.store.journal.JDBCJournalImpl$JDBCJournalSync.run(JDBCJournalImpl.java:991)
        at org.apache.activemq.artemis.core.server.ActiveMQScheduledComponent$2.run(ActiveMQScheduledComponent.java:189)
        at org.apache.activemq.artemis.utils.OrderedExecutorFactory$OrderedExecutor$ExecutorTask.run(OrderedExecutorFactory.java:101)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
        - <0x00000000d148a370> (a java.util.concurrent.ThreadPoolExecutor$Worker)

        1. threaddump.txt
          257 kB

              mtaylor1@redhat.com Martyn Taylor (Inactive)
              eduda_jira Erich Duda (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Created:
                Updated:
                Resolved: