发生“发送测试请求测试”后Quickfix / j的奇怪行为

我正在使用Quickfix / J接收消息,但发生了“已发送测试请求测试”。 日志文件(FIX.4.2-AB.event.log)显示:

23:19:05: Sent test request TEST 23:19:32: Disconnecting: Timed out waiting for heartbeat 23:19:33: Initiated logon request 23:19:44: Disconnecting: Timed out waiting for logon response 23:19:45: Initiated logon request 23:19:56: Disconnecting: Timed out waiting for logon response ... 

但我在另一个日志文件(FIX.4.2-AB.message.log)中找到了一些东西:

 8=FIX.4.2|9=68|35=1|34=250|49=A|52=20140224-23:19:05.909|56=B|112=TEST|10=106 8=FIX.4.2|9=74|35=0|49=B|56=A|43=N|34=1320|52=20140224-23:19:23.381|112=TEST|10=130 

这显然表明对方B已经将心跳发回给我们。

并且FIX.4.2-AB.messages.log文件仍在增长!!!!!!!!!!! 该文件保持接收消息,但Quickfix / J进程无(onMessage()方法中没有任何反应)!!!!

请帮忙告诉我为什么会这样? 收到心跳后,为什么连接仍然丢失并且日志正在断开连接?


由于这个问题尚未解决。 这是更新:

我的配置:

 [default] FileStorePath=/target/data/fixapplication ConnectionType=initiator SenderCompID=A TargetCompID=B SocketConnectHost=xxx.xxx.xxx.xx StartTime=00:00:00 EndTime=00:00:00 HeartBtInt=30 ReconnectInterval=5 FileLogPath=logs/fix/ [session] BeginString=FIX.4.2 SocketConnectPort=xxx ValidateFieldsOutOfOrder=N ResetOnLogon=Y 

这是代码:

 @Override public void fromAdmin(Message message, SessionID sessionID) throws FieldNotFound, IncorrectDataFormat, IncorrectTagValue, RejectLogon { if (adminLog.isInfoEnabled()) adminLog.info("Inside fromAdmin(): " + message.getHeader().getString(MsgType.FIELD) + " ; " + message); } @Override public void fromApp(Message message, SessionID sessionID) throws FieldNotFound, IncorrectDataFormat, IncorrectTagValue, UnsupportedMessageType { crack(message, sessionID); } @Override public void onCreate(SessionID arg0) { } @Override public void onLogon(SessionID session) { if (adminLog.isInfoEnabled()) { adminLog.info("Inside onLogon: Logon completed " + session.toString()); } } @Override public void onLogout(SessionID sessionId) { if (adminLog.isInfoEnabled()) { adminLog.info("Inside onLogout: Logout completed " + sessionId.toString()); } } 

基本上我让Quickfix/J来处理连接本身。

问题是应用程序仍然保持接收消息但不处理它们,并且日志文件显示它没有连接。 所有消息都在FIX.4.2-AB.message.log中,这就是它继续增长的原因。

我发现了一些类似的案例:

http://www.quickfixj.org/jira/browse/QFJ-668

http://www.quickfixj.org/jira/browse/QFJ-624

http://quickfix-j.364392.n2.nabble.com/Timed-out-waiting-for-heartbeat-td365186.html

http://www.quickfixj.org/jira/browse/QFJ-759

不幸的是,它们都没有提供解 所以请帮帮我。


第二次更新如下:

我提取日志文件(我是A和对方是B):

 8=FIX.4.2|9=58|35=0|34=49|49=A|52=23:23:50.075|56=B|10=030| 8=FIX.4.2|9=58|35=0|34=50|49=A|52=23:24:20.074|56=B|10=019| **8=FIX.4.2|9=67|35=1|34=51|49=A|52=23:24:46.074|56=B|112=TEST|10=047|** **8=FIX.4.2|9=74|35=0|49=B|56=A|43=N|34=1103|52=23:24:59.060|112=TEST|10=125|** 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:25:14.076|56=B|98=0|108=30|141=Y|10=059| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:25:27.076|98=0|108=30|10=004| 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:25:27.077|112=03/03/2014-07:25:27|10=117| 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:25:26.076|56=B|98=0|108=30|141=Y|10=062| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:25:39.064|98=0|108=30|10=004| 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:25:39.065|112=03/03/2014-07:25:39|10=120| 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:25:38.076|56=B|98=0|108=30|141=Y|10=065| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:25:51.064|98=0|108=30|10=254| 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:25:51.065|112=03/03/2014-07:25:51|10=108| 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:25:50.076|56=B|98=0|108=30|141=Y|10=059| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:26:03.064|98=0|108=30|10=252| 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:26:03.065|112=03/03/2014-07:26:03|10=104| 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:26:02.076|56=B|98=0|108=30|141=Y|10=057| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:26:15.064|98=0|108=30|10=255| 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:26:15.065|112=03/03/2014-07:26:15|10=110| 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:26:14.076|56=B|98=0|108=30|141=Y|10=060| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:26:27.064|98=0|108=30|10=002| 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:26:27.065|112=03/03/2014-07:26:27|10=116| 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:26:26.076|56=B|98=0|108=30|141=Y|10=063| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:26:39.065|98=0|108=30|10=006| 

