Bug Hunting Session
Bug 112989 - Time required to export a large document has doubled for Latin (text layout issue)
Summary: Time required to export a large document has doubled for Latin (text layout i...
Status: NEW
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: LibreOffice (show other bugs)
Version:
(earliest affected)
5.3.0.1 rc
Hardware: All All
: medium normal
Assignee: Not Assigned
URL:
Whiteboard:
Keywords: bibisected, bisected, haveBacktrace, perf, regression
: 108513 112979 113139 113350 116399 118165 (view as bug list)
Depends on:
Blocks: HarfBuzz-regressions
  Show dependency treegraph
 
Reported: 2017-10-08 09:15 UTC by Telesto
Modified: 2019-05-08 14:20 UTC (History)
3 users (show)

See Also:
Crash report or crash signature:


Attachments
Bibisect log (2.91 KB, text/plain)
2017-10-08 09:16 UTC, Telesto
Details
Example file (361.32 KB, application/vnd.oasis.opendocument.text)
2017-10-08 09:17 UTC, Telesto
Details
Very Sleepy results (725.17 KB, application/x-zip-compressed)
2017-10-30 11:45 UTC, Telesto
Details
Screenshot (59.82 KB, image/png)
2017-11-02 20:55 UTC, Telesto
Details
Screenshot Non-Debug (36.07 KB, image/png)
2017-11-03 08:31 UTC, Telesto
Details
Very Sleepy time profile results (129.94 KB, application/zip)
2017-11-03 08:32 UTC, Telesto
Details
Very sleepy when exporting to PDF in multi-page view (31.93 KB, image/png)
2017-11-03 08:58 UTC, Telesto
Details
SHGetFileInfoW Non-Debug build (28.45 KB, image/png)
2017-11-03 09:00 UTC, Telesto
Details
Example file (637.76 KB, application/vnd.oasis.opendocument.text)
2017-11-15 20:53 UTC, Telesto
Details
Xcode Instruments Screenshots time profiler & code peaks (2.05 MB, application/zip)
2017-11-16 20:46 UTC, Telesto
Details
Example file (21.87 KB, application/vnd.oasis.opendocument.spreadsheet)
2017-11-25 21:46 UTC, Telesto
Details
Perf flamegraph (1.11 MB, image/svg+xml)
2019-04-06 17:44 UTC, Buovjaga
Details
Perf Flame Graph Win (647.54 KB, image/svg+xml)
2019-05-08 14:20 UTC, Telesto
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Telesto 2017-10-08 09:15:50 UTC
Description:
Time required to export a large document has doubled

Steps to Reproduce:
1. Open the attached file
2. Wait until the CPU usage falls back to around 0
3. Export the PDF and take notice of the time required

Actual Results:  
With 5.2.5 it takes around 15-20 seconds

Expected Results:
Since LibO5.3.0.1 around 40 seconds is required


Reproducible: Always

User Profile Reset: No

Additional Info:
Found in
Version: 6.0.0.0.alpha0+
Build ID: c5a93cad149618bbd43632f1660a558c34bdbf7e
CPU threads: 4; OS: Windows 6.3; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-10-07_01:04:25
Locale: nl-NL (nl_NL); Calc: CL

and in LibO5.3.0.1 


User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:52.0) Gecko/20100101 Firefox/52.0
Comment 1 Telesto 2017-10-08 09:16:55 UTC
Created attachment 136840 [details]
Bibisect log

author	Khaled Hosny <khaledhosny@eglug.org>	2016-11-02 21:52:06 (GMT)
committer	Khaled Hosny <khaledhosny@eglug.org>	2016-11-03 00:17:06 (GMT)
commit	8f2dd1df1d6cc94ebbc1149de72bc6d6dffa6533 (patch)
tree	db496889434c484a87b13ffcc4650d65e6672129
parent	c8be45889217c555e4bec92af838d0524ceba4e0 (diff)
Revert "Revert "Enable the new text layout engine by default""
This reverts commit 3950166877bf1308f9e449992e20b558342af825.
Comment 2 Telesto 2017-10-08 09:17:14 UTC
Created attachment 136841 [details]
Example file
Comment 3 Xisco Faulí 2017-10-17 09:22:56 UTC
I can't confirm it. In

Version: 6.0.0.0.alpha0+
Build ID: 616f21db9e50a77b0c02dfb123f871a742f46216
CPU threads: 4; OS: Linux 4.10; UI render: default; VCL: gtk3; 
Locale: ca-ES (ca_ES.UTF-8); Calc: group

it takes 

real	1m1,378s
user	1m0,772s
sys	0m0,328s

to open and export it.
-> time program/soffice --headless --convert-to pdf /home/xisco/Baixades/Demo\(3\)\ -\ kopie.odt --outdir /home/xisco/Escriptori/

