[mule-user] JMS Connector failing with 1.4.3

8 views
Skip to first unread message

Nick Bower

unread,
Jan 8, 2008, 6:40:15 PM1/8/08
to us...@mule.codehaus.org
I'm unable to sustain a connection with a Mule 1.4.3 component and ActiveMQ 4.1.1.  I keep running into what may to be this bug where the JMS connector stops working;

http://mule.mulesource.org/jira/browse/MULE-2616

I've voted for it, but provide another case to support it here.  The typical error I receive when running Mule for a period of hours;


ERROR 2008-01-09 01:50:58,834 [FileParser.94] org.mule.impl.DefaultComponentExceptionStrategy:
********************************************************************************
Message               : Failed to route event via endpoint: MuleEndpoint{endpointUri=jms://datafeeds.records, connector=JmsConnector{this=6c1a82, started=true, initialised=true, name='DatafeedFilePublish', disposed=false, numberOfConcurrentTransactedReceivers=4, createMultipleTransactedReceivers=true, connected=true, supportedProtocols=[jms], serviceOverrides=null}, transformer=ObjectToJMSMessage{this=4fb686, name='ObjectToJMSMessage', ignoreBadInput=false, returnClass=null, sourceTypes=[]}, name='endpoint.jms.datafeeds.records', type='senderAndReceiver', properties={}, transactionConfig=Transaction{factory=null, action=NONE, timeout=30000}, filter=null, deleteUnacceptedMessages=false, initialised=true, securityFilter=null, synchronous=null, initialState=started, createConnector=0, remoteSync=false, remoteSyncTimeout=10000, endpointEncoding=null}. Message payload is of type: String
Type                  : org.mule.umo.provider.DispatchException
Code                  : MULE_ERROR-42999
JavaDoc               : http://mule.mulesource.org/docs/apidocs/org/mule/umo/provider/DispatchException.html
Payload               : <?xml version="1.0"?>
<netcdf xmlns="http://www.unidata.ucar.edu/namespaces/netcdf/ncml-2.2"><dimension isUnlimited="true" length="1" name="records"/><dimension length="2" name="timedim"/><attribute name="Conventions" type="string" value="WNIOM/v2"/><attribute name="data_origin" type="string" value="measured"/><attribute name="project" type="string" value="A0468 Internal Datafeeds"/><attribute name="history" type="string" value="Mule ingest to NetCDF store"/><attribute name="client" type="string" value="RPS Metocean"/><attribute name="location" type="string" value="Metocean Office"/><attribute name="DataFeedId" type="string" value="Metocean Office"/><attribute name="logging_system" type="string" value="UTC"/><variable name="Time" shape="records timedim" type="int"><values>20080107 57600000</values></variable><variable name="WS" shape="records" type="float"><values>1.6</values><attribute name="units" type="string" value="m/s"/></variable><variable name="WD" shape="records" type="float"><values>91.0</values><attribute name="units" type="string" value="deg"/></variable><variable name="WG" shape="records" type="float"><values>2.5</values><attribute name="units" type="string" value="m/s"/></variable><variable name="ST" shape="records" type="float"><values>16.0</values><attribute name="units" type="string" value="deg"/></variable><variable name="AT" shape="records" type="float"><values>31.0</values><attribute name="units" type="string" value="degC"/></variable><variable name="RH" shape="records" type="float"><values>500.0</values><attribute name="units" type="string" value="%"/></variable><variable name="RF" shape="records" type="float"><values>0.0</values><attribute name="units" type="string" value="mm"/></variable><variable name="SR" shape="records" type="float"><values>29.0</values><attribute name="units" type="string" value="W/m2"/></variable><variable name="BP" shape="records" type="float"><values>1004.4</values><attribute name="units" type="string" value="hpa"/></variable><variable name="BV" shape="records" type="float"><values>13.6</values><attribute name="units" type="string" value="V"/></variable><variable name="VWS" shape="records" type="float"><values>1.6</values><attribute name="units" type="string" value="m/s"/></variable><variable name="VWD" shape="records" type="float"><values>91.0</values><attribute name="units" type="string" value="deg"/></variable></netcdf>
********************************************************************************
Exception stack is:
1. This MuleWorkManager is stopped (java.lang.IllegalStateException)
2. Failed to route event via endpoint: MuleEndpoint{endpointUri=jms://datafeeds.records, connector=JmsConnector{this=6c1a82, started=true, initialised=true, name='DatafeedFilePublish', disposed=false, numberOfConcurrentTransactedReceivers=4, createMultipleTransactedReceivers=true, connected=true, supportedProtocols=[jms], serviceOverrides=null}, transformer=ObjectToJMSMessage{this=4fb686, name='ObjectToJMSMessage', ignoreBadInput=false, returnClass=null, sourceTypes=[]}, name='endpoint.jms.datafeeds.records', type='senderAndReceiver', properties={}, transactionConfig=Transaction{factory=null, action=NONE, timeout=30000}, filter=null, deleteUnacceptedMessages=false, initialised=true, securityFilter=null, synchronous=null, initialState=started, createConnector=0, remoteSync=false, remoteSyncTimeout=10000, endpointEncoding=null}. Message payload is of type: String (org.mule.umo.provider.DispatchException)
  org.mule.providers.AbstractMessageDispatcher:176 (http://mule.mulesource.org/docs/apidocs/org/mule/umo/provider/DispatchException.html)
********************************************************************************
Root Exception stack trace:
java.lang.IllegalStateException: This MuleWorkManager is stopped
        at org.mule.impl.work.MuleWorkManager.executeWork(MuleWorkManager.java:270)
        at org.mule.impl.work.MuleWorkManager.scheduleWork(MuleWorkManager.java:243)
        at org.mule.providers.AbstractMessageDispatcher.dispatch(AbstractMessageDispatcher.java:149)
        at org.mule.providers.AbstractConnector.dispatch(AbstractConnector.java:1583)
        at org.mule.impl.ImmutableMuleEndpoint.dispatch(ImmutableMuleEndpoint.java:929)
        at org.mule.impl.MuleSession.dispatchEvent(MuleSession.java:259)
        at org.mule.impl.MuleSession.dispatchEvent(MuleSession.java:162)
        at org.mule.routing.outbound.AbstractOutboundRouter.dispatch(AbstractOutboundRouter.java:81)
        at org.mule.routing.outbound.FilteringOutboundRouter.route(FilteringOutboundRouter.java:70)
        at org.mule.routing.outbound.OutboundRouterCollection$1.doInTransaction(OutboundRouterCollection.java:66)
        at org.mule.transaction.TransactionTemplate.execute(TransactionTemplate.java:39)
        at org.mule.routing.outbound.OutboundRouterCollection.route(OutboundRouterCollection.java:71)
        at org.mule.impl.MuleSession.dispatchEvent(MuleSession.java:139)
        at org.mule.impl.MuleEventContext.dispatchEvent(MuleEventContext.java:478)
        at com.metoceanengineers.datafeeds.ingest.components.AbstractRecordProcessorUmo.processIngest(AbstractRecordProcessorUmo.java:117)
        at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.mule.impl.model.resolvers.DynamicEntryPoint.invokeMethod(DynamicEntryPoint.java:312)
        at org.mule.impl.model.resolvers.DynamicEntryPoint.invoke(DynamicEntryPoint.java:259)
        at org.mule.impl.DefaultLifecycleAdapter.intercept(DefaultLifecycleAdapter.java:194)
        at org.mule.impl.InterceptorsInvoker.execute(InterceptorsInvoker.java:47)
        at org.mule.impl.model.DefaultMuleProxy.run(DefaultMuleProxy.java:467)
        at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)

********************************************************************************


As the ActiveMQ instance is on a different host to the Mule instance and the bug suggested connectivity may be a trigger for the error, I will relocate the activemq onto the same server first, then fall-back to Mule 1.4.1 as a secondary attempt to get a working system.  Here is my config - there is nothing unusual about this I would say.


<?xml version="1.0" encoding="UTF-8"?>

<!DOCTYPE mule-configuration PUBLIC "-//MuleSource //DTD mule-configuration XML V1.0//EN"
                                "http://mule.mulesource.org/dtds/mule-configuration.dtd">

<!--  This is a blank configuration file for the DataFeeds project -->

<mule-configuration id="mule-ingest-files" version="1.0">

    <description>Configuration for the the "DataFeeds" project</description>

    <connector name="DatafeedFilePublish" className="org.mule.providers.jms.JmsConnector">
        <properties>
            <property name="specification" value="1.1"/>
            <property name="connectionFactoryJndiName" value="ConnectionFactory"/>
            <property name="jndiInitialFactory"
                      value="org.apache.activemq.jndi.ActiveMQInitialContextFactory"/>
            <property name="persistentDelivery" value="true"/>
            <property name="clientId" value="DatafeedFilePublish"/>
            <map name="connectionFactoryProperties">
                <property name="brokerURL" value="tcp://${activemq.host}:${activemq.port}"/>
            </map>
        </properties>
        <!-- For order -->
        <threading-profile maxThreadsActive="1" maxThreadsIdle="1"/>
    </connector>

    <connector name="FileStaging" className="org.mule.providers.file.FileConnector">
        <properties>
            <property name="pollingFrequency" value="5000"/>
        </properties>
    </connector>

    <connector name="FileFailures" className="org.mule.providers.file.FileConnector">
        <properties>
            <property name="outputPattern" value="${ORIGINALNAME}"/>
        </properties>
    </connector>

    <connector name="LocalExceptionLog" className="org.mule.providers.file.FileConnector">
        <properties>
            <property name="outputAppend" value="true"/>
            <property name="outputPattern" value="DatafeedException-${DATE:yyyyMMdd}.log"/>
        </properties>
    </connector>

    <transformers>
        <transformer name="ByteArrayToString" className="org.mule.transformers.simple.ByteArrayToString"/>
        <transformer name="ExceptionCauseToString" className="com.metoceanengineers.datafeeds.transformers.ExceptionCauseToString"/>
    </transformers>

    <interceptor-stack name="default">
        <interceptor className="org.mule.interceptors.LoggingInterceptor"/>
        <interceptor className="org.mule.interceptors.TimerInterceptor"/>
    </interceptor-stack>
   
    <model name="FilePublish">

        <!-- Parse files, dispatching either DatafeedRecords or failures -->

        <exception-strategy className="org.mule.impl.DefaultComponentExceptionStrategy">
            <endpoint address="${logs}" connector="LocalExceptionLog" transformers="ExceptionCauseToString"/>
        </exception-strategy>
       
        <mule-descriptor name="FileParser" implementation="fileRecordProcessorUmo">

            <inbound-router>
                <endpoint address="${ingest.files.inbound}" connector="FileStaging" transformers="ByteArrayToString"/>
            </inbound-router>

            <outbound-router>

                <!-- Successfully parsed files go to JMS -->
                <router className="org.mule.routing.outbound.FilteringOutboundRouter">
                    <endpoint address="jms://datafeeds.records" connector="DatafeedFilePublish"/>
                    <filter className="org.mule.routing.filters.logic.AndFilter">
                        <left-filter expression="datafeeds_ingest_success=true"
                                     className="org.mule.routing.filters.MessagePropertyFilter"/>
                           <right-filter className="com.metoceanengineers.datafeeds.ingest.filters.AggregatedFileHistoryFilter"/>
                       </filter>
                </router>
               
                <!-- Failed Files go back to filesystem -->
                <router className="org.mule.routing.outbound.FilteringOutboundRouter">
                    <endpoint address="${ingest.files.failures}" connector="FileFailures"/>
                    <filter expression="datafeeds_ingest_success=false"
                            className="org.mule.routing.filters.MessagePropertyFilter"/>
                </router>
                   
            </outbound-router>
            <properties>
                <container-property name="fileRecordProcessorUmo" reference="fileRecordProcessorUmo" required="true"/>
            </properties>
        </mule-descriptor>

    </model>

</mule-configuration>



Nick Bower

unread,
Jan 8, 2008, 7:49:02 PM1/8/08
to us...@mule.codehaus.org
I've relocated ActiveMQ onto the same server as Mule and the problem repeated itself within 20 minutes of startup.  I'm very much starting to suspect stability issues with my deployments of Mule and/or ActiveMQ.  Check this out;


8:26 - Server startup and all normal operation with new file arriving, picked up by file connector and handed to FileParser which dispatches a UMOMessage for each of the 500 or so lines;

INFO  2008-01-09 08:32:52,015 [FileParser.2] com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo: Dispatched record for "Metocean Office" 08/01/2008 16:00:00.000 GMT
INFO  2008-01-09 08:32:52,259 [FileParser.2] com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo: Dispatched record for "Metocean Office" 08/01/2008 16:01:00.000 GMT
INFO  2008-01-09 08:32:52,292 [FileParser.2] com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo: Dispatched record for "Metocean Office" 08/01/2008 16:02:00.000 GMT
...

System now functioning as normal with files arriving every 10 minutes or so.  Of subsequent files, only the last few dispatched records from FileParser component actually make it onto the JMS connector courtesy of a stateful AggregatedFileHistoryFilter which does an "if new" test.

8:52 - First sign of trouble.  Records being dispatched after file ingest as normal but then java.io.InterruptedIOException, javax.jms.JMSException and edu.emory.mathcs.backport.java.util.concurrent.RejectedExecutionException.  Remember ActiveMQ is on the same server as Mule here connecting through localhost:61616 so I can't see how connectivity is the issue anymore.  Restarting Mule re-enables the JMS connection and we're good to go until the next time it falls over.

...
INFO  2008-01-09 08:52:42,827 [FileParser.7] com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo: Dispatched record for "ONS_00155" 08/01/2008 00:44:00.000 GMT
INFO  2008-01-09 08:52:42,890 [FileParser.7] com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo: Dispatched record for "ONS_00155" 08/01/2008 00:45:00.000 GMT
INFO  2008-01-09 08:52:42,942 [FileParser.7] com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo: Dispatched record for "ONS_00155" 08/01/2008 00:46:00.000 GMT

(all ok but then)

INFO  2008-01-09 08:52:42,956 [FileParser.8] org.mule.providers.jms.JmsMessageDispatcher: Disconnected: JmsMessageDispatcher{this=1fc9a67, endpoint=jms://datafeeds.records}
ERROR 2008-01-09 08:52:42,958 [DatafeedFilePublish.dispatcher.1] org.mule.providers.jms.JmsConnector: Failed to close jms message producer
javax.jms.JMSException: java.io.InterruptedIOException
        at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:58)
        at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1157)
        at org.apache.activemq.ActiveMQSession.asyncSendPacket(ActiveMQSession.java:1651)
        at org.apache.activemq.ActiveMQMessageProducer.close(ActiveMQMessageProducer.java:315)
        at org.mule.providers.jms.JmsConnector.close(JmsConnector.java:939)
        at org.mule.providers.jms.JmsConnector.closeQuietly(JmsConnector.java:953)
        at org.mule.providers.jms.JmsMessageDispatcher.dispatchMessage(JmsMessageDispatcher.java:301)
        at org.mule.providers.jms.JmsMessageDispatcher.doDispatch(JmsMessageDispatcher.java:64)
        at org.mule.providers.AbstractMessageDispatcher$Worker.run(AbstractMessageDispatcher.java:561)

        at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
Caused by: java.io.InterruptedIOException
        at org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:91)
        at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:47)
        at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
        at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1155)
        ... 11 more
