Bug Hunting Session
Bug 108655 - For every add or remove action of a table or shape in Writer or Draw around 120 kb gets written
Summary: For every add or remove action of a table or shape in Writer or Draw around 1...
Status: RESOLVED FIXED
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: LibreOffice (show other bugs)
Version:
(earliest affected)
5.0.0.5 release
Hardware: All Windows (All)
: medium minor
Assignee: Not Assigned
URL:
Whiteboard: target:6.0.0
Keywords:
: 108652 (view as bug list)
Depends on:
Blocks: Too-Much-File-Access
  Show dependency treegraph
 
Reported: 2017-06-20 18:41 UTC by Telesto
Modified: 2017-08-04 15:49 UTC (History)
2 users (show)

See Also:
Crash report or crash signature:


Attachments
Example file (1.15 MB, text/odt)
2017-06-21 18:01 UTC, Telesto
Details
Another example (20.74 KB, application/vnd.oasis.opendocument.text)
2017-07-24 09:38 UTC, Telesto
Details
Process Monitor Output when adding a New comment (14.89 KB, application/vnd.oasis.opendocument.spreadsheet)
2017-08-02 08:57 UTC, Telesto
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Telesto 2017-06-20 18:41:25 UTC
Description:
For every draw shape added or delete 900 kb gets written (also under other circumstances, but no clue why). Introduced with 5.0 branch

Steps to Reproduce:
1. Open Draw
2. Close the sidebar (just precaution for interfering)
3. Open Process Explorer and monitor disk activity of soffice.bin
4. Add a shape (notice a spike)
5. Remove the shape (again a spike with a second delay)

Actual Results:  
Every time something gets written

Expected Results:
Probably no write disk activity


Reproducible: Always

User Profile Reset: No

Additional Info:
Found in
Version: 6.0.0.0.alpha0+
Build ID: cbf371e07fd5dea1ea08a1f299360d1273961ebd
CPU threads: 4; OS: Windows 6.19; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-06-14_23:13:57
Locale: en-US (nl_NL); Calc: CL

and in 5.0.0.5

but not in
Versie: 4.4.6.3 
Build ID: e8938fd3328e95dcf59dd64e7facd2c7d67c704d
Locale: nl_NL


User-Agent: Mozilla/5.0 (Windows NT 6.2; WOW64; rv:45.0) Gecko/20100101 Firefox/45.0
Comment 1 Telesto 2017-06-21 10:23:00 UTC
It isn't just Draw. It also happens in Writer when adding removing shapes or adding and removing tables
Comment 2 Telesto 2017-06-21 13:37:32 UTC
Similar behavior can be observed with Writer (with LibO6.0.0.0) when adding a table or shape.

Steps to reproduce
1. Open a Writer document
2. Press CTRL+F12
3. Open Process Explorer with Properties dialog opened for soffice.bin (performance graph)
4. Press Insert
Comment 3 Telesto 2017-06-21 18:01:25 UTC
Created attachment 134202 [details]
Example file

Similar behavior (930 kb write) when selecting an image in Writer. Found in LibO6.0.0.0 but not in 5.4.0.0b2
Comment 4 Buovjaga 2017-06-29 11:19:40 UTC
Repro.

Version: 6.0.0.0.alpha0+ (x64)
Build ID: e0f67add2ec56706ce06a03572535266f21c0303
CPU threads: 4; OS: Windows 6.19; UI render: default; 
TinderBox: Win-x86_64@42, Branch:master, Time: 2017-06-27_23:04:56
Locale: fi-FI (fi_FI); Calc: group
Comment 5 Telesto 2017-07-24 09:38:14 UTC
Created attachment 134810 [details]
Another example

The data written has dropped to quite a lot. It's *only* 130 kb now. The remaining writes seem to be related to the context depend toolbars. A temp file will be created for every toolbar relevant change. So it will add up pretty quick

