Keep sending resend messages

[gutongjiang]

A resend message will be sent every few messages, requiring the message with the next sequence number to be resent

2023-09-18 16:57:18.223 [fromApp] 8=FIX.4.4^A9=215^A35=W^A34=381953^A49=Orange_Q^A52=20230918-08:57:18.221^A56=Test_Q^A55=CL^A262=CL^A268=2^A269=0^A270=90.05^A271=500^A276=A^A282=M_eju6034_201_plol^A299=309804788^A269=1^A270=90.1^A271=500^A276=A^A282=M_eju6034_201_plol^A299=309804791^A10=244^A 2023-09-18 16:57:18.226 [fromApp] 8=FIX.4.4^A9=204^A35=W^A34=381954^A49=Orange_Q^A52=20230918-08:57:18.225^A56=Test_Q^A55=GBPNZD^A262=GBPNZD^A268=2^A269=0^A270=2.09532^A271=100000^A276=A^A282=TFX^A299=310173508^A269=1^A270=2.09554^A271=100000^A276=A^A282=TFX^A299=310173513^A10=183^A 2023-09-18 16:57:18.261 [toAdmin] 8=FIX.4.4^A9=76^A35=2^A34=10633^A49=Test_Q^A52=20230918-08:57:18.261^A56=Orange_Q^A7=381955^A16=0^A10=226^A 2023-09-18 16:57:18.263 [fromApp] 8=FIX.4.4^A9=223^A35=W^A34=381955^A49=Orange_Q^A52=20230918-08:57:18.260^A56=Test_Q^A55=DOGEUSDT^A262=DOGEUSDT^A268=2^A269=0^A270=0.06174^A271=45741^A276=A^A282=USD_Futures^A299=310173518^A269=1^A270=0.06195^A271=373473^A276=A^A282=USD_Futures^A299=310173523^A10=115^A 2023-09-18 16:57:18.264 [fromApp] 8=FIX.4.4^A9=227^A35=W^A34=381956^A49=Orange_Q^A52=20230918-08:57:18.260^A56=Test_Q^A55=DOGEUSD.hb^A262=DOGEUSD.hb^A268=2^A269=0^A270=0.06174^A271=45741^A276=A^A282=USD_Futures^A299=310173518^A269=1^A270=0.06225^A271=373473^A276=A^A282=USD_Futures^A299=310173523^A10=186^A 2023-09-18 16:57:18.281 [fromApp] 8=FIX.4.4^A9=201^A35=W^A34=381957^A49=Orange_Q^A52=20230918-08:57:18.280^A56=Test_Q^A55=AUDJPY^A262=AUDJPY^A268=2^A269=0^A270=95.05^A271=100000^A276=A^A282=TFX^A299=310173528^A269=1^A270=95.056^A271=100000^A276=A^A282=TFX^A299=310173533^A10=058^A ..... 2023-09-18 16:57:18.792 [fromApp] 8=FIX.4.4^A9=204^A35=W^A34=382030^A49=Orange_Q^A52=20230918-08:57:18.791^A56=Test_Q^A55=AUDUSD^A262=AUDUSD^A268=2^A269=0^A270=0.64378^A271=100000^A276=A^A282=TFX^A299=310174138^A269=1^A270=0.64382^A271=100000^A276=A^A282=TFX^A299=310174143^A10=184^A 2023-09-18 16:57:18.793 [fromApp] 8=FIX.4.4^A9=204^A35=W^A34=382031^A49=Orange_Q^A52=20230918-08:57:18.792^A56=Test_Q^A55=EURJPY^A262=EURJPY^A268=2^A269=0^A270=157.439^A271=100000^A276=A^A282=TFX^A299=310174148^A269=1^A270=157.447^A271=200000^A276=A^A282=TFX^A299=310174153^A10=245^A 2023-09-18 16:57:18.796 [fromApp] 8=FIX.4.4^A9=203^A35=W^A34=382032^A49=Orange_Q^A52=20230918-08:57:18.794^A56=Test_Q^A55=GBPCHF^A262=GBPCHF^A268=2^A269=0^A270=1.1096^A271=100000^A276=A^A282=TFX^A299=310174158^A269=1^A270=1.10968^A271=100000^A276=A^A282=TFX^A299=310174163^A10=079^A 2023-09-18 16:57:18.798 [fromApp] 8=FIX.4.4^A9=203^A35=W^A34=382033^A49=Orange_Q^A52=20230918-08:57:18.797^A56=Test_Q^A55=GBPCAD^A262=GBPCAD^A268=2^A269=0^A270=1.67273^A271=100000^A276=A^A282=TFX^A299=310174168^A269=1^A270=1.67281^A271=76000^A276=A^A282=TFX^A299=310174173^A10=088^A 2023-09-18 16:57:18.804 [toAdmin] 8=FIX.4.4^A9=76^A35=2^A34=10635^A49=Test_Q^A52=20230918-08:57:18.804^A56=Orange_Q^A7=382034^A16=0^A10=220^A 2023-09-18 16:57:18.805 [fromApp] 8=FIX.4.4^A9=223^A35=W^A34=382034^A49=Orange_Q^A52=20230918-08:57:18.802^A56=Test_Q^A55=DOGEUSDT^A262=DOGEUSDT^A268=2^A269=0^A270=0.06174^A271=45902^A276=A^A282=USD_Futures^A299=310174178^A269=1^A270=0.06195^A271=374804^A276=A^A282=USD_Futures^A299=310174183^A10=110^A 2023-09-18 16:57:18.806 [fromApp] 8=FIX.4.4^A9=227^A35=W^A34=382035^A49=Orange_Q^A52=20230918-08:57:18.802^A56=Test_Q^A55=DOGEUSD.hb^A262=DOGEUSD.hb^A268=2^A269=0^A270=0.06174^A271=45902^A276=A^A282=USD_Futures^A299=310174178^A269=1^A270=0.06225^A271=374804^A276=A^A282=USD_Futures^A299=310174183^A10=181^A

