Bug 119840 - FILEOPEN DOCX: Long file open and post-processing time after file open
Summary: FILEOPEN DOCX: Long file open and post-processing time after file open
Status: NEW
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: Writer (show other bugs)
Version:
(earliest affected)
5.1.0.3 release
Hardware: All All
: medium normal
Assignee: Not Assigned
URL:
Whiteboard: target:7.5.0
Keywords: bibisected, bisected, filter:docx, perf
Depends on:
Blocks: DOCX Performance
  Show dependency treegraph
 
Reported: 2018-09-13 12:07 UTC by Telesto
Modified: 2022-11-13 12:34 UTC (History)
7 users (show)

See Also:
Crash report or crash signature:


Attachments
Example file part 1 (11.14 MB, application/x-zip-compressed)
2018-09-13 12:07 UTC, Telesto
Details
Example file part 2 (25.00 MB, application/octet-stream)
2018-09-13 12:08 UTC, Telesto
Details
document load profile (1.09 MB, image/png)
2022-07-05 10:40 UTC, Michael Meeks
Details
work at idle (743.82 KB, image/png)
2022-07-05 10:41 UTC, Michael Meeks
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Telesto 2018-09-13 12:07:03 UTC
Description:
FILEOPEN DOCX: Long file open and post-processing time after file open

Steps to Reproduce:
1. Open the attached file
2. Monitor time from file open until CPU usage drops back to 'idle'

Actual Results:
2 minutes

Expected Results:
45 seconds or so


Reproducible: Always


User Profile Reset: No



Additional Info:
Found in
Version: 6.2.0.0.alpha0+
Build ID: d5a2202f955657e427670a87c2d4e5638884517b
CPU threads: 4; OS: Windows 6.3; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2018-09-12_02:38:23
Locale: nl-NL (nl_NL); Calc: CL

and in
Version: 5.1.0.0.alpha1+

OK inVersie: 4.4.7.2 
Build ID: f3153a8b245191196a4b6b9abd1d0da16eead600
Locale: nl_NL

Note: the comparison is not totally fair; 4.4.7.2 has page count issues (pages are still rendered when scrolling down)
Build ID: 87ac0b1e75a880a68ecb748bd4b34ae5a3d2ae98
Locale: nl-NL (nl_NL)
Comment 1 Telesto 2018-09-13 12:07:35 UTC
Created attachment 144833 [details]
Example file part 1
Comment 2 Telesto 2018-09-13 12:08:17 UTC
Created attachment 144834 [details]
Example file part 2
Comment 3 Telesto 2018-09-13 12:16:35 UTC
Similar issue when saving the file to ODT
Comment 4 Xisco Faulí 2018-10-19 11:54:40 UTC
Time in

Version: 6.2.0.0.alpha0+
Build ID: 5fb66ae5595b7435e8954df31473fad15a74b8c2
CPU threads: 4; OS: Linux 4.15; UI render: default; VCL: gtk3; 
Locale: en-US (ca_ES.UTF-8); Calc: threaded

or 

Version: 5.2.0.0.alpha0+
Build ID: 3ca42d8d51174010d5e8a32b96e9b4c0b3730a53
Threads 4; Ver: 4.10; Render: default; 

real	2m13.149s
user	2m14.268s
sys	0m2.848s

while in

Version: 4.3.0.0.alpha1+
Build ID: c15927f20d4727c3b8de68497b6949e72f9e6e9e

real	1m12.708s
user	1m9.145s
sys	0m1.118s
Comment 5 Buovjaga 2018-10-19 19:03:16 UTC
With bibisect repo win32-5.0, both master and oldest dropped very quickly to 10% CPU and below after loading the file and kept fluctuating, lowest something like 3%.
With win32-5.1, master kept the CPU steadily around 25%, not dropping below 20% anyways (hammering one core).
So rather than "time to idle", I decided "good" equals sharp drop off and "bad" steady hammering for an extended period.

Bibisect points to https://cgit.freedesktop.org/libreoffice/core/commit/?id=48c2815dd20cf20eeec8bb4e003000f4a3d13291

tdf#91727 - Unwind non-dispatch of idle handlers.

Adding Cc: to Michael Meeks
Comment 6 Telesto 2018-10-19 21:16:55 UTC
(In reply to Buovjaga from comment #5)
> With win32-5.1, master kept the CPU steadily around 25%, not dropping below
> 20% anyways (hammering one core).

Not 100% sure if this is the root cause. I have be attempting to do bibisects in that area. In certain cases the performance quite good, even with the permanent CPU hammering (if i remember correctly).

The hammering might be a Windows only thing (not 100% sure). So the MacOS bibisect repro might be the better alternative
Comment 7 Buovjaga 2018-10-20 07:33:11 UTC
Just tested on Linux master and it does hammer like Windows.

The multipart zip required me to use command line to extract:
7z x GS52-GettingStartedLO.z01

Arch Linux 64-bit
Version: 6.2.0.0.alpha0+
Build ID: 9a373521d7a328197a4bf9abeb0a981b7acba896
CPU threads: 8; OS: Linux 4.18; UI render: default; VCL: gtk3_kde5; 
Locale: fi-FI (fi_FI.UTF-8); Calc: threaded
Built on 19 October 2018
Comment 8 QA Administrators 2019-10-21 02:29:19 UTC Comment hidden (obsolete)
Comment 9 Roman Kuznetsov 2020-05-05 18:25:06 UTC
it takes about 1 min 15 sec in

Version: 7.0.0.0.alpha0+ (x64)
Build ID: 861b556bb3779242951c03b3f68a32eb8c15db02
CPU threads: 4; OS: Windows 10.0 Build 18363; UI render: Skia/Vulkan; VCL: win; 
Locale: ru-RU (ru_RU); UI-Language: en-US
Calc: threaded

but after opening it takes about 30 sec for page counting ). 

I'm not sure how Telesto count his time.
Comment 10 Roman Kuznetsov 2021-09-25 15:09:07 UTC
37 sec for opening and 30 sec for postprocessing

in

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

4 sec for opening it in MS Word =(
Comment 11 Michael Meeks 2022-07-05 10:40:14 UTC
The file opens in ~30seconds for me now; I'm not sure this is truly a regression.  Apparently there is a lot of work to do on this file after opening - and the choice as to whether to defer this to a late future date or do it quickly is better is unclear to me - after 30 secs I have it loaded, and it is responsive as I scroll / edit - but whatever work is going on in the background - presumably layout needs to get done. I removed the regression keyword.

I attach some photos of the load performance - lots of the time is spent in BigPtrEntry::GetPos it seems. As for the idle layout - I expect there is something silly going on there - since I can get to the last page and render that rather quickly - but still the work goes on.

Noel - a CC in case you're interested =)
Comment 12 Michael Meeks 2022-07-05 10:40:38 UTC
Created attachment 181124 [details]
document load profile
Comment 13 Michael Meeks 2022-07-05 10:41:20 UTC
Created attachment 181125 [details]
work at idle
Comment 14 Commit Notification 2022-07-15 21:03:03 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

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

tdf#119840 elide some dynamic_cast cost

It will be available in 7.5.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 2022-07-17 17:26:59 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/946d038c71ae09f3ae403474d66c26c959a18e13

tdf#119840 reduce cost of SwPosition::operator<=

It will be available in 7.5.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 2022-07-18 14:13:22 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

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

tdf#119840 exit loop early in DocumentRedlineManager::AppendRedline

It will be available in 7.5.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 Commit Notification 2022-07-19 08:30:51 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/0649dc97bed5639cee20320ce2ae9b9d764cc99f

tdf#119840 use more StartEnd()

It will be available in 7.5.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 18 Commit Notification 2022-07-19 08:31:04 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/3a9d06eac4db5ac1595b8643a64d18c4a818ac96

tdf#119840 remove some unnecessary comparisons

It will be available in 7.5.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 19 Commit Notification 2022-07-19 17:04:42 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/4701d17bfe785f00958ad58a63dc0ece4c5c3281

tdf#119840 loop backwards in DocumentRedlineManager::SplitRedline

It will be available in 7.5.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 20 Commit Notification 2022-07-19 17:05:52 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

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

tdf#119840 reduce lines we need to scan in CompressRedlines

It will be available in 7.5.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 21 Commit Notification 2022-07-21 12:09:02 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/4d42b6fa4e69fed38f069bdc8b24e793ba82626a

tdf#119840 don't load redlines in lcl_FindParagraphClassificationField

It will be available in 7.5.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 22 Commit Notification 2022-07-22 20:02:45 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/2053fac9a81927a92aac016eab1b4525c058ce95

tdf#119840 tweak SwPosition::operator<

It will be available in 7.5.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 23 Commit Notification 2022-07-25 20:31:22 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/306ae32bfa92b06588173ee495acf3cb384ffb24

tdf#119840 HideIterator no need to always call GetRedlinePos

It will be available in 7.5.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 24 Commit Notification 2022-07-27 16:28:13 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/316e4c01f4056242b82047808169c78692a3d9e3

tdf#119840 elide some dynamic_cast

It will be available in 7.5.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 25 Commit Notification 2022-07-27 17:02:30 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

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

tdf#119840 Store pointer to redline

It will be available in 7.5.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 26 Commit Notification 2022-07-28 06:48:39 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/28dc1e713cfc5b5ea38e15f032aba72d05e40b33

tdf#119840 remove some OUString allocation

It will be available in 7.5.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 27 Commit Notification 2022-07-28 07:16:54 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/54f86db0c9267825e9283c523e990dfe71bf3fc9

tdf#119840 reduce OUString allocation

It will be available in 7.5.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 28 Commit Notification 2022-07-28 11:04:19 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/031da439aca27c031bf122a837ee53d074c75358

tdf#119840 elide some allocations

It will be available in 7.5.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 29 Commit Notification 2022-07-29 11:21:54 UTC
Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/7e3b3a9bd5370c68877d7d6abe97043460a687ca

tdf#119840 make this loop a little more efficient

It will be available in 7.5.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 30 Commit Notification 2022-08-12 19:30:25 UTC
Michael Stahl committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/656ff63ed045dfaedff7f34dc4adc0b203850543

tdf#149548 Revert "tdf#119840 loop backwards in ...

It will be available in 7.5.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.