Bug 109158 - slower loading of a huge AutoCorrect replacement table
Summary: slower loading of a huge AutoCorrect replacement table
Status: NEW
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: Linguistic (show other bugs)
Version:
(earliest affected)
5.4.1.1 rc
Hardware: All All
: medium normal
Assignee: Not Assigned
URL:
Whiteboard:
Keywords: bibisected, bisected, perf, regression
: 118761 (view as bug list)
Depends on:
Blocks: AutoCorrect-Complete
  Show dependency treegraph
 
Reported: 2017-07-17 12:28 UTC by tommy27
Modified: 2018-09-01 14:25 UTC (History)
10 users (show)

See Also:
Crash report or crash signature:


Attachments
Bibisect log (2.45 KB, text/plain)
2017-10-04 14:40 UTC, Telesto
Details
Callgrind trace from bug 118761. Thanks to Buovjaga (2.40 MB, application/x-xz)
2018-07-15 10:42 UTC, Xisco Faulí
Details

Note You need to log in before you can comment on or make changes to this bug.
Description tommy27 2017-07-17 12:28:15 UTC
Description:
tested under Win7 x64 using LibO 6.0.0.0.alpha0+
Build ID: 4f17445c12dc26c4881c4e486215b58d26515f8d
CPU threads: 8; OS: Windows 6.1; UI render: GL; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-07-16_23:03:56
Locale: it-IT (it_IT); Calc: group

loading a very big AutoCorrect replacement list such as the one I uploaded as  attachment 134684 [details]

is slower in LibO 6.0.0.0 than in LibO 5.3.4.2

the same file takes 4 seconds to load in in 5.3.x and 10 seconds in LibO 6.0.0.0 alpha

this is a performance regression when dealing with huge autocorrect lists.
I also reported another issue regarding closing the replacement table Bug 109156.

basically LibO 6.0.0.0 is slower loading such lists and hangs while closing them.



Steps to Reproduce:
click on menu "Tools/AutoCorrect/AutoCorrect Options" and count the time needed to display the list.

Actual Results:  
LibO 6.0.x is 2.5 times slower that 5.3.x

Expected Results:
it should take the same time as in 5.3.x


Reproducible: Always

User Profile Reset: 

Additional Info:


User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:49.0) Gecko/20100101 Firefox/49.0 SeaMonkey/2.46
Comment 1 tommy27 2017-07-17 12:35:08 UTC
I suspect this regression may be an unwanted side effect of the fix for Bug 99071...
Comment 2 tommy27 2017-07-18 05:45:26 UTC
retested on a different slower machine with Win8.1 x64.

LibO 6.0.0.0.alpha0+ (the day before bug 99071 fix)
TinderBox: Win-x86@42, Branch:master, Time: 2017-07-13_23:50:53
takes 8 seconds to load which is the same time needed by 5.4.3.2 on the same PC.

LibO 6.0.0.0.alpha0+ (on builds featuring that committ)
TinderBox: Win-x86@42, Branch:master, Time: 2017-07-17_23:50:28
takes 21 seconds to load instead of 8 of the previous 6.0.x builds

so I confirm that the fix for Bug 99071 caused a significant performance drop while loading huge autocorrect replacement tables such as the one loaded as attachment 134684 [details]  (more than 206K entries).
Comment 3 Xisco Faulí 2017-07-19 16:11:07 UTC
the fix for Bug 99071 just reverts 62ea355b2679073b8ee326df5793231996136da9, so I guess it was slower in 4.1 or previous. Could you please test how long it takes with an old version?
Comment 4 tommy27 2017-07-20 04:28:03 UTC
@Xisco

retested on the same Win8.1 x64 machine as in comment 2.

LibO 4.4.0 --> 42 seconds

LibO 5.1.2 --> 10 seconds to load

LibO 5.3.4 --> 8 seconds to load 

LibO 6.0.0 * --> 8 seconds to load (the day before bug 99071 fix)

LibO 6.0.0 * --> 21 seconds to load (the day after bug 99071 fix)


