Uploaded image for project: 'QuickFIX/J'
  1. QuickFIX/J
  2. QFJ-673

QFJ sequence problem following inbound SequenceReset - a previously received ResendRequest not "queued"?

    Details

      Description

      Sequence of events - from the perspective of an Acceptor:

      0. Acceptor is restarted with inbound sequence number reset to 0 - all missed messages were session messages.
      1. Incoming Logon@sequence=6; responded with Logon response.
      2. Outgoing ResendRequest for sequence gap 1-5.
      3. Incoming ResendRequest@sequence=7 for sequence range 1005 to infinity.
      4. Incoming SequenceReset from 1 to 6 – i.e. gap 1-5 now filled. "Processing queued message: 6".
      5. Outgoing SequenceReset - requested gap starting 1005 filled.
      6. Incoming Heartbeat@sequence=8. --> At this point Acceptor complains "MsgSeqNum too high, expecting 7 but received 9". WRONG!
      7. Acceptor claims that "Already sent ResendRequest FROM: 1 TO: 5. Not sending another." --> and hence all subsequent inbound messages are considered out of sequence. PROBLEM!

      This problem seems to be due to that QFJ failed to "queue" the received ResendRequest at step 3 above, and hence treated sequence 7 as never received.

      Log excerpt below:
      --------------------------------------------------------------
      2012-03-29 18:56:43,999 INFO [SocketAcceptorIoProcessor-0.0] AbstractIoHandler.messageReceived(AbstractIoHandler.java:106): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=6535=A34=649=TRS52=20120329-22:56:43.62056=TRS_OUT98=0108=3010=078
      2012-03-29 18:56:44,037 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] Session.send(Session.java:2217): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=6835=A34=100649=TRS_OUT52=20120329-22:56:44.03756=TRS98=0108=3010=229
      2012-03-29 18:56:44,047 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] Session.send(Session.java:2217): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=6535=234=100749=TRS_OUT52=20120329-22:56:44.04656=TRS7=116=510=059
      2012-03-29 18:56:44,047 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] ?.?(?:?): FIX.4.2:TRS_OUT->TRS: Sent ResendRequest FROM: 1 TO: 5
      2012-03-29 18:56:44,050 INFO [SocketAcceptorIoProcessor-0.0] AbstractIoHandler.messageReceived(AbstractIoHandler.java:106): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=6535=234=749=TRS52=20120329-22:56:44.04956=TRS_OUT7=100516=010=061
      2012-03-29 18:56:44,052 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] ?.?(?:?): FIX.4.2:TRS_OUT->TRS: Received ResendRequest FROM: 1005 TO: infinity
      2012-03-29 18:56:44,054 INFO [SocketAcceptorIoProcessor-0.0] AbstractIoHandler.messageReceived(AbstractIoHandler.java:106): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=9135=434=143=Y49=TRS52=20120329-22:56:44.05256=TRS_OUT122=20120329-22:56:4436=6123=Y10=104
      2012-03-29 18:56:44,055 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] Session.send(Session.java:2217): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=9735=434=100543=Y49=TRS_OUT52=20120329-22:56:44.05456=TRS122=20120329-22:56:4436=1008123=Y10=152
      2012-03-29 18:56:44,055 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] ?.?(?:?): FIX.4.2:TRS_OUT->TRS: Sent SequenceReset TO: 1008
      2012-03-29 18:56:44,056 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] ?.?(?:?): FIX.4.2:TRS_OUT->TRS: Received SequenceReset FROM: 1 TO: 6
      2012-03-29 18:56:44,056 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] ?.?(?:?): FIX.4.2:TRS_OUT->TRS: Processing queued message: 6
      2012-03-29 18:57:14,623 INFO [SocketAcceptorIoProcessor-0.0] AbstractIoHandler.messageReceived(AbstractIoHandler.java:106): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=5335=034=849=TRS52=20120329-22:57:14.62156=TRS_OUT10=035
      2012-03-29 18:57:14,626 ERROR [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] SLF4JLog.logError(SLF4JLog.java:133): FIX.4.2:TRS_OUT->TRS: MsgSeqNum too high, expecting 7 but received 8
      2012-03-29 18:57:14,626 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] ?.?(?:?): FIX.4.2:TRS_OUT->TRS: Already sent ResendRequest FROM: 1 TO: 5. Not sending another.
      2012-03-29 18:57:14,627 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] Session.send(Session.java:2217): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=5635=034=100849=TRS_OUT52=20120329-22:57:14.62756=TRS10=189
      2012-03-29 18:57:45,623 INFO [SocketAcceptorIoProcessor-0.0] AbstractIoHandler.messageReceived(AbstractIoHandler.java:106): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=5335=034=949=TRS52=20120329-22:57:45.62156=TRS_OUT10=040
      2012-03-29 18:57:45,625 ERROR [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] SLF4JLog.logError(SLF4JLog.java:133): FIX.4.2:TRS_OUT->TRS: MsgSeqNum too high, expecting 7 but received 9
      2012-03-29 18:57:45,625 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] ?.?(?:?): FIX.4.2:TRS_OUT->TRS: Already sent ResendRequest FROM: 1 TO: 5. Not sending another.
      2012-03-29 18:57:45,626 INFO [QF/J Session dispatcher: FIX.4.2:TRS_OUT->TRS] Session.send(Session.java:2217): FIX.4.2:TRS_OUT->TRS: 8=FIX.4.29=5635=034=100949=TRS_OUT52=20120329-22:57:45.62656=TRS10=193
      -------------------------------------------------------------------

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                chrjohn Christoph John
                Reporter:
                john_x_peng@hotmail.com John Peng
              • Votes:
                2 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: