Marketcetera.org › m-etc-dev

jms timeout causes FIX logout

2 messages Options
Embed this post
Permalink
robparrott

jms timeout causes FIX logout

Reply Threaded More More options
Print post
Permalink
Hi folks,

Now that I've gotten things working a little more, I want to ask about
an error I'm getting. I'm finding that, at least using just the Hermes
client, that the OMS gets into a strange state where it keeps hanging
up the FIX connection.

The following log from the OMS repeats over and over. After the FIX
login to the counterparty, the ActiveMQ engine throws an exception,
which causes the FIX connection to hangup. The error at the end of the
stacktrace claims that the problem was with the FIX logon, but in fact
the logon response was sent from the counterparty.

The cause seems to be the  in QuickFIXApplication class, at

        public void fromAdmin(Message message, SessionID session) throws
FieldNotFound, IncorrectDataFormat, IncorrectTagValue, RejectLogon {
                if (jmsOperations != null){
                        jmsOperations.convertAndSend(message);
                }
        }

Without catching an exception here, then quickfix will hang up it
seems. Shouldn't this kind of exception be caught? I would hope that
the quickfix thread would continue to remain logged in even if the
messaging service on the other end becomes disconnected.

Is this the desired behavior here? Or conversely, why is the channel
inactive? Is message to be sent to the client? Would this mean that
the OMS, without a JMS client on the other end, would hang up to the
FIX connection?

Thanks,
rob





<20070201-22:07:08, FIX.4.3:CLIENT1->SERVER1, outgoing>
(8=FIX.4.39=6635=A34=149=FDO52=20070201-22:07:08.38356=DB98=0108=30141=Y10=138)
<20070201-22:07:08, FIX.4.3:CLIENT1->SERVER1, event> (Initiated logon request)
<20070201-22:07:09, FIX.4.3:CLIENT1->SERVER1, incoming>
(8=FIX.4.39=6235=A49=DB56=FDO34=152=20070201-22:07:08108=30141=Y98=010=186)
<20070201-22:07:09, FIX.4.3:CLIENT1->SERVER1, event> (Logon contains
ResetSeqNumFlag=Y, resetting sequence numbers to 1)
<20070201-22:07:09, FIX.4.3:CLIENT1->SERVER1, event> (Uncategorized
exception occured during JMS processing; nested exception is
org.apache.activemq.ConnectionFailedException: The JMS connection has
failed: Channel was inactive for too long.; nested exception is
org.apache.activemq.transport.InactivityIOException: Channel was
inactive for too long.
org.springframework.jms.UncategorizedJmsException: Uncategorized
exception occured during JMS processing; nested exception is
org.apache.activemq.ConnectionFailedException: The JMS connection has
failed: Channel was inactive for too long.; nested exception is
org.apache.activemq.transport.InactivityIOException: Channel was
inactive for too long.
Caused by: org.apache.activemq.ConnectionFailedException: The JMS
connection has failed: Channel was inactive for too long.
        at org.apache.activemq.ActiveMQConnection.checkClosedOrFailed(ActiveMQConnection.java:1230)
        at org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:273)
        at org.apache.activemq.pool.SessionPool.createSession(SessionPool.java:113)
        at org.apache.activemq.pool.SessionPool.makeObject(SessionPool.java:81)
        at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:771)
        at org.apache.activemq.pool.SessionPool.borrowSession(SessionPool.java:56)
        at org.apache.activemq.pool.ConnectionPool.createSession(ConnectionPool.java:71)
        at org.apache.activemq.pool.PooledConnection.createSession(PooledConnection.java:130)
        at org.springframework.jms.core.JmsTemplate.createSession(JmsTemplate.java:827)
        at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:421)
        at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:477)
        at org.springframework.jms.core.JmsTemplate.convertAndSend(JmsTemplate.java:558)
        at org.springframework.jms.core.JmsTemplate.convertAndSend(JmsTemplate.java:549)
        at org.marketcetera.oms.QuickFIXApplication.fromAdmin(QuickFIXApplication.java:30)
        at quickfix.Session.fromCallback(Session.java:1147)
        at quickfix.Session.verify(Session.java:1103)
        at quickfix.Session.nextLogon(Session.java:1326)
        at quickfix.Session.next(Session.java:641)
        at quickfix.mina.SingleThreadedEventHandlingStrategy$SessionMessageEvent.processMessage(SingleThreadedEventHandlingStrategy.java:103)
        at quickfix.mina.SingleThreadedEventHandlingStrategy.block(SingleThreadedEventHandlingStrategy.java:68)
        at quickfix.mina.SingleThreadedEventHandlingStrategy$1.run(SingleThreadedEventHandlingStrategy.java:84)
        at java.lang.Thread.run(Thread.java:595)
