[Quickfix-developers] Strange things after network problem detected
Brought to you by:
orenmnero
Menu
▾
▴
[Quickfix-developers] Strange things after network problem detected
|
From: Marcin G. <mar...@ar...> - 2018-01-24 12:03:02
|
HI there, we've been trying to figure out what can be wrong with quite old but rather solid version of qf-1.13.3. The worst thing is we never observed such problems before running the same software on Ubuntu 14.04 but after switching to Centos 7.2 almost everyday on one particular server such problems occur: Invalid message: Header fields out of order TO collect more information we've extended debugs on qf to so what's going on inside. It seems like message is randomly stripped in this example start with "R" but message is old one which was already sent - look at TAG52 : 09:20:00.220194 R.9933=1.47=1.1=0110.58=MEMO.439=ARTEST.20051=200053873.20128=9900.9949=XWAR.20074=1.20077=0.22010=0.22012=0.22014=0.10=061.8=FIX.4.2.9=340.35=D.34=970.49=ARTEST.52=20180123-09:20:00.220194.56=INCR.115=ARTEST.128=ARTEST.11=180123000370.15=PLN.21=1.22=4.38=53.40=2.44=4.45.48=PLMSTSD00019.54=1.55=PLMSTSD00019.59=0.60=20180123-09:20:00.209082.167=CS.207=XWA counter 0 orderField 8 field 0 this is sessions setting 20180124 05:02:01.481 DEBUG : name: "BeginString" value "FIX.4.2" 20180124 05:02:01.481 DEBUG : name: "DataDictionary" value "/opt/quickfix-1.13.3/share/quickfix/FIX42XX.xml" 20180124 05:02:01.481 DEBUG : name: "EnableNextExpectedMsgSeqNum" value "Y" 20180124 05:02:01.481 DEBUG : name: "EndDay" value "sunday" 20180124 05:02:01.481 DEBUG : name: "EndTime" value "21:30:00" 20180124 05:02:01.481 DEBUG : name: "HeartBtInt" value "30" 20180124 05:02:01.481 DEBUG : name: "MicrosecondsInTimeStamp" value "Y" 20180124 05:02:01.481 DEBUG : name: "PersistMessages" value "Y" 20180124 05:02:01.481 DEBUG : name: "RefreshOnLogon" value "Y" 20180124 05:02:01.481 DEBUG : name: "ResetOnLogout" value "N" 20180124 05:02:01.481 DEBUG : name: "SendRedundantResendRequests" value "Y" 20180124 05:02:01.481 DEBUG : name: "SenderCompID" value "ARTST" 20180124 05:02:01.481 DEBUG : name: "SenderLocationID" value "XXX" 20180124 05:02:01.481 DEBUG : name: "SessionQualifier" value "A03" 20180124 05:02:01.481 DEBUG : name: "SocketConnectHost" value "193.X.Y.Z" 20180124 05:02:01.481 DEBUG : name: "SocketConnectPort" value "22000" 20180124 05:02:01.481 DEBUG : name: "StartDay" value "monday" 20180124 05:02:01.481 DEBUG : name: "StartTime" value "04:00:00" 20180124 05:02:01.481 DEBUG : name: "TargetCompID" value "INCR" event log: 20180123-04:03:04.518464 : Initiated logon request 20180123-04:03:04.526790 : Received logon response 20180123-09:43:09.066969 : Sent test request TEST 20180123-09:43:45.104563 : Timed out waiting for heartbeat 20180123-09:43:45.104604 : Disconnecting 20180123-09:44:04.978081 : Connecting to 193.X.Y.Z on port 22000 20180123-09:44:12.001407 : Initiated logon request 20180123-09:44:12.003893 : Received logon response 20180123-09:44:12.003927 : MsgSeqNum too high, expecting 1890 but received 1893 20180123-09:44:12.003973 : Detected fill gap FROM: 1890 TO: 1892. NextExpectedSeqNum enabled - no resend request sent 20180123-09:44:12.003987 : GenerateResendMessages, persist: Y 20180123-09:44:12.004345 : Msg to resend: 8=FIX.4.2.9=269.35=F.34=1244.43=Y.49=ARTEST.52=20180123-09:44:12.004215.56=INCR.115=ARTEST.122=20180123-09:42:59.550926.128=ARTEST.11=180123000612.22=4.37=20180123000306.38=1.41=180123000605.48=NL0000474351.54=1.55=NL0000474351.58=MEMO.60=20180123-09:42:59.543119.167=CS.207=XWAR.10=233. 20180123-09:44:12.004436 : Resending Message: 1244 20180123-09:44:12.004708 : Msg to resend: 8=FIX.4.2.9=270.35=F.34=1245.43=Y.49=ARTEST.52=20180123-09:44:12.004589.56=INCR.115=ARTEST.122=20180123-09:42:59.583347.128=ARTEST.11=180123000613.22=4.37=20180123001095.38=53.41=180123000606.48=PLMSTSD00019.54=1.55=PLMSTSD00019.58=MEMO.60=20180123-09:42:59.569505.167=CS.207=XWAR.10=087. 20180123-09:44:12.004752 : Resending Message: 1245 20180123-09:44:12.004960 : Msg to resend: 8=FIX.4.2.9=270.35=F.34=1246.43=Y.49=ARTEST.52=20180123-09:44:12.004860.56=INCR.115=ARTEST.122=20180123-09:42:59.598277.128=ARTEST.11=180123000614.22=4.37=20180123000224.38=68.41=180123000610.48=PLROBYG00016.54=1.55=PLROBYG00016.58=MEMO.60=20180123-09:42:59.594677.167=CS.207=XWAR.10=069. 20180123-09:44:12.004989 : Resending Message: 1246 20180123-09:44:12.005238 : Invalid message: Header fields out of order R.9933=1.47=1.1=0110.58=MEMO.439=ARTEST.20051=200053873.20128=9900.9949=XWAR.20074=1.20077=0.22010=0.22012=0.22014=0.10=061.8=FIX.4.2.9=340.35=D.34=970.49=ARTEST.52=20180123-09:20:00.220194.56=INCR.115=ARTEST.128=ARTEST.11=180123000370.15=PLN.21=1.22=4.38=53.40=2.44=4.45.48=PLMSTSD00019.54=1.55=PLMSTSD00019.59=0.60=20180123-09:20:00.209082.167=CS.207=XWA counter 0 orderField 8 field 0 20180123-09:44:12.006203 : ResendRequest for messages FROM: 1890 TO: 1892 has been satisfied. 20180123-09:44:12.006529 : Received SequenceReset FROM: 1892 TO: 1894 message log: 20180123-09:42:33.021497 : 8=FIX.4.2 | 9=60 | 35=0 | 34=1889 | 49=INCR | 56=ARTEST | 52=20180123-09:42:33.020154 | 10=132 | 20180123-09:42:33.022005 : 8=FIX.4.2 | 9=73 | 35=0 | 34=1242 | 49=ARTEST | 52=20180123-09:42:33.021864 | 56=INCR | 142=811P01GF | 10=045 | 20180123-09:42:59.520949 : 8=FIX.4.2 | 9=236 | 35=F | 34=1243 | 49=ARTEST | 52=20180123-09:42:59.520838 | 56=INCR | 115=ARTEST | 128=ARTEST | 11=180123000611 | 22=4 | 37=20180123001216 | 38=20 | 41=180123000604 | 48=PLGTBCK00297 | 54=1 | 55 =PLGTBCK00297 | 58=MEMO | 60=20180123-09:42:59.510429 | 167=CS | 207=XWAR | 10=108 | 20180123-09:42:59.551024 : 8=FIX.4.2 | 9=235 | 35=F | 34=1244 | 49=ARTEST | 52=20180123-09:42:59.550926 | 56=INCR | 115=ARTEST | 128=ARTEST | 11=180123000612 | 22=4 | 37=20180123000306 | 38=1 | 41=180123000605 | 48=NL0000474351 | 54=1 | 55= NL0000474351 | 58=MEMO | 60=20180123-09:42:59.543119 | 167=CS | 207=XWAR | 10=081 | 20180123-09:42:59.583517 : 8=FIX.4.2 | 9=236 | 35=F | 34=1245 | 49=ARTEST | 52=20180123-09:42:59.583347 | 56=INCR | 115=ARTEST | 128=ARTEST | 11=180123000613 | 22=4 | 37=20180123001095 | 38=53 | 41=180123000606 | 48=PLMSTSD00019 | 54=1 | 55 =PLMSTSD00019 | 58=MEMO | 60=20180123-09:42:59.569505 | 167=CS | 207=XWAR | 10=186 | 20180123-09:42:59.598380 : 8=FIX.4.2 | 9=236 | 35=F | 34=1246 | 49=ARTEST | 52=20180123-09:42:59.598277 | 56=INCR | 115=ARTEST | 128=ARTEST | 11=180123000614 | 22=4 | 37=20180123000224 | 38=68 | 41=180123000610 | 48=PLROBYG00016 | 54=1 | 55 =PLROBYG00016 | 58=MEMO | 60=20180123-09:42:59.594677 | 167=CS | 207=XWAR | 10=176 | 20180123-09:43:09.066925 : 8=FIX.4.2 | 9=82 | 35=1 | 34=1247 | 49=ARTEST | 52=20180123-09:43:09.066558 | 56=INCR | 142=811P01GF | 112=TEST | 10=082 | 20180123-09:44:12.001348 : 8=FIX.4.2 | 9=94 | 35=A | 34=1248 | 49=ARTEST | 52=20180123-09:44:12.001120 | 56=INCR | 142=811P01GF | 98=0 | 108=30 | 789=1890 | 10=006 | 20180123-09:44:12.003111 : 8=FIX.4.2 | 9=87 | 35=A | 34=1893 | 49=INCR | 56=ARTEST | 52=20180123-09:44:12.002028 | 108=30 | 98=0 | 141=N | 789=1244 | 10=132 | 20180123-09:44:12.004380 : 8=FIX.4.2 | 9=269 | 35=F | 34=1244 | 43=Y | 49=ARTEST | 52=20180123-09:44:12.004215 | 56=INCR | 115=ARTEST | 122=20180123-09:42:59.550926 | 128=ARTEST | 11=180123000612 | 22=4 | 37=20180123000306 | 38=1 | 41=18012 3000605 | 48=NL0000474351 | 54=1 | 55=NL0000474351 | 58=MEMO | 60=20180123-09:42:59.543119 | 167=CS | 207=XWAR | 10=233 | 20180123-09:44:12.004735 : 8=FIX.4.2 | 9=270 | 35=F | 34=1245 | 43=Y | 49=ARTEST | 52=20180123-09:44:12.004589 | 56=INCR | 115=ARTEST | 122=20180123-09:42:59.583347 | 128=ARTEST | 11=180123000613 | 22=4 | 37=20180123001095 | 38=53 | 41=1801 23000606 | 48=PLMSTSD00019 | 54=1 | 55=PLMSTSD00019 | 58=MEMO | 60=20180123-09:42:59.569505 | 167=CS | 207=XWAR | 10=087 | 20180123-09:44:12.004976 : 8=FIX.4.2 | 9=270 | 35=F | 34=1246 | 43=Y | 49=ARTEST | 52=20180123-09:44:12.004860 | 56=INCR | 115=ARTEST | 122=20180123-09:42:59.598277 | 128=ARTEST | 11=180123000614 | 22=4 | 37=20180123000224 | 38=68 | 41=1801 23000610 | 48=PLROBYG00016 | 54=1 | 55=PLROBYG00016 | 58=MEMO | 60=20180123-09:42:59.594677 | 167=CS | 207=XWAR | 10=069 | has anyone observed such strange issue ? Could it be Centos problem ? Thx Marcin |