OTOH, in

Version: 5.2.0.0.alpha1+
Build ID: 5b168b3fa568e48e795234dc5fa454bf24c9805e
CPU Threads: 4; OS Version: Linux 4.8; UI Render: default; 
Locale: ca-ES (ca_ES.UTF-8)

it takes

real	2m18,425s
user	2m3,976s
sys	0m0,400s

Could you please use 'time' to get accurate numbers?
Comment 4 Telesto 2017-10-17 11:44:18 UTC
LibO6 on Windows
$ time instdir/program/soffice --headless --convert-to pdf "C:\Demo.odt"
convert C:\Demo.odt -> C:\cygwin\home\DEMO\bibisect-win32-6.0\Demo.pdf using filter : writer_pdf_Export

real    1m8,039s
user    0m0,015s
sys     0m0,000s

LibO5.2 on Windows
$ time instdir/program/soffice --headless --convert-to pdf "C:\Demo.odt"
convert C:\Demo.odt -> C:\cygwin\home\DEMO\bibisect-win32-5.2\Demo.pdf using filter : writer_pdf_Export

real    0m29,305s
user    0m0,000s
sys     0m0,000s

It's the same file, I only renamed it.
Comment 5 Telesto 2017-10-29 17:04:28 UTC
*** Bug 113139 has been marked as a duplicate of this bug. ***
Comment 6 Telesto 2017-10-29 17:05:10 UTC
*** Bug 113350 has been marked as a duplicate of this bug. ***
Comment 7 Telesto 2017-10-29 17:06:07 UTC
*** Bug 112979 has been marked as a duplicate of this bug. ***
Comment 8 Khaled Hosny 2017-10-30 09:10:29 UTC
Can someone run this in a profiler and find where the new time is spent? I’m not very familiar with Windows to know how to do that, sorry.
Comment 9 Telesto 2017-10-30 11:45:57 UTC
Created attachment 137368 [details]
Very Sleepy results

