Bug 80955 - XLS export perf. problem
Summary: XLS export perf. problem
Status: RESOLVED FIXED
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: filters and storage (show other bugs)
Version:
(earliest affected)
4.4.0.0.alpha0+ Master
Hardware: Other All
: medium major
Assignee: David Tardon
URL:
Whiteboard: target:4.4.0
Keywords: regression
Depends on:
Blocks: mab4.4
  Show dependency treegraph
 
Reported: 2014-07-05 19:19 UTC by Michael Meeks
Modified: 2014-07-07 17:04 UTC (History)
3 users (show)

See Also:
Crash report or crash signature:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Michael Meeks 2014-07-05 19:19:36 UTC
It seems (from the callgrind regression tests) that we have a significant performance regression on master / 4.4.

Unfortunately this occurred during the period the performance testing was disabled for some days - also it is not reproducible locally either - which is a doubly royal pain. It seems that:

2014-06-25 14:01:19+02:00 db960181fe63efa28c2370505b2074d1db485e07
2014-07-03 20:42:10+02:00 628520684fafb1bcbf184ab8ed2f755c6ae9ee52
2014-07-04 14:09:44+02:00 dfeef9e970a69c5736a54619b96607899c57e9a1

In this range we went from:

11086
1383415
624715

pseudo-cycles converting 032_numbers.xls-convert - which seems a very significant jump in time - 2x orders of magnitude.

In this time range though the most likely candidates also look like being my fault ;-) perhaps:

	commit e820df579d9be4c1f9bb1ad8f02a8072c69b52da
	Author: Michael Meeks <michael.meeks@collabora.com>
	Date:   Sat Jun 28 09:36:20 2014 +0100

	    filters: Batch fetch filter config properties.

Or the patch that changes the order of configmgr keys - so that they are no longer sorted in the same order [ of course I'd -like- to think that filter configuration is independent of key sort order but ... this is the filters code ].

http://dev-builds.libreoffice.org/callgrind_report/traces/

shows that all the time (some thousand trillion cycles) is spent in the XSLT code - which (of course) shouldn't be triggered for this command:

cmd:  /home/buildslave/build/instdir/program/soffice.bin --splash-pipe=0 --headless --convert-to xls --outdir tmp /home/buildslave/source/test-files/loperf/032_numbers.xls

Converting XLS to XLS should use native filters in each direction. Kohei - you were/are the next last person brave enough to touch the filter code =) any advice here ?
Comment 1 Michael Meeks 2014-07-07 10:31:39 UTC
Seems its a filter selection problem; cf. aFilterName in this trace:

#0  SfxObjectShell::SaveTo_Impl (this=this@entry=0x101dbe0, rMedium=..., pSet=pSet@entry=0x0)
    at /home/buildslave/source/libo-core/sfx2/source/doc/objstor.cxx:1124
#1  0x00007ffff562e8aa in SfxObjectShell::PreDoSaveAs_Impl (this=this@entry=0x101dbe0, 
    rFileName="file:///home/buildslave/build/instdir/program/tmp/032_numbers.xls", aFilterName="MS Excel 2003 XML", pParams=0x137bab0, 
    pParams@entry=0x137b320) at /home/buildslave/source/libo-core/sfx2/source/doc/objstor.cxx:2830
#2  0x00007ffff562f1cd in SfxObjectShell::CommonSaveAs_Impl (this=this@entry=0x101dbe0, aURL=..., aFilterName="MS Excel 2003 XML", 
    aParams=aParams@entry=0x137b320) at /home/buildslave/source/libo-core/sfx2/source/doc/objstor.cxx:2689
#3  0x00007ffff5619550 in SfxObjectShell::APISaveAs_Impl (this=0x101dbe0, 
    aFileName="file:///home/buildslave/build/instdir/program/tmp/032_numbers.xls", aParams=aParams@entry=0x137b320)
    at /home/buildslave/source/libo-core/sfx2/source/doc/objserv.cxx:314
#4  0x00007ffff5663807 in SfxBaseModel::impl_store (this=this@entry=0x7fffe1d92b30, 
    sURL="file:///home/buildslave/build/instdir/program/tmp/032_numbers.xls", seqArguments=uno::Sequence of length 2 = {...}, 
    bSaveTo=bSaveTo@entry=true) at /home/buildslave/source/libo-core/sfx2/source/doc/sfxbasemodel.cxx:3064
#5  0x00007ffff5664f7d in SfxBaseModel::storeToURL (this=0x7fffe1d92b30, 
    rURL="file:///home/buildslave/build/instdir/program/tmp/032_numbers.xls", rArgs=uno::Sequence of length 2 = {...})
    at /home/buildslave/source/libo-core/sfx2/source/doc/sfxbasemodel.cxx:1701
#6  0x00007ffff574afbb in desktop::DispatchWatcher::executeDispatchRequests (this=0x7fffe3d65a90, 
    aDispatchRequestsList=std::vector of length 1, capacity 1 = {...}, bNoTerminate=<optimized out>)
    at /home/buildslave/source/libo-core/desktop/source/app/dispatchwatcher.cxx:495
#7  0x00007ffff5751982 in desktop::OfficeIPCThread::ExecuteCmdLineRequests (aRequest=...)
    at /home/buildslave/source/libo-core/desktop/source/app/officeipcthread.cxx:1060
