Bug 96095 - Performance regression when opening "Getting Started" in 5.0+
Summary: Performance regression when opening "Getting Started" in 5.0+
Status: RESOLVED WORKSFORME
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: Writer (show other bugs)
Version:
(earliest affected)
5.0.3.2 release
Hardware: All All
: medium normal
Assignee: Not Assigned
URL:
Whiteboard:
Keywords: bibisectRequest, perf, regression
Depends on:
Blocks:
 
Reported: 2015-11-26 22:27 UTC by Yousuf Philips (jay) (retired)
Modified: 2017-08-14 13:21 UTC (History)
7 users (show)

See Also:
Crash report or crash signature:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Yousuf Philips (jay) (retired) 2015-11-26 22:27:35 UTC
Steps:
1) Open https://wiki.documentfoundation.org/images/0/0f/GS42-GettingStartedLO.odt
2) Notice that once the document loads, the cursor is frantically blinking
3a) In 5.0.x, the UI hangs and one CPU core is hammered at 100% for 1.40 mins and then drops to ~0%
3b) In 5.1.x, UI is accessible, the statusbar page numbers field shows '1 of 812' rather than '1 of 396' and one CPU core is hammered for 4 mins and then drops to ~70% after the repagination and stays at this level even after an addition 6 mins. Also scrolling through the document during the time the CPU core is being hammered results in the page number field to always switch back to '1 of 812'.

Regression as in 4.4, the UI never hangs, the statusbar page number field accurately shows the correct current page during repagination, and after loading the document, the CPU gets hammered only for ~30 secs and then drops to ~10%.

I noticed that during the period when the cursor is blinking frantically, what seemed to be the borders around invisible images would appear and disappear repeatedly at the top left corner of the document area. I had seen this happen in other documents as well which took long time to load

Version: 5.1.0.0.alpha1+
Build ID: f6bc5b79c31225c02e9500d0ced4bd26f998f82b
Threads 2; Ver: 3.13; Render: default; 
TinderBox: Linux-rpm_deb-x86_64@70-TDF, Branch:master, Time: 2015-11-24_01:06:28
Locale: en-US (en_US.UTF-8)

Version: 5.0.4.0.0+
Build ID: ec0da57d9cc93b2bfaaa5b6b2d47c3850b3a814e
TinderBox: Linux-rpm_deb-x86_64@46-TDF, Branch:libreoffice-5-0, Time: 2015-11-12_14:15:55
Locale: en-US (en_US.UTF-8)

Version: 4.4.7.0.0+
Build ID: f4e658ec2e0b6885ec461d5c3e2bc0e2b1d5c649
TinderBox: Linux-rpm_deb-x86_64@46-TDF, Branch:libreoffice-4-4, Time: 2015-10-27_23:05:57
Locale: en_US.UTF-8
Comment 1 m_a_riosv 2015-11-27 01:08:04 UTC
Hi @Jay,

I can't reproduce with Win10x64 Version: 5.0.3.2 (x64)
Build ID: e5f16313668ac592c1bfb310f4390624e3dbfb75.

It shows 396 pages. 115248 words, 660899 characters.

Maybe you have lower values in Menu/Tools/Options/Memory - Graphics cache. I have 640 Mb - 2,5 Mb - 01:00 hour - 256 objects.

BTW, curious the page style name OOoPageStyle.
Comment 2 Cor Nouws 2015-11-27 07:28:13 UTC
@jay:

Is openGL enabled or not ?

(In reply to m.a.riosv from comment #1)

> BTW, curious the page style name OOoPageStyle.

Yeh, the document has a long history ;)
Comment 3 Michael Meeks 2015-11-27 09:30:55 UTC
The CPU being hammered thing is a silly in 5.1.x - that I have a local set of fixes for - just testing here. Can you test with a build that includes: ed4d8c89ee954b3c9340583c95e8622a6cb47b3b ? =)

Thanks !
Comment 4 m_a_riosv 2015-11-27 12:10:07 UTC
Works fine for me the sample file with:

Win10x64