Caused by: org.apache.activemq.transport.InactivityIOException:
Channel was inactive for too long.
        at org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
        at org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
        at org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
        at edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
        at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
        at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
        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)
        ... 1 more
)
<20070201-22:07:19, FIX.4.3:CLIENT1->SERVER1, event> (Timed out
waiting for logon response)
<20070201-22:07:19, FIX.4.3:CLIENT1->SERVER1, event> (Disconnecting)
_______________________________________________
m-etc-dev mailing list
[hidden email]
http://lists.marketcetera.org/cgi-bin/mailman/listinfo/m-etc-dev
toli

Re: jms timeout causes FIX logout

Reply Threaded More More options
Print post
Permalink
Rob,

It seems that the UncategorizedJmsException is a subset of
RuntimeException - which is why we are not explicitly catching it.

I can see how it could become a problem in the case that you are describing.

What's the best way to reproduce your error condition? What makes your
JMS session stale?
Once i can repro/simulate it here, i can figure out what the best way
to approach the problem will be.

But for now, you can probably surround both the fromAdmin and from App
calls with a try/catch(Excpetion ex) to allow you to move forward. It
wasn't our intent to die completely in the case when there are
problems with the downstream JMS receiver.

However, we use JMS internall as well to communicate between differnet
OMS "stages", so if the JMS gets confused we may have other issues
later.

Regardless, i'd be interested in finding out what happens with JMS so
that we can repro it here and write some unit tests against that case.

i've created a bug on Trac for this, feel free to add more information there.
http://trac.marketcetera.org/trac.fcgi/ticket/120

thanks

On 2/1/07, Robert Parrott <[hidden email]> wrote:

