Azure linux - Incorrect BeginString (FIX.4.4) - Sometimes when receiving simultenuous messages of type (35=8 and 150=F)

[ahossny]

Technical Issue Description:

Our FIX Engine intermittently disconnects due to an error message stating “Incorrect BeginString (FIX.4.4)”, even though the BeginString field is received correctly and shows no formatting or content issues upon inspection. As a result, our FIX server experiences temporary disconnections during message handling.

We are currently using QuickFIX/n.Core version 1.13.1, and our implementation functions exclusively as a FIX initiator (not an acceptor).

Based on our internal analysis and logs, this issue appears to occurs periodically under high message throughput, specifically when multiple simultaneous messagss are received at nearly the same time. What makes this behavior particularly unusual is that it tends to happen during the reception of certain message types — specifically messages with the following criteria:

MsgType (35) = 8 (Execution Report)

ExecType (150) = F (Trade Cancel)

Although the root cause remains unclear, our theory is that when multiple messages of this type are received concurrently, a race condition or message parsing conflict may occur within the QuickFIX/n engine, resulting in the temporary “Incorrect BeginString” error and subsequent disconnects.

Here is all information needed to replicate our issue:

Incoming Message:
8=FIX.4.4�9=383�35=8�34=5�49=FIXBRIDGETT�52=20250904-09:01:09.727�56=EVV-VMD-TST�128=VDM�1=786381253695�6=102.34�11=ORD.59.0�14=144.099837�15=CHF�17=OTR252470000231�22=4�31=102.34�32=1.40805�37=AUF250825-13328158�39=1�40=1�48=CH03481111111�54=D�55=CH0348067338�59=1�60=20250903-09:00:19.000�64=20250905�75=20250903�150=F�151=0.000163�152=144.1000000�423=2�526=AUF250825-13328158�528=R�10=116�

Outgoing Message:
8=FIX.4.4�35=5�34=2�49=EVV-VMD-TST�52=20250904-09:01:09.791�56=FIXBRIDGETT�58=Incorrect BeginString (FIX.4.4)�

Initiator.cfg :

[DEFAULT]
ConnectionType=initiator
ReconnectInterval=30
FileStorePath=store
FileLogPath=log
StartTime=00:00:00
EndTime=23:59:59
UseDataDictionary=Y
DataDictionary=specs/FIX44.xml
SocketConnectHost=1.1.1.1
SocketConnectPort=8080
ResetOnLogon=Y
ResetOnDisconnect=Y

[SESSION]
BeginString=FIX.4.4
SenderCompID=EVV-VMD-TST
TargetCompID=FIXBRIDGETT
HeartBtInt=30

[gbirchmeier]

Your event log should have a line that looks something like this:

20251022-22:05:32.014 : QuickFix.UnsupportedVersion: Incorrect BeginString (FIX.4.1)
   at QuickFix.Session.Next(MessageBuilder msgBuilder) in /Users/grantb/fork/quickfixn/QuickFIXn/Session.cs:line 593

Can you send me that message+stacktrace? The Exception can be thrown from 3 different places, and it would be very helpful to know which one.

[gbirchmeier]

@ahossny, any chance you can follow up? If I can't get that stacktrace, I probably won't investigate this at all.

[gbirchmeier]

Closing because I can't pursue without further follow-up from the reporter.

[yumyumsun]

I've run into this problem too. Wondering if it's been fixed yet?

[gbirchmeier]

If someone who is seeing the problem can get me a stacktrace as I requested above, them maybe I'll have a hope of fixing it. I can't fix something I can't see.

[yumyumsun]

If someone who is seeing the problem can get me a stacktrace as I requested above, them maybe I'll have a hope of fixing it. I can't fix something I can't see.

@gbirchmeier hi，I can only get this fix event and message， and I'm using QuickFIX.Core 1.11.2 with .net core 6.0。It's work in windows， but not in linux。

