Re: [Quickfix-developers] [Quickfix-users] Performance

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 454-5900

There are a number of validation tunings you can set in the config file that
will have some impact on performance (less validation == faster)

http://quickfixengine.org/quickfix/doc/html/configuration.html

Data dictionary is required for parsing repeating groups.

--
Kenny Stone
Connamara Systems, LLC

On Wed, Sep 22, 2010 at 12:54 PM, Wilhelm Thomas <th...@cu...>wrote:

> QuickFIX Documentation:
> http://www.quickfixengine.org/quickfix/doc/html/index.html
> QuickFIX Support: http://www.quickfixengine.org/services.html
>
>
> Hello
>
> On the performance side here are some numbers, not really comparing 2
> version but just showing where the time is spent....
>
> setString, setField and their get counter part seem pretty slow:
>
> *Downward trace*
> *100.00 % setString - 66862* ms - 1443841 calls -
> QuickFix.Message.setString(Int32, String)*
> *  97.76 % mapSetString - 65364* ms - 1443841 calls - .mapSetString(Int32,
> String, FieldMap *)   (from QuickFix)*
> *    50.51 % convertString - 33774* ms - 1443841 calls -
> .convertString(basic_string<char, std::char_traits<char>,
> std::allocator<char> > *, String)   (from QuickFix)*
> *      16.75 %** Compare - 11201 ms **- 1443841 calls -
> System.String.Compare(String, String)*
> *      12.81 % createUnmanagedString - 8564 ms - 1443841 calls -
> .createUnmanagedString(String)   (from QuickFix)*
> *        10.10 %** StringToHGlobalAnsi - 6755 ms -** 1443841 calls -
> System.Runtime.InteropServices.Marshal.StringToHGlobalAnsi(String)*
> *      6.16 % FreeHGlobal - 4118 ms - 1443841 calls -
> System.Runtime.InteropServices.Marshal.FreeHGlobal(IntPtr)*
> *      1.91 % {ctor} - 1279 ms - 1443841 calls -
> .{ctor}(basic_string<char, std::char_traits<char>, std::allocator<char> > *,
> SByte *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *      1.84 % {ctor} - 1232 ms - 1443840 calls -
> .{ctor}(basic_string<char, std::char_traits<char>, std::allocator<char> > *,
> basic_string<char, std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *      1.77 % {dtor}* - 1186 ms - 1443840 calls -
> .{dtor}*(basic_string<char, std::char_traits<char>, std::allocator<char> >
> *)   (from std.basic_string<char,std::char_traits<char>,std::allocator<char>
> >)*
> *    28.02 % setField - 18736 ms - 1443840 calls - .setField(FieldMap *,
> FieldBase *, Boolean)   (from FIX.FieldMap)*
> *      16.82 % find - 11248 ms - 1443840 calls -
> .find(_Tree<std::_Tmap_traits<int, FIX::FieldBase, FIX::message_order,
> std::allocator<std::pair<int const, FIX::FieldBase> >, 1> > *, iterator *,
> Int32 *)   (from
> std._Tree<std::_Tmap_traits<int,FIX::FieldBase,FIX::message_order,std::allocator<std::pair<int
> const ,FIX::FieldBase> >,1> >)*
> *        11.85 % _Lbound - 7925 ms - 1443840 calls -
> ._Lbound(_Tree<std::_Tmap_traits<int, FIX::FieldBase, FIX::message_order,
> std::allocator<std::pair<int const, FIX::FieldBase> >, 1> > *, Int32 *)
> (from
> std._Tree<std::_Tmap_traits<int,FIX::FieldBase,FIX::message_order,std::allocator<std::pair<int
> const ,FIX::FieldBase> >,1> >)*
> *          5.76 % () - 3853 ms - 5775360 calls - .()(message_order *,
> Int32 *, Int32 *)   (from FIX.message_order)*
> *        1.40 % () - 936 ms - 1443840 calls - .()(message_order *, Int32
> *, Int32 *)   (from FIX.message_order)*
> *      7.47 % = - 4992 ms - 1443840 calls - .=(FieldBase *, FieldBase *)
> (from FIX.FieldBase)*
> *        2.87 % =* - 1919 ms - 2887680 calls - .=*(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *, basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *    4.57 % {dtor}* - 3058 ms - 4331520 calls -
> .{dtor}*(basic_string<char, std::char_traits<char>, std::allocator<char> >
> *)   (from std.basic_string<char,std::char_traits<char>,std::allocator<char>
> >)*
> *    1.61 % {ctor} - 1076 ms - 1443840 calls - .{ctor}(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *    1.49 % {ctor} - 998 ms - 1443840 calls - .{ctor}(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *, basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
>
>
> *Downward trace*
> *100.00 % **setField** - 18439 ms - 393141 calls -
> QuickFix.Message.setField(Int32, String)*
> *  97.29 % mapSetField - 17940 ms - 393141 calls - .mapSetField(Int32,
> String, FieldMap *)   (from QuickFix)*
> *    50.25 % convertString - 9266 ms - 393141 calls -
> .convertString(basic_string<char, std::char_traits<char>,
> std::allocator<char> > *, String)   (from QuickFix)*
> *      18.36 % Compare - 3385 ms - 393141 calls -
> System.String.Compare(String, String)*
> *      10.74 % createUnmanagedString - 1981 ms - 393141 calls -
> .createUnmanagedString(String)   (from QuickFix)*
> *        7.61 % StringToHGlobalAnsi - 1404 ms - 393141 calls -
> System.Runtime.InteropServices.Marshal.StringToHGlobalAnsi(String)*
> *      7.70 % FreeHGlobal - 1420 ms - 393141 calls -
> System.Runtime.InteropServices.Marshal.FreeHGlobal(IntPtr)*
> *      1.78 % {ctor} - 328 ms - 393141 calls - .{ctor}(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *, basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *      1.69 % {ctor} - 312 ms - 393141 calls - .{ctor}(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *, SByte *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *      0.93 % {dtor}* - 172 ms - 393141 calls -
> .{dtor}*(basic_string<char, std::char_traits<char>, std::allocator<char> >
> *)   (from std.basic_string<char,std::char_traits<char>,std::allocator<char>
> >)*
> *    40.69 % setField - 7504 ms - 393141 calls - .setField(FieldMap *,
> Int32, basic_string<char, std::char_traits<char>, std::allocator<char> > *)
>   (from FIX.FieldMap)*
> *      25.63 % setField - 4727 ms - 393141 calls - .setField(FieldMap *,
> FieldBase *, Boolean)   (from FIX.FieldMap)*
> *        14.97 % find - 2761 ms - 393141 calls -
> .find(_Tree<std::_Tmap_traits<int, FIX::FieldBase, FIX::message_order,
> std::allocator<std::pair<int const, FIX::FieldBase> >, 1> > *, iterator *,
> Int32 *)   (from
> std._Tree<std::_Tmap_traits<int,FIX::FieldBase,FIX::message_order,std::allocator<std::pair<int
> const ,FIX::FieldBase> >,1> >)*
> *          10.49 % _Lbound - 1934 ms - 393141 calls -
> ._Lbound(_Tree<std::_Tmap_traits<int, FIX::FieldBase, FIX::message_order,
> std::allocator<std::pair<int const, FIX::FieldBase> >, 1> > *, Int32 *)
> (from
> std._Tree<std::_Tmap_traits<int,FIX::FieldBase,FIX::message_order,std::allocator<std::pair<int
> const ,FIX::FieldBase> >,1> >)*
> *          1.02 % () - 187 ms - 393141 calls - .()(message_order *, Int32
> *, Int32 *)   (from FIX.message_order)*
> *        7.02 % = - 1295 ms - 393141 calls - .=(FieldBase *, FieldBase *)
>   (from FIX.FieldBase)*
> *          2.45 % =* - 452 ms - 786282 calls - .=*(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *, basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *      3.05 % {dtor}* - 562 ms - 786282 calls -
> .{dtor}*(basic_string<char, std::char_traits<char>, std::allocator<char> >
> *)   (from std.basic_string<char,std::char_traits<char>,std::allocator<char>
> >)*
> *      1.61 % {ctor} - 296 ms - 393141 calls - .{ctor}(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *, basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *      1.61 % {ctor} - 296 ms - 393141 calls - .{ctor}(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
> *    0.76 % {dtor}* - 140 ms - 393141 calls - .{dtor}*(basic_string<char,
> std::char_traits<char>, std::allocator<char> > *)   (from
> std.basic_string<char,std::char_traits<char>,std::allocator<char> >)*
>
>
> The destructor also, may be there is a way to use a pool of messages
> instead of really disposing them?
> *
> *
> *Upward trace*
> *6.89 % {**dtor**}* - 19266 ms - 796435 calls - .{dtor}*(FieldMap *)
> (from FIX.FieldMap)*
> *  4.64 % __vecDelDtor - 12979 of 19266 ms - 443321 of 796435 calls -
> .__vecDelDtor(FieldMap *, UInt32)   (from FIX.FieldMap)*
> *    2.61 % {dtor}* - 7301 of 19266 ms - 221660 of 796435 calls -
> .{dtor}*(FieldMap *)   (from FIX.FieldMap)*
> *      2.61 % {dtor} - 7301 of 19266 ms - 221660 of 796435 calls -
> .{dtor}(Message *)   (from FIX.Message)*
> *        2.61 % __vecDelDtor - 7301 of 19266 ms - 221660 of 796435 calls -
> .__vecDelDtor(Message *, UInt32)   (from FIX.Message)*
> *          2.61 % ?function?* - 7301 of 19266 ms - 221660 of 796435 calls
> - ?class?.?function?*(?parameters?)*
> *            2.61 % **Dispose **- 7301 of 19266 ms - 221660 of 796435
> calls - QuickFix.Message.Dispose()*
> *              1.70 % Finalize - 4742 of 19266 ms - 111139 of 796435 calls
> - QuickFix.Message.Finalize()*
> *              0.91 % fromApp - 2558 of 19266 ms - 110457 of 796435 calls
> - POLR.Gateway.Application_Initiator.fromApp(Message, SessionID)*
> *              0.00 % DisconnectInstrumentIfNeeded - 0 of 19266 ms - 16 of
> 796435 calls - POLR.Gateway.PG_Util.DisconnectInstrumentIfNeeded(Message,
> InstrumentID)*
> *              0.00 % AcceptorFromApp_InitiatorToApp - 0 of 19266 ms - 48
> of 796435 calls -
> POLR.Gateway.Application_Acceptor.AcceptorFromApp_InitiatorToApp(Message,
> SessionID)*
> *    0.96 % =* - 2699 of 19266 ms - 111140 of 796435 calls - .=*(FieldMap
> *, FieldMap *)   (from FIX.FieldMap)*
> *    0.76 % Thread #6673184 - 2137 of 19266 ms - 76059 of 796435 calls*
> *    0.09 % Thread #6646824 - 250 of 19266 ms - 13712 of 796435 calls*
> *    0.00 % Thread #6648528 - 0 of 19266 ms - 24 of 796435 calls*
> *  1.40 % {dtor} - 3916 of 19266 ms - 242571 of 796435 calls -
> .{dtor}(Message *)   (from FIX.Message)*
> *  0.85 % {dtor} - 2371 of 19266 ms - 110543 of 796435 calls -
> .{dtor}(Group *)   (from FIX.Group)*
>
>
> (please do not compare the timeframe in those 2 subtrees, just look at what
> functions cost a lot)
> Something to note from other tests setString is faster than setField but
> getField is way faster than getString
> I there faster other functions that I could use? thanks
>
>
> Here is another one very expensive
> *UpwardTrace*
> *37.22 % **=*** - 104131 ms - 364156 calls - .=*(FieldMap *, FieldMap *)
> (from FIX.FieldMap)*
> *  37.22 % = - 104131 of 104131 ms - 364134 of 364156 calls - .=(Message
> *, Message *)   (from FIX.Message)*
> *    25.48 % **setUnmanaged **- 71277 of 104131 ms - 242568 of 364156
> calls - QuickFix.Message.setUnmanaged(Message *)*
> *      25.48 % create - 71277 of 104131 ms - 242568 of 364156 calls -
> .create(Application *, Message *)   (from Application)*
> *        12.85 % toApp - 35958 of 104131 ms - 118278 of 364156 calls -
> .toApp(Application *, Message *, SessionID *)   (from Application)*
> *          12.85 % sendToTarget* - 35958 of 104131 ms - 118278 of 364156
> calls - .sendToTarget*(Message *, SenderCompID *, TargetCompID *,
> basic_string<char, std::char_traits<char>, std::allocator<char> > *)   (from
> FIX.Session)*
> *            12.85 % sendToTarget - 35958 of 104131 ms - 118278 of 364156
> calls - QuickFix.Session.sendToTarget(Message, String, String)*
> *              12.83 % InitiatorFromApp_AcceptorToApp - 35896 of 104131 ms
> - 117762 of 364156 calls -
> POLR.Gateway.Application_Initiator.InitiatorFromApp_AcceptorToApp(Message,
> SessionID)*
> *              0.02 % onLogon - 47 of 104131 ms - 480 of 364156 calls -
> POLR.Gateway.Application_Initiator.onLogon(SessionID)*
> *              0.01 % AcceptorFromApp_InitiatorToApp - 16 of 104131 ms -
> 27 of 364156 calls -
> POLR.Gateway.Application_Acceptor.AcceptorFromApp_InitiatorToApp(Message,
> SessionID)*
> *              0.00 % ReconnectToInstrumentsFeed - 0 of 104131 ms - 3 of
> 364156 calls - POLR.Gateway.PG_Util.ReconnectToInstrumentsFeed()*
> *              0.00 % DisconnectInstrumentIfNeeded - 0 of 104131 ms - 6 of
> 364156 calls - POLR.Gateway.PG_Util.DisconnectInstrumentIfNeeded(Message,
> InstrumentID)*
> *        12.59 % fromApp - 35209 of 104131 ms - 117813 of 364156 calls -
> .fromApp(Application *, Message *, SessionID *)   (from Application)*
> *        0.02 % toAdmin - 62 of 104131 ms - 3288 of 364156 calls -
> .toAdmin(Application *, Message *, SessionID *)   (from Application)*
> *        0.02 % fromAdmin - 47 of 104131 ms - 3189 of 364156 calls -
> .fromAdmin(Application *, Message *, SessionID *)   (from Application)*
> *    11.73 % toApp - 32823 of 104131 ms - 118278 of 364156 calls -
> .toApp(Application *, Message *, SessionID *)   (from Application)*
> *    0.01 % toAdmin - 31 of 104131 ms - 3288 of 364156 calls -
> .toAdmin(Application *, Message *, SessionID *)   (from Application)*
> *  0.00 % getGroup - 0 of 104131 ms - 22 of 364156 calls -
> .getGroup(FieldMap *, Int32, Int32, FieldMap *)   (from FIX.FieldMap)*
>
> Here is a set from a long test of the function that take most of the time
>
>    1. *FieldMap * .=*(FieldMap *, FieldMap *)   (from FIX.FieldMap)*
>    2. *message_order * .=*(message_order *, message_order *)   (from
>    FIX.message_order)*
>    3. *Void .delete[]*(Void *)*
>    4. *Void ._Adopt(_Iterator_base *, _Container_base_secure *)   (from
>    std._Iterator_base)*
>    5. *Void .{dtor}*(FieldMap *)   (from FIX.FieldMap)*
>    6. *Message .create(Application *, Message *)   (from Application)*
>    7. *Group QuickFix.Message.getGroup(UInt32, Group)*
>    8. *String QuickFix.Group.getField(Int32)*
>    9. *MDEntrySize
>    QuickFix42.MarketDataIncrementalRefresh.NoMDEntries.getMDEntrySize()*
>    10. *MDEntryPx
>    QuickFix42.MarketDataIncrementalRefresh.NoMDEntries.getMDEntryPx()*
>    11. *MDEntryType
>    QuickFix42.MarketDataIncrementalRefresh.NoMDEntries.getMDEntryType()*
>    12. *NoMDEntries
>    QuickFix42.MarketDataIncrementalRefresh.getNoMDEntries()*
>    13. *MDEntryPositionNo
>    QuickFix42.MarketDataIncrementalRefresh.NoMDEntries.getMDEntryPositionNo()
>    *
>    14. *MDUpdateAction
>    QuickFix42.MarketDataIncrementalRefresh.NoMDEntries.getMDUpdateAction()
>    *
>    15. *Void QuickFix42.MarketDataIncrementalRefresh.NoMDEntries..ctor()*
>    16. *UtcTimeStamp * .getCreationTime(MessageStore *, UtcTimeStamp *)
>    (from MessageStore)*
>    17. *MDReqID QuickFix42.MarketDataIncrementalRefresh.getMDReqID()*
>    18. *Boolean QuickFix42.MarketDataIncrementalRefresh.isSetNoMDEntries()
>    *
>    19. *Void System.Windows.Forms.TextBoxBase.AppendText(String)*
>    20. *Object System.Delegate.DynamicInvokeImpl(Object [])*
>
>
>
> Something else:
> Is there a way to totally disable the Dictionary check even with repeating
> group, like I have 2 machines that I control, I already run them with the
> dictionary enable and everything is fine, now I want to run them without the
> dictionary check as I know those machines won't change.....
>
> Thanks
>
> Wil
>
> On Wed, Jun 23, 2010 at 5:48 PM, Hei Chan <str...@ya...>wrote:
>
>> QuickFIX Documentation:
>> http://www.quickfixengine.org/quickfix/doc/html/index.html
>> QuickFIX Support: http://www.quickfixengine.org/services.html
>>
>> Hi,
>>
>> I just wonder whether anyone has compared the performance of the latest
>> quickfix/C++ 1.13.3 with 1.12.4.
>>
>> With 1.12.4 (with a small modification -- added support to set send buffer
>> size), it seems to be faster than 1.13.3 during my ping test:
>> - A server logs the timestamp and sends me a "ping" FIX message.
>> - My server replies and the server logs the timestamp when it receives my
>> reply.
>>
>> The ping time increased from 2.2275ms to 2.65833ms out of 120 pings within
>> an hour.
>>
>> Although I understand that it is not a very accurate measure (since the
>> time isn't logged in microsecond and # of samples are few), it roughly
>> indicates some performance degradation.
>>
>> I am not saying that there must be a performance degradation...
>>
>> But I am curious whether anyone on the list can share some stats...
>>
>> Thanks in advance.
>>
>>
>> Cheers,
>> Hei
>>
>>
>>
>>
>>
>>
>> ------------------------------------------------------------------------------
>> ThinkGeek and WIRED's GeekDad team up for the Ultimate
>> GeekDad Father's Day Giveaway. ONE MASSIVE PRIZE to the
>> lucky parental unit.  See the prize list and enter to win:
>> http://p.sf.net/sfu/thinkgeek-promo
>> _______________________________________________
>> Quickfix-users mailing list
>> Qui...@li...
>> https://lists.sourceforge.net/lists/listinfo/quickfix-users
>>
>
>
>
> ------------------------------------------------------------------------------
> Start uncovering the many advantages of virtual appliances
> and start using them to simplify application deployment and
> accelerate your shift to cloud computing.
> http://p.sf.net/sfu/novell-sfdev2dev
> _______________________________________________
> Quickfix-developers mailing list
> Qui...@li...
> https://lists.sourceforge.net/lists/listinfo/quickfix-developers
>