Using QuickFIX/J 1.6.3
I'm getting this strange behavior on my QuickFIX/J Acceptor and I quite don't know why. My Acceptor is sending a TestRequest, expecting for a Heartbeat, the Initiator sends me a Heartbeat, but my acceptor is disconnecting anyways saying:
Timed out waiting for heartbeat
It gets all even more strange when the Initiator tries to logon and the Acceptor doesn't let it saying
Multiple logons/connections for this session are not allowed
You can see it in the event and the message logs below. Any help is much appreciated.
Also, my Acceptor has the config CheckLatency=N. I do this because the Initiator's SendingTime is slightly behind mine.
20170321-17:22:48: Session FIX.4.2:MY_COMP_ID->MY_CUSTOMER_COMP_ID schedule is weekly, SUN 00:00:00-UTC - SAT 23:00:00-UTC
20170321-17:22:48: Created session: FIX.4.2:MY_COMP_ID->MY_CUSTOMER_COMP_ID
20170321-17:25:31: Accepting session FIX.4.2:MY_COMP_ID->MY_CUSTOMER_COMP_ID from /x.x.x.x:yyyy
20170321-17:25:31: Acceptor heartbeat set to 60 seconds
20170321-17:25:31: Logon contains ResetSeqNumFlag=Y, resetting sequence numbers to 1
20170321-17:25:31: Received logon
20170321-17:25:31: Responding to Logon request
20170321-17:47:49: Sent test request TEST
20170321-17:48:43: Disconnecting: Timed out waiting for heartbeat
20170321-17:48:50: Accepting session FIX.4.2:MY_COMP_ID->MY_CUSTOMER_COMP_ID from /x.x.x.x:yyyy
20170321-17:48:50: Acceptor heartbeat set to 60 seconds
20170321-17:49:21: Multiple logons/connections for this session are not allowed
20170321-17:49:51: Multiple logons/connections for this session are not allowed
20170321-17:50:22: Multiple logons/connections for this session are not allowed
20170321-17:55:31: Multiple logons/connections for this session are not allowed
20170321-17:56:01: Multiple logons/connections for this session are not allowed
20170321-17:56:32: Multiple logons/connections for this session are not allowed
8=FIX.4.2 | 9=77 | 35=1 | 34=55 | 49=MY_COMP_ID | 52=20170321-17:47:49.041 | 56=MY_CUSTOMER_COMP_ID | 112=TEST | 10=120 |
8=FIX.4.2 | 9=78 | 35=0 | 34=229 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:47:34.838 | 56=MY_COMP_ID | 112=TEST | 10=179 |
8=FIX.4.2 | 9=85 | 35=A | 34=1 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:48:36.583 | 56=MY_COMP_ID | 98=0 | 108=60 | 141=Y | 10=141 |
8=FIX.4.2 | 9=85 | 35=A | 34=1 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:49:07.034 | 56=MY_COMP_ID | 98=0 | 108=60 | 141=Y | 10=131 |
8=FIX.4.2 | 9=85 | 35=A | 34=1 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:49:37.469 | 56=MY_COMP_ID | 98=0 | 108=60 | 141=Y | 10=146 |
8=FIX.4.2 | 9=85 | 35=A | 34=1 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:50:07.952 | 56=MY_COMP_ID | 98=0 | 108=60 | 141=Y | 10=132 |
8=FIX.4.2 | 9=85 | 35=A | 34=1 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:55:17.035 | 56=MY_COMP_ID | 98=0 | 108=60 | 141=Y | 10=130 |
8=FIX.4.2 | 9=85 | 35=A | 34=1 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:55:47.502 | 56=MY_COMP_ID | 98=0 | 108=60 | 141=Y | 10=132 |
8=FIX.4.2 | 9=85 | 35=A | 34=1 | 49=MY_CUSTOMER_COMP_ID | 52=20170321-17:56:17.985 | 56=MY_COMP_ID | 98=0 | 108=60 | 141=Y | 10=145 |
There seems to exist a QuickFIX/J bug where the Heartbeat timer and the check for logged on status is out of sync.
This solution is not ideal and is more of a workaround:
Set TestRequestDelayMultiplier=1 on the Acceptor's session.cfg. This will give the engine more leeway in time to check the logon status based on heartbeats.