#8  0x00007ffff5737612 in desktop::Desktop::OpenClients () at /home/buildslave/source/libo-core/desktop/source/app/app.cxx:2442
#9  0x00007ffff5738350 in desktop::Desktop::OpenClients_Impl (this=0x7fffffffdc60)
    at /home/buildslave/source/libo-core/desktop/source/app/app.cxx:1975
#10 0x00007ffff63b844a in Call (pCaller=<optimized out>, this=<optimized out>) at /home/buildslave/source/libo-core/include/tools/link.hxx:139
#11 ImplHandleUserEvent (pSVEvent=0xf70d70) at /home/buildslave/source/libo-core/vcl/source/window/winproc.cxx:1921
#12 ImplWindowFrameProc (pWindow=<optimized out>, nEvent=<optimized out>, pEvent=0xf70d70)
    at /home/buildslave/source/libo-core/vcl/source/window/winproc.cxx:2492
#13 0x00007ffff665d926 in CallCallback (pEvent=<optimized out>, nEvent=<optimized out>, this=<optimized out>)
    at /home/buildslave/source/libo-core/vcl/inc/salframe.hxx:243
#14 SvpSalInstance::Yield (this=0x6c5130, bWait=<optimized out>, bHandleAllCurrentEvents=<optimized out>)
    at /home/buildslave/source/libo-core/vcl/headless/svpinst.cxx:293
#15 0x00007ffff6585b8e in ImplYield (i_bAllEvents=false, i_bWait=true) at /home/buildslave/source/libo-core/vcl/source/app/svapp.cxx:360
#16 Application::Yield () at /home/buildslave/source/libo-core/vcl/source/app/svapp.cxx:392
Comment 2 Michael Meeks 2014-07-07 10:38:14 UTC
#6  0x00007ffff574afbb in desktop::DispatchWatcher::executeDispatchRequests (this=0x7fffe3d65a90, 
    aDispatchRequestsList=std::vector of length 1, capacity 1 = {...}, bNoTerminate=<optimized out>)
    at /home/buildslave/source/libo-core/desktop/source/app/dispatchwatcher.cxx:495
(gdb) p conversionProperties
$8 = uno::Sequence of length 2 = {{Name = "Overwrite", Handle = 0, Value = uno::Any 1 '\001', 
    State = com::sun::star::beans::PropertyState_DIRECT_VALUE}, {Name = "FilterName", Handle = 0, Value = uno::Any "MS Excel 2003 XML", 
    State = com::sun::star::beans::PropertyState_DIRECT_VALUE}}
...

Seems like dispatchwatcher.cxx's:

static OUString impl_GuessFilter( const OUString& aUrlIn, const OUString& aUrlOut )
{
    /* aAppl can also be set to Factory like scalc, swriter... */
    OUString aAppl;
    aAppl = impl_GetFilterFromExt( aUrlIn, SFX_FILTER_IMPORT, aAppl );
    return  impl_GetFilterFromExt( aUrlOut, SFX_FILTER_EXPORT, aAppl );
}

is getting a sillier than expected results =)
Comment 3 Michael Meeks 2014-07-07 10:51:33 UTC
Looks like the problem is in the ordering of filters here:

#0  filter::config::FilterCache::detectFlatForURL (this=0xf74d30, aURL=..., rFlatTypes=empty std::list)
    at /home/buildslave/source/libo-core/filter/source/config/cache/filtercache.cxx:744
744             for (OUStringList::const_iterator pIt  = rTypesForExtension.begin();
...
(gdb) p rTypesForExtension
$23 = (const filter::config::OUStringList &) @0xf91408: {<std::vector<rtl::OUString, std::allocator<rtl::OUString> >> = std::vector of length 5, capacity 8 = {"calc_MS_Excel_2003_XML", "calc_MS_Excel_5095", "calc_MS_Excel_95", "calc_MS_Excel_40", "calc_MS_Excel_97"}, <No data fields>}

Of course - it would be hard to believe that this ordering is based on some un-controlled / random sort order - surely !?
Comment 4 Maxim Monastirsky 2014-07-07 11:05:14 UTC
@Michael: There is a similar issue in Bug 78989. It seems to return different results on different systems.
Comment 5 David Tardon 2014-07-07 14:10:16 UTC
(In reply to comment #3)
> Of course - it would be hard to believe that this ordering is based on some
> un-controlled / random sort order - surely !?

This does not matter for save/export dialogs, as these always set an exact filter type. So I suppose nobody cared (or noticed) till now.
Comment 6 Commit Notification 2014-07-07 14:36:12 UTC
David Tardon committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=24d20bce789063f6dba2df1c5d2c5a8948d24370

fdo#80955 make calc_MS_Excel_97 filter default for xls ext.



The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.
Comment 7 David Tardon 2014-07-07 14:36:32 UTC
There is a way to set a filter as "preferred" for a given extension. But it had not been used for the filters associated with 'xls'.
Comment 8 Kohei Yoshida 2014-07-07 14:38:28 UTC
(In reply to comment #0)
> It seems (from the callgrind regression tests) that we have a significant
> performance regression on master / 4.4.
                            ^^^^^^^^^^^^

I'll set the version field per Michael's comment.
Comment 9 Commit Notification 2014-07-07 17:04:43 UTC
Michael Meeks committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=0f8cf397d4de28ab9e16d4d1c6ca408323d7e189

fdo#80955 - add a unit test.



The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds
Affected users are encouraged to test the fix and report feedback.