CentOS Linux release 7.9.2009 quickfixj: 2.1.0

[chrjohn]

This looks strange. You are sending a ResendRequest for a message that you did not yet receive?! 381953 and 381954 come in and then a ResendRequest for 381955 is sent out? Afterwards 381955 comes in, but not as a response to the ResendRequest (neither 43=Y nor 122/OrigSendingTime is set).

Could you please post your session config? Moreover, what are you doing in your fromApp callback? Could you post the code? To me it seems that either these operations are blocking too long or are you maybe manipulating sequence numbers by yourself?

Thanks, Chris

[gutongjiang]

session config

[default]
ConnectionType=initiator
BeginString=FIX.4.4
SocketConnectHost=xx.xx.xx.xx
StartTime=00:00:00
EndTime=00:00:00
HeartBtInt=20
ReconnectInterval=5
RejectInvalidMessage=N
FileStorePath=client-store
FileStoreSync=Y
SocketUseSSL=Y
EnabledProtocols=TLSv1

[session]
SenderCompID=Test_Q
TargetCompID=Orange_Q
SocketConnectHost=xx.xx.xx.xx
SocketConnectPort=10000
ResetOnDisconnect=Y
ResetOnLogout=Y
ResetOnLogon=Y
FileLogPath=logs/quote
SLF4JLogEventCategory=${senderCompID}.events-
SLF4JLogIncomingMessageCategory=${senderCompID}.in-
SLF4JLogOutgoingMessageCategory=${senderCompID}.out-

fromApp callback

    @Override
    public void fromApp(Message message, SessionID sessionID) {
        log.info("[fromApp] {}", message);
        try {
            crack(message, sessionID);
        } catch (Exception e) {
            log.error(e.getMessage(), e);
        }
    }

[gutongjiang]

By the way, the code has been running stably for several months. Suddenly this problem occurs. Temporarily add the ValidateIncomingMessage=N configuration to avoid frequent sending.

[chrjohn]

A thing that sticks out is FileStoreSync=Y. Maybe that slows down noticeably. But even if, then I would not expect the problems with seqnums that you are seeing (i.e. sending ResendRequest for seqnum that has not been used yet).

And what are you doing in the crack() method? Why do you wrap it in try-catch? How do you handle messages anyway? Are you maybe pushing them to a separate queue and processing them async?

[gutongjiang]

crack() is the function of quickfixj. After receiving the MarketDataSnapshotFullRefresh message, it is pushed to the Kafka message queue. It is not asynchronous.

@chrjohn Thanks for your reply, I will try to handle the message asynchronously

[chrjohn]

You could override crack() in your MessageCracker, that's why I'm asking. Is there maybe some Exception in the log that you are catching in your fromApp() code that you posted above that could lead to the behaviour that you are seeing?

Where in your code are you pushing the message to Kafka? It is not in fromApp(), then where? When you push the message to the queue it is asynchronous to QFJ's processing from there on. But I am not supposing you are manipulating seqnums by yourself?