> Hi folks,
>
> Now that I've gotten things working a little more, I want to ask about
> an error I'm getting. I'm finding that, at least using just the Hermes
> client, that the OMS gets into a strange state where it keeps hanging
> up the FIX connection.
>
> The following log from the OMS repeats over and over. After the FIX
> login to the counterparty, the ActiveMQ engine throws an exception,
> which causes the FIX connection to hangup. The error at the end of the
> stacktrace claims that the problem was with the FIX logon, but in fact
> the logon response was sent from the counterparty.
>
> The cause seems to be the  in QuickFIXApplication class, at
>
>         public void fromAdmin(Message message, SessionID session) throws
> FieldNotFound, IncorrectDataFormat, IncorrectTagValue, RejectLogon {
>                 if (jmsOperations != null){
>                         jmsOperations.convertAndSend(message);
>                 }
>         }
>
> Without catching an exception here, then quickfix will hang up it
> seems. Shouldn't this kind of exception be caught? I would hope that
> the quickfix thread would continue to remain logged in even if the
> messaging service on the other end becomes disconnected.
>
> Is this the desired behavior here? Or conversely, why is the channel
> inactive? Is message to be sent to the client? Would this mean that
> the OMS, without a JMS client on the other end, would hang up to the
> FIX connection?
>
> Thanks,
> rob
>
>
>
>
>
> <20070201-22:07:08, FIX.4.3:CLIENT1->SERVER1, outgoing>
> (8=FIX.4.39=6635=A34=149=FDO52=20070201-22:07:08.38356=DB98=0108=30141=Y10=138)
> <20070201-22:07:08, FIX.4.3:CLIENT1->SERVER1, event> (Initiated logon request)
> <20070201-22:07:09, FIX.4.3:CLIENT1->SERVER1, incoming>
> (8=FIX.4.39=6235=A49=DB56=FDO34=152=20070201-22:07:08108=30141=Y98=010=186)
> <20070201-22:07:09, FIX.4.3:CLIENT1->SERVER1, event> (Logon contains
> ResetSeqNumFlag=Y, resetting sequence numbers to 1)
> <20070201-22:07:09, FIX.4.3:CLIENT1->SERVER1, event> (Uncategorized
> exception occured during JMS processing; nested exception is
> org.apache.activemq.ConnectionFailedException: The JMS connection has
> failed: Channel was inactive for too long.; nested exception is
> org.apache.activemq.transport.InactivityIOException: Channel was
> inactive for too long.
> org.springframework.jms.UncategorizedJmsException: Uncategorized
> exception occured during JMS processing; nested exception is
> org.apache.activemq.ConnectionFailedException: The JMS connection has
> failed: Channel was inactive for too long.; nested exception is
> org.apache.activemq.transport.InactivityIOException: Channel was
> inactive for too long.
> Caused by: org.apache.activemq.ConnectionFailedException: The JMS
> connection has failed: Channel was inactive for too long.
>         at org.apache.activemq.ActiveMQConnection.checkClosedOrFailed(ActiveMQConnection.java:1230)
>         at org.apache.activemq.ActiveMQConnection.createSession(ActiveMQConnection.java:273)
>         at org.apache.activemq.pool.SessionPool.createSession(SessionPool.java:113)
>         at org.apache.activemq.pool.SessionPool.makeObject(SessionPool.java:81)
>         at org.apache.commons.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:771)
>         at org.apache.activemq.pool.SessionPool.borrowSession(SessionPool.java:56)
>         at org.apache.activemq.pool.ConnectionPool.createSession(ConnectionPool.java:71)
>         at org.apache.activemq.pool.PooledConnection.createSession(PooledConnection.java:130)
>         at org.springframework.jms.core.JmsTemplate.createSession(JmsTemplate.java:827)
>         at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:421)
>         at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:477)
>         at org.springframework.jms.core.JmsTemplate.convertAndSend(JmsTemplate.java:558)
>         at org.springframework.jms.core.JmsTemplate.convertAndSend(JmsTemplate.java:549)
>         at org.marketcetera.oms.QuickFIXApplication.fromAdmin(QuickFIXApplication.java:30)
>         at quickfix.Session.fromCallback(Session.java:1147)
>         at quickfix.Session.verify(Session.java:1103)
>         at quickfix.Session.nextLogon(Session.java:1326)
>         at quickfix.Session.next(Session.java:641)
>         at quickfix.mina.SingleThreadedEventHandlingStrategy$SessionMessageEvent.processMessage(SingleThreadedEventHandlingStrategy.java:103)
>         at quickfix.mina.SingleThreadedEventHandlingStrategy.block(SingleThreadedEventHandlingStrategy.java:68)
>         at quickfix.mina.SingleThreadedEventHandlingStrategy$1.run(SingleThreadedEventHandlingStrategy.java:84)
>         at java.lang.Thread.run(Thread.java:595)
> Caused by: org.apache.activemq.transport.InactivityIOException:
> Channel was inactive for too long.
>         at org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         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)
>         ... 1 more
> )
> <20070201-22:07:19, FIX.4.3:CLIENT1->SERVER1, event> (Timed out
> waiting for logon response)
> <20070201-22:07:19, FIX.4.3:CLIENT1->SERVER1, event> (Disconnecting)
> _______________________________________________
> m-etc-dev mailing list
> [hidden email]
> http://lists.marketcetera.org/cgi-bin/mailman/listinfo/m-etc-dev
>


--
Toli Kuznets
http://www.marketcetera.com: Open-Source Trading Platform
download.run.trade.
_______________________________________________
m-etc-dev mailing list
[hidden email]
http://lists.marketcetera.org/cgi-bin/mailman/listinfo/m-etc-dev
Free Embeddable Forum Powered by Nabble Help