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

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

And again, it's me: would it be possible for you to share the content of your toApp/toAdmin 
implementations?
Otherwise I cannot imagine where the messages could get altered.
Would be good to have a reproducible test case. :) Never seen this behaviour and we have some 
installations with 100+ sessions in one VM.

Chris.

On 15.10.20 15:05, Christoph John wrote:
> Just asking because the Heartbeat might only be a logging issue, unless you have proof that the 
> Heartbeat was sent out like shown in your log. But if that was the case I would expect the 
> counterparty rejected it.
>
>
>
> On 15.10.20 14:27, Christoph John via Quickfixj-users wrote:
>> QuickFIX/J Documentation:http://www.quickfixj.org/documentation/
>> QuickFIX/J Support:http://www.quickfixj.org/support/
>>
>>
>>
>> Hi,
>>
>> one more thing, could you post the original message log? Did I get it right that the heartbeat 
>> was not rejected although it contains invalid tags?
>>
>> Thanks,
>> Chris.
>>
>> On 14.10.20 05:00, Darren wrote:
>>>
>>> Hi Chris,
>>>
>>> thanks for the reply,
>>>
>>> My application just create one session only, and it's a single thread process to send request,
>>>
>>> I encounter this error after upgrade quickfixj to version 2.1.1,
>>>
>>> never seem this error when still using 1.5.3,
>>>
>>> I cant figure out what cause this error so I tried to update to the latest version 2.2.0,
>>>
>>> but it seems still happened...
>>>
>>> yes this looks like heartbeat msg is blocked by something,
>>>
>>> and i think it's not a big deal, but my request content is modified, that's a serious problem XD
>>>
>>> I traced the message creation process, there is no way one message will be affected by another,
>>>
>>> especially by the heartbeat message,
>>>
>>> Session.java
>>>
>>>     public void generateHeartbeat() {
>>>         final Message heartbeat = messageFactory.create(sessionID.getBeginString(),
>>>                 MsgType.HEARTBEAT);
>>>         initializeHeader(heartbeat.getHeader());
>>>         sendRaw(heartbeat, 0);
>>>     }
>>>
>>> this heartbeat generation process looks straightforward and simple,
>>>
>>> how this heartbeat message get tags from my order request content?
>>>
>>> checked the sendRaw method but everything looks fine to me XD
>>>
>>>
>>> Regards,
>>>
>>> Darren
>>>
>>>
>>> Christoph John 於 2020/10/13 下午 08:53 寫道:
>>>> 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

-- 
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