(In reply to Khaled Hosny from comment #8)
> Can someone run this in a profiler and find where the new time is spent? I’m
> not very familiar with Windows to know how to do that, sorry.

I created a time profile with very sleepy (http://www.codersnotes.com/sleepy/).
http://github.com/CyberShadow/verysleepy/releases/download/v0.90/verysleepy-cs-0.90.exe

Not sure how reliable it is, but it might work. 

I did three runs (x86). Two with LibO 5.3.7.2 (old and new layout) and one with a LibO6 debug build from 22 oct with symbols.
Comment 10 Telesto 2017-11-02 20:55:10 UTC
Created attachment 137481 [details]
Screenshot

Most time is spend in ScriptRun:

u_getNumericValue_59	icuuc59	[unknown]	0	0x5c1f6ad7
uscript_getScript_59	icuuc59	[unknown]	0	0x5c1f8d96
vcl::ScriptRun::next	vcllo	c:\cygwin\home\tinderbox\master\vcl\source\gdi\scrptrun.cxx	162	0x5c77e8dd
vcl::TextLayoutCache::TextLayoutCache	vcllo	c:\cygwin\home\tinderbox\master\vcl\source\gdi\commonsallayout.cxx	290	0x5c782423
CommonSalLayout::LayoutText	vcllo	c:\cygwin\home\tinderbox\master\vcl\source\gdi\commonsallayout.cxx	454	0x5c783d28
Comment 11 Khaled Hosny 2017-11-03 00:09:35 UTC
(In reply to Telesto from comment #10)
> Created attachment 137481 [details]
> Screenshot
> 
> Most time is spend in ScriptRun:
> 
> u_getNumericValue_59	icuuc59	[unknown]	0	0x5c1f6ad7
> uscript_getScript_59	icuuc59	[unknown]	0	0x5c1f8d96
> vcl::ScriptRun::next	vcllo
> c:\cygwin\home\tinderbox\master\vcl\source\gdi\scrptrun.cxx	162	0x5c77e8dd
> vcl::TextLayoutCache::TextLayoutCache	vcllo
> c:\cygwin\home\tinderbox\master\vcl\source\gdi\commonsallayout.cxx	290
> 0x5c782423
> CommonSalLayout::LayoutText	vcllo
> c:\cygwin\home\tinderbox\master\vcl\source\gdi\commonsallayout.cxx	454
> 0x5c783d28

Debug builds are unreliable for performance profiling, you need to do this with a non-debug build.
Comment 12 Telesto 2017-11-03 08:31:42 UTC
Created attachment 137491 [details]
Screenshot Non-Debug

Version: 6.0.0.0.alpha1+
Build ID: 13c5dd1d98a480cb01ca8f24242c80e326e4ade8
CPU threads: 4; OS: Windows 6.3; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-10-30_23:52:07
Locale: nl-NL (nl_NL); Calc: CL
Comment 13 Telesto 2017-11-03 08:32:46 UTC
Created attachment 137492 [details]
Very Sleepy time profile results
Comment 14 Telesto 2017-11-03 08:58:32 UTC
Created attachment 137493 [details]
Very sleepy when exporting to PDF in multi-page view

I probably found a second issue.
1. Exporting to PDF is single page view (or using command line) is slow
2. Doing that in multi-page view makes thing even slower (something about freeing SwAnchoredDrawObject::IsValidPos) [Not sure if I should report this here, though]
Comment 15 Telesto 2017-11-03 09:00:59 UTC
Created attachment 137494 [details]
SHGetFileInfoW Non-Debug build
Comment 16 Telesto 2017-11-15 19:40:41 UTC
Only for the record. Another example.
1. Open attachment bug 123999
2. Hold page down key and take notice of the time to scroll down with page down (a similar increase as with the export time). LibO5.3 with the old layout engine noticeably faster. 
Setting to win only
Comment 17 Khaled Hosny 2017-11-15 20:30:11 UTC
(In reply to Telesto from comment #16)
> Only for the record. Another example.
> 1. Open attachment bug 123999
> 2. Hold page down key and take notice of the time to scroll down with page
> down (a similar increase as with the export time). LibO5.3 with the old
> layout engine noticeably faster. 
> Setting to win only

The old layout engine on Windows (for Latin text) was a very simplistic and didn’t do much. It would be interesting to compare with non-Latin text (e.g. Arabic) to have a more meaningful comparison.
Comment 18 Telesto 2017-11-15 20:53:01 UTC
Created attachment 137792 [details]
Example file

> The old layout engine on Windows (for Latin text) was a very simplistic and
> didn’t do much. It would be interesting to compare with non-Latin text (e.g.
> Arabic) to have a more meaningful comparison.

Scrolling speed with Harbuzz is a little slower
Comment 19 Telesto 2017-11-16 08:06:35 UTC
Similar result with MacOS

Version: 6.0.0.0.alpha1
Build ID: c1d1f859b268f650143d48f294999cda0fa57350
CPU threads: 4; OS: Mac OS X 10.12.6; UI render: default; 
Locale: nl-NL (nl_NL.UTF-8); Calc: group

MacBook-Air-van:~ demo$ time /Applications/LibreOfficeDev.app/Contents/MacOS/soffice --headless --convert-to pdf /Users/demo/Downloads/Demo\(3\)\ -\ kopie.odt --outdir /Users/demo/Documents/
convert /Users/demo/Downloads/Demo(3) - kopie.odt -> /Users/demo/Documents//Demo(3) - kopie.pdf using filter : writer_pdf_Export
Overwriting: /Users/demo/Documents//Demo(3) - kopie.pdf

real	2m1.820s
user	1m59.029s
sys	0m2.147s

-----------------

Version: 5.3.7.2
Build ID: 6b8ed514a9f8b44d37a1b96673cbbdd077e24059
CPU Threads: 4; OS Version: Mac OS X 10.12.6; UI Render: default; Layout Engine: old; 
Locale: nl-NL (nl_NL.UTF-8); Calc: group

without Harfbuzz

MacBook-Air-van:~ demo$ time /Applications/LibreOffice.app/Contents/MacOS/soffice --headless --convert-to pdf /Users/demo/Downloads/Demo\(3\)\ -\ kopie.odt --outdir /Users/demo/Documents/
convert /Users/demo/Downloads/Demo(3) - kopie.odt -> /Users/demo/Documents//Demo(3) - kopie.pdf using filter : writer_pdf_Export
Overwriting: /Users/demo/Documents//Demo(3) - kopie.pdf

real	1m12.281s
user	1m9.470s
sys	0m1.874s

with harfbuzz
MacBook-Air-van:~ demo$ time /Applications/LibreOffice.app/Contents/MacOS/soffice --headless --convert-to pdf /Users/demo/Downloads/Demo\(3\)\ -\ kopie.odt --outdir /Users/demo/Documents/
convert /Users/demo/Downloads/Demo(3) - kopie.odt -> /Users/demo/Documents//Demo(3) - kopie.pdf using filter : writer_pdf_Export
Overwriting: /Users/demo/Documents//Demo(3) - kopie.pdf

real	1m52.251s
user	1m48.966s
sys	0m2.180s
Comment 20 Telesto 2017-11-16 20:46:21 UTC
Created attachment 137818 [details]
Xcode Instruments Screenshots time profiler & code peaks
Comment 21 Buovjaga 2017-11-22 11:23:58 UTC
*** Bug 108513 has been marked as a duplicate of this bug. ***
Comment 22 Buovjaga 2017-11-22 11:24:33 UTC
NEW per dupes.
Comment 23 Telesto 2017-11-25 21:46:13 UTC
Created attachment 137988 [details]
Example file

A fast way to reproduce:
1. Open the attached file
2. Hold scroll down & monitor CPU usage; CPU will be 25% with the new Text Layout engine and 12% with the old one. Scrolling speed is fine, though

Repro on Windows, but not on Linux
Comment 24 Khaled Hosny 2017-11-26 12:34:15 UTC
Any meaningful comparison should use Arabic, Indic or other complex scripts. The old layout engines had a shortcut for Latin and similar scripts that did very simplistic and fast layout, the new engine does not have such shortcuts in principle.

This is not to say our text layout is sub-optimal, it is very sub-optimal actually, but that is not a regression. It has always been sub-optimal, we were just lying by handling Latin in a special way.
Comment 25 Telesto 2017-11-27 11:02:50 UTC
(In reply to Khaled Hosny from comment #24)
> Any meaningful comparison should use Arabic, Indic or other complex scripts.
> The old layout engines had a shortcut for Latin and similar scripts that did
> very simplistic and fast layout, the new engine does not have such shortcuts
> in principle.

I compared it again, with some Arabic text. Slow with the old engine, bit faster but still slow with the new engine. 

> This is not to say our text layout is sub-optimal, it is very sub-optimal
> actually, but that is not a regression. It has always been sub-optimal, we
> were just lying by handling Latin in a special way.

It depends how you interpret a regression. There are multiple sub-types:
a. Regression due a change in the operation system (the code has not changed, isn't working anymore as expected) 
b. A regression between versions of LibreOffice (the behavior changed to the worse, sec)
c. Technical approach. A unexpected /unintended performance loss.

A/B feel like regressions in the users point of view, but maybe not in the technical sense of a dev. So it's depending how the keywords are meant (not clear to me)

Anyway, losing the Latin shortcuts is quite noticeable in quite a lot area's. (I keep finding new variant). For example large copy/paste actions

I would add it to the tender suggestions. It's quite a core feature. Or an attempt to find a sponsor for this one :-).
Comment 26 Khaled Hosny 2017-11-27 15:20:59 UTC
(In reply to Telesto from comment #25)
> I would add it to the tender suggestions. It's quite a core feature.

Please do.

> Or an attempt to find a sponsor for this one :-).

Good luck with that. I've been told (and experienced) no one cares about text layout, no one with deep enough pockets to finance such work.
Comment 27 Telesto 2018-02-19 09:19:20 UTC
Only for the record (before I forget), an additional way to repro
1. Open the attached file 136841
2. Wait until the CPU usage falls back to around 0
3. At a page header

Still hoping for tender is this area ;-)
Comment 28 Telesto 2018-03-14 11:32:25 UTC
A more real life example: attachment 140185 [details]
Comment 29 Timur 2018-06-14 12:20:15 UTC
*** Bug 116399 has been marked as a duplicate of this bug. ***
Comment 30 Telesto 2018-07-02 14:10:35 UTC
*** Bug 118165 has been marked as a duplicate of this bug. ***
Comment 32 Telesto 2018-10-27 13:09:42 UTC
Repro with
Version: 6.2.0.0.alpha1+
Build ID: 96cf06c947838120e37f3fbb4d0543dd882cb20c
CPU threads: 4; OS: Windows 6.3; UI render: default; VCL: win; 
TinderBox: Win-x86@42, Branch:master, Time: 2018-10-25_22:57:51
Locale: nl-NL (nl_NL); Calc: CL
Comment 33 Telesto 2018-10-27 13:20:41 UTC
@Miklos
Not sure if you're interested, but this might be related to "Text layout performance". See comment 24
Comment 34 Buovjaga 2019-04-06 17:44:29 UTC
Created attachment 150572 [details]
Perf flamegraph

Arch Linux 64-bit
Version: 6.3.0.0.alpha0+
Build ID: 558956dc811a1f0f07411e348f7081a467bbc3b5
CPU threads: 8; OS: Linux 5.0; UI render: default; VCL: gtk3; 
Locale: fi-FI (fi_FI.UTF-8); UI-Language: en-US
Calc: threaded
Built on 4 April 2019
Comment 35 Telesto 2019-05-08 14:20:58 UTC
Created attachment 151246 [details]
Perf Flame Graph Win

Version: 6.3.0.0.alpha0+
Build ID: 128145e227ef91fb2f23893e73d38ae72cf074e5
CPU threads: 2; OS: Windows 6.3; UI render: default; VCL: win; 
Locale: nl-NL (nl_NL); UI-Language: en-US
Calc: threaded

symbol-only build