{{Quickfixn}} Existing Connection Forcibly Closed

Thu Sep 17 12:40:23 PDT 2015

We have experienced a similar issue when doing load testing. We are sending
a large number of messages from an initiator to an acceptor. If the rate at
which we send messages exceeds the rate at which the acceptor can process
them (due to expensive OnMessage calls on the acceptor side), eventually
the initiator will forcibly close the connection. When it reconnects we see
the same thing: ResendRequest (allegedly successful) followed by a
SequenceReset, but the acceptor side ends up missing a large number of
messages in its logs, and a large number of messages never get processed by
OnMessage on the acceptor side.

On Thu, Sep 17, 2015 at 2:27 PM, Ian Clements <
ian.clements at investmentsoftwareltd.com> wrote:

> Thanks Mike, the messages I am missing are partial fills and fills and
> Bloomberg definitely sent them (Or tried to!).
>
> Below is a sample of my message log which I think covers what is
> happening.  The first 2 messages are the last 2 of hundreds of partial +
> full fills where everything was working fine.  Then there was a remote host
> disconnect socket error (Something on our network I think killing the
> connection) then we get the resend requests which I assumed would try and
> recover the missing messages and then the SequenceReset which is what I
> think is causing the messages to be lost.  The last two messages are a
> resumption of normal fills before it fails and repeats.
>
>
>
> Any insights would be great!
>
> 20150917-14:28:13.168 :
> 8=FIX.4.29=033535=849=ABCDEFG56=SOMECOMPID34=2145050=LSTM57=SOMESUBID52=20150917-14:29:0260=20150917-14:28:57150=F1=Jig531=10.5151=6032=1064=201509216=10.537=267618438=10039=140=111=211114=4015=GBP17=9172129948=GB000574635822=454=155=MCB
> LN58=BOT(MCB) 10 at 1050.00(GBp) for ORDER ID #
> 267618459=0453=1448=EFIX447=I452=110=000
>
> 20150917-14:28:13.187 :
> 8=FIX.4.29=033535=849=ABCDEFG56=SOMECOMPID34=2145150=LSTM57=SOMESUBID52=20150917-14:29:0260=20150917-14:28:57150=F1=Jig531=10.5151=6032=1064=201509216=10.537=267616538=10039=140=111=209214=4015=GBP17=9172130048=GB000574635822=454=155=MCB
> LN58=BOT(MCB) 10 at 1050.00(GBp) for ORDER ID #
> 267616559=0453=1448=EFIX447=I452=110=246
>
> 20150917-14:28:51.039 :
> 8=FIX.4.29=8535=A34=285049=SOMECOMPID50=SOMESUBID52=20150917-14:28:51.03956=ABCDEFG98=0108=3010=143
>
> 20150917-14:28:51.156 :
> 8=FIX.4.29=007135=A49=ABCDEFG56=SOMECOMPID34=2209952=20150917-14:30:0098=0108=3010=061
>
> 20150917-14:28:51.157 :
> 8=FIX.4.29=8635=234=285149=SOMECOMPID50=SOMESUBID52=20150917-14:28:51.15756=ABCDEFG7=2145216=010=178
>
> 20150917-14:28:51.160 :
> 8=FIX.4.29=008735=149=ABCDEFG56=SOMECOMPID34=2210052=20150917-14:30:00112=L.4FF3.5654.0B23.14300010=166
>
> 20150917-14:28:51.279 :
> 8=FIX.4.29=010135=449=ABCDEFG56=SOMECOMPID34=2145243=Y122=20150917-14:30:0052=20150917-14:30:00123=Y36=2210110=006
>
> 20150917-14:28:51.279 :
> 8=FIX.4.29=008735=149=ABCDEFG56=SOMECOMPID34=2210152=20150917-14:30:00112=R.4FF3.5655.0B24.14300010=175
>
> 20150917-14:28:51.279 :
> 8=FIX.4.29=10135=034=285249=SOMECOMPID50=SOMESUBID52=20150917-14:28:51.27956=ABCDEFG112=R.4FF3.5655.0B24.14300010=054
>
> 20150917-14:28:51.414 :
> 8=FIX.4.29=033535=849=ABCDEFG56=SOMECOMPID34=2210250=LSTM57=SOMESUBID52=20150917-14:30:0060=20150917-14:29:03150=F1=Jig331=10.5151=5032=1064=201509216=10.537=267580438=10039=140=111=173114=5015=GBP17=9172194848=GB000574635822=454=155=MCB
> LN58=BOT(MCB) 10 at 1050.00(GBp) for ORDER ID #
> 267580459=0453=1448=EFIX447=I452=110=235
>
> 20150917-14:28:51.554 :
> 8=FIX.4.29=033535=849=ABCDEFG56=SOMECOMPID34=2210350=LSTM57=SOMESUBID52=20150917-14:30:0060=20150917-14:29:03150=F1=Jig331=10.5151=5032=1064=201509216=10.537=267584038=10039=140=111=176714=5015=GBP17=9172194948=GB000574635822=454=155=MCB
> LN58=BOT(MCB) 10 at 1050.00(GBp) for ORDER ID #
> 267584059=0453=1448=EFIX447=I452=110=246
>
>
>
> *From:* Quickfixn [mailto:quickfixn-bounces at lists.quickfixn.com] *On
> Behalf Of *Mike Gatny
> *Sent:* 17 September 2015 19:01
>
> *To:* Mailing list for QuickFIX/n <quickfixn at lists.quickfixn.com>
> *Subject:* Re: {{Quickfixn}} Existing Connection Forcibly Closed
>
>
>
> Can you post your (possibly lightly sanitized) messages log? Also, note
> that admin-type messages (logon, heartbeat, test request) are skipped
> during a resend.
>
>
> --
>
> Mike Gatny
> Connamara Systems, LLC
>
>
>
> On Thu, Sep 17, 2015 at 1:31 PM, Ian Clements <
> ian.clements at investmentsoftwareltd.com> wrote:
>
> Further to the issue of the connection being forcibly closed I have found
> we are now missing a significant number of messages when we manage to
> reconnect as it seems we get sequence resets that skip over messages even
> though we request them which is really messes things up.  I have included
> our QuickFix engine log if anyone can shed some light on what has gone
> wrong it would be greatly appreciated.  The messages we lost were sent
> during the session disconnect I have included some missing sequence numbers
> below but we are missing over 100 in total.  Probably my ignorance of FIX
> but I had assumed we should have recovered these messages when we
> reconnected and it looks like it is attempting to do that.
>
>
>
> 20078
>
> 22080
>
> 23074
>
> 24079
>
> 26088
>
> 27065
>
>
>
>
>
> 20150917-14:20:48.575 : Created session
>
> 20150917-14:20:48.584 : Connecting to xxx.xxx.xxx.xx on port xxxxx
>
> 20150917-14:20:50.268 : Connection succeeded
>
> 20150917-14:20:50.294 : Initiated logon request
>
> 20150917-14:20:50.429 : Received logon
>
> 20150917-14:27:32.281 : Session FIX.4.2:xxxxxxxxxxxxxxxxxxxxxxxxxxx
> disconnecting: System.Net.Sockets.SocketException (0x80004005): An existing
> connection was forcibly closed by the remote host
>
>    at QuickFix.SocketInitiatorThread.ReadSome(Byte[] buffer, Int32
> timeoutMilliseconds)
>
>    at QuickFix.SocketInitiatorThread.Read()
>
> 20150917-14:27:49.004 : Connecting to xxx.xxx.xxx.xx on port xxxxx
>
> 20150917-14:27:50.597 : Connection succeeded
>
> 20150917-14:27:50.598 : Initiated logon request
>
> 20150917-14:27:50.671 : Received logon
>
> 20150917-14:27:50.671 : MsgSeqNum too high, expecting 19768 but received
> 20464
>
> 20150917-14:27:50.673 : Sent ResendRequest FROM: 19768 TO: 0
>
> 20150917-14:27:50.680 : Got resend request from 2846 to 0
>
> 20150917-14:27:50.683 : Sent SequenceReset TO: 2849
>
> 20150917-14:27:50.749 : ResendRequest for messages FROM: 19768 TO: 0 has
> been satisfied.
>
> 20150917-14:27:50.750 : Received SequenceReset FROM: 19768 TO: 20466
>
> 20150917-14:28:13.200 : Session
> FIX.4.2:xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx disconnecting:
> System.Net.Sockets.SocketException (0x80004005): An existing connection was
> forcibly closed by the remote host
>
>    at QuickFix.SocketInitiatorThread.ReadSome(Byte[] buffer, Int32
> timeoutMilliseconds)
>
>    at QuickFix.SocketInitiatorThread.Read()
>
> 20150917-14:28:49.073 : Connecting to xxx.xxx.xxx.xx on port xxxxx
>
> 20150917-14:28:51.039 : Connection succeeded
>
> 20150917-14:28:51.039 : Initiated logon request
>
> 20150917-14:28:51.157 : Received logon
>
> 20150917-14:28:51.157 : MsgSeqNum too high, expecting 21452 but received
> 22099
>
> 20150917-14:28:51.157 : Sent ResendRequest FROM: 21452 TO: 0
>
> 20150917-14:28:51.161 : MsgSeqNum too high, expecting 21452 but received
> 22100
>
> 20150917-14:28:51.161 : Already sent ResendRequest FROM: 21452 TO: 0.  Not
> sending another.
>
> 20150917-14:28:51.279 : ResendRequest for messages FROM: 21452 TO: 0 has
> been satisfied.
>
> 20150917-14:28:51.279 : Received SequenceReset FROM: 21452 TO: 22101
>
> 20150917-14:29:17.136 : Session FIX.4.2:xxxxxxxxxxxxxxxxxxxxxxxxxxxx
> disconnecting: System.Net.Sockets.SocketException (0x80004005): An existing
> connection was forcibly closed by the remote host
>
>    at QuickFix.SocketInitiatorThread.ReadSome(Byte[] buffer, Int32
> timeoutMilliseconds)
>
>    at QuickFix.SocketInitiatorThread.Read()
>
> 20150917-14:29:49.139 : Connecting to xxx.xxx.xxx.xx on port xxxxx
>
> 20150917-14:29:50.465 : Connection succeeded
>
> 20150917-14:29:50.465 : Initiated logon request
>
> 20150917-14:29:50.543 : Received logon
>
> 20150917-14:29:50.543 : MsgSeqNum too high, expecting 23055 but received
> 24855
>
> 20150917-14:29:50.543 : Sent ResendRequest FROM: 23055 TO: 0
>
> 20150917-14:29:50.551 : MsgSeqNum too high, expecting 23055 but received
> 24856
>
> 20150917-14:29:50.551 : Already sent ResendRequest FROM: 23055 TO: 0.  Not
> sending another.
>
> 20150917-14:29:50.617 : ResendRequest for messages FROM: 23055 TO: 0 has
> been satisfied.
>
> 20150917-14:29:50.617 : Received SequenceReset FROM: 23055 TO: 24857
>
> 20150917-14:30:15.978 : Session FIX.4.2:xxxxxxxxxxxxxxxxxxxxxxxxxxx
> disconnecting: System.Net.Sockets.SocketException (0x80004005): An existing
> connection was forcibly closed by the remote host
>
>    at QuickFix.SocketInitiatorThread.ReadSome(Byte[] buffer, Int32
> timeoutMilliseconds)
>
>    at QuickFix.SocketInitiatorThread.Read()
>
>
>
>
>
> *From:* Quickfixn [mailto:quickfixn-bounces at lists.quickfixn.com] *On
> Behalf Of *Ian Clements
> *Sent:* 17 September 2015 16:03
>
>
> *To:* Mailing list for QuickFIX/n <quickfixn at lists.quickfixn.com>
> *Subject:* Re: {{Quickfixn}} Existing Connection Forcibly Closed
>
>
>
> Running on my local development machine behind a firewall which connects
> via fibre to our DNS server which is off site in a data centre then out via
> another firewall (I think).
>
>
>
> Could it be a firewalls killing it thinking it’s hostile traffic?
>
>
>
> *From:* Quickfixn [mailto:quickfixn-bounces at lists.quickfixn.com
> <quickfixn-bounces at lists.quickfixn.com>] *On Behalf Of *Christopher
> Karpyszyn
> *Sent:* 17 September 2015 15:59
> *To:* Mailing list for QuickFIX/n <quickfixn at lists.quickfixn.com>
> *Subject:* Re: {{Quickfixn}} Existing Connection Forcibly Closed
>
>
>
> It could be a network issue. What kind of environment is the application
> running from?
>
>
>
> Chris
>
> *From:* Quickfixn [mailto:quickfixn-bounces at lists.quickfixn.com
> <quickfixn-bounces at lists.quickfixn.com>] *On Behalf Of *Ian Clements
> *Sent:* Thursday, September 17, 2015 10:49 AM
> *To:* Mailing list for QuickFIX/n <quickfixn at lists.quickfixn.com>
> *Subject:* Re: {{Quickfixn}} Existing Connection Forcibly Closed
>
>
>
> Thanks Grant.
>
>
>
> That’s kind of what I figured but they didn’t seem so impressed when I
> implied it might be them - they said we were connecting to the best
> hardware which loads of people were connecting to and it was our fault!
>
>
>
> *From:* Quickfixn [mailto:quickfixn-bounces at lists.quickfixn.com
> <quickfixn-bounces at lists.quickfixn.com>] *On Behalf Of *Grant Birchmeier
> *Sent:* 17 September 2015 15:44
> *To:* Mailing list for QuickFIX/n <quickfixn at lists.quickfixn.com>
> *Subject:* Re: {{Quickfixn}} Existing Connection Forcibly Closed
>
>
>
> "An existing connection was forcibly closed* by the remote host*"
>
> Basically, Bloomberg hung up on you.
>
> The only way to find out why is to ask them.
>
>
>
> I mean, check your logs first to see if something looks weird, but
> otherwise reach out to Bloomberg's support.
>
>
>
>
>
> On Thu, Sep 17, 2015 at 9:34 AM, Ian Clements <
> ian.clements at investmentsoftwareltd.com> wrote:
>
> Hi all,
>
>
>
> I have an established connection to a Bloomberg FIX acceptor over SSL.
> The problem is when I am doing fills for a large quantity of orders (1000
> in this case with 10 fills per order) I am getting the following exception…
>
>
>
> disconnecting: System.Net.Sockets.SocketException (0x80004005): An
> existing connection was forcibly closed by the remote host
>
>    at QuickFix.SocketInitiatorThread.ReadSome(Byte[] buffer, Int32
> timeoutMilliseconds)
>
>    at QuickFix.SocketInitiatorThread.Read()
>
>
>
> QuickFix/N reconnects and resumes filling and after a few of these
> exceptions and reconnects all orders end up filled.  I was wondering what
> is causing this exception and how do I prevent it.
>
>
>
> Any help would be really appreciated.
>
>
>
> Many thanks,
>
> Ian.
>
>
> _______________________________________________
> Quickfixn mailing list
> Quickfixn at lists.quickfixn.com
> http://lists.quickfixn.com/listinfo.cgi/quickfixn-quickfixn.com
>
>
>
>
>
> --
>
> Grant Birchmeier
>
> *Connamara Systems, LLC*
>
> *Made-To-Measure Trading Solutions.*
>
> Exactly what you need. No more. No less.
>
> http://connamara.com
>
>
> _______________________________________________
> Quickfixn mailing list
> Quickfixn at lists.quickfixn.com
> http://lists.quickfixn.com/listinfo.cgi/quickfixn-quickfixn.com
>
>
>
> _______________________________________________
> Quickfixn mailing list
> Quickfixn at lists.quickfixn.com
> http://lists.quickfixn.com/listinfo.cgi/quickfixn-quickfixn.com
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.quickfixn.com/pipermail/quickfixn-quickfixn.com/attachments/20150917/4ddde15a/attachment-0002.htm>