Bug 125892 - Time to export a certain PDF increased with in 10 fold (previously 30 seconds (6.0) now 5 minutes (6.4)
Summary: Time to export a certain PDF increased with in 10 fold (previously 30 seconds...
Status: VERIFIED FIXED
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: Printing and PDF export (show other bugs)
Version:
(earliest affected)
6.2.0.0.alpha1+
Hardware: All All
: medium normal
Assignee: Not Assigned
URL:
Whiteboard: target:6.4.0 target:6.3.0.1 target:7....
Keywords: bibisected, bisected, haveBacktrace, perf, regression
Depends on:
Blocks: PDF-Export
  Show dependency treegraph
 
Reported: 2019-06-13 07:10 UTC by Telesto
Modified: 2022-01-22 23:08 UTC (History)
7 users (show)

See Also:
Crash report or crash signature:


Attachments
Flamegraph (57.76 KB, application/x-bzip)
2019-06-15 08:42 UTC, Julien Nabet
Details
Flamegraph (268.09 KB, application/x-bzip)
2019-10-27 14:44 UTC, Julien Nabet
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Telesto 2019-06-13 07:10:24 UTC
Description:
Time to export a certain PDF increased with in 10 fold (previously 30 seconds (6.0) now 5 minutes (6.4)

Steps to Reproduce:
1. Open attachment 152116 [details] (bug 125869)
2. Export PDF

Actual Results:
5 minutes

Expected Results:
30 seconds


Reproducible: Always


User Profile Reset: No



Additional Info:
Version: 6.4.0.0.alpha0+ (x86)
Build ID: ac14e5613597e7361ce6995dacb1bb5bd55b6b00
CPU threads: 4; OS: Windows 6.3; UI render: default; VCL: win; 
TinderBox: Win-x86@42, Branch:master, Time: 2019-06-06_05:09:49
Locale: nl-NL (nl_NL); UI-Language: en-US
Calc: threaded
Comment 1 Telesto 2019-06-13 07:12:22 UTC
Setting to NEW
Confirmed at bug 125869 comment 3 (not the specific export time, but the slowdown in general)
Comment 2 Roman Kuznetsov 2019-06-13 07:54:01 UTC
I can confirm it for LO 6.4
Comment 3 Xisco Faulí 2019-06-13 08:58:31 UTC
Regression introduced by:

https://cgit.freedesktop.org/libreoffice/core/commit/?id=85613aa81a885488f99ed038f2254ddb0c8a1037

author	Matteo Casalin <matteo.casalin@yahoo.com>	2018-05-16 23:26:44 +0200
committer	Matteo Casalin <matteo.casalin@yahoo.com>	2018-06-03 12:17:45 +0200
commit 85613aa81a885488f99ed038f2254ddb0c8a1037 (patch)
tree d6a577b1837ca5e430d31a7e0b979afa3b764321
parent c4fb67f712ddde0e31bda0f22ef4e4247d63ea9a (diff)
Fix tdf#117410 - UI: Settings in PDF Options not remembered...

Bisected with: bibisect-linux64-6.2

Adding Cc: to Matteo Casalin
Comment 4 Xisco Faulí 2019-06-14 11:00:54 UTC
@buovjaga, @julien, is it possible to have a perf graph here ?
Comment 5 Julien Nabet 2019-06-15 08:42:58 UTC
Created attachment 152207 [details]
Flamegraph

On pc Debian x86-64 with master sources updated today + enable-symbols (not enable-dbgutil), I retrieved this Flamegraph.
Comment 6 Matteo Casalin 2019-06-16 10:51:12 UTC
The fix in https://cgit.freedesktop.org/libreoffice/core/commit/?id=85613aa81a885488f99ed038f2254ddb0c8a1037 aimed to avoid considering an empty token (if rTree ended with a '/') when validating the tree.
Comparing against the length of the string was an option that I assumed not to introduce heavy load (since likely more expensive functions are called in ImpIsTreeAvailable), but this seems to be not true.
I'm not familiar with the internals of this code, other options to achieve the same result could be:

1. Performs checks as before, and then if bAvailable is false (would it be false?) and rTree ends with '/' and we are parsing last token (which is empty) then return true

2. Check if it's correct that a tree with final '/' is passed and fix the (PDF) caller, if this is wrong. FilterConfigItem::ImpInitTree also uses the same tree, I don't know if fixing the caller would introduce an issue here or if the final '/' which is currently neglected in ImpIsTreeAvailable is problematic also in FilterConfigItem::ImpInitTree.

I will try to have a look at this, but I have almost no spare time at the moment so it can take a while.
Comment 7 Matteo Casalin 2019-06-24 20:09:00 UTC
The function modified in https://cgit.freedesktop.org/libreoffice/core/commit/?id=85613aa81a885488f99ed038f2254ddb0c8a1037 is called just one during the export process, so the slowdown should not depend on that function but on some other factor. I can't say if it's related, but I see a lot of "warn:vcl.gdi:5267:5267:vcl/source/outdev/map.cxx:1489: MapUnit::MapPixel approximated with 72dpi"
Comment 8 Xisco Faulí 2019-06-25 10:11:58 UTC
@Noel, I thought you might be interested in this issue...
Comment 9 Commit Notification 2019-06-25 13:36:58 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/+/d1c075c6a7002521129bddb5860f20746f168a29%5E%21

tdf#125892 improve time to export PDF, use int ops for scaling

It will be available in 6.4.0.

The patch should be included in the daily builds available at
https://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
https://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 10 Xisco Faulí 2019-06-26 07:47:23 UTC
in

Version: 6.4.0.0.alpha0+
Build ID: fe855eda54faf6196ad9dea12d8dc090b6d6c1da
CPU threads: 4; OS: Linux 4.15; UI render: default; VCL: gtk3; 
Locale: ca-ES (ca_ES.UTF-8); UI-Language: en-US
Calc: threaded

it takes

real	3m8,099s
user	3m5,145s
sys	0m2,638s

while before noel's commit it takes

real	3m21,532s
user	3m18,985s
sys	0m2,536s

still a problem in master... anyway, I'll backport the commit, as it improves cases like bug 123361
Comment 11 Commit Notification 2019-06-26 08:34:10 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "libreoffice-6-3":

https://git.libreoffice.org/core/+/36b26c1ee6aff5b5101f45067736bd619fb56171%5E%21

tdf#125892 improve time to export PDF, use int ops for scaling

It will be available in 6.3.0.1.

The patch should be included in the daily builds available at
https://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
https://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 12 Julien Nabet 2019-10-27 14:44:08 UTC
Created attachment 155341 [details]
Flamegraph

Here's an update of Flamegraph with master sources updated today.
Comment 13 Buovjaga 2021-09-10 17:44:48 UTC
Some optimisations after 2019 might positively affect this as I got 1 min with fresh master and 1 min 11 sec with last commit in 7.0 repo.
Comment 14 Commit Notification 2021-09-21 10:21:34 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/e0c7d1e4cf7e6cf73211e69a91f458e6ffe303cb

stack allocate this TextLayoutCache object (tdf#125892

It will be available in 7.3.0.

The patch should be included in the daily builds available at
https://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
https://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 15 Commit Notification 2021-09-21 12:52:36 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/96ff90857a066da70b04684f71237056e12eddfe

reduce cost of some getProperty calls (tdf#125892)

It will be available in 7.3.0.

The patch should be included in the daily builds available at
https://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
https://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 16 Commit Notification 2021-09-21 13:35:37 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/19d638eaedf84cefadf55d561c3c36df33fed6fe

reduce cost of BasePrimitive2D (tdf#125892)

It will be available in 7.3.0.

The patch should be included in the daily builds available at
https://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
https://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 17 Roman Kuznetsov 2021-09-24 14:31:21 UTC
It took 30 sec in

Version: 7.3.0.0.alpha0+ (x64) / LibreOffice Community
Build ID: 1516711eb7861a08cc9fd19ec867360737a6d070
CPU threads: 8; OS: Windows 10.0 Build 19043; UI render: Skia/Vulkan; VCL: win
Locale: ru-RU (ru_RU); UI: ru-RU
Calc: threaded

Noel, thank you! Will you plan to do something else here? Or we can close it as FIXED?
Comment 18 Noel Grandin 2021-09-24 14:39:43 UTC
I'm not working on this anymore
Comment 19 Stéphane Guillou (stragu) 2021-12-31 05:18:19 UTC
I am back at comparably slow times between 7.2.4.1 (2m24) and 7.3.0.1 (2m26):

Version: 7.2.4.1 / LibreOffice Community
Build ID: 27d75539669ac387bb498e35313b970b7fe9c4f9
CPU threads: 8; OS: Linux 5.4; UI render: default; VCL: gtk3
Locale: en-AU (en_AU.UTF-8); UI: en-US
Calc: threaded

and

Version: 7.3.0.1 / LibreOffice Community
Build ID: 840fe2f57ae5ad80d62bfa6e25550cb10ddabd1d
CPU threads: 8; OS: Linux 5.4; UI render: default; VCL: gtk3
Locale: en-AU (en_AU.UTF-8); UI: en-US
Calc: threaded
Comment 20 Stéphane Guillou (stragu) 2022-01-22 22:27:35 UTC
I just tried it on Windows 10, and MS Word (version 2112, build 14729.20260) took 5:10 min to export it, whereas LO 7.3.0.2 took 1:25 min.

Happy to have this one closed as fixed, but I'm wondering if we should have a new bug opened for Linux-specific slow times.

Version: 7.3.0.2 (x64) / LibreOffice Community
Build ID: f1c9017ac60ecca268da7b1cf147b10e244b9b21
CPU threads: 8; OS: Windows 10.0 Build 19043; UI render: Skia/Vulkan; VCL: win
Locale: en-US (en_US); UI: en-US
Calc: threaded
Comment 21 Stéphane Guillou (stragu) 2022-01-22 23:08:47 UTC
It's true that's there's still a lot of space for improvement though.
I can confirm that 6.0.0.2 only took 23 seconds to export the PDF, on the same system as in Comment 20:

Version: 6.0.0.3 (x64)
Build ID: 64a0f66915f38c6217de274f0aa8e15618924765
CPU threads: 8; OS: Windows 10.0; UI render: GL; 
Locale: en-US (en_US); Calc: CL

I don't understand how the commit identified by the bisect in Comment 3 could have made such a big difference, given that it's supposed to only be about remembering PDF export settings...

https://cgit.freedesktop.org/libreoffice/core/commit/?id=85613aa81a885488f99ed038f2254ddb0c8a1037