Message Queue Stalled
joydeep.sarkar Nov 3, 2010 4:31 AMHello,
I am running HornetQ in symmetric mode in two servers.
Things were working well untill it started observing NullPointerExceptions. At this point many transactions started getting times out. Few transactions were even marked as zombies.
Also, "Timed out waiting for handler to complete processing" messages are seen.
Now, at some point the message queue is stuck and stopped responding. Though bouncing the servers started the queue, the cause is not clear.
Does anyone have any idea what could be the reason? How to avoid it in the future?
Added the log trace below.
TIA,
Joydeep
2010-11-02 04:44:47,011 ERROR [STDERR] java.lang.NullPointerException 2010-11-02 04:44:47,012 ERROR [STDERR] at com.getty.mm.metadata.indexing.XMLGenerator.processMessage(XMLGenerator.java:108) 2010-11-02 04:44:47,012 ERROR [STDERR] at com.getty.mm.metadata.indexing.Grp4XMLGenerator.onMessage(Grp4XMLGenerator.java:39) 2010-11-02 04:44:47,012 ERROR [STDERR] at sun.reflect.GeneratedMethodAccessor328.invoke(Unknown Source) 2010-11-02 04:44:47,012 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) 2010-11-02 04:44:47,012 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:597) 2010-11-02 04:44:47,012 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122) 2010-11-02 04:44:47,012 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111) 2010-11-02 04:44:47,012 ERROR [STDERR] at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:69) 2010-11-02 04:44:47,012 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:73) 2010-11-02 04:44:47,012 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:59) 2010-11-02 04:44:47,013 ERROR [STDERR] at sun.reflect.GeneratedMethodAccessor324.invoke(Unknown Source) 2010-11-02 04:44:47,013 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) 2010-11-02 04:44:47,013 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:597) 2010-11-02 04:44:47,013 ERROR [STDERR] at org.jboss.aop.advice.PerJoinpointAdvice.invoke(PerJoinpointAdvice.java:174) 2010-11-02 04:44:47,013 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,013 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.fillMethod(InvocationContextInterceptor.java:72) 2010-11-02 04:44:47,013 ERROR [STDERR] at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_fillMethod_646128166.invoke(InvocationContextInterceptor_z_fillMethod_646128166.java) 2010-11-02 04:44:47,013 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,013 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.setup(InvocationContextInterceptor.java:88) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_setup_646128166.invoke(InvocationContextInterceptor_z_setup_646128166.java) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.ejb3.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:62) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:56) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,014 ERROR [STDERR] at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:68) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:194) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.ejb3.security.Ejb3AuthenticationInterceptorv2.invoke(Ejb3AuthenticationInterceptorv2.java:80) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,015 ERROR [STDERR] at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67) 2010-11-02 04:44:47,016 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 04:44:47,016 ERROR [STDERR] at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:282) 2010-11-02 04:44:47,016 ERROR [STDERR] at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:270) 2010-11-02 04:44:47,016 ERROR [STDERR] at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:140) 2010-11-02 04:44:47,017 ERROR [STDERR] at $Proxy284.onMessage(Unknown Source) 2010-11-02 04:44:47,017 ERROR [STDERR] at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:219) 2010-11-02 04:44:47,017 ERROR [STDERR] at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:767) 2010-11-02 04:44:47,017 ERROR [STDERR] at org.hornetq.core.client.impl.ClientConsumerImpl.access$100(ClientConsumerImpl.java:45) 2010-11-02 04:44:47,017 ERROR [STDERR] at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:885) 2010-11-02 04:44:47,017 ERROR [STDERR] at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:96) 2010-11-02 04:44:47,017 ERROR [STDERR] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) 2010-11-02 04:44:47,017 ERROR [STDERR] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) 2010-11-02 04:44:47,017 ERROR [STDERR] at java.lang.Thread.run(Thread.java:619)
2010-11-02 05:21:57,949 SEVERE [general] Transaction which began on 2010/11/02 05:19:49:475 has timed out after 2 minutes. Progress message: null java.lang.Throwable: Transaction has timed out at imagenet.system.util.Transaction.<init>(Transaction.java:73) at imagenet.system.util.TransactionManager.beginTransaction(TransactionManager.java:56) at com.getty.mm.metadata.indexing.XMLGenerator.processMessage(XMLGenerator.java:110) at com.getty.mm.metadata.indexing.DefaultXMLGenerator.onMessage(DefaultXMLGenerator.java:40) at sun.reflect.GeneratedMethodAccessor326.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111) at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:69) at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:73) at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:59) at sun.reflect.GeneratedMethodAccessor324.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.aop.advice.PerJoinpointAdvice.invoke(PerJoinpointAdvice.java:174) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.fillMethod(InvocationContextInterceptor.java:72) at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_fillMethod_646128166.invoke(InvocationContextInterceptor_z_fillMethod_646128166.java) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.setup(InvocationContextInterceptor.java:88) at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_setup_646128166.invoke(InvocationContextInterceptor_z_setup_646128166.java) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:62) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:56) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:68) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126) at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:194) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.security.Ejb3AuthenticationInterceptorv2.invoke(Ejb3AuthenticationInterceptorv2.java:80) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:282) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:270) at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:140) at $Proxy284.onMessage(Unknown Source) at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:219) at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:767) at org.hornetq.core.client.impl.ClientConsumerImpl.access$100(ClientConsumerImpl.java:45) at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:885) at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:96) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) 2010-11-02 05:22:12,450 ERROR [STDERR] java.sql.SQLException: Unable to get connection from pool 2010-11-02 05:22:12,450 ERROR [STDERR] at imagenet.system.sql.GenericConnectionPool.getConnection(GenericConnectionPool.java:152) 2010-11-02 05:22:12,450 ERROR [STDERR] at imagenet.system.util.Transaction.lockRows(Transaction.java:353) 2010-11-02 05:22:12,451 ERROR [STDERR] at imagenet.system.util.TransactionManager.lockRows(TransactionManager.java:107) 2010-11-02 05:22:12,451 ERROR [STDERR] at com.getty.mm.metadata.indexing.XMLGenerator.processMessage(XMLGenerator.java:119) 2010-11-02 05:22:12,451 ERROR [STDERR] at com.getty.mm.metadata.indexing.DefaultXMLGenerator.onMessage(DefaultXMLGenerator.java:40) 2010-11-02 05:22:12,451 ERROR [STDERR] at sun.reflect.GeneratedMethodAccessor326.invoke(Unknown Source) 2010-11-02 05:22:12,451 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) 2010-11-02 05:22:12,451 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:597) 2010-11-02 05:22:12,451 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122) 2010-11-02 05:22:12,451 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111) 2010-11-02 05:22:12,451 ERROR [STDERR] at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:69) 2010-11-02 05:22:12,451 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:73) 2010-11-02 05:22:12,451 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:59) 2010-11-02 05:22:12,452 ERROR [STDERR] at sun.reflect.GeneratedMethodAccessor324.invoke(Unknown Source) 2010-11-02 05:22:12,452 ERROR [STDERR] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) 2010-11-02 05:22:12,452 ERROR [STDERR] at java.lang.reflect.Method.invoke(Method.java:597) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.aop.advice.PerJoinpointAdvice.invoke(PerJoinpointAdvice.java:174) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.fillMethod(InvocationContextInterceptor.java:72) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_fillMethod_646128166.invoke(InvocationContextInterceptor_z_fillMethod_646128166.java) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.setup(InvocationContextInterceptor.java:88) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_setup_646128166.invoke(InvocationContextInterceptor_z_setup_646128166.java) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,452 ERROR [STDERR] at org.jboss.ejb3.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:62) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:56) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:68) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:194) 2010-11-02 05:22:12,453 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.ejb3.security.Ejb3AuthenticationInterceptorv2.invoke(Ejb3AuthenticationInterceptorv2.java:80) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:282) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:270) 2010-11-02 05:22:12,454 ERROR [STDERR] at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:140) 2010-11-02 05:22:12,455 ERROR [STDERR] at $Proxy284.onMessage(Unknown Source) 2010-11-02 05:22:12,455 ERROR [STDERR] at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:219) 2010-11-02 05:22:12,455 ERROR [STDERR] at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:767) 2010-11-02 05:22:12,455 ERROR [STDERR] at org.hornetq.core.client.impl.ClientConsumerImpl.access$100(ClientConsumerImpl.java:45) 2010-11-02 05:22:12,455 ERROR [STDERR] at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:885) 2010-11-02 05:22:12,455 ERROR [STDERR] at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:96) 2010-11-02 05:22:12,455 ERROR [STDERR] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) 2010-11-02 05:22:12,455 ERROR [STDERR] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) 2010-11-02 05:22:12,455 ERROR [STDERR] at java.lang.Thread.run(Thread.java:619) 2010-11-02 05:22:12,456 ERROR [STDERR] Caused by: java.lang.IllegalStateException: Transaction which began on 2010/11/02 05:19:54:516 has timed out after 2 minutes. Progress message: null 2010-11-02 05:22:12,456 ERROR [STDERR] at imagenet.system.util.Transaction.throwExceptionIfExpired(Transaction.java:126) 2010-11-02 05:22:12,456 ERROR [STDERR] at imagenet.system.util.TransactionManager.getElement(TransactionManager.java:157) 2010-11-02 05:22:12,456 ERROR [STDERR] at imagenet.system.sql.GenericConnectionPool.getConnection(GenericConnectionPool.java:148) 2010-11-02 05:22:12,456 ERROR [STDERR] ... 56 more 2010-11-02 05:22:12,456 ERROR [STDERR] Caused by: java.lang.Throwable: Transaction has timed out 2010-11-02 05:22:12,456 ERROR [STDERR] at imagenet.system.util.Transaction.<init>(Transaction.java:73) 2010-11-02 05:22:12,456 ERROR [STDERR] at imagenet.system.util.TransactionManager.beginTransaction(TransactionManager.java:56) 2010-11-02 05:22:12,456 ERROR [STDERR] at com.getty.mm.metadata.indexing.XMLGenerator.processMessage(XMLGenerator.java:110) 2010-11-02 05:22:12,457 ERROR [STDERR] ... 53 more
2010-11-02 05:27:12,533 WARN [org.hornetq.core.transaction.impl.ResourceManagerImpl] transaction with xid XidImpl (633958270 bq:97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.49.101 formatID:131075 gtxid:49.45.97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.49.100 timed out 2010-11-02 05:27:12,533 WARN [org.hornetq.core.transaction.impl.ResourceManagerImpl] transaction with xid XidImpl (1311829434 bq:97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.50.50 formatID:131075 gtxid:49.45.97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.50.49 timed out 2010-11-02 05:27:12,553 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce1d in state RUN 2010-11-02 05:27:12,553 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce21 in state RUN 2010-11-02 05:27:12,553 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce25 in state RUN 2010-11-02 05:27:12,563 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state RUN 2010-11-02 05:27:12,563 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id af084d9:a589:4cac374e:6ce1d invoked while multiple threads active within it. 2010-11-02 05:27:12,575 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action af084d9:a589:4cac374e:6ce1d aborting with 1 threads active! 2010-11-02 05:27:13,063 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce1d in state CANCEL 2010-11-02 05:27:13,063 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce21 in state SCHEDULE_CANCEL 2010-11-02 05:27:13,063 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce25 in state SCHEDULE_CANCEL 2010-11-02 05:27:13,063 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state SCHEDULE_CANCEL 2010-11-02 05:27:13,531 WARN [org.hornetq.core.transaction.impl.ResourceManagerImpl] transaction with xid XidImpl (1091242899 bq:97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.50.54 formatID:131075 gtxid:49.45.97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.50.53 timed out 2010-11-02 05:27:13,541 WARN [org.hornetq.core.transaction.impl.ResourceManagerImpl] transaction with xid XidImpl (626930153 bq:97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.50.97 formatID:131075 gtxid:49.45.97.102.48.56.52.100.57.58.97.53.56.57.58.52.99.97.99.51.55.52.101.58.54.99.101.50.57 timed out 2010-11-02 05:27:13,572 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce1d in state CANCEL_INTERRUPTED 2010-11-02 05:27:13,572 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_6] - TransactionReaper::check worker Thread[Thread-15,5,jboss] not responding to interrupt when cancelling TX af084d9:a589:4cac374e:6ce1d -- worker marked as zombie and TX scheduled for mark-as-rollback 2010-11-02 05:27:13,572 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_11] - TransactionReaper::check failed to mark TX af084d9:a589:4cac374e:6ce1d as rollback only 2010-11-02 05:27:13,572 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce21 in state SCHEDULE_CANCEL 2010-11-02 05:27:13,572 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce25 in state SCHEDULE_CANCEL 2010-11-02 05:27:13,572 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state SCHEDULE_CANCEL 2010-11-02 05:27:13,574 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id af084d9:a589:4cac374e:6ce21 invoked while multiple threads active within it. 2010-11-02 05:27:13,574 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action af084d9:a589:4cac374e:6ce21 aborting with 1 threads active! 2010-11-02 05:27:14,081 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce21 in state CANCEL 2010-11-02 05:27:14,082 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce25 in state SCHEDULE_CANCEL 2010-11-02 05:27:14,082 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state SCHEDULE_CANCEL 2010-11-02 05:27:14,595 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce21 in state CANCEL_INTERRUPTED 2010-11-02 05:27:14,595 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_6] - TransactionReaper::check worker Thread[Thread-40,5,jboss] not responding to interrupt when cancelling TX af084d9:a589:4cac374e:6ce21 -- worker marked as zombie and TX scheduled for mark-as-rollback 2010-11-02 05:27:14,596 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_11] - TransactionReaper::check failed to mark TX af084d9:a589:4cac374e:6ce21 as rollback only 2010-11-02 05:27:14,596 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce25 in state SCHEDULE_CANCEL 2010-11-02 05:27:14,596 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state SCHEDULE_CANCEL 2010-11-02 05:27:14,598 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id af084d9:a589:4cac374e:6ce25 invoked while multiple threads active within it. 2010-11-02 05:27:14,598 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action af084d9:a589:4cac374e:6ce25 aborting with 1 threads active! 2010-11-02 05:27:15,099 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce25 in state CANCEL 2010-11-02 05:27:15,100 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state SCHEDULE_CANCEL 2010-11-02 05:27:15,616 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce25 in state CANCEL_INTERRUPTED 2010-11-02 05:27:15,617 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_6] - TransactionReaper::check worker Thread[Thread-41,5,jboss] not responding to interrupt when cancelling TX af084d9:a589:4cac374e:6ce25 -- worker marked as zombie and TX scheduled for mark-as-rollback 2010-11-02 05:27:15,617 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_11] - TransactionReaper::check failed to mark TX af084d9:a589:4cac374e:6ce25 as rollback only 2010-11-02 05:27:15,617 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state SCHEDULE_CANCEL 2010-11-02 05:27:15,619 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id af084d9:a589:4cac374e:6ce29 invoked while multiple threads active within it. 2010-11-02 05:27:15,620 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action af084d9:a589:4cac374e:6ce29 aborting with 1 threads active! 2010-11-02 05:27:16,120 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state CANCEL 2010-11-02 05:27:16,632 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce29 in state CANCEL_INTERRUPTED 2010-11-02 05:27:16,633 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_6] - TransactionReaper::check worker Thread[Thread-42,5,jboss] not responding to interrupt when cancelling TX af084d9:a589:4cac374e:6ce29 -- worker marked as zombie and TX scheduled for mark-as-rollback 2010-11-02 05:27:16,633 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_11] - TransactionReaper::check failed to mark TX af084d9:a589:4cac374e:6ce29 as rollback only 2010-11-02 05:27:22,584 WARN [org.hornetq.core.client.impl.ClientConsumerImpl] Timed out waiting for handler to complete processing 2010-11-02 05:27:23,584 WARN [org.hornetq.core.client.impl.ClientConsumerImpl] Timed out waiting for handler to complete processing 2010-11-02 05:27:24,617 WARN [org.hornetq.core.client.impl.ClientConsumerImpl] Timed out waiting for handler to complete processing 2010-11-02 05:27:25,630 WARN [org.hornetq.core.client.impl.ClientConsumerImpl] Timed out waiting for handler to complete processing 2010-11-02 05:27:27,460 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX af084d9:a589:4cac374e:6ce30 in state RUN