[Quickfix-developers] QFJ: Test message => Heartbeat response => Disconnect
Brought to you by:
orenmnero
|
From: Shepheard, T. (London) <Tob...@ml...> - 2006-02-02 19:13:00
|
I'm seeing some unexpected behaviour after sending a Test message and getting a Heartbeat response back. This is with the QFJ, taken from CVS head ~1 week ago. =20 Here's what I see in the logs at my end (XXX to replace 3rd party) [2006-02-02 18:34:19,445][INFO ] msg.incoming: FIX.4.4:ML_RTFI_DEV1->XXXXFIXTEST1: 8=3DFIX.4.4=019=3D121=0135=3DH=0134=3D1107=0149=3DXXXXFIXTEST1=0150=3DTob= y_Shepheard@MLRX=0152=3D2 0060202-18:34:19.336=0156=3DML_RTFI_DEV1=0111=3D5.1.152297=0154=3D1=0155=3D= [N/A]=0110=3D047 ...... protocol.XXXXXXXQFApplication: Sending FIX admin message (1)8=3DFIX.4.4=019=3D78=0135=3D1=0134=3D954=0149=3DML_RTFI_DEV1=0152=3D20= 060202-18:35:05.383=015 6=3DXXXXFIXTEST1=01112=3DTEST=0110=3D147=01 [2006-02-02 18:35:05,383][INFO ] msg.outgoing: FIX.4.4:ML_RTFI_DEV1->XXXXFIXTEST1: 8=3DFIX.4.4=019=3D78=0135=3D1=0134=3D954=0149=3DML_RTFI_DEV1=0152=3D20060= 202-18:35:05.383=0156=3DX XXXFIXTEST1=01112=3DTEST=0110=3D147=01 [2006-02-02 18:35:05,430][INFO ] quickfixj.event: FIX.4.4:ML_RTFI_DEV1->XXXXFIXTEST1: Sent test request TEST [2006-02-02 18:35:32,399][INFO ] quickfixj.event: FIX.4.4:ML_RTFI_DEV1->XXXXFIXTEST1: Timed out waiting for heartbeat [2006-02-02 18:35:32,399][INFO ] quickfixj.event: FIX.4.4:ML_RTFI_DEV1->XXXXFIXTEST1: Disconnecting =20 From the logs, no great shakes - we sent a Test request, got no response, timed out due to receiving no messages and disconnected. However..... a network snoop reveals the following: =20 =20 8=3DFIX.4.4.9=3D78.35=3D1.34=3D954.49=3DML_RTFI_DEV1.52=3D20060202-18:35:= 05.383.56=3DR EUTFIXTEST1.112=3DTEST.10=3D147. =3D>>>>> this is my Test message =20 8=3DFIX.4.4.9=3D79.35=3D0.34=3D1115.49=3DREUTFIXTEST1.52=3D20060202-18:35= :05.374.56=3D ML_RTFI_DEV1.112=3DTEST.10=3D185. <<<<<<=3D This is a heartbeat = message response =20 =20 The heartbeat message was received ~20ms after the Test message, but due to some slight difference in clock times, the Sending Time (52) makes it look like it came a fraction earlier. I'm not sure if this is perhaps part of the problem? There doesn't seem to be any sign of this heartbeat being received on my side, which leads me to believe there's something fishy here, but I'm not sure if its related to the TEST message or the SendingTime being prior to my SystemTime when I'm processing it, or something else altogether. =20 The time between the last recorded message I received (the resend request at the top, which I ignored) and the disconnect is ~73 seconds, matching the 2.4*heartbeat interval in the code. So everything points to he heartbeat message from the 3rd party, send almost immediately after the Test message request, being totally ignored.... any ideas why? =20 MTIA, Toby -------------------------------------------------------- If you are not an intended recipient of this e-mail, please notify the = sender, delete it and do not read, act upon, print, disclose, copy, = retain or redistribute it. Click here for important additional terms = relating to this e-mail. http://www.ml.com/email_terms/ -------------------------------------------------------- |