RE: [Quickfix-developers] Unexplained TEST Message From Server

[Jo J. <jo...@tr...>]

Here are the logs from the time of the disconnect. Upon further
investigation, it looks are though it was a legitimate line drop,
though. The heartbeat timeout was real since we receive no messages from
the counterparty for over a minute in the incoming log.

After reconnection, it went into a crazy loop, trying to sync up again.
It locked up the server for a while until I killed it and restarted it.
It them seemed to come up ok, w/o resetting the sequence numbers.

Thanks,
Jo

/* EVENT */
20041206-13:40:18 : Created session
20041206-13:40:19 : Connecting to 169.196.243.47 on port 21600
20041206-13:40:19 : Connection succeeded
20041206-13:40:19 : Initiated logon request
20041206-13:40:20 : Received logon response
20041206-19:25:52 : Sent test request TEST
20041206-19:26:28 : Timed out waiting for heartbeat
20041206-19:26:28 : Disconnecting
20041206-19:26:35 : Connecting to 169.196.243.47 on port 21600
20041206-19:26:35 : Connection succeeded
20041206-19:26:35 : Initiated logon request
20041206-19:26:35 : Received logon response
20041206-19:26:35 : MsgSeqNum too high, expecting  11520 but received
11522
20041206-19:26:35 : Sent ResendRequest FROM: 11520 TO: 999999
20041206-19:26:35 : Received ResendRequest FROM: 6833 TO: 6859
20041206-19:26:35 : Resending Message: 6833

/* INCOMING */
8=3DFIX.4.1=019=3D265=0135=3D8=0149=3DLHTRIDE=0156=3DTRIDE=0157=3D573=013=
4=3D11518=0152=3D20041206-19:
25:16=0137=3D12966239=0111=3D20041206-006762=0141=3D20041206-006710=0176=3D=
ARCA=0117=3D10017
0592=0120=3D0=01150=3D6=0139=3D6=0155=3DAMWD=01207=3DARCA=0154=3D2=0138=3D=
100=0140=3D2=0144=3D44.0900=0159=3D0=013
2=3D0=0131=3D0=01151=3D100=0114=3D0=016=3D0=0160=3D20041206-19:25:17=0158=
=3DCancel pending=0110=3D070=01
8=3DFIX.4.1=019=3D266=0135=3D8=0149=3DLHTRIDE=0156=3DTRIDE=0157=3D573=013=
4=3D11519=0152=3D20041206-19:
25:16=0137=3D12966239=0111=3D20041206-006762=0141=3D20041206-006710=0176=3D=
ARCA=0117=3D10017
0593=0120=3D0=01150=3D4=0139=3D4=0155=3DAMWD=01207=3DARCA=0154=3D2=0138=3D=
100=0140=3D2=0144=3D44.0900=0159=3D0=013
2=3D0=0131=3D0=01151=3D0=0114=3D0=016=3D0=0160=3D20041206-19:25:17=0158=3D=
Cancelled by
User=0110=3D206=01
8=3DFIX.4.1=019=3D67=0135=3DA=0149=3DLHTRIDE=0156=3DTRIDE=0134=3D11522=01=
52=3D20041206-19:26:36=0198
=3D0=01108=3D30=0110=3D138=01
8=3DFIX.4.1=019=3D70=0135=3D2=0149=3DLHTRIDE=0156=3DTRIDE=0134=3D11523=01=
52=3D20041206-19:26:36=017=3D
6833=0116=3D6859=0110=3D039=01
8=3DFIX.4.1=019=3D70=0135=3D2=0149=3DLHTRIDE=0156=3DTRIDE=0134=3D11524=01=
52=3D20041206-19:26:36=017=3D
6833=0116=3D6859=0110=3D040=01
8=3DFIX.4.1=019=3D282=0135=3D8=0149=3DLHTRIDE=0156=3DTRIDE=0157=3D352=013=
4=3D11520=0143=3DY=0152=3D2004120
6-19:26:36=01122=3D20041206-19:25:18=0137=3D12980301=0111=3D20041206-0067=
14=0176=3DARCA=01
17=3D300933443=0120=3D0=01150=3D2=0139=3D2=0155=3DRCRC=01207=3DARCA=0154=3D=
2=0138=3D900=0140=3D2=0144=3D31.430
0=0159=3D0=0132=3D800=0131=3D31.4300=0130=3DP=01151=3D0=0114=3D900=016=3D=
31.4300=0160=3D20041206-19:25:1
9=0158=3DFill=0110=3D201=01
8=3DFIX.4.1=019=3D284=0135=3D8=0149=3DLHTRIDE=0156=3DTRIDE=0157=3D573=013=
4=3D11521=0143=3DY=0152=3D2004120
6-19:26:36=01122=3D20041206-19:25:46=0137=3D13008372=0111=3D20041206-0067=
31=0176=3DARCA=01
17=3D200934918=0120=3D0=01150=3D2=0139=3D2=0155=3DANSS=01207=3DARCA=0154=3D=
1=0138=3D1100=0140=3D2=0144=3D33.54
00=0159=3D0=0132=3D700=0131=3D33.5400=0130=3DP=01151=3D0=0114=3D1100=016=3D=
33.5400=0160=3D20041206-19:25
:47=0158=3DFill=0110=3D064=01