Fix Event:
20251223-14:09:14.824 : Session reset: ResetOnLogon
20251223-14:09:14.909 : Session reset: ResetSeqNumFlag
20251223-14:09:14.912 : Initiated logon request
20251223-14:09:17.464 : Sequence numbers reset due to ResetSeqNumFlag=Y
20251223-14:09:17.483 : Received logon
20251223-14:09:55.124 : QuickFix.UnsupportedVersion: Incorrect BeginString (FIX.4.4)
at QuickFix.DefaultMessageFactory.Create(String beginString, String msgType, Int32 groupCounterTag)
at QuickFix.Message.SetGroup(StringField grpNoFld, String msgstr, Int32 pos, FieldMap fieldMap, IGroupSpec groupDD, DataDictionary sessionDataDictionary, DataDictionary appDD, IMessageFactory msgFactory)
at QuickFix.Message.FromString(String msgstr, Boolean validate, DataDictionary sessionDD, DataDictionary appDD, IMessageFactory msgFactory, Boolean ignoreBody)
at QuickFix.Message.FromString(String msgstr, Boolean validate, DataDictionary sessionDD, DataDictionary appDD, IMessageFactory msgFactory)
at QuickFix.MessageBuilder.Build()
at QuickFix.Session.Next(MessageBuilder msgBuilder)
20251223-14:09:55.341 : Received logout response
20251223-14:09:55.342 : Session FIX.4.4:SRCUAT->DSTUAT disconnecting: Received logout response

FixMessage:
20251223-14:09:54.299 : 8=FIX.4.4�9=359�35=D�34=4�49=SRCUAT�52=20251223-14:09:54.277�56=DSTUAT�11=11138765�22=108�38=100�40=1�44=0�48=PDD US�54=1�58=[GTC]�59=6�126=20251224-23:59:59�432=20251224�6374=105652713�7751=1�9894=2�9896=4117�9998=25080219�78=1�79=RD0001�80=100�661=100�21053=3�21054=FLOW_CONTROL_FLAG�21055=1�21054=CHECK_PRETRADE_COMPLIANCE�21055=Y�21054=LIST_PROCESSING_LEVEL�21055=LIST�10=196� 20251223-14:09:55.116 : 8=FIX.4.4�9=1421�35=8�49=DSTUAT�56=SRCUAT�34=4�52=20251223-14:09:55�37=-1�11=11138765�17=0�150=8�39=8�103=702�48=PDD US�22=108�9894=2�54=1�38=100.000000�40=1�44=0.0000000000�59=6�151=100.000000�14=0.000000�6=0.0000000000�58=Override Reason Missing�9896=4117�9998=25080219�6374=105652713�21053=5�21054=FLOW_CONTROL_FLAG�21055=1�21054=CHECK_PRETRADE_COMPLIANCE�21055=Y�21054=LIST_PROCESSING_LEVEL�21055=LIST�21054=COMPLIANCE_VIOLATION_DETAIL�21055=<?xml version="1.0"?><pretrade><violation Index="0" Severity="VMGR Approval" Security="us7223041028" Ruleshort="DEV008 " Rulelong="DEV008 " Room="-63168539966.000000" MktVal="1427417668873.572021" Value="63168539966.000000" ToOut="-63168539966.000000" Limit="0.000000" Unit="POSITION" Type="A" Violator="RD0001" Note="true" RuleNum="11007" ScopeNum="218" ScopeType="1" ScopeCode="RD0001" BrokerNum="-1" BrokerType="0" BrokerName="" Status="4" PriceType="1" Hidden="0" Curr="CNY" cusip1="60945074" cusip2="9000" cusip3="541401120" flag="2" sflag="2" bktMktVal="20583307712.941803" bktVal="20583307712.941803" bktDenom="1.000000" bktLimit="10000000.000000" bktRoom="-20573307712.941803" bktToOut="-20573307712.941803" ticker="PDD US" violId="-1807686135" SettleDate="-1" /><summary state="VMGR Approval" numbroken="1" datafile="/tstmp/f4117query_data.13687.3026947.bin" perSecVmgr="0" SeqNo="13687" ></summary></pretrade>�21054=COMPLIANCE_STATUS�21055=2�10=229� 20251223-14:09:55.127 : 8=FIX.4.4�9=92�35=5�34=5�49=SRCUAT�52=20251223-14:09:55.125�56=DSTUAT�58=Incorrect BeginString (FIX.4.4)�10=241�

[gbirchmeier]

Awesome, that's the stacktrace I want to see!

I'm reopening the issue. After the holidays I'll find some time to investigate this.

Can you give me the timespan of logs that start a few messages before this and ending a few messages after?

[yumyumsun]

Awesome, that's the stacktrace I want to see!

I'm reopening the issue. After the holidays I'll find some time to investigate this.