请注意,它会继续尝试再次登录会话但失败。

与此同时,我确信应用程序会继续接收来自对方的消息。 证据是FIX.4.2-AB.message.log文件保持增长有效消息(不仅仅是心跳,而是其他有效消息)。 这意味着连接不会丢失。

为什么我不能登录会话?

请帮忙


第三次更新:

我发起登录的成功日志如下:

 8=FIX.4.2|9=75|35=A|34=1|49=A|52=23:00:07.095|56=B|98=0|108=30|141=Y|10=055| 8=FIX.4.2|9=74|35=A|49=B|56=A|43=N|34=1|52=23:00:20.221|98=0|108=30|10=238| 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:00:20.222|112=07:00:20|10=081| 8=FIX.4.2|9=81|35=0|34=2|49=A|52=23:00:07.301|56=B|112=07:00:20|10=091| 8=FIX.4.2|9=57|35=0|34=3|49=A|52=23:00:38.075|56=B|10=228| 8=FIX.4.2|9=63|35=0|49=B|56=A|43=N|34=26|52=23:00:51.260|10=00 

第三行表示对方向我发送了TEST请求,但我没有回复,这似乎没问题并建立了连接。

我应该明确处理TEST请求的响应吗? 似乎quickfix / j会为我处理。

FIX标准的心跳行为如下:

 1. On Logon, the Initiator requests a heartbeat interval (usual default 30 seconds) 2. From now on every side expects at least one message every 30 seconds (defined heartbeat interval) 3. If there is no application message available, a heartbeat is sent instead 4. If one side does not get neither a heartbeart nor an application message after 30 seconds, a connection issue is suspected. 5. Therefore, a TestRequest is sent ("Are you still there?"): Sent test request TEST 6. This TestRequest is not answered by a Heartbeat with the supplied TestRequestID, the connection is considered dead. 7. Finally, the network connection is dropped: Disconnecting: Timed out waiting for heartbeat 

在第三次更新中,您的启动器A确实通过心跳响应了测试请求,并提供了请求的id标记112:

 8=FIX.4.2|9=86|35=1|49=B|56=A|43=N|34=2|52=23:00:20.222|112=07:00:20|10=081| 8=FIX.4.2|9=81|35=0|34=2|49=A|52=23:00:07.301|56=B|112=07:00:20|10=091| 

这很好。 从那时起,A在30秒后提供心跳:

 8=FIX.4.2|9=57|35=0|34=3|49=A|52=23:00:38.075|56=B|10=228| 

但是B没有回复13秒:

 8=FIX.4.2|9=63|35=0|49=B|56=A|43=N|34=26|52=23:00:51.260|10=00 

A和B之间是否存在网络问题? 你遇到了什么问题?

您的分析通常是正常的,但这里仔细查看每条消息的时间:

 23:19:05: Sent test request TEST 23:19:05.909: Sent the 35=1 with 112=TEST 23:19:23.381: Received the 35=0 with 112=TEST 23:19:32: Disco timeout "waiting for heartbeat" 23:19:44: Disco timeout "waiting for logon response" 

如果你的网络中有一些奇怪的东西……

打电话给网络团队?

有些事情导致你的第一次脱节。 正如消息所说它正在等待心跳,可能不包括对测试请求的35 = 0响应。 它可能正在等待B = 35 = 1。

什么样的消息填满了FIX.4.2-AB.messages.log? 你能发一些例子吗?