Re: [Quickfix-developers] SocketConnection session registration BUG

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

Hi Sean

I am Raman. Oren has been helping me to decipher a similar trouble.

I am using QF 1.9.4 and I could not get a connection going.
After trying everything I could with C++, I switched to QF-J Implementation=
.
the FIX Version is 4.2. The problem(s) were as follows:
I was using data dictionary in the settings. This caused the Session to
reject a legitimate LOGON message  from the counterparty.
Java Exception indicated the problem with Tag 52 SendingTime not being in=
=20
order. Since the LOGON message is rejected the session is not active
and any other message (seq..reset etc) all fail. And the app kind of melts
down.

I agree with you 100% I find QF to be an excellent tool well written.
I am planning to add documentation and how-to kind of messages to the
group so the ease of using QF is brought out. Unfortunately I am allergic t=
o
C++. If you need help with java version send me a note.=20

Regards
--
RK
On 6/27/05, Sean Kirkpatrick <Sea...@pi...> wrote:
> QuickFIX Documentation: http://www.quickfixengine.org/quickfix/doc/html/i=
ndex.html
> QuickFIX FAQ: http://www.quickfixengine.org/wikifix/index.php?QuickFixFAQ
> QuickFIX Support: http://www.quickfixengine.org/services.html
>=20
> I have added proprietary logging to the quickfix library to help debug
> an issue we have been having with a client not being able to log in.
> We could see the logon message coming across via tethereal, but were
> unable to determine the reason why the socket was being dropped.
>=20
> The following logs expose where the logic error in quickfix occurs:
>=20
> 09:00:20.452 {QF::SocketMonitor::block} Socket [393] has data
> 09:00:20.452 {QF::ServerWrapper::onEvent} data found on socket [393]
> 09:00:20.452 {QF::SocketAcceptor::onData} getting SocketConnection [393]
> 09:00:20.452 {QF::SocketAcceptor::onData} found SocketConnection [393]
> 09:00:20.452 {QF::SocketConnection::read} reading message
> 09:00:20.452 {QF::Parser::readFromStream} socket_fionread returned [72] b=
ytes
> 09:00:20.452 {QF::Parser::readFromStream} recv [72] bytes on socket [393]
> 09:00:20.452 {QF::Parser::readFixMessage} found BeginString tag 8
> 09:00:20.452 {QF::Parser::readFixMessage} found CheckSum tag 10
> 09:00:20.452 {QF::Parser::readFixMessage} found final SOH char
> 09:00:20.452 {QF::Parser::readFixMessage} message [8=3DFIX.4.0^A9=3D50^A3=
5=3D0^A49=3DSEND^A56=3DRECV
> ^A34=3D1^A52=3D20050627-13:00:20^A10=3D056^A]
> 09:00:20.452 {QF::SocketConnection::read} looking for session based on [8=
=3DFIX.4.0^A9=3D50^A35=3D0
> ^A49=3DSEND^A56=3DRECV^A34=3D1^A52=3D20050627-13:00:20^A10=3D056^A]
> 09:00:20.452 {QF::Session::lookupSession} Looking for session: [FIX.4.0:R=
ECV->SEND]
> 09:00:20.452 {QF::Session::lookupSession} FOUND IT!
> 09:00:20.452 {QF::SocketConnection::read} registering session [FIX.4.0:RE=
CV->SEND]
> 09:00:20.453 {QF::Session::lookupSession} Looking for session: [FIX.4.0:R=
ECV->SEND]
> 09:00:20.453 {QF::Session::lookupSession} FOUND IT!
> 09:00:20.453 {QF::Session::registerSession} found session [FIX.4.0:RECV->=
SEND]
> 09:00:20.453 {QF::Session::registerSession} registering session
> ----
> 09:00:20.453 {QF::SocketConnection::read} getting SocketAcceptor session =
[8=3DFIX.4.0^A9=3D50^A35
> =3D0^A49=3DSEND^A56=3DRECV^A34=3D1^A52=3D20050627-13:00:20^A10=3D056^A]
> 09:00:20.453 {QF::Acceptor::getSession} msgType [0] not valid
> 09:00:20.453 {QF::SocketConnection::read} Dropping socket connection
> 09:00:20.453 {QF::SocketConnection::read} reading message
> 09:00:20.453 {QF::Parser::readFromStream} socket_fionread failed
> 09:00:20.453 {QF::SocketMonitor::block} queue has sockets to drop
> 09:00:20.453 {QF::SocketAcceptor::onDisconnect} Disconnecting socket: [39=
3]
> 09:00:20.453 {QF::SocketConnection::~SocketConnection} destroying SocketC=
onnection
>=20
> The problem occurs between the "----" separated log lines.  The library
> registers the session, but then attempts to validate that the recvd messa=
ge
> is a logon.  If it is not, the function return NULL as the m_pSession
> variable.  The next section of the SocketConnection read checks for a val=
id
> m_pSession.  If the session is NULL, the socket is dropped.  When the
> SocketConnection is destroyed, it's m_pSession is still NULL, and the obj=
ect
> is never unregistered.  Subsequent attempts to connect to this session lo=
g
> the following:
>=20
> 09:04:26.744 {QF::SocketMonitor::block} Socket [393] has data
> 09:04:26.744 {QF::ServerWrapper::onEvent} data found on socket [393]
> 09:04:26.744 {QF::SocketAcceptor::onData} getting SocketConnection [393]
> 09:04:26.744 {QF::SocketAcceptor::onData} found SocketConnection [393]
> 09:04:26.744 {QF::SocketConnection::read} reading message
> 09:04:26.744 {QF::Parser::readFromStream} socket_fionread returned [84] b=
ytes
> 09:04:26.744 {QF::Parser::readFromStream} recv [84] bytes on socket [393]
> 09:04:26.745 {QF::Parser::readFixMessage} found BeginString tag 8
> 09:04:26.745 {QF::Parser::readFixMessage} found CheckSum tag 10
> 09:04:26.745 {QF::Parser::readFixMessage} found final SOH char
> 09:04:26.745 {QF::Parser::readFixMessage} message [8=3DFIX.4.0^A9=3D62^A3=
5=3DA^A49=3DSEND^A56=3DRECV
> ^A34=3D3^A52=3D20050627-13:04:26^A98=3D0^A108=3D20^A10=3D112^A]
> 09:04:26.745 {QF::SocketConnection::read} looking for session based on [8=
=3DFIX.4.0^A9=3D62^A35=3DA
> ^A49=3DSEND^A56=3DRECV^A34=3D3^A52=3D20050627-13:04:26^A98=3D0^A108=3D20^=
A10=3D112^A]
> 09:04:26.745 {QF::Session::lookupSession} Looking for session: [FIX.4.0:R=
ECV->SEND]
> 09:04:26.745 {QF::Session::lookupSession} FOUND IT!
> 09:04:26.745 {QF::SocketConnection::read} registering session [FIX.4.0:RE=
CV->SEND]
> 09:04:26.745 {QF::Session::lookupSession} Looking for session: [FIX.4.0:R=
ECV->SEND]
> 09:04:26.745 {QF::Session::lookupSession} FOUND IT!
> 09:04:26.745 {QF::Session::registerSession} found session [FIX.4.0:RECV->=
SEND]
> ----
> 09:04:26.745 {QF::SocketConnection::read} Dropping socket connection
> 09:04:26.745 {QF::SocketConnection::read} reading message
> 09:04:26.745 {QF::Parser::readFromStream} socket_fionread failed
> 09:04:26.745 {QF::SocketMonitor::block} queue has sockets to drop
> 09:04:26.745 {QF::SocketAcceptor::onDisconnect} Disconnecting socket: [39=
3]
> 09:04:26.745 {QF::SocketConnection::~SocketConnection} destroying SocketC=
onnection
>=20
> In between the "----" separated log lines, the session is detected as alr=
eady
> registered and the m_pSession member is again set to NULL and the socket =
is
> dropped.
>=20
> I believe that there is a very simple fix that will correct this issue.  =
The
> order of the following code in SocketConnection::read (the LOGDEBUG lines=
 are
> for the logging I added):
>=20
>  if ( m_pSession ) {
>    LOGDEBUG(funcname,"registering session [%s]",m_pSession->getSessionID(=
).toString().c_str());
>    m_pSession =3D Session::registerSession( m_pSession->getSessionID() );
>  }
>=20
>  if ( m_pSession ) {
>    LOGDEBUG(funcname,"getting SocketAcceptor session [%s]",msg.c_str());
>    m_pSession =3D a.getSession( msg, *this );
>  }
>=20
> needs to be reversed to be:
>=20
>  if ( m_pSession ) {
>    LOGDEBUG(funcname,"getting SocketAcceptor session [%s]",msg.c_str());
>    m_pSession =3D a.getSession( msg, *this );
>  }
>=20
>  if ( m_pSession ) {
>    LOGDEBUG(funcname,"registering session [%s]",m_pSession->getSessionID(=
).toString().c_str());
>    m_pSession =3D Session::registerSession( m_pSession->getSessionID() );
>  }
>=20
> If this is the case, any invalid initial messages will invalidate the
> m_pSession member prior to attempting to register the session.  Only vali=
d
> connections will be registered, and the disconnect logic works fine so
> long as the registration is done properly.  A week of development was los=
t
> due to the lack of engine-level logging in the quickfix library, and I
> know that this is an issue that has been raised several times in the past=
.
>=20
> Please provide feedback.
>=20
> --Sean
>=20
>=20
> -------------------------------------------------------
> SF.Net email is sponsored by: Discover Easy Linux Migration Strategies
> from IBM. Find simple to follow Roadmaps, straightforward articles,
> informative Webcasts and more! Get everything you need to get up to
> speed, fast. http://ads.osdn.com/?ad_idt77&alloc_id=16492&opclick
> _______________________________________________
> Quickfix-developers mailing list
> Qui...@li...
> https://lists.sourceforge.net/lists/listinfo/quickfix-developers
>