Some examples
* For example when (a) selecting an image and (b) deselecting it (sample file attached)
* Adding a table, entering a table, removing a table (Writer/Impress)
* Adding a shape, selecting a shape, removing a shape
* Adding textbox, selecting, removing a textbox
* Inserting a comment; selecting a comment; deselecting a comment.
Comment 6 Telesto 2017-07-24 12:05:46 UTC
In probably moving goal posts. The in comment 5 described behavior is much older. 
Found in
LibreOffice 3.5.7.2 
Build ID: 3215f89-f603614-ab984f2-7348103-1225a5b

but not in
LibreOffice 3.3.0 
OOO330m19 (Build:6)
tag libreoffice-3.3.0.4
Comment 7 Telesto 2017-07-31 15:40:13 UTC
Caolán: any idea if the behavior described in comment 5 should be happening? It started somewhere between LibO 3.0 and 3.5.7.2 

The amount of data written increased with the LibO 5.0 branch (900 kb) and has recently dropped back to the pre LibO 5.0 branch (120 kb). I guess,  because of a few commits of Muhammet Kara made (https://cgit.freedesktop.org/libreoffice/core/commit/?id=8e71acc7b775aa4ad93b45aa18d0ec7d6a47a314) 

However 120 kb temp file for every toolbar event doesn't seem desirable to me

Partial stack for the temp file creating
sal3.dll	osl_writeSocket + 0x329
sal3.dll	osl_writeSocket + 0xb3
sal3.dll	osl_createTempFile + 0xe5
configmgrlo.dll	configmgr_component_getFactory + 0x12a90
configmgrlo.dll	configmgr_component_getFactory + 0x13c06
configmgrlo.dll	configmgrlo.dll + 0x5d7aa
salhelper3MSC.dll	salhelper::Thread::run + 0x50
salhelper3MSC.dll	salhelper::Thread::run + 0x908
sal3.dll	osl_getTempDirURL + 0x3e3
ucrtbase.DLL	thread_start<unsigned int (__stdcall*)(void *)> + 0x54
KERNEL32.DLL	BaseThreadInitThunk + 0xe
ntdll.dll	__RtlUserThreadStart + 0x72
ntdll.dll	_RtlUserThreadStart + 0x1b
Comment 8 Caolán McNamara 2017-07-31 20:19:41 UTC
maybe its Components::writeModifications in configmgr/source/components.cxx
Comment 9 Caolán McNamara 2017-07-31 20:41:54 UTC
Maybe the problem is on each context switch of a sidebar since https://cgit.freedesktop.org/libreoffice/core/commit/?id=187445b2d2885ced92be37ffb11cd2a9bb11f8d6 there is a UpdateConfigurations (which has TODO above it) in sfx2/source/sidebar/SidebarController.cxx which might be where some of these writes come from. Possibly simply checking if the values have changed before writing to config might give some improvements in the various config writing of the sidebar. Possibly worth investigating if there's any real value in writing the setting on each context switch.
Comment 10 Commit Notification 2017-08-01 11:03:52 UTC
Caolán McNamara committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=879c1c398ffdd00b7a9e9cc3cbe26e1aa263e00d

Related: tdf#108655 only write to config if values changed

It will be available in 6.0.0.

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 Caolán McNamara 2017-08-01 11:17:24 UTC
I'm interested in knowing if the above makes a difference to you
Comment 12 Telesto 2017-08-01 12:33:11 UTC
(In reply to Caolán McNamara from comment #11)
> I'm interested in knowing if the above makes a difference to you

I will report my finding tomorrow. Anyway, thanks for the effort!!
Comment 13 Telesto 2017-08-02 08:56:41 UTC
Sadly enough, the issue still persists. The tmp file creation always starts with New Thread. The New Thread has the follow (partial) stack) (More complete stack is attached)

16	ucrtbase.DLL	_beginthreadex + 0x4a
17	sal3.dll	osl_getTempDirURL + 0x2ac
18	sal3.dll	osl_createSuspendedThread + 0x12
19	salhelper3MSC.dll	salhelper::Thread::operator delete + 0xff0
20	salhelper3MSC.dll	salhelper::Thread::launch + 0x138
21	configmgrlo.dll	configmgrlo.dll + 0x621fc
22	configmgrlo.dll	configmgrlo.dll + 0x80bce
23	fwklo.dll	com_sun_star_comp_framework_UIConfigurationManager_get_implementation + 0xd51d
24	fwklo.dll	Point::Y + 0xfa87
25	fwklo.dll	Point::Y + 0x12ada
26	fwklo.dll	Point::Y + 0x116d7
27	fwklo.dll	Point::Point + 0xcd9c
28	sfxlo.dll	SfxDockingWindow::SetDockingRects + 0x12a7
29	sfxlo.dll	SfxDockingWindow::SetDockingRects + 0x148f
30	sfxlo.dll	SfxDispatcher::Update_Impl + 0x521
31	sfxlo.dll	SfxBindings::NextJob_Impl + 0x91
32	sfxlo.dll	SfxBindings::NextJob + 0x13
33	sfxlo.dll	SfxBindings::LinkStubNextJob + 0xf
34	vcllo.dll	Timer::operator= + 0x303
35	vcllo.dll	Timer::Invoke + 0x16
36	vcllo.dll	Scheduler::ProcessTaskScheduling + 0xb90
37	vcllo.dll	Scheduler::CallbackTaskScheduling + 0x8


The New Thread appears in various cases

* Writer (with the sidebar disabled)
- Open/ Closing Find 
- Opening/ Closing Find & Replace (CTRL+H)
- When adding a table, when entering the table, when selecting two table cells, inserting row, removing a table
- Inserting a comment; selecting a comment; deselecting a comment.
- Adding textbox, when selecting the textbox, when entering the textbox, removing a textbox
- When switching between multiple documents (using Menu -> Window)

* Calc 
- entering a cell; 
- Inserting a comment; selecting a comment; deselecting a comment

* Impress
- Entering a textbox
Comment 14 Telesto 2017-08-02 08:57:39 UTC
Created attachment 135062 [details]
Process Monitor Output when adding a New comment
Comment 15 Caolán McNamara 2017-08-03 12:50:17 UTC
But is there *less* data written then before ? There's probably always going to be some amount of data written in the config.
Comment 16 Telesto 2017-08-03 13:47:27 UTC
(In reply to Caolán McNamara from comment #15)
> But is there *less* data written then before ? There's probably always going
> to be some amount of data written in the config.

Switching between two empty Writer Documents (using the Window menu)
891 KB -> Version: 5.2.5.0.0+
678 KB -> Version: 5.3.3.1 
335 KB -> Version: 5.4.0.3
1000 KB-> Version: 6.0.0.0.alpha0+  Time: 2017-07-28_05:15:48
286 KB -> Version: 6.0.0.0.alpha0+  Time: 2017-08-02_01:19:29 (debug build)
193 KB -> Version: 6.0.0.0.alpha0+  Time: 2017-08-02_23:46:51

Don't know how I got 120 kb in the first place; strange. Anyway, it dropped.
Comment 17 Buovjaga 2017-08-04 10:47:18 UTC
Well, let's set to FIXED then.
Comment 18 Telesto 2017-08-04 12:47:47 UTC
*** Bug 108652 has been marked as a duplicate of this bug. ***
Comment 19 Telesto 2017-08-04 15:49:00 UTC
@Caolán
A small addition. I should have noticed it before, the disk write occur because LibO is updating the registrymodifications.xcu.

* LibO is updating registrymodifications.xcu when Switching between two empty Writer Documents, without making any actual to the file content. And there seem to be more cases where this is happening (for example selecting two table cells)

* A real change is saved when using the color picker (RecentColor/ RecentColorName) but I'm not sure if this is desired. 

<item oor:path="/org.openoffice.Office.Common/UserColors"><prop oor:name="RecentColor" oor:op="fuse"><value>0</value></prop></item>
<item oor:path="/org.openoffice.Office.Common/UserColors"><prop oor:name="RecentColorName" oor:op="fuse"><value><it>Black</it></value></prop></item>