[esb-issues] [JBoss JIRA] Commented: (JBESB-1806) Error processing courier, backing off - ESBs stop processing messages
Darrin Mison (JIRA)
jira-events at lists.jboss.org
Thu Jul 24 20:01:45 EDT 2008
[ https://jira.jboss.org/jira/browse/JBESB-1806?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12422493#action_12422493 ]
Darrin Mison commented on JBESB-1806:
-------------------------------------
Proposed SOA 4.2 TP02 Release Note:
Database connection pool is now cleaned rather than closed upon connection failures. This fixes the "Error processing courier, backing off" error
> Error processing courier, backing off - ESBs stop processing messages
> ---------------------------------------------------------------------
>
> Key: JBESB-1806
> URL: https://jira.jboss.org/jira/browse/JBESB-1806
> Project: JBoss ESB
> Issue Type: Bug
> Security Level: Public(Everyone can see)
> Components: Rosetta
> Affects Versions: 4.2.1 CP3
> 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
> Assignee: Kevin Conner
> Fix For: 4.2.1 CP3
>
>
> 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: https://jira.jboss.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the esb-issues
mailing list