[#QFJ-915] After sending TEST REQUEST message, FIXEngine can't be connected

[QFJ-915] After sending TEST REQUEST message, FIXEngine can't be connected Created: 14/Feb/17 Updated: 15/Feb/17 Resolved: 15/Feb/17
Status:	Closed
Project:	QuickFIX/J
Component/s:	Engine
Affects Version/s:	1.5.3
Fix Version/s:	None

Type:

Bug

Priority:

Default

Reporter:

Dai Shinohara

Assignee:

Unassigned

Resolution:

Incomplete

Votes:

Labels:

QuickfixJ, testRequest, timeout

Environment:

Java 1.7, RHEL 6.3

Description

We are using QuickFIX on the Initiator side.
Suddenly, QuickFIX sent TEST REQUEST.
Acceptor returned HEARTBEAT message immediately.
But QuickFIX didn't recognize HEARTBEAT message.
Therefore QuickFIX judged time-out.

After judging time-out, QuickFIX sent LOGON message.
Acceptor returned LOGON message immediately.
But QuickFIX didn't recognize LOGON message again.
Therefore QuickFIX judged time-out.

20170209-00:01:26: Sent test request TEST
20170209-00:02:20: Disconnecting: Timed out waiting for heartbeat
20170209-00:02:21: Initiated logon request
20170209-00:02:32: Disconnecting: Timed out waiting for logon response
20170209-00:02:33: Initiated logon request
20170209-00:02:43: Disconnecting: Timed out waiting for logon response
20170209-00:02:44: Initiated logon request
20170209-00:02:54: Disconnecting: Timed out waiting for logon response
20170209-00:02:55: Initiated logon request
20170209-00:03:05: Disconnecting: Timed out waiting for logon response

Acceptor message log:
2017 Feb 09 09:01:24.041.936 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:01:24.041,34=1195283,...
2017 Feb 09 09:01:24.203.275 [FIXSND] 8=FIX.4.4,9=220,35=S,52=20170209-00:01:24.203,34=1195284,...
2017 Feb 09 09:01:24.424.520 [FIXSND] 8=FIX.4.4,9=216,35=S,52=20170209-00:01:24.424,34=1195285,...
2017 Feb 09 09:01:25.012.688 [FIXSND] 8=FIX.4.4,9=220,35=S,52=20170209-00:01:25.012,34=1195286,...
2017 Feb 09 09:01:25.013.568 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:01:25.013,34=1195287,...
2017 Feb 09 09:01:25.109.057 [FIXSND] 8=FIX.4.4,9=216,35=S,52=20170209-00:01:25.108,34=1195288,...
2017 Feb 09 09:01:25.293.963 [FIXSND] 8=FIX.4.4,9=220,35=S,52=20170209-00:01:25.293,34=1195289,...
2017 Feb 09 09:01:25.525.713 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:01:25.525,34=1195290,...
2017 Feb 09 09:01:26.141.202 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:01:26.141,34=1195291,...
2017 Feb 09 09:01:26.270.703 [FIXRCV] 8=FIX.4.4,9=70,35=1,34=5411,49=...,52=20170209-00:01:26.270,56=...,112=TEST,10=146
2017 Feb 09 09:01:26.270.787 [FIXSND] 8=FIX.4.4,9=73,35=0,52=20170209-00:01:26.270,34=1195292,49=SCI,56=...,112=TEST,10=054
2017 Feb 09 09:01:26.424.711 [FIXSND] 8=FIX.4.4,9=216,35=S,52=20170209-00:01:26.424,34=1195293,...
2017 Feb 09 09:01:26.429.398 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:01:26.429,34=1195294,...
2017 Feb 09 09:01:26.641.169 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:01:26.641,34=1195295,...
2017 Feb 09 09:01:26.994.496 [FIXSND] 8=FIX.4.4,9=220,35=S,52=20170209-00:01:26.994,34=1195296,...
2017 Feb 09 09:01:26.994.933 [FIXSND] 8=FIX.4.4,9=220,35=S,52=20170209-00:01:26.994,34=1195297,...
2017 Feb 09 09:01:27.109.910 [FIXSND] 8=FIX.4.4,9=216,35=S,52=20170209-00:01:27.109,34=1195298,...
.
.
.
2017 Feb 09 09:02:18.992.329 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:02:18.992,34=1195523,...
2017 Feb 09 09:02:19.300.151 [FIXSND] 8=FIX.4.4,9=220,35=S,52=20170209-00:02:19.300,34=1195524,...
2017 Feb 09 09:02:19.310.049 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:02:19.309,34=1195525,...
2017 Feb 09 09:02:19.508.998 [FIXSND] 8=FIX.4.4,9=220,35=S,52=20170209-00:02:19.508,34=1195526,...
2017 Feb 09 09:02:19.720.621 [FIXSND] 8=FIX.4.4,9=216,35=S,52=20170209-00:02:19.720,34=1195527,...
2017 Feb 09 09:02:19.766.977 [FIXSND] 8=FIX.4.4,9=216,35=S,52=20170209-00:02:19.766,34=1195528,...
2017 Feb 09 09:02:19.888.979 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:02:19.888,34=1195529,...
2017 Feb 09 09:02:19.949.890 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:02:19.949,34=1195530,...
2017 Feb 09 09:02:20.050.769 [FIXSND] 8=FIX.4.4,9=218,35=S,52=20170209-00:02:20.050,34=1195531,...
2017 Feb 09 09:02:21.271.969 [FIXRCV] 8=FIX.4.4,9=76,35=A,34=1,49=...,52=20170209-00:02:21.271,56=...,98=0,108=60,141=Y,10=066
2017 Feb 09 09:02:21.312.495 [FIXSND] 8=FIX.4.4,9=76,35=A,52=20170209-00:02:21.312,34=1,49=SCI,56=JBKI-QUOTE01,98=0,108=60,141=Y,1

Initiator message log
8=FIX.4.4^A9=218^A35=S^A52=20170209-00:02:19.309^A34=1195525...
8=FIX.4.4^A9=220^A35=S^A52=20170209-00:02:19.508^A34=1195526...
8=FIX.4.4^A9=216^A35=S^A52=20170209-00:02:19.720^A34=1195527...
8=FIX.4.4^A9=216^A35=S^A52=20170209-00:02:19.766^A34=1195528...
8=FIX.4.4^A9=218^A35=S^A52=20170209-00:02:19.888^A34=1195529...
8=FIX.4.4^A9=218^A35=S^A52=20170209-00:02:19.949^A34=1195530...
8=FIX.4.4^A9=218^A35=S^A52=20170209-00:02:20.050^A34=1195531...
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:02:21.271^A56=...^A98=0^A108=60^A141=Y^A10=066^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:02:21.312^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=062^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:02:33.270^A56=...^A98=0^A108=60^A141=Y^A10=068^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:02:33.283^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=072^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:02:44.270^A56=...^A98=0^A108=60^A141=Y^A10=070^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:02:44.285^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=076^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:02:55.270^A56=...^A98=0^A108=60^A141=Y^A10=072^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:02:55.280^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=073^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:03:06.270^A56=...^A98=0^A108=60^A141=Y^A10=069^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:03:06.285^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=075^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:03:17.270^A56=...^A98=0^A108=60^A141=Y^A10=071^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:03:17.279^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=080^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:03:28.270^A56=...^A98=0^A108=60^A141=Y^A10=073^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:03:28.280^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=074^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:03:39.270^A56=...^A98=0^A108=60^A141=Y^A10=075^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:03:39.304^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=073^A
8=FIX.4.4^A9=76^A35=A^A34=1^A49=...^A52=20170209-00:03:50.270^A56=...^A98=0^A108=60^A141=Y^A10=068^A
8=FIX.4.4^A9=76^A35=A^A52=20170209-00:03:50.282^A34=1^A49=...^A56=...^A98=0^A108=60^A141=Y^A10=071^A

We hava 2 questions.
1.Why did QuickFIX send TEST REQUEST suddenly?
2.Is this problem settled by a newest version?

Comments

Comment by Christoph John [ 15/Feb/17 ]

Looks like a thread is hanging, but without a stack trace it is impossible to tell. When the issue occurs next time, please create a stack trace and attach it here.

Generated at Mon Apr 29 04:14:14 UTC 2024 using JIRA 7.5.2#75007-sha1:9f5725bb824792b3230a5d8716f0c13e296a3cae.

[QFJ-915] After sending TEST REQUEST message, FIXEngine can't be connected Created: 14/Feb/17 Updated: 15/Feb/17 Resolved: 15/Feb/17