小贝子编程

QuickFIX/J - 接收多个安全定义时，远程主机强制关闭连接



我正在使用quickfixj处理来自ICE交换的安全定义。当我为证券低于 1000/1200 的市场执行此操作时，我通过多条消息(每个请求 100 个证券(35=d((获得它，没有任何问题。 但是，当它比 14 条消息后有更多的安全性时，我的会话会断开连接并出现以下错误：

"套接字异常：java.io.IOException：远程主机强行关闭了现有连接">

我仍然可以在日志中看到消息 15，但它没有来自 App 方法。

我知道，如果fromAPP方法中发生过多的处理，有时会发生此类问题。我检查了fromApp方法，我只是将消息放入由另一个线程处理的队列中，我没有在该方法中执行任何操作。 为了解决此错误，我已经从fromApp方法中删除了任何逻辑，现在我只是打印到目前为止收到的消息数量。即使这样，我的会话在 14 条消息后也会断开连接。(而应该有 50 多条消息来了。

@Override
public void fromApp(quickfix.Message message, SessionID sessionID)
throws FieldNotFound, IncorrectDataFormat, IncorrectTagValue, UnsupportedMessageType {
try {
counter++;
System.out.println("Inside from App, message : " +counter);
} catch (Exception e) {
System.out.println("Failed to process the underlying. Error message: " + e.getMessage());
}
}

我也检查了配置文件。我已经玩过它，看看是否有任何验证是否会导致它但没有运气。 这是我正在使用的配置文件：

[default]
FileStorePath=C:Test
BeginString=FIX.4.4
ConnectionType=initiator
[session]
SenderCompID=XXXX
SenderSubID=X
SenderLocationID=X  
TargetCompID=ICE
SocketConnectHost=XX.XXX.XXX.XXX
SocketConnectPort=80
StartTime=00:00:00
EndTime=23:59:59
HeartBtInt=60
ReconnectInterval=5
UseDataDictionary=Y
ResetOnLogon=Y
ForceResync=Y 
CheckLatency=N

我希望收到所有 50 条消息，而不是 14 条消息，然后是我现在收到的会话断开连接错误。关于为什么会发生此问题以及如何解决此问题的任何帮助/想法将不胜感激。 谢谢。

注释中提到的日志(证券总数 19293，预期消息计数 (35=d( - 1 个安全定义请求的 193。收到 -13，之后会话断开：

{Inside Logon
2019-09-08 12:43:46 INFO  DefaultSessionSchedule:87 - [FIX.4.4:xxxx/x/x->ICE] daily, 00:00:00-UTC - 23:59:59-UTC
<20190908-10:43:46, FIX.4.4:xxxx/x/x->ICE, event> (Session FIX.4.4:xxxx/x/x->ICE schedule is daily, 00:00:00-UTC - 23:59:59-UTC)
<20190908-10:43:46, FIX.4.4:xxxx/x/x->ICE, event> (Created session: FIX.4.4:xxxx/x/x->ICE)
inside oncreate
<20190908-10:43:46, FIX.4.4:xxxx/x/x->ICE, event> (Configured socket addresses for session: [/63.247.113.249:80])
2019-09-08 12:43:46 INFO  ThreadedSocketInitiator:321 - SessionTimer started
<20190908-10:43:46, FIX.4.4:xxxx/x/x->ICE, event> (MINA session created: local=/10.72.59.226:54361, class org.apache.mina.transport.socket.nio.NioSocketSession, remote=/63.247.113.249:80)
<20190908-10:43:47, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=108 35=A 34=1 49=xxxx 50=1 52=20190908-10:43:47.860 56=ICE 142=0 553=xxxxxxxx 554=xxxxxxx 98=0 108=30 141=Y 10=098 )
<20190908-10:43:47, FIX.4.4:xxxx/x/x->ICE, event> (Initiated logon request)
2019-09-08 12:43:48 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:43:48, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=73 35=A 49=ICE 34=1 52=20190908-10:43:47.519 56=xxxx 57=1 98=0 108=30 141=Y 10=189 )
<20190908-10:43:48, FIX.4.4:xxxx/x/x->ICE, event> (Logon contains ResetSeqNumFlag=Y, resetting sequence numbers to 1)
<20190908-10:43:48, FIX.4.4:xxxx/x/x->ICE, event> (Received logon)
2019-09-08 12:44:18 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:44:18, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=55 35=0 49=ICE 34=2 52=20190908-10:44:17.563 56=xxxx 57=1 10=100 )
<20190908-10:44:18, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=61 35=0 34=3 49=xxxx 50=1 52=20190908-10:44:18.844 56=ICE 142=0 10=099 )
2019-09-08 12:44:18 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:44:18, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=64 35=2 49=ICE 34=3 52=20190908-10:44:18.459 56=xxxx 57=1 7=2 16=2 10=234 )
<20190908-10:44:18, FIX.4.4:xxxx/x/x->ICE, event> (Received ResendRequest FROM: 2 TO: 2)
inside toApp
<20190908-10:44:18, FIX.4.4:xxxx/x/x->ICE, event> (Resending message: 2)
<20190908-10:44:18, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=134 35=c 34=2 43=Y 49=xxxx 50=1 52=20190908-10:44:18.963 56=ICE 122=20190908-10:43:48.598 142=0 48=2 320=1567939428584_0 321=3 461=FXXXXX 10=178 )
2019-09-08 12:44:19 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:44:19, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=61 35=1 49=ICE 34=4 52=20190908-10:44:18.564 56=xxxx 57=1 112=1 10=105 )
<20190908-10:44:19, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=67 35=0 34=4 49=xxxx 50=1 52=20190908-10:44:19.064 56=ICE 142=0 112=1 10=104 )
2019-09-08 12:44:19 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:44:19, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=73 35=1 49=ICE 34=5 52=20190908-10:44:18.578 56=xxxx 57=1 112=1567939458579 10=255 )
<20190908-10:44:19, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=79 35=0 34=5 49=xxxx 50=1 52=20190908-10:44:19.078 56=ICE 142=0 112=1567939458579 10=254 )
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:44:20, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=67593 35=d 49=ICE 34=6 52=20190908-10:44:19.844 56=xxxx 57=1 322=7250 323=4 320=1567939428584_0 393=19238 82=193 67=1 9064=0 711=100 311=5832793 ..
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  1:
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:44:20, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=60808 35=d 49=ICE 34=7 52=20190908-10:44:19.844 56=xxxx 57=1 322=7251 323=4 320=1567939428584_0 393=19238 82=193 67=2 9064=0 711=100 311=5832754 ...
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  2:
<20190908-10:44:20, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=56951 35=d 49=ICE 34=8 52=20190908-10:44:19.844 56=xxxx 57=1 322=7252 323=4 320=1567939428584_0 393=19238 82=193 67=3 9064=0 711=100 311=5964169 ...
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  3:
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
2019-09-08 12:44:20 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
<20190908-10:44:20, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=60133 35=d 49=ICE 34=9 52=20190908-10:44:20.070 56=xxxx 57=1 322=7253 323=4 320=1567939428584_0 393=19238 82=193 67=4 9064=0 711=100 311=5931984 ...
2019-09-08 12:44:25 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  4:
<20190908-10:44:25, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=59412 35=d 49=ICE 34=10 52=20190908-10:44:20.184 56=xxxx 57=1 322=7254 323=4 320=1567939428584_0 393=19238 82=193 67=5 9064=0 711=100 311=5932131 ...
2019-09-08 12:44:25 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  5:
<20190908-10:44:25, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=58564 35=d 49=ICE 34=11 52=20190908-10:44:20.184 56=xxxx 57=1 322=7255 323=4 320=1567939428584_0 393=19238 82=193 67=6 9064=0 711=100 311=6063274 ..
2019-09-08 12:44:25 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  6:
<20190908-10:44:25, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=58085 35=d 49=ICE 34=12 52=20190908-10:44:20.296 56=xxxx 57=1 322=7256 323=4 320=1567939428584_0 393=19238 82=193 67=7 9064=0 711=100 311=6063858 ...
2019-09-08 12:44:43 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  7:
<20190908-10:44:43, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=58654 35=d 49=ICE 34=13 52=20190908-10:44:20.296 56=xxxx 57=1 322=7257 323=4 320=1567939428584_0 393=19238 82=193 67=8 9064=0 711=100 311=5867472 ....
2019-09-08 12:44:43 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  8:
<20190908-10:44:43, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=59786 35=d 49=ICE 34=14 52=20190908-10:44:20.296 56=xxxx 57=1 322=7258 323=4 320=1567939428584_0 393=19238 82=193 67=9 9064=0 711=100 311=5867638 ..
2019-09-08 12:44:43 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  9:
<20190908-10:44:43, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=57341 35=d 49=ICE 34=15 52=20190908-10:44:20.296 56=xxxx 57=1 322=7259 323=4 320=1567939428584_0 393=19238 82=193 67=10 9064=0 711=100 311=5867886 3..
<20190908-10:45:17, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=61 35=0 34=6 49=xxxx 50=1 52=20190908-10:44:49.846 56=ICE 142=0 10=108 )
<20190908-10:45:17, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=57999 35=d 49=ICE 34=16 52=20190908-10:44:20.357 56=xxxx 57=1 322=7260 323=4 320=1567939428584_0 393=19238 82=193 67=11 9064=0 711=100 311=6097650 ..
security message no :  10:
2019-09-08 12:45:17 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  11:
<20190908-10:45:17, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=63224 35=d 49=ICE 34=17 52=20190908-10:44:20.357 56=xxxx 57=1 322=7261 323=4 320=1567939428584_0 393=19238 82=193 67=12 9064=0 711=100 311=5770217 ...
2019-09-08 12:45:17 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 1
security message no :  12:
<20190908-10:45:17, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=54954 35=d 49=ICE 34=18 52=20190908-10:44:20.357 56=xxxx 57=1 322=7262 323=4 320=1567939428584_0 393=19238 82=193 67=13 9064=0 711=100 311=5868773..
<20190908-10:45:53, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=61 35=0 34=7 49=xxxx 50=1 52=20190908-10:45:19.846 56=ICE 142=0 10=107 )
<20190908-10:45:53, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=61 35=0 34=8 49=xxxx 50=1 52=20190908-10:45:53.875 56=ICE 142=0 10=108 )
security message no :  13:
<20190908-10:45:53, FIX.4.4:xxxx/x/x->ICE, event> (Disconnecting: Encountered END_OF_STREAM)
inside onLogOut
java.io.IOException: An existing connection was forcibly closed by the remote host
at sun.nio.ch.SocketDispatcher.write0(Native Method)
at sun.nio.ch.SocketDispatcher.write(Unknown Source)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(Unknown Source)
at sun.nio.ch.IOUtil.write(Unknown Source)
at sun.nio.ch.SocketChannelImpl.write(Unknown Source)
at org.apache.mina.transport.socket.nio.NioProcessor.write(NioProcessor.java:384)
at org.apache.mina.transport.socket.nio.NioProcessor.write(NioProcessor.java:47)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.writeBuffer(AbstractPollingIoProcessor.java:1107)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.flushNow(AbstractPollingIoProcessor.java:994)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.flush(AbstractPollingIoProcessor.java:921)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:688)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2019-09-08 12:45:54 DEBUG AbstractIoService:338 - awaitTermination on (nio socket connector: managedSessionCount: 0) called by thread=[QFJ Timer]
2019-09-08 12:45:54 DEBUG AbstractIoService:340 - awaitTermination on (nio socket connector: managedSessionCount: 0) finished
<20190908-10:45:54, FIX.4.4:xxxx/x/x->ICE, event> (MINA session created: local=/10.72.59.226:54391, class org.apache.mina.transport.socket.nio.NioSocketSession, remote=/63.247.113.249:80)
inside add credetials
<20190908-10:45:55, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=108 35=A 34=1 49=xxxx 50=1 52=20190908-10:45:55.850 56=ICE 142=0 553=xxxxxxxx 554=xxxxxxx 98=0 108=30 141=Y 10=098 )
<20190908-10:45:55, FIX.4.4:xxxx/x/x->ICE, event> (Initiated logon request)
2019-09-08 12:45:55 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 2
<20190908-10:45:55, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=73 35=A 49=ICE 34=1 52=20190908-10:45:55.495 56=xxxx 57=1 98=0 108=30 141=Y 10=193 )
<20190908-10:45:55, FIX.4.4:xxxx/x/x->ICE, event> (Logon contains ResetSeqNumFlag=Y, resetting sequence numbers to 1)
<20190908-10:45:55, FIX.4.4:xxxx/x/x->ICE, event> (Received logon)
<20190908-10:46:25, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=61 35=0 34=2 49=xxxx 50=1 52=20190908-10:46:25.848 56=ICE 142=0 10=102 )
2019-09-08 12:46:26 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 2
<20190908-10:46:26, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=55 35=0 49=ICE 34=2 52=20190908-10:46:25.684 56=xxxx 57=1 10=105 )
<20190908-10:46:55, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=61 35=0 34=3 49=xxxx 50=1 52=20190908-10:46:55.848 56=ICE 142=0 10=106 )
2019-09-08 12:46:56 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 2
<20190908-10:46:56, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=55 35=0 49=ICE 34=3 52=20190908-10:46:55.689 56=xxxx 57=1 10=114 )
<20190908-10:47:25, FIX.4.4:xxxx/x/x->ICE, outgoing> (8=FIX.4.4 9=61 35=0 34=4 49=xxxx 50=1 52=20190908-10:47:25.848 56=ICE 142=0 10=105 )
2019-09-08 12:47:26 DEBUG ProtocolCodecFilter:233 - Processing a MESSAGE_RECEIVED for session 2
<20190908-10:47:26, FIX.4.4:xxxx/x/x->ICE, incoming> (8=FIX.4.4 9=55 35=0 49=ICE 34=4 52=20190908-10:47:25.692 56=xxxx 57=1 10=107 )