Version: 5.0.4.0.0+
Build ID: 65bdad52a04dc1f5d771bdfdc8bce23e9ba74296
TinderBox: Win-x86@62-merge-TDF, Branch:libreoffice-5-0, Time: 2015-11-26_16:11:50

After clean profile, takes about 01'35" before CPU goes to zero.
With graphics cache: 32 Mb takes about 01'34" before CPU goes to zero.
With graphics cache: 48 Mb takes about 01'14" before CPU goes to zero.

Version: 5.2.0.0.alpha0+
Build ID: dc269d07e8e5d71818bc0a546c3daef4d50eb1c7
Threads 4; Ver: Windows 6.19; Render: GL; 
TinderBox: Win-x86@39, Branch:master, Time: 2015-11-27_07:36:59

After clean profile, takes about 03'55" before CPU goes to zero.
With graphics cache: 32 Mb takes about 03'55" before CPU goes to zero.
With graphics cache: 48 Mb takes about 01'00" before CPU goes to zero.

Seeing the big difference on times until the CPU load is reduced, the lower is a 20% less for 5.0.4, maybe it's time to change default memory size for graphics cache, 48 Mb I think is a low value and acceptable for basic computers.
Comment 5 m_a_riosv 2015-11-27 12:19:14 UTC
(In reply to Cor Nouws from comment #2)
> @jay:
> 
> Is openGL enabled or not ?

I forgot this point, for the above estimations, Yes - 5.0.4, Not - Master, default values with a clean profile.

> 
> (In reply to m.a.riosv from comment #1)
> 
> > BTW, curious the page style name OOoPageStyle.
> 
> Yeh, the document has a long history ;)

What sounds good about ODF.
Comment 6 Michael Meeks 2015-11-27 12:43:07 UTC
At least on Linux, with the fixes I pushed I see no bad behavior here; no CPU hammering, fast load and ~no flickering =)

Can you re-open if it persists ?