Can you give me the timespan of logs that start a few messages before this and ending a few messages after?

@gbirchmeier Thanks。 I Hope the message bellow will help you.

20251223-14:09:14.094 : Created session
20251223-14:09:14.103 : Connecting to 160.1.1.1 on port 8228
20251223-14:09:14.819 : Connection succeeded
20251223-14:09:14.824 : Session reset: ResetOnLogon
20251223-14:09:14.909 : Session reset: ResetSeqNumFlag
20251223-14:09:14.912 : Initiated logon request
20251223-14:09:17.464 : Sequence numbers reset due to ResetSeqNumFlag=Y
20251223-14:09:17.483 : Received logon
20251223-14:09:55.124 : QuickFix.UnsupportedVersion: Incorrect BeginString (FIX.4.4)
at QuickFix.DefaultMessageFactory.Create(String beginString, String msgType, Int32 groupCounterTag)
at QuickFix.Message.SetGroup(StringField grpNoFld, String msgstr, Int32 pos, FieldMap fieldMap, IGroupSpec groupDD, DataDictionary sessionDataDictionary, DataDictionary appDD, IMessageFactory msgFactory)
at QuickFix.Message.FromString(String msgstr, Boolean validate, DataDictionary sessionDD, DataDictionary appDD, IMessageFactory msgFactory, Boolean ignoreBody)
at QuickFix.Message.FromString(String msgstr, Boolean validate, DataDictionary sessionDD, DataDictionary appDD, IMessageFactory msgFactory)
at QuickFix.MessageBuilder.Build()
at QuickFix.Session.Next(MessageBuilder msgBuilder)
20251223-14:09:55.341 : Received logout response
20251223-14:09:55.342 : Session FIX.4.4:SRCUAT->DSTUAT disconnecting: Received logout response
20251223-14:09:56.112 : Connecting to 160.1.1.1 on port 8228
20251223-14:09:56.788 : Connection succeeded
20251223-14:09:56.790 : Session reset: ResetOnLogon
20251223-14:09:56.791 : Session reset: ResetSeqNumFlag
20251223-14:09:56.792 : Initiated logon request
20251223-14:09:59.519 : Sequence numbers reset due to ResetSeqNumFlag=Y
20251223-14:09:59.520 : Received logon