ERROR 2008-01-09 08:52:42,959 [DatafeedFilePublish.dispatcher.1] org.mule.providers.jms.JmsConnector: Failed to close jms session consumer
javax.jms.JMSException: java.io.InterruptedIOException
        at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:58)
        at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1157)
        at org.apache.activemq.ActiveMQSession.close(ActiveMQSession.java:517)
        at org.mule.providers.jms.JmsConnector.close(JmsConnector.java:1003)
        at org.mule.providers.jms.JmsConnector.closeQuietly(JmsConnector.java:1017)
        at org.mule.providers.jms.JmsMessageDispatcher.dispatchMessage(JmsMessageDispatcher.java:323)
        at org.mule.providers.jms.JmsMessageDispatcher.doDispatch(JmsMessageDispatcher.java:64)
        at org.mule.providers.AbstractMessageDispatcher$Worker.run(AbstractMessageDispatcher.java:561)

        at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
Caused by: java.io.InterruptedIOException
        at org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:91)
        at org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:47)
        at org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
        at org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1155)
        ... 10 more
ERROR 2008-01-09 08:52:42,960 [DatafeedFilePublish.dispatcher.1] org.mule.impl.DefaultExceptionStrategy: Caught exception in Exception Strategy: Interrupted.
javax.jms.JMSException: Interrupted.
        at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:58)
        at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1185)
        at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1551)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:465)
        at org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:384)
        at org.mule.providers.jms.Jms11Support.send(Jms11Support.java:226)
        at org.mule.providers.jms.JmsMessageDispatcher.dispatchMessage(JmsMessageDispatcher.java:273)
        at org.mule.providers.jms.JmsMessageDispatcher.doDispatch(JmsMessageDispatcher.java:64)
        at org.mule.providers.AbstractMessageDispatcher$Worker.run(AbstractMessageDispatcher.java:561)

        at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
