Search code examples
pythonquickfixfix-protocol

Using python's quickfix, after multiple heartbeats suddenly the receiver doesn't see mine anymore?


I am using the Python quickfix package which connects to a vendor. We send thirty-second heartbeats and have no issues for 10+ heartbeats. Then, randomly the vendor doesn't see my heartbeat that I send, I don't receive any responses they send, and then they forcefully log me out of the session.

Neither of us know what is causing this. Our sequence numbers are in sync as well, as shown by the prior successful heartbeats. Here is a sample of the FIX messages being sent between us. They stop seeing my heartbeats when I send my last one with sequence number 34 = 13.

Does anyone know what might be the issue here? Unfortuantely, their support has no additional information to provide other than they don't receive anything after my message with sequence number 34 = 12.

2017-09-08 13:31:55,312 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=67|35=5|34=23|49=XXXX|52=20170908-17:31:55.285|56=****|141=N|10=115|

2017-09-08 13:31:55,433 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=78|35=A|34=1|49=XXXX |52=20170908-17:31:55.403|56=**** |141=N|98=0|108=30|10=094|

2017-09-08 13:31:55,717 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=77|35=A|34=1|43=N|49=****|52=20170908-17:31:58.106|56=XXXX|98=0|108=30|10=049|

2017-09-08 13:31:55,789 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=89|35=1|34=2|43=N|49=****|52=20170908-17:31:58.175|56=XXXX|112=08/09/2017-13:31:58|10=179|

2017-09-08 13:31:55,815 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=90|35=0|34=2|49=XXXX|52=20170908-17:31:55.801|56=****|141=N|112=08/09/2017-13:31:58|10=210|

2017-09-08 13:32:25,401 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=3|49=XXXX|52=20170908-17:32:25.386|56=****|141=N|10=059|

2017-09-08 13:32:26,000 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=65|35=0|34=3|43=N|49=****|52=20170908-17:32:28.387|56=XXXX|10=015|

2017-09-08 13:32:55,420 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=4|49=XXXX|52=20170908-17:32:55.406|56=****|141=N|10=056|

2017-09-08 13:33:01,443 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=75|35=1|34=5|49=XXXX|52=20170908-17:33:01.429|56=****|141=N|112=TEST|10=073|

2017-09-08 13:33:05,502 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=65|35=0|34=4|43=N|49=****|52=20170908-17:32:58.496|56=XXXX|10=020|

2017-09-08 13:33:05,713 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=89|35=1|34=5|43=N|49=****|52=20170908-17:33:07.942|56=XXXX|112=08/09/2017-13:33:07|10=176|

2017-09-08 13:33:05,739 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=90|35=0|34=6|49=XXXX|52=20170908-17:33:05.722|56=****|141=N|112=08/09/2017-13:33:07|10=209|

2017-09-08 13:33:07,400 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=74|35=0|34=6|43=N|49=****|52=20170908-17:33:09.791|56=XXXX|112=TEST|10=035|

2017-09-08 13:33:35,470 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=7|49=XXXX|52=20170908-17:33:35.449|56=****|141=N|10=065|

2017-09-08 13:33:37,575 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=65|35=0|34=7|43=N|49=****|52=20170908-17:33:39.967|56=XXXX|10=026|

2017-09-08 13:34:05,490 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=8|49=XXXX|52=20170908-17:34:05.475|56=****|141=N|10=063|

2017-09-08 13:34:07,661 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=65|35=0|34=8|43=N|49=****|52=20170908-17:34:10.057|56=XXXX|10=007|

2017-09-08 13:34:35,513 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=9|49=XXXX|52=20170908-17:34:35.497|56=****|141=N|10=071|

2017-09-08 13:34:37,924 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=65|35=0|34=9|43=N|49=****|52=20170908-17:34:40.320|56=XXXX|10=004|

2017-09-08 13:35:05,532 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=67|35=0|34=10|49=XXXX|52=20170908-17:35:05.520|56=****|141=N|10=097|

2017-09-08 13:35:08,276 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=10|43=N|49=****|52=20170908-17:35:10.579|56=XXXX|10=059|

2017-09-08 13:35:35,555 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=67|35=0|34=11|49=XXXX|52=20170908-17:35:35.537|56=****|141=N|10=109|

2017-09-08 13:35:38,571 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=11|43=N|49=****|52=20170908-17:35:40.967|56=XXXX|10=064|

2017-09-08 13:36:05,573 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=67|35=0|34=12|49=XXXX|52=20170908-17:36:05.560|56=****|141=N|10=104|

2017-09-08 13:36:10,144 - fix_connection.FIX_IO - INFO - fromAdmin >>>>:
8=FIX.4.2|9=66|35=0|34=12|43=N|49=****|52=20170908-17:36:11.256|56=XXXX|10=055|

2017-09-08 13:36:35,594 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=67|35=0|34=13|49=XXXX|52=20170908-17:36:35.580|56=****|141=N|10=110|

2017-09-08 13:36:46,611 - fix_connection.FIX_IO - INFO - toAdmin >>>>:
8=FIX.4.2|9=76|35=1|34=14|49=XXXX|52=20170908-17:36:46.598|56=****|141=N|112=TEST|10=141|

2017-09-08 13:36:54,493 - fix_connection.FIX_IO - INFO - 

*** Force Logout ****

My config file is as follows:

[DEFAULT]
ConnectionType=initiator
ReconnectInterval=60
FileStorePath=store
FileLogPath=log
StartTime=07:00:00
EndTime=19:00:00
UseDataDictionary=Y
DataDictionary=spec/FIX42.xml
HttpAcceptPort=9911
ValidateUserDefinedFields=N
ResetOnLogout=N
ResetOnLogon=Y

# standard config elements

[SESSION]
# inherit ConnectionType, ReconnectInterval and SenderCompID from default
BeginString=FIX.4.2
SenderCompID=XXXX
TargetCompID=****
SocketConnectHost=11.111.111.1
SocketConnectPort=11111
HeartBtInt=30

Solution

  • The difference between the timestamp and the 52 (text) field in the messages you are sending out are something like 5 milliseconds. The differences between those fields in the messages you are receiving are MUCH larger, between 1-3 seconds. It looks to me like your clocks are getting out of sync. This has happened to me before, with the same effect that you are describing. It can occur when messages pile up on your end. Is the CPU swamped for resources, or are you sharing a port with something else that has a lot of I/O? You could try switching the port you are on, to something that is definitely unused, and starting QuickFix in its own process.