/* OUTGOING */
8=3DFIX.4.1=019=3D63=0135=3D1=0134=3D6845=0149=3DTRIDE=0152=3D20041206-19=
:25:52=0156=3DLHTRIDE=01112
=3DTEST=0110=3D072=01
8=3DFIX.4.1=019=3D133=0135=3DF=0134=3D6846=0149=3DTRIDE=0152=3D20041206-1=
9:25:53=0156=3DLHTRIDE=0111
=3D20041206-006775=0138=3D106=0141=3D20041206-006711=0154=3D5=0155=3DTUES=
=0160=3D20041206-19:2
5:53=0110=3D176=01
8=3DFIX.4.1=019=3D133=0135=3DF=0134=3D6847=0149=3DTRIDE=0152=3D20041206-1=
9:25:54=0156=3DLHTRIDE=0111
=3D20041206-006776=0138=3D200=0141=3D20041206-006690=0154=3D1=0155=3DUTEK=
=0160=3D20041206-19:2
5:54=0110=3D169=01
8=3DFIX.4.1=019=3D174=0135=3DD=0134=3D6848=0149=3DTRIDE=0150=3D352=0152=3D=
20041206-19:25:55=0156=3DLHT
RIDE=0111=3D20041206-006777=0121=3D1=0138=3D300=0140=3D2=0144=3D24.02=015=
4=3D2=0155=3DAFCE=0159=3D0=0160=3D2
0041206-19:25:55=01100=3DARCA=01114=3DN=01204=3D0=01439=3D352=0110=3D211=01=

8=3DFIX.4.1=019=3D134=0135=3DF=0134=3D6849=0149=3DTRIDE=0152=3D20041206-1=
9:25:56=0156=3DLHTRIDE=0111
=3D20041206-006778=0138=3D2600=0141=3D20041206-006697=0154=3D5=0155=3DSBS=
A=0160=3D20041206-19:
25:56=0110=3D227=01
8=3DFIX.4.1=019=3D183=0135=3DD=0134=3D6850=0149=3DTRIDE=0150=3D352=0152=3D=
20041206-19:25:59=0156=3DLHT
RIDE=0111=3D20041206-006779=0121=3D1=0138=3D200=0140=3D2=0144=3D30.16=015=
4=3D1=0155=3DHEW=0159=3D0=0160=3D20
041206-19:25:59=01100=3DNS3=01114=3DN=01204=3D0=01439=3D352=019431=3DNY =
NX=0110=3D228=01
8=3DFIX.4.1=019=3D133=0135=3DF=0134=3D6851=0149=3DTRIDE=0152=3D20041206-1=
9:26:02=0156=3DLHTRIDE=0111
=3D20041206-006780=0138=3D2700=0141=3D20041206-006703=0154=3D1=0155=3DGTI=
=0160=3D20041206-19:2
6:02=0110=3D112=01
8=3DFIX.4.1=019=3D173=0135=3DD=0134=3D6852=0149=3DTRIDE=0150=3D573=0152=3D=
20041206-19:26:07=0156=3DLHT
RIDE=0111=3D20041206-006781=0121=3D1=0138=3D1000=0140=3D2=0144=3D30.28=01=
54=3D1=0155=3DAPPX=0159=3D0=0160=3D
20041206-19:26:07=01100=3DIS=01114=3DN=01204=3D0=01439=3D573=0110=3D175=01=