Caused by: java.io.InterruptedIOException: Interrupted.
        at org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:49)
        at org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:75)
        at org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1175)
        ... 11 more
ERROR 2008-01-09 08:52:42,966 [FileParser.8] com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo: There has been an error: org.mule.umo.routing.RoutingException: Failed to route event via endpoint: null. Message payload is of type: String
ERROR 2008-01-09 08:52:42,970 [FileParser.8] org.mule.impl.DefaultComponentExceptionStrategy:
********************************************************************************
Message               : Failed to route event via endpoint: MuleEndpoint{endpointUri=jms://datafeeds.records, connector=JmsConnector{this=6c1a82, started=true, initialised=true, name='DatafeedFilePublish', disposed=false, numberOfConcurrentTransactedReceivers=4, createMultipleTransactedReceivers=true, connected=true, supportedProtocols=[jms], serviceOverrides=null}, transformer=ObjectToJMSMessage{this=c8ec7e, name='ObjectToJMSMessage', ignoreBadInput=false, returnClass=null, sourceTypes=[]}, name='endpoint.jms.datafeeds.records', type='senderAndReceiver', properties={}, transactionConfig=Transaction{factory=null, action=NONE, timeout=30000}, filter=null, deleteUnacceptedMessages=false, initialised=true, securityFilter=null, synchronous=null, initialState=started, createConnector=0, remoteSync=false, remoteSyncTimeout=10000, endpointEncoding=null}. Message payload is of type: String

Type                  : org.mule.umo.provider.DispatchException
Code                  : MULE_ERROR-42999
JavaDoc               : http://mule.mulesource.org/docs/apidocs/org/mule/umo/provider/DispatchException.html
DispatchException.html
Payload               : <?xml version="1.0"?>
<netcdf xmlns="http://www.unidata.ucar.edu/namespaces/netcdf/ncml-2.2"><dimension isUnlimited="true" length="1" name="records"/><dimension length="2" name="timedim"/><attribute name="Conventions" type="string" value="WNIOM/v2"/><attribute name="data_origin" type="string" value="measured"/><attribute name="project" type="string" value="A0468 Internal Datafeeds"/><attribute name="history" type="string" value="Mule ingest to NetCDF store"/><attribute name="client" type="string" value="RPS Metocean"/><attribute name="location" type="string" value="ONS_00155"/><attribute name="DataFeedId" type="string" value="ONS_00155"/><attribute name="logging_system" type="string" value="UTC"/><variable name="Time" shape="records timedim" type="int"><values>20080108 57660000</values></variable><variable name="WS" shape="records" type="float"><values>5.8</values><attribute name="units" type="string" value="m/s"/></variable><variable name="WD" shape="records" type="float"><values>228.0</values><attribute name="units" type="string" value="deg"/></variable><variable name="WG" shape="records" type="float"><values>7.5</values><attribute name="units" type="string" value="m/s"/></variable><variable name="ST" shape="records" type="float"><values>8.0</values><attribute name="units" type="string" value="deg"/></variable><variable name="AT" shape="records" type="float"><values>28.1</values><attribute name="units" type="string" value="degC"/></variable><variable name="RH" shape="records" type="float"><values>75.5</values><attribute name="units" type="string" value="%"/></variable><variable name="BP" shape="records" type="float"><values>1008.2</values><attribute name="units" type="string" value="hPa"/></variable><variable name="BV" shape="records" type="float"><values>12.71</values><attribute name="units" type="string" value="V"/></variable><variable name="VWS" shape="records" type="float"><values>5.8</values><attribute name="units" type="string" value="m/s"/></variable><variable name="VWD" shape="records" type="float"><values>228.0</values><attribute name="units" type="string" value="deg"/></variable></netcdf>
********************************************************************************
Exception stack is:
1. null (edu.emory.mathcs.backport.java.util.concurrent.RejectedExecutionException)
  org.mule.util.concurrent.WaitPolicy:56 (null)
2. Failed to route event via endpoint: MuleEndpoint{endpointUri=jms://datafeeds.records, connector=JmsConnector{this=6c1a82, started=true, initialised=true, name='DatafeedFilePublish', disposed=false, numberOfConcurrentTransactedReceivers=4, createMultipleTransactedReceivers=true, connected=true, supportedProtocols=[jms], serviceOverrides=null}, transformer=ObjectToJMSMessage{this=c8ec7e, name='ObjectToJMSMessage', ignoreBadInput=false, returnClass=null, sourceTypes=[]}, name='endpoint.jms.datafeeds.records', type='senderAndReceiver', properties={}, transactionConfig=Transaction{factory=null, action=NONE, timeout=30000}, filter=null, deleteUnacceptedMessages=false, initialised=true, securityFilter=null, synchronous=null, initialState=started, createConnector=0, remoteSync=false, remoteSyncTimeout=10000, endpointEncoding=null}. Message payload is of type: String (org.mule.umo.provider.DispatchException)

  org.mule.providers.AbstractMessageDispatcher:176 (http://mule.mulesource.org/docs/apidocs/org/mule/umo/provider/DispatchException.html)
********************************************************************************
Root Exception stack trace:
edu.emory.mathcs.backport.java.util.concurrent.RejectedExecutionException
        at org.mule.util.concurrent.WaitPolicy.rejectedExecution(WaitPolicy.java:56)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:391)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:865)
        at org.mule.impl.work.ScheduleWorkExecutor.doExecute(ScheduleWorkExecutor.java:39)
        at org.mule.impl.work.MuleWorkManager.executeWork(MuleWorkManager.java:276)

        at org.mule.impl.work.MuleWorkManager.scheduleWork(MuleWorkManager.java:243)
        at org.mule.providers.AbstractMessageDispatcher.dispatch(AbstractMessageDispatcher.java:149)
        at org.mule.providers.AbstractConnector.dispatch(AbstractConnector.java:1583)
        at org.mule.impl.ImmutableMuleEndpoint.dispatch(ImmutableMuleEndpoint.java:929)
        at org.mule.impl.MuleSession.dispatchEvent(MuleSession.java:259)
        at org.mule.impl.MuleSession.dispatchEvent(MuleSession.java:162)
        at org.mule.routing.outbound.AbstractOutboundRouter.dispatch(AbstractOutboundRouter.java:81)
        at org.mule.routing.outbound.FilteringOutboundRouter.route(FilteringOutboundRouter.java:70)
        at org.mule.routing.outbound.OutboundRouterCollection$1.doInTransaction(OutboundRouterCollection.java:66)
        at org.mule.transaction.TransactionTemplate.execute(TransactionTemplate.java:39)
        at org.mule.routing.outbound.OutboundRouterCollection.route(OutboundRouterCollection.java:71)
        at org.mule.impl.MuleSession.dispatchEvent(MuleSession.java:139)
        at org.mule.impl.MuleEventContext.dispatchEvent(MuleEventContext.java:478)
        at com.metoceanengineers.datafeeds.ingest.components.AbstractRecordProcessorUmo.processIngest(AbstractRecordProcessorUmo.java:117)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at org.mule.impl.model.resolvers.DynamicEntryPoint.invokeMethod(DynamicEntryPoint.java:312)
        at org.mule.impl.model.resolvers.DynamicEntryPoint.invoke(DynamicEntryPoint.java:259)
        at org.mule.impl.DefaultLifecycleAdapter.intercept(DefaultLifecycleAdapter.java:194)
        at org.mule.impl.InterceptorsInvoker.execute(InterceptorsInvoker.java:47)
        at org.mule.impl.model.DefaultMuleProxy.run(DefaultMuleProxy.java:467)
        at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)