我想连接断开的问题是因为您没有及时处理消息。ICE可能正在等待你发送得太晚的心跳(如果你问，他们可能会告诉你(，并因此而断开连接。不幸的是，我不能只从日志中看出为什么它这么慢。

但是缓慢是在传入带有 seqnum 9 的消息之后开始的。您可以看到，到目前为止，日志时间戳和消息的 52/发送时间几乎匹配。

传入消息 10 已有 5 秒延迟。

使用 seqnum 6 发送的检测信号有 28 秒的延迟。

传入消息 16 几乎晚了一分钟。

起初我怀疑您连接的"客户端"。但这不会减慢你传出的心跳。

可能是您的应用程序配置的堆空间太少，因此正在执行大量垃圾回收。记录和处理 60kB 的 FIX 消息可能并不常见。或者由于某种原因，QFJ确实需要很长时间来处理如此大的消息。一系列堆栈跟踪或探查器将有助于进一步诊断此问题。

我会分别尝试两件事：

  1. 完全禁用日志记录，即将级别设置为 WARN 或 ERROR，以便防止记录长消息，如果问题仍然存在，请重新测试。
  2. 增加应用程序的堆内存，如果问题仍然存在，请重新测试。

相关内容

最新更新


热门标签：

javascript python java c# php android html jquery c++ css ios sql mysql arrays asp.net json python-3.x ruby-on-rails .net sql-server django objective-c excel regex ruby linux ajax iphone xml vba spring asp.net-mvc database wordpress string postgresql wpf windows xcode bash git oracle list vb.net multithreading eclipse algorithm macos powershell visual-studio image forms numpy scala function api selenium