8=3DFIX.4.1=019=3D177=0135=3DD=0134=3D6853=0149=3DTRIDE=0150=3D352=0152=3D=
20041206-19:26:11=0156=3DLHT
RIDE=0111=3D20041206-006782=0121=3D1=0138=3D2200=0140=3D2=0144=3D1.38=015=
4=3D5=0155=3DAGR=0159=3D0=0160=3D20
041206-19:26:11=0165=3DA=01100=3DNS3=01114=3DN=01204=3D0=01439=3D352=0110=
=3D058=01
8=3DFIX.4.1=019=3D172=0135=3DD=0134=3D6854=0149=3DTRIDE=0150=3D352=0152=3D=
20041206-19:26:12=0156=3DLHT
RIDE=0111=3D20041206-006783=0121=3D1=0138=3D300=0140=3D2=0144=3D119.49=01=
54=3D1=0155=3DSPY=0159=3D0=0160=3D2
0041206-19:26:12=01100=3DIS=01114=3DN=01204=3D0=01439=3D352=0110=3D112=01=

8=3DFIX.4.1=019=3D132=0135=3DF=0134=3D6855=0149=3DTRIDE=0152=3D20041206-1=
9:26:15=0156=3DLHTRIDE=0111
=3D20041206-006784=0138=3D200=0141=3D20041206-006742=0154=3D5=0155=3DACP=01=
60=3D20041206-19:26
:15=0110=3D063=01
8=3DFIX.4.1=019=3D174=0135=3DD=0134=3D6856=0149=3DTRIDE=0150=3D352=0152=3D=
20041206-19:26:17=0156=3DLHT
RIDE=0111=3D20041206-006785=0121=3D1=0138=3D1100=0140=3D2=0144=3D20.6=015=
4=3D5=0155=3DVSAT=0159=3D0=0160=3D2
0041206-19:26:17=01100=3DARCA=01114=3DN=01204=3D0=01439=3D352=0110=3D000=01=

8=3DFIX.4.1=019=3D134=0135=3DF=0134=3D6857=0149=3DTRIDE=0152=3D20041206-1=
9:26:20=0156=3DLHTRIDE=0111
=3D20041206-006786=0138=3D1200=0141=3D20041206-006709=0154=3D1=0155=3DEEF=
T=0160=3D20041206-19:
26:20=0110=3D189=01
8=3DFIX.4.1=019=3D133=0135=3DF=0134=3D6858=0149=3DTRIDE=0152=3D20041206-1=
9:26:26=0156=3DLHTRIDE=0111
=3D20041206-006787=0138=3D1100=0141=3D20041206-006720=0154=3D1=0155=3DASX=
=0160=3D20041206-19:2
6:26=0110=3D138=01
8=3DFIX.4.1=019=3D66=0135=3DA=0134=3D6859=0149=3DTRIDE=0152=3D20041206-19=
:26:35=0156=3DLHTRIDE=0198=3D
0=01108=3D30=0110=3D105=01
8=3DFIX.4.1=019=3D72=0135=3D2=0134=3D6860=0149=3DTRIDE=0152=3D20041206-19=
:26:35=0156=3DLHTRIDE=017=3D1
1520=0116=3D999999=0110=3D159=01
8=3DFIX.4.1=019=3D198=0135=3DD=0134=3D6833=0143=3DY=0149=3DTRIDE=0150=3D3=
52=0152=3D20041206-19:26:35=015
6=3DLHTRIDE=01122=3D20041206-19:25:18=0111=3D20041206-006763=0121=3D1=013=
8=3D400=0140=3D2=0144=3D6
.48=0154=3D1=0155=3DTCF=0159=3D0=0160=3D20041206-19:25:18=01100=3DNS3=011=
14=3DN=01204=3D0=01439=3D352=0110
=3D108=01
8=3DFIX.4.1=019=3D199=0135=3DD=0134=3D6834=0143=3DY=0149=3DTRIDE=0150=3D5=
73=0152=3D20041206-19:26:35=015
6=3DLHTRIDE=01122=3D20041206-19:25:19=0111=3D20041206-006764=0121=3D1=013=
8=3D100=0140=3D2=0144=3D3
8.27=0154=3D5=0155=3DAVD=0159=3D0=0160=3D20041206-19:25:19=01100=3DNS3=01=
114=3DN=01204=3D0=01439=3D573=011
0=3D172=01