********************************************************************************


Then later we start receiving the problems below.

Nick Bower

unread,
Jan 8, 2008, 11:02:36 PM1/8/08
to us...@mule.codehaus.org
Fingers crossed, but after seeing this:

http://www.nabble.com/JMSException-under-heavy-load-...-td4899934.html#a4899934

instead of going with the threading profile for preserving JMS queue
ordering as discussed here

http://www.nabble.com/Ordered-JMS-consumption-td14611724.html

I tried this one;

<threading-profile maxThreadsActive="1" maxThreadsIdle="1"

poolExhaustedAction="WAIT"
threadWaitTimeout ="-1"/>

and things are working better during bursts of messages. I'm not sure
why WAIT wouldn't be the default.

I think also the exception message could be tweaked? You get an
uninformative InterupptedIOException and RejectedExecutionException once
initially (if you manage to notice them), but then much later repeated
MuleManager stopped messages. Personally I would have liked to see Mule
fail when the JMS connector eventually fails - Mule doesn't initially
start if it doesn't afterall.


Nick Bower wrote:
> I've relocated ActiveMQ onto the same server as Mule and the problem
> repeated itself within 20 minutes of startup. I'm very much starting
> to suspect stability issues with my deployments of Mule and/or
> ActiveMQ. Check this out;
>
>
> 8:26 - Server startup and all normal operation with new file arriving,
> picked up by file connector and handed to FileParser which dispatches
> a UMOMessage for each of the 500 or so lines;
>
> INFO 2008-01-09 08:32:52,015 [FileParser.2]
> com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo:
> Dispatched record for "Metocean Office" 08/01/2008 16:00:00.000 GMT
> INFO 2008-01-09 08:32:52,259 [FileParser.2]
> com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo:
> Dispatched record for "Metocean Office" 08/01/2008 16:01:00.000 GMT
> INFO 2008-01-09 08:32:52,292 [FileParser.2]
> com.metoceanengineers.datafeeds.ingest.components.RecordProcessorUmo:
> Dispatched record for "Metocean Office" 08/01/2008 16:02:00.000 GMT
> ...
>
> System now functioning as normal with files arriving every 10 minutes
> or so. Of subsequent files, only the last few dispatched records from
> FileParser component actually make it onto the JMS connector courtesy
> of a stateful AggregatedFileHistoryFilter which does an "if new" test.
>

> _8:52 - First sign of trouble._ Records being dispatched after file
> ingest as normal but then *java.io.InterruptedIOException,
> javax.jms.JMSException and
> edu.emory.mathcs.backport.java.util.concurrent.RejectedExecutionException*.

---------------------------------------------------------------------
To unsubscribe from this list please visit:

http://xircles.codehaus.org/manage_email

Reply all
Reply to author
Forward
0 new messages