[esb-issues] [JBoss JIRA] Created: (JBESB-1806) Error processing courier, backing off - ESBs stop processing messages
Kevin Conner (JIRA)
jira-events at lists.jboss.org
Wed Jun 11 07:42:26 EDT 2008
Error processing courier, backing off - ESBs stop processing messages
---------------------------------------------------------------------
Key: JBESB-1806
URL: http://jira.jboss.com/jira/browse/JBESB-1806
Project: JBoss ESB
Issue Type: Bug
Security Level: Public (Everyone can see)
Components: Rosetta
Affects Versions: 4.2.1, 4.3
Environment: Centos(2.6.18-8.el5 #1 SMP, x86_64 GNU/Linux), Sun JDK1.6, JBoss AS 4.2.2, MySQL (5.0.22)
Reporter: Ed Bowler
Assigned To: Kevin Conner
Fix For: 4.4
Hi,
I have asked for help on the forums about this here:
http://www.jboss.com/index.html?module=bb&op=viewtopic&t=135536
To summarise, after a few days of (reasonably heavy, but happy) usage,
the ESB services I have deployed stop picking up messages from their
JMS queues, and "Error processing courier, backing off for 32000
milliseconds" is repeatedly written into the log files.
I have configured a few datasources to use MySQL instead of the
default HSQL (namely esb, jms and juddi).
After the suggested upgrade JbossESB to 4.3CR1 I am still getting the
"Error processing courier, backing off" error.
I now see:
{{{
2008-05-17 10:09:03,558 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id a01023a:9f00:482d5dee:eb53a invoked while multiple threads active within it.
2008-05-17 10:09:03,615 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action a01023a:9f00:482d5dee:eb53a aborting with 1 threads active!
}}}
followed by several:
{{{
2008-05-17 10:09:19,067 ERROR [net.rockshore.cdm.services.cdmeventdiscriminator.CDMEventDiscriminatorInboundMessageHandler] Exception whilst processing incoming message: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction is not active!
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1379)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
at org.jboss.aspects.tx.TxPolicy.endTransaction(TxPolicy.java:175)
at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:87)
at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessContainer.dynamicInvoke(StatelessContainer.java:304)
at org.jboss.ejb3.remoting.IsLocalInterceptor.invokeLocal(IsLocalInterceptor.java:81)
at org.jboss.ejb3.remoting.IsLocalInterceptor.invoke(IsLocalInterceptor.java:72)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessRemoteProxy.invoke(StatelessRemoteProxy.java:107)
at $Proxy325.processEvent(Unknown Source)
at net.rockshore.cdm.services.cdmeventdiscriminator.CDMEventDiscriminatorMessageProcessor.process(CDMEventDiscriminatorMessageProcessor.java:184)
at net.rockshore.cdm.services.cdmeventdiscriminator.CDMEventDiscriminatorInboundMessageHandler.processMessage(CDMEventDiscriminatorInboundMessageHandler.java:34)
at sun.reflect.GeneratedMethodAccessor131.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.jboss.soa.esb.listeners.message.ActionProcessorMethodInfo.processMethods(ActionProcessorMethodInfo.java:102)
at org.jboss.soa.esb.listeners.message.OverriddenActionLifecycleProcessor.process(OverriddenActionLifecycleProcessor.java:74)
at org.jboss.soa.esb.listeners.message.ActionProcessingPipeline.process(ActionProcessingPipeline.java:316)
at org.jboss.soa.esb.listeners.message.MessageAwareListener$TransactionalRunner.run(MessageAwareListener.java:530)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:619)
}}}
and:
{{{
2008-05-17 10:44:02,412 WARN [org.jboss.soa.esb.listeners.message.MessageAwareListener] Error processing courier, backing off for 1000 milliseconds
2008-05-17 10:44:06,681 WARN [org.jboss.soa.esb.listeners.lifecycle.AbstractThreadedManagedLifecycle] Unexpected error from doRun()
java.lang.NullPointerException
at org.jboss.internal.soa.esb.couriers.JmsCourier.jmsConnectRetry(JmsCourier.java:272)
at org.jboss.internal.soa.esb.couriers.JmsCourier.pickupPayload(JmsCourier.java:434)
at org.jboss.internal.soa.esb.couriers.JmsCourier.pickup(JmsCourier.java:402)
at org.jboss.internal.soa.esb.couriers.TwoWayCourierImpl.pickup(TwoWayCourierImpl.java:232)
at org.jboss.internal.soa.esb.couriers.TwoWayCourierImpl.pickup(TwoWayCourierImpl.java:214)
at org.jboss.soa.esb.listeners.message.MessageAwareListener.waitForEventAndProcess(MessageAwareListener.java:280)
at org.jboss.soa.esb.listeners.message.MessageAwareListener.doRun(MessageAwareListener.java:248)
at org.jboss.soa.esb.listeners.lifecycle.AbstractThreadedManagedLifecycle.run(AbstractThreadedManagedLifecycle.java:115)
at java.lang.Thread.run(Thread.java:619)
}}}
which returns us to the backing off error. Followed by:
{{{
2008-05-17 12:30:09,180 INFO [org.jboss.soa.esb.client.ServiceInvoker] Unresponsive EPR: JMSEpr [ PortReference < <wsa:Address jms://0.0.0.0:1099/queue/cdm_inbound_event_esb/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : jnp://jndi-server-1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jboss.naming:org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>,<wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/> > ] for message: header: [ To: JMSEpr [ PortReference < <wsa:Address jms://0.0.0.0:1099/queue/acl_cbr_esb/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.initial : org.jnp.interfaces.NamingContextFactory/>, <wsa:ReferenceProperties jbossesb:java.naming.provider.url : jnp://jndi-server-1:1099/>, <wsa:ReferenceProperties jbossesb:java.naming.factory.url.pkgs : org.jboss.naming:org.jnp.interfaces/>, <wsa:ReferenceProperties jbossesb:destination-type : queue/>, <wsa:ReferenceProperties jbossesb:specification-version : 1.1/>, <wsa:ReferenceProperties jbossesb:connection-factory : ConnectionFactory/>, <wsa:ReferenceProperties jbossesb:persistent : true/>, <wsa:ReferenceProperties jbossesb:acknowledge-mode : AUTO_ACKNOWLEDGE/>, <wsa:ReferenceProperties jbossesb:transacted : false/>, <wsa:ReferenceProperties jbossesb:type : urn:jboss/esb/epr/type/jms/>> ] MessageID: 1d18b548-9f67-44a5-8b65-b08f666dcb6f RelatesTo: jms:correlationID#1d18b548-9f67-44a5-8b65-b08f666dcb6f ]
}}}
Then:
{{{
2008-05-17 21:24:54,610 WARN [org.jboss.mq.Connection] Connection failure, already in the exception listener
org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketTimeoutException: Read timed out)
at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:72)
at org.jboss.mq.Connection.asynchFailure(Connection.java:423)
at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:174)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:466)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:395)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:79)
at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2249)
at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2429)
at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2499)
at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2571)
at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2720)
at java.io.ObjectInputStream.readByte(ObjectInputStream.java:895)
at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:340)
... 1 more
}}}
and:
{{{
2008-05-17 21:24:54,624 WARN [org.jboss.mq.Connection] Connection failure, already in the exception listener
org.jboss.mq.SpyJMSException: No pong received; - nested throwable: (java.io.IOException: ping timeout.)
at org.jboss.mq.Connection$PingTask.run(Connection.java:1313)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(ClockDaemon.java:364)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.io.IOException: ping timeout.
... 3 more
}}}
and no messages are taken from the JMS queues, and processed by the
ESB services.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the esb-issues
mailing list