Re: [Quickfixj-users] Order request message truncated and affected by heartbeat message

[Christoph J. <chr...@ma...>]

Hi,

some thoughts/questions:

How many sessions do you operate in the same JVM?
So you are saying you did not encounter that error with older versions of QFJ?
Are you sending messages from several threads concurrently to the same session?

It could be that heartbeats are off by some time since they are triggered by the timer thread which 
runs about once per second. 200ms is a bit large a delay however.
Since the heartbeat is sent in the same millisecond as the order message it looks like something was 
blocking.

Cheers,
Chris.



On 13.10.20 08:24, Darren wrote:
> QuickFIX/J Documentation: http://www.quickfixj.org/documentation/
> QuickFIX/J Support: http://www.quickfixj.org/support/
>
>
>
> Hi everyone,
>
> I update my quickfixj-developed project to version 2.2.0 recently,
>
> after a couple of weeks later, i was reported a order request issue,
>
> receive error message(tag58) shows 'Missing Account(1)'
>
> after checking msg log, I noticed the order request and heartbeat message sent at the same time
>
> 8=FIX.4.2 
9=77
 35=0
 34=2161 
49=XXXXX
 52=20201008-13:09:36.386
 56=XXXXX
 38= 1
59=0 
77=O
 
> 10=240

>
> 8=FIX.4.2 
9=137
 35=D
 34=2162 
49=XXXXX 
52=20201008-13:09:36.386 
56=XXXXX
 11=1602107675
 21=1 
> 
38=1 
40=3 
54=1
 55=YM 
59=0
60=20201008-13:09:36.386 
77=O
 10=121

>
> 8=FIX.4.2 
9=00296
 35=8
 49=XXXXX 
56=XXXXX 
34=2324 
52=20201008-13:09:36.457
 129=NONE
 
> 37=3040153c-7a98-4249-bc8f-5f881fb9af41
11=1602107675
 17=7626495d-aa27-49ae-a4d4-935e2d9e9abb 
> 
20=0 
150=8
 39=8 
103=99 
55=YM
 54=1
 38=1 
40=3 
59=0
 32=0
 31=0 
151=0
 14=0
6=0 
> 
60=20201008-13:09:36.457 
77=O
 58=Missing Account(1) 
21=1
10=017
>
> and a few tags from my order request was missing, so server responsed error msg with Missing 
> Account(1).
>
> I checked the heartbeat msg log before this request
>
> 8=FIX.4.2 
9=00062
 35=0
 49=XXXX 
56=XXXX 
34=2320
52=20201008-13:08:06.185 
10=191

> 8=FIX.4.2 
9=62 
35=0
34=2158 
49=XXXX 
52=20201008-13:08:06.155
 56=XXXX 
10=053

> 8=FIX.4.2 
9=00062 
35=0 
49=XXXX 
56=XXXX 
34=2321
52=20201008-13:08:36.185
 10=195

> 8=FIX.4.2
 9=62 
35=0
34=2159 
49=XXXX 
52=20201008-13:08:36.154
 56=XXXX 
10=056

> 8=FIX.4.2 9=00062 
35=0 
49=XXXX 
56=XXXX 
34=2322
52=20201008-13:09:06.185
 10=194

> 8=FIX.4.2
 9=62 
35=0
34=2160 
49=XXXX 
52=20201008-13:09:06.153
 56=XXXX 
10=045

> 8=FIX.4.2
 9=00062
 35=0
 49=XXXX 
56=XXXX 
34=2323
52=20201008-13:09:36.185 
10=198

> 8=FIX.4.2 
9=77 
35=0
34=2161 
49=XXXX 
52=20201008-13:09:36.386 
56=XXXX 
38=1
 59=0 
77=O 
10=240

>
> my heartbeat interval setting is 30sec, so I thought the last heartbeat msg should be sent at 
> around 20201008-13:09:36.153,
>
> but log shows it was sent at 20201008-13:09:36.386, about 200 ms delayed,
>
> after checking the source of quickfixj, I still cant figure out who delayed the heartbeat msg,
>
> and why this heartbeat msg contains tag37, tag59 and tag77,
>
> these tags looks like copied from my order request, and a few tags from my order request is missing
>
> normal request:
>
> 8=FIX.4.2 
9=265
 35=D
 34=2157
49=XXXX 
52=20201008-13:07:35.953 
56=XXXX
 57=170886 5
1=XXXX
 
> 11=1602107674
21=1
38=1
40=2
44=28344
50=XXXX 
54=1 
55=YM 
59=0 
60=20201008-13:07:35.953 
77=O 
> 
116=XXXX
 167=FUT
 207=CME 
454=1 
455=YM Dec20 
456=97 
11028=Y 
16142=TW
18205=A1
10=182

>
> abnormal request:
>
> 8=FIX.4.2 
9=137
 35=D
 34=2162 
49=XXXXX 
52=20201008-13:09:36.386 
56=XXXXX
 11=1602107675
 21=1 
> 
38=1 
40=3 
54=1
 55=YM 
59=0
60=20201008-13:09:36.386 
77=O
 10=121

>
> this issue happens about once a month, difficult to duplicate,
>
> any thoughts / ideas would be appreciated. :)
>
>
> Regards,
>
> Darren
>
>

-- 
Christoph John
Software Engineering
T +49 241 557080-28
chr...@ma...

MACD GmbH
Oppenhoffallee 103
52066 Aachen, Germany
www.macd.com

Amtsgericht Aachen: HRB 8151
Ust.-Id: DE 813021663
Geschäftsführer: George Macdonald