-----Original Message-----
From: Oren Miller [mailto:or...@qu...]=20
Sent: Wednesday, December 08, 2004 08:27
To: Jo Janssens
Cc: qui...@li...
Subject: Re: [Quickfix-developers] Unexplained TEST Message From Server

Are any logs available?

--oren

On Dec 8, 2004, at 8:18 AM, Jo Janssens wrote:

> QuickFIX Documentation: =20
> http://www.quickfixengine.org/quickfix/doc/html/index.html
> QuickFIX FAQ: =20
> http://www.quickfixengine.org/wikifix/index.php?QuickFixFAQ
> QuickFIX Support: http://www.quickfixengine.org/services.html
>
> I believe I had a similar problem yesterday (also QF 1.9.2) - a TEST
> message followed by a heartbeat timeout and dropping the connection.
At
> the time, I just thought the line dropped...
>
> Jo
>
> -----Original Message-----
> From: qui...@li...
> [mailto:qui...@li...] On Behalf Of
> Jon Dahl
> Sent: Tuesday, December 07, 2004 15:51
> To: qui...@li...
> Subject: [Quickfix-developers] Unexplained TEST Message From Server
>
> QuickFIX Documentation:
> http://www.quickfixengine.org/quickfix/doc/html/index.html
> QuickFIX FAQ:
> http://www.quickfixengine.org/wikifix/index.php?QuickFixFAQ
> QuickFIX Support: http://www.quickfixengine.org/services.html
>
> We're using QF 1.9.2 with a HeatBeatInt=3D15
>
> We had the following happen today in production:
>
> incoming:
> 8=3DFIX.4.29=3D6235=3D034=3D170449=3DUNG531N52=3D20041207-19:48:=20
> 07.20356=3DLDFIXGWY110
> =3D223
> 8=3DFIX.4.29=3D6235=3D034=3D170549=3DUNG531N52=3D20041207-19:48:=20
> 22.21856=3DLDFIXGWY110
> =3D227
> 8=3DFIX.4.29=3D6235=3D034=3D170649=3DUNG531N52=3D20041207-19:48:=20
> 37.23456=3DLDFIXGWY110
> =3D232
> 8=3DFIX.4.29=3D6235=3D034=3D170749=3DUNG531N52=3D20041207-19:48:=20
> 52.28156=3DLDFIXGWY110
> =3D232
>
> outgoing:
> 8=3DFIX.4.29=3D6235=3D034=3D171149=3DLDFIXGWY152=3D20041207-19:48:=20
> 11.12256=3DUNG531N10
> =3D216
> 8=3DFIX.4.29=3D6235=3D034=3D171249=3DLDFIXGWY152=3D20041207-19:48:=20
> 26.13256=3DUNG531N10
> =3D224
> 8=3DFIX.4.29=3D6235=3D034=3D171349=3DLDFIXGWY152=3D20041207-19:48:=20
> 41.18256=3DUNG531N10
> =3D227
> 8=3DFIX.4.29=3D6235=3D034=3D171449=3DLDFIXGWY152=3D20041207-19:48:=20
> 56.19156=3DUNG531N10
> =3D234
> 8=3DFIX.4.29=3D7135=3D134=3D171549=3DLDFIXGWY152=3D20041207-19:48:=20
> 59.19156=3DUNG531N11
> 2=3DTEST10=3D001
>
> event:
> 20041207-19:48:59 : Sent test request TEST
> 20041207-19:49:13 : Dropped Connection
>
> Why would the server send out a TEST request when it received a
> HeartBeat
> message 7 seconds earlier?
>
> Or am I missing something here?
>
> -jd-
>
>
>
> -------------------------------------------------------
> SF email is sponsored by - The IT Product Guide
> Read honest & candid reviews on hundreds of IT Products from real =20
> users.
> Discover which products truly live up to the hype. Start reading now.
> http://productguide.itmanagersjournal.com/
> _______________________________________________
> Quickfix-developers mailing list
> Qui...@li...
> https://lists.sourceforge.net/lists/listinfo/quickfix-developers
>
>
>
> -------------------------------------------------------
> SF email is sponsored by - The IT Product Guide
> Read honest & candid reviews on hundreds of IT Products from real =20
> users.
> Discover which products truly live up to the hype. Start reading now.
> http://productguide.itmanagersjournal.com/
> _______________________________________________
> Quickfix-developers mailing list
> Qui...@li...
> https://lists.sourceforge.net/lists/listinfo/quickfix-developers
>