so the situation was even worse in 4.1.x but a considerable performance improvement was achieved in the 5.x branch. see also history in Bug 79761

the performance was the same as 5.3.x in recent 6.0.x daily builds but just after the bug 99071 got fixed , thing become worse again.

according to my tests the regression happened during recent 6.x development.
I don't know if the regression was effectively caused by that committ or is just a coincidence... anyway something has happened.

I cannot test 5.4.x daily builds since the Windows tinderbox are not working.
Comment 5 tommy27 2017-07-30 12:18:46 UTC
(In reply to tommy27 from comment #4)
> 
> retested on the same Win8.1 x64 machine as in comment 2.
> 
> ....
> 
> LibO 5.3.4 --> 8 seconds to load 
> 
> LibO 6.0.0 * --> 8 seconds to load (the day before bug 99071 fix)
> 
> LibO 6.0.0 * --> 21 seconds to load (the day after bug 99071 fix)
> 
> ....
> 
> I cannot test 5.4.x daily builds since the Windows tinderbox are not working.


issue affect the 5.4.x branch as well

5.4.1.0.0+ (x64)* --> 21 seconds to load

* Build ID: b78c398817940bbbe0b9ebe848a923cef1856758
CPU threads: 4; OS: Windows 6.29; UI render: default; 
TinderBox: Win-x86_64@62-TDF, Branch:libreoffice-5-4, Time: 2017-07-28_09:02:44
Locale: it-IT (it_IT); Calc: group


this is gonna be an upgrade stopper for me, since I often open the autocorrect replacement table at work.

I can cope with an 8 seconds wait as in 5.3.x but I cannot stand a 21 seconds wait.... such a performance drop is not compatible with my workflow... I'll stick to 5.3.x in the meantime, hoping the issue will be resolved in next 5.4.x releases.
Comment 6 Aron Budea 2017-07-30 13:40:20 UTC
My 32-bit Windows build of 46bfe17e2bceced4ceffe82ba98d8687b31d9ce8 isn't that slow, it takes ~10s to open the dialog with the sample from the description.

However looking at profiling results I do see that performance could be improved: when looping through entries and inserting each in OfaAutocorrReplacePage::RefillReplaceBox(...), a couple of levels deeper in SvTreeList::Insert(...) the SvListAction::INSERTED event is broadcasted, then further deeper handled, which updates the view data.
Doing that per each entry seems wasteful.

Loading the XML could be faster as well.
Comment 7 tommy27 2017-07-30 18:24:32 UTC
Maybe the total lenght is O/S related...

I retested on a Win7 x64 machine and result is:

5.3.4.2 -> 4 seconds 

6.0.0.0 → 10 seconds


Win8.1 x64 machine is:

Intel Core i7 959 @ 3.07Ghz
12 GB RAM
SSD disk

Win7 x64 machine in:

AMD A8-6410
8 GB RAM
SSD disk


so the same file and the same version of LibO are slower under Win8.1
anyway the performance drop between 5.3.x an 5.4.x is clear in either O/S

@Aron
can you confirm it's slower in 5.4.x and 6.0.x compared to 5.3.x ?
Comment 8 Telesto 2017-08-01 10:00:23 UTC
I can confirm a slow down:
Version: 5.4.0.3 -> 4 seconds 
Version 6.0.0.0 → 10 seconds
Comment 9 tommy27 2017-08-01 18:08:19 UTC
(In reply to Telesto from comment #8)
> I can confirm a slow down:
> Version: 5.4.0.3 -> 4 seconds 
> Version 6.0.0.0 → 10 seconds

interesting...
I see the slowdown in 5.4.1.x but you don't see it in 5.4.0.3.
Comment 10 tommy27 2017-08-03 05:37:59 UTC
I confirm there's no slowdown in 5.4.0.3
the loading time is the same as in 5.3.4.2

this means that the guilty committ comes from the 6.0.x branch and has been backported to 5.4.1 but not in 5.4.0

as said before in comment 2 I suspect that bug 99071 fix started the regression which appeared between 13th and 17th of July.

a bibisect is needed to confirm.
Comment 11 tommy27 2017-10-04 05:31:53 UTC
performance drop unchanged with latest LibO 6.0.0.0.alpha0+ daily build downloaded tonight.

I confirm the perfomance regression (test done on a Win8.1 x64 machine, but affects Win7 x74 as well)

> 
> LibO 4.4.0 --> 42 seconds
> 
> LibO 5.1.2 --> 10 seconds to load
> 
> LibO 5.3.4 --> 8 seconds to load 
> 
> LibO 6.0.0 --> 8 seconds to load (the day before bug 99071 fix)
> 
> LibO 6.0.0 --> 21 seconds to load (the day after bug 99071 fix)
> 

as said before I have strong suspects that the regression was caused by bug 99071 fix.
Comment 12 Caolán McNamara 2017-10-04 08:39:09 UTC
which is, quite frankly, useless information in the sense that if one picks a fairly random fixed value as the size of text instead of measuring it then its faster to use that number and have wrong text size then measure the text and have correct text size. Throwing "regression" around doesn't change that.
Comment 13 Telesto 2017-10-04 14:40:24 UTC
Created attachment 136759 [details]
Bibisect log

~/bibisect-win32-6.0
$ git bisect good
53cd0ea77358e5ea6f8933846afdfa4192290b10 is the first bad commit
commit 53cd0ea77358e5ea6f8933846afdfa4192290b10
Author: Norbert Thiebaud <nthiebaud@gmail.com>
Date:   Sat Jul 29 16:11:21 2017 -0700

    source sha:94c7a401583200cf5982594b1b043ad1a5e3cd38

    source sha:94c7a401583200cf5982594b1b043ad1a5e3cd38

:040000 040000 aeb8bb5ed3559a4d854e68b2667c85b3e1e7c64f b8f5129dbc48f015bbd7e7f90ff1bd83dd364e62 M      instdir

----

author	Caolán McNamara <caolanm@redhat.com>	2017-07-14 13:22:06 (GMT)
committer	Caolán McNamara <caolanm@redhat.com>	2017-07-14 16:11:03 (GMT)
commit	94c7a401583200cf5982594b1b043ad1a5e3cd38 (patch)
tree	993b6717312394349d547e271b8e2e8811194b12
parent	6b6b81cae861a1e6463360d1b320c0d3e24de111 (diff)
Resolves: tdf#99071 tree view shows odd text widths when > 100 lines
reverts

commit 62ea355b2679073b8ee326df5793231996136da9
Date:   Thu Dec 12 09:55:35 2013 +0100

    fdo#72125: GetTextWidth() can get very expensive.

    Let's just count an approximate width using a cached value when we have too
    many entries.

The expert dialog got fixed by not populating it with all options on load
and instead by incremental disclosure as the users searches/expands it so
this optimization effort isn't needed

in the meantime there was another problem the above papered over with

commit b4bbb5e5d7b31caad2fbcc00382ad27df3c81001
Date:   Sun May 17 22:56:46 2015 +0900

refactor how font, fg. and bg. are applied in widgets/controls

which was fixed (hopefully) in the previous commit

Change-Id: I8383d9cd7a9983a85c7f3acec0281d984c44f9e7
Reviewed-on: https://gerrit.libreoffice.org/39951
Tested-by: Jenkins <ci@libreoffice.org>
Reviewed-by: Caolán McNamara <caolanm@redhat.com>
Tested-by: Caolán McNamara <caolanm@redhat.com>
Comment 14 tommy27 2017-10-05 07:28:09 UTC
(In reply to Caolán McNamara from comment #12)
> which is, quite frankly, useless information in the sense that if one picks
> a fairly random fixed value as the size of text instead of measuring it then
> its faster to use that number and have wrong text size then measure the text
> and have correct text size. Throwing "regression" around doesn't change that.

well, being just an user my suspect was just caused by the fact that before that bug 99071 got fixed performance was good and after the fix was poor. 

I have no technical knowledge to inspect the code and tell if my suspect was correct or not.

but what do you think about Telestos's bibisect? 
it seems to confirm that a precise committ caused the performance drop.
Comment 15 tommy27 2017-11-01 03:04:00 UTC
retested on the same Win8.1 x64 machine as in comment 4

> LibO 6.0.0.0.alpha0+ (the day before bug 99071 fix)
> TinderBox: Win-x86@42, Branch:master, Time: 2017-07-13_23:50:53
> takes 8 seconds to load which is the same time needed by 5.4.3.2 on the same
> PC.

> LibO 6.0.0.0.alpha0+ (on builds featuring that committ)
> TinderBox: Win-x86@42, Branch:master, Time: 2017-07-17_23:50:28
> takes 21 seconds to load instead of 8 of the previous 6.0.x builds

LibO 6.0.0.0.alpha1+ (*)
takes 12 seconds to load, which is still slower than 5.3.6.1 (still 8 seconds) but much better that 6.0.x alpha0+


(*) Build ID: 8ea346b87c8f62d93bec283515abae8db36a08ed
CPU threads: 4; OS: Windows 6.3; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-10-31_23:37:25
Locale: it-IT (it_IT); Calc: group
Comment 16 tommy27 2017-11-19 09:31:50 UTC
retested on latest daily build (*) but this time the performance is worsened a lot...

it takes 23 seconds instead of 12 of october 31st build.

(*) 6.0.0.0.alpha1+
Build ID: 2865210607364feaff2c0275b7cd6c5439f5f070
CPU threads: 4; OS: Windows 6.3; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-11-18_23:53:39
Locale: it-IT (it_IT); Calc: group
Comment 17 tommy27 2017-12-27 07:45:39 UTC
bad performance affects LibO 6.1.x master too.
it still takes 23 seconds to load the list

the same list is loaded in 8 seconds with LibO 5.3.6.1

unfortunately the issue is present in the 5.4.x branch as well with 23 seconds to load the list using LibO 5.4.3.2

this means that something caused a 3x slower performance in the 5.4.x and master branches in respect to the 5.3.x branch.

a bibisect has been performed by telesto (see comment 13) so I gently ask to the developers to give a look at it

@Norbert Thiebaud
would you please take a look at the bibisect log?
Comment 18 tommy27 2018-01-09 04:49:55 UTC
that bibisect log points toward a fix for Bug 72125 - Expert config dialog takes too much time to come up

could that fix be the culprit of the current autocorrect table performance regression?
Comment 19 tommy27 2018-02-10 07:01:12 UTC
bug still present in 6.1.0.0.alpha0+
Build ID: e0a94ded5d1635fa2a2d9e222bfcfa0a2289a01f
CPU threads: 4; OS: Windows 6.3; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2018-02-08_23:36:06
Locale: it-IT (it_IT); Calc: group

as said before there's a huge performance drop between LibO 5.3.x and 5.4.x and 6.x branches  (8 seconds vs. 23 seconds)

a bibisect has been performed and apperently identified the committ which introduced the regression.

I really hope so developer can take a look into it..
this bug has become a showstopper for me and I'm stuck with 5.3.7
Comment 20 V Stuart Foote 2018-02-10 14:46:50 UTC
Testing with the acor-it-IT.dat file of attachment 134684 [details] downloaded and renamed acor-en-US.dat and pasted into $ORIGIN/../Data/settings/user/autocorr

With LO Writer opened, the Tools -> AutoCorrect -> AutoCorrect Options dialog opens the 206,956 entry list in ~8 seconds. With just the default 2,399 entry list (i.e. built-ins and Emojis) the dialog opens in ~4 seconds.

And with NVDA 2017.3 screen reader assistive technology (IAccessible2 based) enabled--the time delay is perhaps 1 sec longer.  So issue of bug 72125, bug 70465 are not in play. Expert Config dialog was converted to tree view [1] which eliminated need to use a fixed width when traversing long tables [2] and is the commit Caolán had reverted with [3]

Guess one question might be what structure is used when opening the autocorrect table data? Looks like a table like Expert Config used to be, and is it populated with a GetTextWidth() call? I don't see it spike like it was doing with Expert Configuration but parsing 200K entries must cause some load.

Using OpenGL or default rendering does not seem to affect the loading speed on Windows 10. Once visible the table scrolls cleanly--but is there otherwise a font rendering issue when building it?

=-Testing-=

Version: 6.1.0.0.alpha0+ (x64)
Build ID: 609888f3c8d6c0fe72c41ac26de431a12ad3fdd0
CPU threads: 4; OS: Windows 10.0; UI render: GL; 
TinderBox: Win-x86_64@42, Branch:master, Time: 2018-02-08_02:03:29
Locale: en-US (en_US); Calc: CL

[1] https://cgit.freedesktop.org/libreoffice/core/commit/?id=db35b73037483cd22cd7d4ac93fe40f23fbe3967

[2] http://cgit.freedesktop.org/libreoffice/core/commit/?id=62ea355b2679073b8ee326df5793231996136da9

[3] https://cgit.freedesktop.org/libreoffice/core/commit/?id=94c7a401583200cf5982594b1b043ad1a5e3cd38
Comment 21 tommy27 2018-02-11 07:41:29 UTC
@Stuart

yes, parsing 200K entries must cause some load, but why LibO 6.x and 5.4.x load the same autocorrect replacament table 3 times slower than 5.3.x ?

the point of my report is that there has been a performance regression between those releases.

another thing I've noticed is that Win8.1 x64 is musch slower than Win7 x64

in my initial description which was performed on a Win7 machine the loading time was 4 seconds in 5.3.x and 10 seconds in other branches 

when moving on another computer with Win8.1 x64 the time climbed to 8 and 21 seconds respectively.

in order to fully reproduce the bug you should test that autocorrect table in 5.3.7 and measure the time needed to load the list.

you tested only 6.1.x and you took 10 seconds to load the list... try 5.3.x and you see that is faster
Comment 22 tommy27 2018-02-11 07:42:57 UTC
a portable 5.3.7 release is available here:
https://sourceforge.net/projects/winpenpack/files/X-LibreOffice/releases/
Comment 23 V Stuart Foote 2018-02-11 18:23:54 UTC
OK sure, there is a regression 5.4.0.3 -> 5.4.1.1, and in 6.0 and master.

4s -- Version: 5.4.0.3 (x64)
Build ID: 7556cbc6811c9d992f4064ab9287069087d7f62c
CPU threads: 4; OS: Windows 6.19; UI render: GL; 
Locale: en-US (en_US); Calc: group

8s -- Version: 5.4.1.1 (x64)
Build ID: a5be49f0c45fe24a575c7f41559aa8fc79a781a2
CPU threads: 4; OS: Windows 6.19; UI render: GL; 
Locale: en-US (en_US); Calc: group

With earlier benchmarks improved as for bug 79761
18s -- Version: 4.1.6.2
Build ID: 40ff705089295be5be0aae9b15123f687c05b0a

14s -- Version: 4.2.0.1
Build ID: 7bf567613a536ded11709b952950c9e8f7181a4a

4s -- Version: 5.2.7.2 --> on ward.
Build ID: 2b7f1e640c46ceb28adf43ee075a6e8b8439ed10
CPU Threads: 4; OS Version: Windows 6.2; UI Render: GL; 
Locale: en-US (en_US); Calc: group

So fixing bug 99071, reverted Kendy's hack for populating list box views with more than 100 items, and means all entries in a list box again must lookup the font and calculate font text width and height. For a user's autocorrect list box of 200K entries--this is expensive.

Maybe the better way to have fixed it might have been to bump up the number of GetEntryCount items in a list box before shifting to an approximate_char_width. With a complex document, would 1000 or 2000 entries in a list box be enough for well formed list box in Navigator?
Comment 24 tommy27 2018-02-11 20:37:49 UTC
thanks Stuart for confirming the regression and giving some insight about the bug roots
Comment 25 tommy27 2018-03-24 06:22:06 UTC
I hope this issue could be addressed by some developer.

the bibisect data is already available (see comment 13) and there are also some hints about a possible solution (see comment 23)

because of this issue I'm stuck with LibO 5.3.7
Comment 26 tommy27 2018-05-26 05:10:44 UTC
bad performance affects LibO 6.2.x master too.
it still takes 23 seconds to load the list under Win8 x64 on a SSD disk.

the same list is loaded in 8 seconds with LibO 5.3.7

this performance drop affects all the 5.4.x, 6.0.x and 6.1.x branches as well

interestingly on older Win7 x64 O/S the time to load those list is lower (4 seconds with 5.3.x and 11 seconds with 5.4.x and later releases) but there's still almost a 3x difference.

I'll try soon on a Win x10 machine and report the results.
Comment 27 tommy27 2018-05-26 07:17:16 UTC
issue confirmed even on a Windows 10 Pro for Workstations 64-bit

CPU Intel Xeon @ 3.60GHz	
RAM 16GB 
Motherboard HP 81C5 (CPU0)

autocorrect table loads in 3 seconds using 5.3.7 and in 9 seconds using 6.0.4

basically there's a 3x performance drop in all Windows O/S with overall speed being worst under Win 8.1 compared to Win7 and Win10

a bibisect is available from long time
I hope someone could fix this annoying regression
Comment 28 V Stuart Foote 2018-05-26 16:48:55 UTC
Of course it remains slow--populating an autocorrect listbox of 200K entries--each pair of strings has their size precisely calculated with GetTextWidth() and GetTextHeight() calls [1], looks very expensive.

Kendy's original approach for bug 72125 of using an "approximate character width" against the "string length" for lists over > 100 entries avoided that overhead with the Expert Configuration dialog.

Though reverted, seems restoring similar logic (bumping the limit to 500 or 1000 list items) would still be helpful for folks using really large autocorrection replacement tables. 

It might cause some layout problems (truncation like bug 99071) with a pair of long strings, but should be rare with a higher threshold.

=-ref-=
https://opengrok.libreoffice.org/xref/core/svtools/source/contnr/svlbitm.cxx#209
Comment 29 tommy27 2018-06-02 12:52:20 UTC
interestingly LibO 6.0.4 x64 takes the same amount of time to load that list of the corresponding x32 version.

I hoped that x64 could be faster but I wasn't right
Comment 30 Xisco Faulí 2018-07-15 10:41:36 UTC
*** Bug 118761 has been marked as a duplicate of this bug. ***
Comment 31 Xisco Faulí 2018-07-15 10:42:30 UTC
Created attachment 143558 [details]
Callgrind trace from bug 118761. Thanks to Buovjaga
Comment 32 tommy27 2018-09-01 07:31:59 UTC
retested  under Win8.1 x64
there's a worsening of the bug...

6.0.5.2 still takes 23 seconds to load
6.1.0.3 takes 27 seconds to load.
Comment 33 V Stuart Foote 2018-09-01 13:55:56 UTC
(In reply to Xisco Faulí from comment #31)
> Created attachment 143558 [details]
> Callgrind trace from bug 118761. Thanks to Buovjaga

In this callgrind -- see line# 47060

Each of the 2642 items  loaded in the Autocorrect listbox's GUI with SvLBoxString::InitViewData() cost both a GetTextHeight() and more expensive GetTextWidth() call.

As suggested comment 23 the GetTextWidth() could again be controlled by testing size of the list, assigning a fixed width when list is > some number maybe ~300.

Also, since this controls all GUI listboxes, we can't just make the text height fixed, but guess we could include within the same list size testing and save that cost as well?
Comment 34 V Stuart Foote 2018-09-01 14:25:48 UTC
(In reply to V Stuart Foote from comment #33)
> testing size of the list, assigning a fixed width when list is > some number

And of course not a fixed width (which would be ugly). But rather than doing a precise calculation, would calculate width with an "approximate character width" of the font against the "string length" of each list entry. Just for lists above the threshold.