XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Blocker Blocker
    • 7.0.0.ER5
    • 7.0.0.DR13 (Alpha)
    • ActiveMQ, Transactions
    • None
    • Hide

      1. Configure EAP to use ActiveMQ journaling as transaction object store.
      2. Configure transactions object store journaling path to reference to mounted partition.
      3. Run thousands of transactions, they will be finished.
      4. Fill the mounted partition where object store was referenced by some fake data. So no empty space is left on that partition.
      5. Run thousands of transactions.
      At some point transactions are not finished and WARN messages

       "AMQ142030: Could not open a file in 60 Seconds: java.lang.Exception: trace" 

      are logged endless in logs. This is OK as there is not space left on object store partition.
      6. Free the object store partition from added fake files, so there is plenty of empty space on that partition.
      7. In server log file, still it is logged that WARN message endless and transaction is still hanged, which is the bug:

      2015-11-24 03:31:18,993 WARN  [org.apache.activemq.artemis.journal] (EJB default - 1) AMQ142030: Could not open a file in 60 Seconds: java.lang.Exception: trace
      	at org.apache.activemq.artemis.core.journal.impl.JournalFilesRepository.openFile(JournalFilesRepository.java:433)
      	at org.apache.activemq.artemis.core.journal.impl.JournalImpl.moveNextFile(JournalImpl.java:2767)
      	at org.apache.activemq.artemis.core.journal.impl.JournalImpl.switchFileIfNecessary(JournalImpl.java:2722)
      	at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendRecord(JournalImpl.java:2402)
      	at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:710)
      	at org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecord(JournalBase.java:90)
      	at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:79)
      	at org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecord(JournalBase.java:84)
      	at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:79)
      	at com.arjuna.ats.internal.arjuna.objectstore.hornetq.HornetqJournalStore.write_committed(HornetqJournalStore.java:189)
      	at com.arjuna.ats.internal.arjuna.objectstore.hornetq.HornetqObjectStoreAdaptor.write_committed(HornetqObjectStoreAdaptor.java:288)
      	at com.arjuna.ats.arjuna.coordinator.BasicAction.updateState(BasicAction.java:3248)
      	at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2475)
      	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1495)
      	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
      	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
      	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200)
      	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
      	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
      	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:53)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:75)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
      	at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636)
      	at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
      	at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
      	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
      	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
      	at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)
      	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:331)
      	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:69)
      	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:202)
      	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)
      

      From what I can see in

       org.apache.activemq.artemis.core.journal.impl.JournalFilesRepository.openFile() 

      It tries to read file en endless while loop.

      Show
      1. Configure EAP to use ActiveMQ journaling as transaction object store. 2. Configure transactions object store journaling path to reference to mounted partition. 3. Run thousands of transactions, they will be finished. 4. Fill the mounted partition where object store was referenced by some fake data. So no empty space is left on that partition. 5. Run thousands of transactions. At some point transactions are not finished and WARN messages "AMQ142030: Could not open a file in 60 Seconds: java.lang.Exception: trace" are logged endless in logs. This is OK as there is not space left on object store partition. 6. Free the object store partition from added fake files, so there is plenty of empty space on that partition. 7. In server log file, still it is logged that WARN message endless and transaction is still hanged, which is the bug: 2015-11-24 03:31:18,993 WARN [org.apache.activemq.artemis.journal] (EJB default - 1) AMQ142030: Could not open a file in 60 Seconds: java.lang.Exception: trace at org.apache.activemq.artemis.core.journal.impl.JournalFilesRepository.openFile(JournalFilesRepository.java:433) at org.apache.activemq.artemis.core.journal.impl.JournalImpl.moveNextFile(JournalImpl.java:2767) at org.apache.activemq.artemis.core.journal.impl.JournalImpl.switchFileIfNecessary(JournalImpl.java:2722) at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendRecord(JournalImpl.java:2402) at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:710) at org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecord(JournalBase.java:90) at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:79) at org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecord(JournalBase.java:84) at org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:79) at com.arjuna.ats.internal.arjuna.objectstore.hornetq.HornetqJournalStore.write_committed(HornetqJournalStore.java:189) at com.arjuna.ats.internal.arjuna.objectstore.hornetq.HornetqObjectStoreAdaptor.write_committed(HornetqObjectStoreAdaptor.java:288) at com.arjuna.ats.arjuna.coordinator.BasicAction.updateState(BasicAction.java:3248) at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2475) at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1495) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1200) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89) at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91) at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:279) at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327) at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:53) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.EjbExceptionTransformingInterceptorFactories$1.processInvocation(EjbExceptionTransformingInterceptorFactories.java:75) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356) at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:636) at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356) at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80) at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340) at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195) at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:331) at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:69) at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:202) 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) From what I can see in org.apache.activemq.artemis.core.journal.impl.JournalFilesRepository.openFile() It tries to read file en endless while loop.

      When ActiveMQ journaling store partition was full and after was freed, there is still endless "WARN AMQ142030: Could not open a file in 60 Seconds:" in server log and transactions are hanged.

            rh-ee-ataylor Andy Taylor
            hhovsepy@redhat.com Hayk Hovsepyan
            Hayk Hovsepyan Hayk Hovsepyan
            Hayk Hovsepyan Hayk Hovsepyan
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Created:
              Updated:
              Resolved: