Bug 73300 - FILEOPEN Very slow load times and enormous memory use loading documents with many images
Summary: FILEOPEN Very slow load times and enormous memory use loading documents with ...
Status: RESOLVED FIXED
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: Writer (show other bugs)
Version:
(earliest affected)
4.1.0.4 release
Hardware: All All
: medium critical
Assignee: Michael Stahl
QA Contact:
URL:
Whiteboard: target:4.3.0 target:4.1.5 target:4.2.1
Keywords: bibisected, perf, regression
: 73299 (view as bug list)
Depends on: 74435
Blocks: Image-Caching
  Show dependency treegraph
 
Reported: 2014-01-05 13:04 UTC by Matthias Basler
Modified: 2015-12-15 11:07 UTC (History)
7 users (show)

See Also:
Crash report or crash signature:


Attachments
Error shown by LO 4.2 (10.06 KB, image/png)
2014-01-05 13:04 UTC, Matthias Basler
Details
Error shown by LO 4.1 (one one version of sample doc) (15.12 KB, image/png)
2014-01-05 13:05 UTC, Matthias Basler
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Matthias Basler 2014-01-05 13:04:18 UTC
Created attachment 91515 [details]
Error shown by LO 4.2

Fresh default install of LibreOffice 4.2.0.1.

Loaded a rather large document (177MB, 200 pages) read only. Initially this worked. Scrolled a bit through it, then tried to close LO by clicking on the top right window "X".
-> Error message "Error osl::Thread::create failed" popped up (see attachment).

Then started LO new (skipping document recovery).
Tried to load the book again (read-only or not, doesn't matter), and it already failed loading with the same error. LO uses up to 1.7 GB of memory during document load (before crashing)

This is 100% reproducable.

----------
To sum up:
LO 4.2.0.1 loads ~30s, then throws "osl::Thread::create failed" error
LO 4.1.4.2 loads ~30s, then gives up or throws error about missing "fwklo.dll"
           (Both give up after allocating 1.7 GB of memory.)
LO 3.6.7. loads this document without any fuss in about 5 seconds.

Now I call this a regression!


Unfortunately the test document in 177MB in size, so I cannot attach it.
Comment 1 Matthias Basler 2014-01-05 13:05:13 UTC
Created attachment 91516 [details]
Error shown by LO 4.1 (one one version of sample doc)
Comment 2 Matthias Basler 2014-01-05 13:08:06 UTC
I set version to 4.1.4.2 which is is the older one having issues loading the document.
Comment 3 Matthias Basler 2014-01-05 13:36:45 UTC
No success with bibisect40 under ubuntu: Both test documents load fine with LO oldest/latest of bibisect40. Either a windows specific issue or introduced later.
Comment 4 Matthias Basler 2014-01-05 14:29:19 UTC
Was successful with bibisect2013-10-12:

Under ubuntu the issue obviously manifests by OOo loading the document very slowly at a certain point  (at ~2/3 of progress) and eating up 2.4 GB (!!!) of memory while previous versions would not consume any significant memory loading the document.

--------
9f0987a02b9346609f06e35214cb6cf9da98de44 is the first bad commit
commit 9f0987a02b9346609f06e35214cb6cf9da98de44
Author: Bjoern Michaelsen <bjoern.michaelsen@canonical.com>
Date:   Wed Oct 16 15:34:19 2013 +0000

    source-hash-918f8ed91e325606a44d088da5fbbf8c463dffba
    
    commit 918f8ed91e325606a44d088da5fbbf8c463dffba
    Author:     Caolán McNamara <caolanm@redhat.com>
    AuthorDate: Sat Mar 16 17:30:29 2013 +0000
    Commit:     Caolán McNamara <caolanm@redhat.com>
    CommitDate: Sat Mar 16 21:25:17 2013 +0000
    
        "show logo" in slideshow settings doesn't do anything
    
        This wants to load about.png which doesn't exist anymore.  "about.svg" does,
        but is a rather abstract background image for the about dialog these days, so
        use "flat_logo.svg" instead.
    
        Which requires moving the svg loader out of cui into sfx2 for re-use.
    
        Change-Id: I8654f0f93766556ef4ed4b87eff35b45d8189761

:100644 100644 9af7c52a2ec791a06511f71544b24146ed9d5fcd 2a046b0767aad70318a3416319d832fe15a631fb M	ccache.log
:100644 100644 46b05478104c87327d32212c10b10498fce993c9 48e7827182c97732044243944ed02a6786e7005c M	commitmsg
:100644 100644 725d95418781718c9e6000ebcacf1c2bf8753f83 a7f1e346b5de8d7b9874b86e1297f56b51f012e7 M	dev-install.log
:100644 100644 c0313ea7ac08b677506b0084a0a94ba391188685 b610fbfd55253b96f69de999ff9ac458cc86ca04 M	make.log
:040000 040000 afb0503b3b0210eae6b21eac96b0332cd6306d2d aac4c675e8f0de8c2b398e1317b4314e29bc5271 M	opt
--------

Is this coincidence? This is the very same result I got for bibisecting bug Bug 73299, which was about longer load times (for a different document).
Comment 5 Matthias Basler 2014-01-05 14:34:26 UTC
*** Bug 73299 has been marked as a duplicate of this bug. ***
Comment 6 Matthias Basler 2014-01-05 14:37:52 UTC
Changed issue title to reflect the underlying issue instead of the first noted consequence of it.
Comment 7 Matthias Basler 2014-01-05 14:40:33 UTC
BTW, here is the output of "git bisect log":

# bad: [25428b1e953636f74986622c5df614f04c150ed1] source-hash-cb4e009c4539c535108021934e545194b35cad9d
# good: [f0f6c65eb764f0303f59c58d320e9b0d5a894377] source-hash-4b9740b4ec3987e1d4d2ad6d20b4dcf996a4fa2e
git bisect start 'latest' 'oldest'
# bad: [a72833796a7e527d9efc9ca6d8fe9b579e469105] source-hash-1472b5f87314fe660ef1a7b254e51272669f12f6
git bisect bad a72833796a7e527d9efc9ca6d8fe9b579e469105
# bad: [4300c48268179afe8db66410fad04436183407cd] source-hash-753310b7db6a36aeaae36cef3bfca970e9310569
git bisect bad 4300c48268179afe8db66410fad04436183407cd
# good: [280c5141ea58e6b50f7d46546a9c52891225eeff] source-hash-ba446dd58a4ad324d242afcd5b28d3b4dff5a881
git bisect good 280c5141ea58e6b50f7d46546a9c52891225eeff
# good: [8734d0269629a270d9e97cb5176bcc6b76338a54] source-hash-07352f07ce40ef40e9b73fd05aa4f9c5eac38290
git bisect good 8734d0269629a270d9e97cb5176bcc6b76338a54
# bad: [9f0987a02b9346609f06e35214cb6cf9da98de44] source-hash-918f8ed91e325606a44d088da5fbbf8c463dffba
git bisect bad 9f0987a02b9346609f06e35214cb6cf9da98de44
# good: [787867fcf60413048299e6a3b0574f6d460f41f9] source-hash-34847f1cf7538c333e9b8700eb4012ae358644a6
git bisect good 787867fcf60413048299e6a3b0574f6d460f41f9
# good: [b5ad0c13d2f8c864f71c32bd8c3e68738819f793] source-hash-1ce6d6d4133865d9616e12228be2c04cbba1976c
git bisect good b5ad0c13d2f8c864f71c32bd8c3e68738819f793
Comment 8 Matthias Basler 2014-01-05 17:09:42 UTC
Since it is not possible to attach serious larger sample documents here directly you will have to download two sample documents form my media center. Please use following link:

https://mc.gmx.net/guest?path=Sample%20documents%20von%20MatthiasBasler%40gmx.de&token=B7BCF2CC054CF2C3

You will find two files there. The smaller (TestbookWithLotsOfImages.odt) is a test book I created for another issue, but it comes handy here. It does NOT make LO crash on windows - it is not large enough for this. And yet, LO 4.1.4.2 allocates 1.2 GB of memory to open it (and needs really long to do so). It also keeps this memory allocated as long as the document is open.

In contrast, LO 3.6.7.2 barely needs 50-100 MB or so!

The far larger file (TestBook2.odt) is a scrambled former book, and this one makes LO4.1/4.2 crash for me.

Maybe LO 4.1 / 4.2 try to keep all the uncompressed images in memory, while LO 3.6 loads them on demand and forgets them afterwards. I am just guessing from the symptoms.
Comment 9 Michael Stahl 2014-02-03 11:37:03 UTC
can reproduce this... good work with the bibisect!

doesn't crash for me but does use > 2G of un-shared memory right after loading
the big TestBook2.odt; guess on 32 bit platforms it will crash.

bibisect range: 1ce6d6d4133865d9616e12228be2c04cbba1976c..918f8ed91e325606a44d088da5fbbf8c463dffba

regression introduced by commit: bd55f05b332c1573bd410fd9e21ea7fcf977e1b0

... but that is only for the initial file load, we still use too much
RAM when scrolling...

there are 2 more problems here:

when scrolling down at some points (first around page 7) 
i'm seeing 225 graphics painted at once.

worse, the images are all loaded and then not released.
they used to be released in 4.1 but not in 4.2...

regression from commit 2e5167528f7566dd9b000e50fc1610b7bf99132a

the problem that > 200 images are erroneously determined to be visible
is already in 4.0 although it was less severe then since the memory
was immediately released.

for the 3rd problem i'll file separate bug since it's in 4.0 already
(bug 74435).

Fixed to release the images in Writer with a timeout; it is derived from the setting:
Tools->Options->LibreOffice->Memory->Graphics cache->"Remove from memory
after"
(divided by 12, default is 50 seconds)

_ideally_ we'd want some sort of LRU cache with a fixed max size for images like apparently the old GraphicsManager had - but for now a timeout-based mechanism will have to do even though it may temporarily need some
100s MB RAM extra when scrolling.

fixed on master.
Comment 10 Commit Notification 2014-02-03 11:37:40 UTC
Michael Stahl committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=9b9eb2e4f619c63eabdc54b5d749ac55d8eaf333

fdo#73300: sw: don't swap in all images when loading files



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 11 Commit Notification 2014-02-03 11:37:55 UTC
Michael Stahl committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=2d9d20edc999ef2c2ad2ee628a6a5f27efb801d8

fdo#73300: sw: GraphicObjects are never swapped out



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 12 Commit Notification 2014-02-04 12:28:06 UTC
Michael Stahl committed a patch related to this issue.
It has been pushed to "libreoffice-4-1":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=39892ecb0db10ffa4a9803862264fd6e12d497aa&h=libreoffice-4-1

fdo#73300: sw: don't swap in all images when loading files


It will be available in LibreOffice 4.1.6.

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 13 Commit Notification 2014-02-04 12:33:52 UTC
Michael Stahl committed a patch related to this issue.
It has been pushed to "libreoffice-4-2":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=d05a33018794f7ec63daf4232d521fd2adcc5921&h=libreoffice-4-2

fdo#73300: sw: don't swap in all images when loading files


It will be available in LibreOffice 4.2.1.

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 14 Commit Notification 2014-02-04 12:35:11 UTC
Michael Stahl committed a patch related to this issue.
It has been pushed to "libreoffice-4-2":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=453bd2246011e1144ce30dbbac90f3d42839a69d&h=libreoffice-4-2

fdo#73300: sw: GraphicObjects are never swapped out


It will be available in LibreOffice 4.2.1.

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 15 Commit Notification 2014-02-05 11:39:21 UTC
Michael Stahl committed a patch related to this issue.
It has been pushed to "libreoffice-4-1-5":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=45618cc1549fd00d9d0155cbeaa50e04e8300c86&h=libreoffice-4-1-5

fdo#73300: sw: don't swap in all images when loading files


It will be available already in LibreOffice 4.1.5.

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 16 Robinson Tryon (qubit) 2015-12-15 11:07:50 UTC
Migrating Whiteboard tags to Keywords: (perf, bibisected)
[NinjaEdit]