Thread: [Quickfix-developers] SocketConnection session registration BUG
Brought to you by:
orenmnero
Menu
▾
▴
quickfix-developers
|
From: Sean K. <Sea...@Pi...> - 2005-06-27 15:34:47
|
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:
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] =
bytes
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^A35=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:RECV->SEND]
09:00:20.452 {QF::Session::lookupSession} FOUND IT!
09:00:20.452 {QF::SocketConnection::read} registering session =
[FIX.4.0:RECV->SEND]
09:00:20.453 {QF::Session::lookupSession} Looking for session: =
[FIX.4.0:RECV->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: =
[393]
09:00:20.453 {QF::SocketConnection::~SocketConnection} destroying =
SocketConnection
The problem occurs between the "----" separated log lines. The library
registers the session, but then attempts to validate that the recvd =
message
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 =
valid
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 =
object
is never unregistered. Subsequent attempts to connect to this session =
log
the following:
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] =
bytes
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^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::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:RECV->SEND]
09:04:26.745 {QF::Session::lookupSession} FOUND IT!
09:04:26.745 {QF::SocketConnection::read} registering session =
[FIX.4.0:RECV->SEND]
09:04:26.745 {QF::Session::lookupSession} Looking for session: =
[FIX.4.0:RECV->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: =
[393]
09:04:26.745 {QF::SocketConnection::~SocketConnection} destroying =
SocketConnection
In between the "----" separated log lines, the session is detected as =
already
registered and the m_pSession member is again set to NULL and the socket =
is
dropped.
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):
if ( m_pSession ) {
LOGDEBUG(funcname,"registering session =
[%s]",m_pSession->getSessionID().toString().c_str());
m_pSession =3D Session::registerSession( m_pSession->getSessionID() =
);
}
if ( m_pSession ) {
LOGDEBUG(funcname,"getting SocketAcceptor session =
[%s]",msg.c_str());
m_pSession =3D a.getSession( msg, *this );
}
needs to be reversed to be:
if ( m_pSession ) {
LOGDEBUG(funcname,"getting SocketAcceptor session =
[%s]",msg.c_str());
m_pSession =3D a.getSession( msg, *this );
}
if ( m_pSession ) {
LOGDEBUG(funcname,"registering session =
[%s]",m_pSession->getSessionID().toString().c_str());
m_pSession =3D Session::registerSession( m_pSession->getSessionID() =
);
}
If this is the case, any invalid initial messages will invalidate the
m_pSession member prior to attempting to register the session. Only =
valid
connections will be registered, and the disconnect logic works fine so
long as the registration is done properly. A week of development was =
lost
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.
Please provide feedback.
--Sean
|
|
From: Oren M. <or...@qu...> - 2005-06-27 22:16:15
|
Sean, I'll try to design a test that duplicates this scenario. --oren ----- Original Message ----- From: "Sean Kirkpatrick" <Sea...@Pi...> To: <qui...@li...> Sent: Monday, June 27, 2005 10:34 AM Subject: [Quickfix-developers] SocketConnection session registration BUG QuickFIX Documentation: http://www.quickfixengine.org/quickfix/doc/html/index.html QuickFIX FAQ: http://www.quickfixengine.org/wikifix/index.php?QuickFixFAQ QuickFIX Support: http://www.quickfixengine.org/services.html 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. The following logs expose where the logic error in quickfix occurs: 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] bytes 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=FIX.4.0^A9=50^A35=0^A49=SEND^A56=RECV ^A34=1^A52=20050627-13:00:20^A10=056^A] 09:00:20.452 {QF::SocketConnection::read} looking for session based on [8=FIX.4.0^A9=50^A35=0 ^A49=SEND^A56=RECV^A34=1^A52=20050627-13:00:20^A10=056^A] 09:00:20.452 {QF::Session::lookupSession} Looking for session: [FIX.4.0:RECV->SEND] 09:00:20.452 {QF::Session::lookupSession} FOUND IT! 09:00:20.452 {QF::SocketConnection::read} registering session [FIX.4.0:RECV->SEND] 09:00:20.453 {QF::Session::lookupSession} Looking for session: [FIX.4.0:RECV->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=FIX.4.0^A9=50^A35 =0^A49=SEND^A56=RECV^A34=1^A52=20050627-13:00:20^A10=056^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: [393] 09:00:20.453 {QF::SocketConnection::~SocketConnection} destroying SocketConnection The problem occurs between the "----" separated log lines. The library registers the session, but then attempts to validate that the recvd message 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 valid 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 object is never unregistered. Subsequent attempts to connect to this session log the following: 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] bytes 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=FIX.4.0^A9=62^A35=A^A49=SEND^A56=RECV ^A34=3^A52=20050627-13:04:26^A98=0^A108=20^A10=112^A] 09:04:26.745 {QF::SocketConnection::read} looking for session based on [8=FIX.4.0^A9=62^A35=A ^A49=SEND^A56=RECV^A34=3^A52=20050627-13:04:26^A98=0^A108=20^A10=112^A] 09:04:26.745 {QF::Session::lookupSession} Looking for session: [FIX.4.0:RECV->SEND] 09:04:26.745 {QF::Session::lookupSession} FOUND IT! 09:04:26.745 {QF::SocketConnection::read} registering session [FIX.4.0:RECV->SEND] 09:04:26.745 {QF::Session::lookupSession} Looking for session: [FIX.4.0:RECV->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: [393] 09:04:26.745 {QF::SocketConnection::~SocketConnection} destroying SocketConnection In between the "----" separated log lines, the session is detected as already registered and the m_pSession member is again set to NULL and the socket is dropped. 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): if ( m_pSession ) { LOGDEBUG(funcname,"registering session [%s]",m_pSession->getSessionID().toString().c_str()); m_pSession = Session::registerSession( m_pSession->getSessionID() ); } if ( m_pSession ) { LOGDEBUG(funcname,"getting SocketAcceptor session [%s]",msg.c_str()); m_pSession = a.getSession( msg, *this ); } needs to be reversed to be: if ( m_pSession ) { LOGDEBUG(funcname,"getting SocketAcceptor session [%s]",msg.c_str()); m_pSession = a.getSession( msg, *this ); } if ( m_pSession ) { LOGDEBUG(funcname,"registering session [%s]",m_pSession->getSessionID().toString().c_str()); m_pSession = Session::registerSession( m_pSession->getSessionID() ); } If this is the case, any invalid initial messages will invalidate the m_pSession member prior to attempting to register the session. Only valid connections will be registered, and the disconnect logic works fine so long as the registration is done properly. A week of development was lost 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. Please provide feedback. --Sean ------------------------------------------------------- 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_id492&op=ick _______________________________________________ Quickfix-developers mailing list Qui...@li... https://lists.sourceforge.net/lists/listinfo/quickfix-developers |
|
From: Oren M. <or...@qu...> - 2005-06-28 13:27:38
|
Sean,
When applying your patch, other acceptance tests break. In fact it results
in a crash during a typical multiple logon scenario. (If you run your
acceptance tests, it should reveal the same thing to you). I've included
another implementation of SocketConnection::read which passes all the
acceptance tests and should also fix the bug you've reported. Please report
back if that is the case:
bool SocketConnection::read( SocketAcceptor& a, SocketServer& s )
{ QF_STACK_PUSH(SocketConnection::read)
std::string msg;
try
{
readFromSocket();
if ( !m_pSession )
{
if ( !readMessage( msg ) ) return false;
m_pSession = Session::lookupSession( msg, true );
if( m_pSession &&
Session::isSessionRegistered(m_pSession->getSessionID()) )
m_pSession = 0;
if( m_pSession )
m_pSession = a.getSession( msg, *this );
if( m_pSession )
m_pSession->next( msg );
if( !m_pSession )
{
s.getMonitor().drop( m_socket );
return false;
}
Session::registerSession( m_pSession->getSessionID() );
}
readMessages( s.getMonitor() );
return true;
}
catch ( SocketRecvFailed& e )
{
if( m_pSession )
m_pSession->getLog()->onEvent( e.what() );
s.getMonitor().drop( m_socket );
}
catch ( InvalidMessage& )
{
s.getMonitor().drop( m_socket );
}
return false;
QF_STACK_POP
}
----- Original Message -----
From: "Sean Kirkpatrick" <Sea...@Pi...>
To: <qui...@li...>
Sent: Monday, June 27, 2005 10:34 AM
Subject: [Quickfix-developers] SocketConnection session registration BUG
QuickFIX Documentation:
http://www.quickfixengine.org/quickfix/doc/html/index.html
QuickFIX FAQ: http://www.quickfixengine.org/wikifix/index.php?QuickFixFAQ
QuickFIX Support: http://www.quickfixengine.org/services.html
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):
if ( m_pSession ) {
LOGDEBUG(funcname,"registering session
[%s]",m_pSession->getSessionID().toString().c_str());
m_pSession = Session::registerSession( m_pSession->getSessionID() );
}
if ( m_pSession ) {
LOGDEBUG(funcname,"getting SocketAcceptor session [%s]",msg.c_str());
m_pSession = a.getSession( msg, *this );
}
needs to be reversed to be:
if ( m_pSession ) {
LOGDEBUG(funcname,"getting SocketAcceptor session [%s]",msg.c_str());
m_pSession = a.getSession( msg, *this );
}
if ( m_pSession ) {
LOGDEBUG(funcname,"registering session
[%s]",m_pSession->getSessionID().toString().c_str());
m_pSession = Session::registerSession( m_pSession->getSessionID() );
}
|
|
From: VP M. IT A. E. T. <ass...@gm...> - 2005-06-28 20:43:55
|
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 > |
