[QFJ-659] Sequence number issues when acceptor sends a message immediately following logon response Created: 09/Jan/12  Updated: 09/Jan/12

Status: Open
Project: QuickFIX/J
Component/s: Engine
Affects Version/s: 1.4.0, 1.5.2
Fix Version/s: None

Type: Bug Priority: Default
Reporter: Andrew Richards Assignee: Unassigned
Resolution: Unresolved Votes: 2
Labels: logon, sequnece


 Description   

I have an initiator connection to a foreign acceptor which has sequence number confusion on logon as the foreign acceptor sends a TestRequest immediately after the logon response.

It looks like the following is happening: Quickfix/J accepts both (Logon & TestRequest) messages. The and proceeds to check the sequence number of the Logon to make sure the session is valid. It does this via Session.isTargetTooHigh() which looks at the last message in the message store which is now 1 higher than is should be because the TestRequest has been received and stored. The "MsgSeqNum too high" is issued and the engine tries to recover. In some most circumstances, but not all it (with the engine in question) it can recover however it's not ideal.

The effect can be simulated (QuickFIX/J -> QuickFIX/J) by using and acceptor with the toAdmin below.

public void toAdmin(Message message, SessionID sessionID)
{
print("toAdmin", message, sessionID);

try {
Header header = message.getHeader();
if ( header.getField( new MsgType() ).valueEquals( MsgType.LOGON ) )

{ quickfix.fix44.TestRequest tst = new quickfix.fix44.TestRequest(new TestReqID("TEST")); Session.sendToTarget(tst, sessionID); }

}
catch (Exception e) {}
}

09-Jan-2012 08:49:19 INFO : Initialize
09-Jan-2012 08:49:50 INFO : FIX.4.4:CLIENT->SERVER: 8=FIX.4.49=5535=034=349=SERVER52=20120109-08:49:50.01356=CLIENT10=107
09-Jan-2012 08:49:50 SEVERE : FIX.4.4:CLIENT->SERVER: MsgSeqNum too high, expecting 2 but received 3: 8=FIX.4.49=5535=034=349=SERVER52=20120109-08:49:50.01356=CLIENT10=107
09-Jan-2012 08:49:50 INFO : FIX.4.4:CLIENT->SERVER: Enqueued at pos 3: 8=FIX.4.49=5535=034=349=SERVER52=20120109-08:49:50.01356=CLIENT10=107
09-Jan-2012 08:49:50 INFO : [toAdmin](FIX.4.4:CLIENT->SERVER)[2](MsgType:ResendRequest (2))
09-Jan-2012 08:49:50 INFO : FIX.4.4:CLIENT->SERVER: 8=FIX.4.49=6435=234=249=CLIENT52=20120109-08:49:50.01956=SERVER7=216=010=238
09-Jan-2012 08:49:50 INFO : FIX.4.4:CLIENT->SERVER: Sent ResendRequest FROM: 2 TO: 2
09-Jan-2012 08:49:50 INFO : FIX.4.4:CLIENT->SERVER: 8=FIX.4.49=9335=434=243=Y49=SERVER52=20120109-08:49:50.02556=CLIENT122=20120109-08:49:5036=4123=Y10=182
09-Jan-2012 08:49:50 INFO : FIX.4.4:CLIENT->SERVER: ResendRequest for messages FROM 2 TO 2 has been satisfied.
09-Jan-2012 08:49:50 INFO : [fromAdmin](FIX.4.4:CLIENT->SERVER)[2](MsgType:SequenceReset (4))
09-Jan-2012 08:49:50 INFO : FIX.4.4:CLIENT->SERVER: Received SequenceReset FROM: 2 TO: 4
09-Jan-2012 08:50:20 INFO : [toAdmin](FIX.4.4:CLIENT->SERVER)[3](MsgType:Heartbeat (0))
09-Jan-2012 08:50:20 INFO : FIX.4.4:CLIENT->SERVER: 8=FIX.4.49=5535=034=349=CLIENT52=20120109-08:50:20.21556=SERVER10=100
09-Jan-2012 08:50:20 INFO : FIX.4.4:CLIENT->SERVER: 8=FIX.4.49=5535=034=449=SERVER52=20120109-08:50:20.21856=CLIENT10=104
09-Jan-2012 08:50:20 INFO : [fromAdmin](FIX.4.4:CLIENT->SERVER)[4](MsgType:Heartbeat (0))


Generated at Sat Nov 23 07:35:11 UTC 2024 using JIRA 7.5.2#75007-sha1:9f5725bb824792b3230a5d8716f0c13e296a3cae.