20251223-14:09:14.911 : 8=FIX.4.4�9=75�35=A�34=1�49=SRCUAT�52=20251223-14:09:14.829�56=DSTUAT�98=0�108=60�141=Y�10=093� 20251223-14:09:17.446 : 8=FIX.4.4�9=0077�35=A�49=DSTUAT�56=SRCUAT�34=1�52=20251223-14:09:17�98=0�108=60�141=Y�789=2�10=009� 20251223-14:09:17.486 : 8=FIX.4.4�9=0081�35=1�49=DSTUAT�56=SRCUAT�34=2�52=20251223-14:09:17�112=L.0001.0002.0002.140917�10=229� 20251223-14:09:17.490 : 8=FIX.4.4�9=85�35=0�34=2�49=SRCUAT�52=20251223-14:09:17.490�56=DSTUAT�112=L.0001.0002.0002.140917�10=083� 20251223-14:09:17.701 : 8=FIX.4.4�9=0081�35=1�49=DSTUAT�56=SRCUAT�34=3�52=20251223-14:09:17�112=A.0003.0003.0003.140917�10=223� 20251223-14:09:17.702 : 8=FIX.4.4�9=85�35=0�34=3�49=SRCUAT�52=20251223-14:09:17.702�56=DSTUAT�112=A.0003.0003.0003.140917�10=073� 20251223-14:09:54.299 : 8=FIX.4.4�9=359�35=D�34=4�49=SRCUAT�52=20251223-14:09:54.277�56=DSTUAT�11=11138765�22=108�38=100�40=1�44=0�48=PDD US�54=1�58=[GTC]�59=6�126=20251224-23:59:59�432=20251224�6374=105652713�7751=1�9894=2�9896=4117�9998=25080219�78=1�79=RD0001�80=100�661=100�21053=3�21054=FLOW_CONTROL_FLAG�21055=1�21054=CHECK_PRETRADE_COMPLIANCE�21055=Y�21054=LIST_PROCESSING_LEVEL�21055=LIST�10=196� 20251223-14:09:55.116 : 8=FIX.4.4�9=1421�35=8�49=DSTUAT�56=SRCUAT�34=4�52=20251223-14:09:55�37=-1�11=11138765�17=0�150=8�39=8�103=702�48=PDD US�22=108�9894=2�54=1�38=100.000000�40=1�44=0.0000000000�59=6�151=100.000000�14=0.000000�6=0.0000000000�58=Override Reason Missing�9896=4117�9998=25080219�6374=105652713�21053=5�21054=FLOW_CONTROL_FLAG�21055=1�21054=CHECK_PRETRADE_COMPLIANCE�21055=Y�21054=LIST_PROCESSING_LEVEL�21055=LIST�21054=COMPLIANCE_VIOLATION_DETAIL�21055=<?xml version="1.0"?><pretrade><violation Index="0" Severity="VMGR Approval" Security="us7223041028" Ruleshort="DEV008 " Rulelong="DEV008 " Room="-63168539966.000000" MktVal="1427417668873.572021" Value="63168539966.000000" ToOut="-63168539966.000000" Limit="0.000000" Unit="POSITION" Type="A" Violator="RD0001" Note="true" RuleNum="11007" ScopeNum="218" ScopeType="1" ScopeCode="RD0001" BrokerNum="-1" BrokerType="0" BrokerName="" Status="4" PriceType="1" Hidden="0" Curr="CNY" cusip1="60945074" cusip2="9000" cusip3="541401120" flag="2" sflag="2" bktMktVal="20583307712.941803" bktVal="20583307712.941803" bktDenom="1.000000" bktLimit="10000000.000000" bktRoom="-20573307712.941803" bktToOut="-20573307712.941803" ticker="PDD US" violId="-1807686135" SettleDate="-1" /><summary state="VMGR Approval" numbroken="1" datafile="/tstmp/f4117query_data.13687.3026947.bin" perSecVmgr="0" SeqNo="13687" ></summary></pretrade>�21054=COMPLIANCE_STATUS�21055=2�10=229� 20251223-14:09:55.127 : 8=FIX.4.4�9=92�35=5�34=5�49=SRCUAT�52=20251223-14:09:55.125�56=DSTUAT�58=Incorrect BeginString (FIX.4.4)�10=241� 20251223-14:09:55.338 : 8=FIX.4.4�9=0077�35=5�49=DSTUAT�56=SRCUAT�34=5�52=20251223-14:09:55�58=Logout confirmed (6)�10=069� 20251223-14:09:56.791 : 8=FIX.4.4�9=75�35=A�34=1�49=SRCUAT�52=20251223-14:09:56.790�56=DSTUAT�98=0�108=60�141=Y�10=096� 20251223-14:09:59.519 : 8=FIX.4.4�9=0077�35=A�49=DSTUAT�56=SRCUAT�34=1�52=20251223-14:09:59�98=0�108=60�141=Y�789=2�10=015� 20251223-14:09:59.520 : 8=FIX.4.4�9=0081�35=1�49=DSTUAT�56=SRCUAT�34=2�52=20251223-14:09:59�112=L.0001.0002.0002.140959�10=241� 20251223-14:09:59.521 : 8=FIX.4.4�9=85�35=0�34=2�49=SRCUAT�52=20251223-14:09:59.521�56=DSTUAT�112=L.0001.0002.0002.140959�10=090� 20251223-14:09:59.742 : 8=FIX.4.4�9=0081�35=1�49=DSTUAT�56=SRCUAT�34=3�52=20251223-14:09:59�112=A.0003.0003.0003.140959�10=235� 20251223-14:09:59.743 : 8=FIX.4.4�9=85�35=0�34=3�49=SRCUAT�52=20251223-14:09:59.743�56=DSTUAT�112=A.0003.0003.0003.140959�10=090�

[gbirchmeier]

@yumyumsun that should help, thank you!

[yumyumsun]

@gbirchmeier I've already figured out where my problem lies. I failed to add the package dependency for FIX4.4（QuickFIXn.FIX4.4） when packaging the application in the Linux. I think my problem has been solved now. Thanks a lot!

[gbirchmeier]

@yumyumsun Do you see any similarity between your situation and that of the guy that submitted this issue? (attn @ahossny )

I'm hoping these two issues are the same.

(Either way, I think I should try to improve the error message here.)

[yumyumsun]

@gbirchmeier I Think may be the same problem. It will help if the error message shows FIX Message Factory is missing.