Thanks !
Comment 7 Yousuf Philips (jay) (retired) 2015-11-27 22:28:34 UTC
(In reply to m.a.riosv from comment #1)
> Maybe you have lower values in Menu/Tools/Options/Memory - Graphics cache. I
> have 640 Mb - 2,5 Mb - 01:00 hour - 256 objects.

I have the default values - 20 Mb, 5.2 Mb, 00:10, 20 objects.

(In reply to Cor Nouws from comment #2)
> Is openGL enabled or not ?

OpenGL is not enabled, as indicated in the description "Threads 2; Ver: 3.13; Render: default;" (the "default" shows its not using opengl)

(In reply to m.a.riosv from comment #4)
> After clean profile, takes about 01'35" before CPU goes to zero.
> With graphics cache: 32 Mb takes about 01'34" before CPU goes to zero.
> With graphics cache: 48 Mb takes about 01'14" before CPU goes to zero.
[...]
> After clean profile, takes about 03'55" before CPU goes to zero.
> With graphics cache: 32 Mb takes about 03'55" before CPU goes to zero.
> With graphics cache: 48 Mb takes about 01'00" before CPU goes to zero.

During this time, one of the CPU treads is being hammered before going to zero, right?

> Seeing the big difference on times until the CPU load is reduced, the lower
> is a 20% less for 5.0.4, maybe it's time to change default memory size for
> graphics cache, 48 Mb I think is a low value and acceptable for basic
> computers.

Changing these default settings is being discussed in bug 94760.

(In reply to Michael Meeks from comment #6)
> At least on Linux, with the fixes I pushed I see no bad behavior here; no
> CPU hammering, fast load and ~no flickering =)

Tried the latest master and no difference in one CPU core being hammered for 4 mins, but atleast is now drops down to zero rather than going to ~70%.

Version: 5.2.0.0.alpha0+
Build ID: 4f088f78050ec1c831b31b3bf3d4e8d5197c7daa
Threads 2; Ver: 3.13; Render: default; 
TinderBox: Linux-rpm_deb-x86_64@70-TDF, Branch:master, Time: 2015-11-27_18:25:47
Locale: en-US (en_US.UTF-8)
Comment 8 m_a_riosv 2015-11-27 23:07:24 UTC
(In reply to Yousuf (Jay) Philips from comment #7)
> (In reply to m.a.riosv from comment #1)
.......
> 
> During this time, one of the CPU treads is being hammered before going to
> zero, right?

Right.

> 
......
> Changing these default settings is being discussed in bug 94760.

Thanks for the info, I'll comment there.

Pardon, my mistake about OpenGL active, it's just the contrary, No - 5.0.4, Yes - Master.

The long time for Master with 20Mb of cache doesn't increase a bit with OpenGL disable. Also with OpenGL active for 5.0.4 improves a bit. (about 5%)
Comment 9 m_a_riosv 2015-11-28 01:59:38 UTC
New test: 
Version: 5.2.0.0.alpha0+ (x64)
Build ID: b33236bfd25333513823e69fac1bc833ee4b5f6e
Threads 4; Ver: Windows 6.19; Render: GL; 
TinderBox: Win-x86_64@62-TDF, Branch:MASTER, Time: 2015-11-27_11:30:47

After clean profile, takes about 01'08" before CPU goes to zero.
With graphics cache: 48 Mb takes about 00'30" before CPU goes to zero.

Version: 5.2.0.0.alpha0+
Build ID: a8860122fecbaa932a48f41a38077f621275be9d
Threads 4; Ver: Windows 6.2; Render: GL; 
TinderBox: Win-x86@62-merge-TDF, Branch:MASTER, Time: 2015-11-27_10:34:00
After clean profile, takes about 01'29" before CPU goes to zero.
With graphics cache: 48 Mb takes about 00'47" before CPU goes to zero.


With windows TinderBox:Win-x86@39 has symbols, maybe that explain the big difference.
Comment 10 Buovjaga 2015-11-30 08:41:58 UTC
I confirm the CPU burning, but not the pagination error.
When I scrolled through the document a bit, I didn't notice any pagination weirdness, but I got a fatal error - bad allocation!
I couldn't get a bt.

Let's set to NEW for now.

Win 7 Pro 64-bit Version: 5.2.0.0.alpha0+
Build ID: a7c3a2a9be83686657c06f37d521f9f6d2004ddd
Threads 4; Ver: Windows 6.1; Render: default; 
TinderBox: Win-x86@39, Branch:master, Time: 2015-11-28_04:39:18
Locale: fi-FI (fi_FI)
Comment 11 Robinson Tryon (qubit) 2015-12-09 18:05:59 UTC Comment hidden (obsolete)
Comment 12 raal 2016-03-31 14:19:52 UTC
Reproducible with Version: 5.2.0.0.alpha0+
Build ID: ef34535ceb60d7d63b8d8671e4c6e9e43ffbd17d
CPU Threads: 4; OS Version: Linux 4.2; UI Render: default; 
TinderBox: Linux-rpm_deb-x86_64@70-TDF, Branch:master, Time: 2016-03-27_09:53:05
Comment 13 Xisco Faulí 2016-09-12 12:14:20 UTC
Adding keyword 'bibisectRequest'.
Comment 14 Telesto 2017-08-08 17:16:47 UTC
No repro with:
Version: 6.0.0.0.alpha0+
Build ID: 386fcf9be786b302cd2c6f85ff6d8d97a6777926
CPU threads: 4; OS: Windows 6.19; UI render: GL; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-08-06_01:57:50
Locale: nl-NL (nl_NL); Calc: CL
Comment 15 Buovjaga 2017-08-14 13:21:04 UTC
(In reply to Telesto from comment #14)
> No repro with:
> Version: 6.0.0.0.alpha0+
> Build ID: 386fcf9be786b302cd2c6f85ff6d8d97a6777926
> CPU threads: 4; OS: Windows 6.19; UI render: GL; 
> TinderBox: Win-x86@42, Branch:master, Time: 2017-08-06_01:57:50
> Locale: nl-NL (nl_NL); Calc: CL

Same here, let's close.

Arch Linux 64-bit, KDE Plasma 5
Version: 6.0.0.0.alpha0+
Build ID: db17a874af37350b3270932175854ee674447bc1
CPU threads: 8; OS: Linux 4.12; UI render: default; VCL: kde4; 
Locale: fi-FI (fi_FI.UTF-8); Calc: group
Built on August 11th 2017