[frameworks-kxmlgui] [Bug 456208] KMainWindow saves auto settings too often: this can freeze applications
https://bugs.kde.org/show_bug.cgi?id=456208 --- Comment #2 from Amaury Pouly --- Yes, the problem occurs on my machine with KDE framework 5.94.0. Here is the link of the kmainwindow file that still contains the same code: https://github.com/KDE/kxmlgui/blob/master/src/kmainwindow.cpp -- You are receiving this mail because: You are watching all bug changes.
[frameworks-kxmlgui] [Bug 456208] KMainWindow saves auto settings too often: this can freeze applications
https://bugs.kde.org/show_bug.cgi?id=456208 Amaury Pouly changed: What|Removed |Added Platform|Other |Debian unstable Version|unspecified |5.94.0 -- You are receiving this mail because: You are watching all bug changes.
[frameworks-kxmlgui] [Bug 456208] New: KMainWindow saves auto settings too often: this can freeze applications
https://bugs.kde.org/show_bug.cgi?id=456208
Bug ID: 456208
Summary: KMainWindow saves auto settings too often: this can
freeze applications
Product: frameworks-kxmlgui
Version: unspecified
Platform: Other
OS: Linux
Status: REPORTED
Severity: normal
Priority: NOR
Component: general
Assignee: kdelibs-b...@kde.org
Reporter: amaury.po...@gmail.com
Target Milestone: ---
Created attachment 150320
--> https://bugs.kde.org/attachment.cgi?id=150320=edit
example code to reproduce
DISCLAIMER:
I don't know if this qualifies as a "bug" or not, but I think it does highlight
a problem either with the framework or with users of the framework. This
"problem" explains https://bugs.kde.org/show_bug.cgi?id=451059
SUMMARY
KMainWindow saves the auto settings on various event. Most problematic is that
it triggers a save on many visibility events:
https://github.com/KDE/kdelibs/blob/1c5b25966136b6099665477616fb4d38a98fd7ef/kdeui/widgets/kmainwindow.cpp
In most cases, this is not an issue except under this, unfortunately not
uncommon, situation: switching virtual desktops of many windows using the same
config file. More precisely, assume N windows of the same application (for
example okular) are in a first desktop. All those windows share the same
configuration file. If one switching virtual desktop for example, potentially
all N windows will receive a visibility event notification. Hence all will
trigger the setSettingsDirty(), which will launch a timeout that will
eventually saveAutoSaveSettings(). This will .sync() on the autoSaveGroup. The
sync() will all happen almost at the same time and, eventually, all N-1 of them
will block in QLockFile trying to acquire a lock. The logic in QLockFile
(qtbase/src/corelib/io/qlockfile.cpp) doubles the timer every times it fails.
This means that in the unlucky, but not so rare event, where every process
blocks, this will wait 2^N*100 ms. In practice, I have managed to reach more
than 5 seconds freezes with 10 windows. There might be other ways the auto
settings are saved, I think what I described above is correct, based on playing
around with gdb.
A caveat is that the settings are saved only if something changed (ie settings
are dirty). Simply moving a window is sufficient. For a more complex UI such as
the one used by okular, it seems that simply switching desktops is sufficient
to makes settings dirty, I am not entirely sure why/how.
To simplify the reproducibility of this problem, I have written a trivial
application (attached). It runs a timer and measures when the timer is not
called then prints a message. Since the saving codes runs on the main thread,
blocking on QLockFile freezes the main thread and prevents from dispatching the
timer event.
STEPS TO REPRODUCE
1. compile the application: cmake -G 'Unix Makefiles' && make
2. run 10 copies of the application:
for i in {1..10}; do ./example_bug& done
3. This should already print some very large delays, showing that the saving
mecanism triggers some long waits
4. Manually move each of the windows
5. Switching to another virtual desktop and switch back
6. This should print some huge delays
7. close all windows: kilall example_bug
OBSERVED RESULT
Some windows freezes for 5seconds or more, here is the output:
time elapsed: 212 ms
time elapsed: 233 ms
time elapsed: 285 ms
time elapsed: 300 ms
time elapsed: 384 ms
time elapsed: 201 ms
time elapsed: 387 ms
time elapsed: 386 ms
time elapsed: 406 ms
time elapsed: 806 ms
time elapsed: 1619 ms
time elapsed: 3209 ms
time elapsed: 6412 ms
EXPECTED RESULT
Windows should not freeze.
ADDITIONAL INFORMATION
I have not specified any version for Qt/KDE because based on the source code of
kmainwindow, I suspect this has been an issue for a long time. Any recent
version of Qt/KF5 will trigger this issue.
--
You are receiving this mail because:
You are watching all bug changes.
[okular] [Bug 451059] Okular freezes for up to 10 seconds when loading a document or switching windows
https://bugs.kde.org/show_bug.cgi?id=451059 --- Comment #10 from Amaury Pouly --- (In reply to Amaury Pouly from comment #9) > I cannot explain yet *how* this can possibly lock for 10 seconds however. I think this behaviour comes from QLockFile: https://github.com/RSATom/Qt/blob/master/qtbase/src/corelib/io/qlockfile.cpp In QLockFile::tryLock(), the sleep time is doubled on every failure, up to 5 seconds. So if all okular instances rush to lock the file, it is actually possible that this happens. -- You are receiving this mail because: You are watching all bug changes.
[okular] [Bug 451059] Okular freezes for up to 10 seconds when loading a document or switching windows
https://bugs.kde.org/show_bug.cgi?id=451059 --- Comment #9 from Amaury Pouly --- Hi, I have made progress on this (I think)! By running okular in a debugger and stopping the program when it freezes, I have noticed that almost every time the backtrace is as follows (slightly abbreviated): #0 0x76231be5 in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7fffd0f0, rem=0x7fffd0f0) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:43 #1 0x76236ca3 in __GI___nanosleep (req=, rem=) at ../sysdeps/unix/sysv/linux/nanosleep.c:25 #2 0x7686ca5d in ?? () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5 #3 0x7674b01f in QLockFile::tryLock(int) () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5 #4 0x779adc59 in KConfigIniBackend::lock (this=0x556e12b0) at ./src/core/kconfigini.cpp:632 #5 0x77998796 in KConfigPrivate::lockLocal (this=0x556e2a90) at ./src/core/kconfig.cpp:123 #6 KConfig::sync (this=0x556e2b50) at ./src/core/kconfig.cpp:422 #7 0x77c97c0e in KMainWindow::saveAutoSaveSettings (this=) at ./src/kmainwindow.cpp:882 #8 0x7684c123 in ?? () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5 #9 0x7684ffca in QTimer::timeout(QTimer::QPrivateSignal) () from /usr/lib/x86_64-linux-gnu/libQt5Core.so.5 Recall that I have many (20+) instances of okular running so my theory is now that there might be a lot of contention on the config file lock. This can be easily checked by running (in my case): inotifywait -m -r /home/pamaury/.config/ and observe that okular is *very very frequently* taking a lock okularrc.lock to write okularrc. Actually, this is slightly scary: just switching between virtual desktop will trigger a flurry of creation/deletion of this file. I cannot explain yet *how* this can possibly lock for 10 seconds however. -- You are receiving this mail because: You are watching all bug changes.
[okular] [Bug 451059] Okular freezes for up to 10 seconds when loading a document or switching windows
https://bugs.kde.org/show_bug.cgi?id=451059 --- Comment #7 from Amaury Pouly --- (In reply to Albert Astals Cid from comment #6) > But if it happens just by switching virtual desktops, it has nothing to do > with dbus? > > dbus is not involved in that scenario that i can see That's a good point. Do you have any advice on how I could track down this problem? -- You are receiving this mail because: You are watching all bug changes.
[okular] [Bug 451059] Okular freezes for up to 10 seconds when loading a document or switching windows
https://bugs.kde.org/show_bug.cgi?id=451059 --- Comment #5 from Amaury Pouly --- (In reply to Albert Astals Cid from comment #4) > I just tried with 32 okular instances open and the canOpenDocs elapsed time > for all the instances when opening a new one never took more than 75ms > (tried 20 times or so), which makes sense, canOpenDocs should be very fast > since it do much. > > When you say "open a new document", how exactly are you opening it? > > Any peculiarity of your system that you think may cause this? Remote NFS > file system? weird libc? weird dbus rules? I usually either open it using Dolphin or using Zotero, but it can also happen just when switching between virtual desktops and not opening anything (less common though). Everything is local (not NFS), nothing particularly custom, no special dbus rules. When it happens, switching between virtual desktops is a often a trigger. For example: 1) open file A.pdf => fast 2) switch to other virtual desktop 3) open file A.pdf => slow 4) close it, open A.pdf => fast 5) switch to other virtual desktop 6) open A.pdf => slow -- You are receiving this mail because: You are watching all bug changes.
[okular] [Bug 451059] Okular freezes for up to 10 seconds when loading a document or switching windows
https://bugs.kde.org/show_bug.cgi?id=451059 --- Comment #3 from Amaury Pouly --- (In reply to Albert Astals Cid from comment #2) > I understand you don't have tabs enabled, right? Yes that's correct. -- You are receiving this mail because: You are watching all bug changes.
[okular] [Bug 451059] Okular freezes for up to 10 seconds when loading a document or switching windows
https://bugs.kde.org/show_bug.cgi?id=451059 Amaury Pouly changed: What|Removed |Added CC||amaury.po...@gmail.com -- You are receiving this mail because: You are watching all bug changes.
[okular] [Bug 451059] New: Okular freezes for up to 10 seconds when loading a document or switching windows
https://bugs.kde.org/show_bug.cgi?id=451059 Bug ID: 451059 Summary: Okular freezes for up to 10 seconds when loading a document or switching windows Product: okular Version: 21.12.2 Platform: Debian unstable OS: Linux Status: REPORTED Severity: major Priority: NOR Component: general Assignee: okular-de...@kde.org Reporter: amaury.po...@gmail.com Target Milestone: --- Created attachment 147249 --> https://bugs.kde.org/attachment.cgi?id=147249=edit D-BUS log of a such an instance I have a large number of okular instances running (typically 20 or more) and very often either loading a new document or just switching between windows (or switching between virtual desktops) will make okular completely freeze for a long time. Quite regularly, the freeze is short enough to be an annoyance (a couple of seconds), but every now and then, it can freeze for 10 seconds and more. I tried to debug the code myself but I am out of my depth. I got to suspect, however, that it is related to okular asking other okular instances questions over D-BUS, specifically the canOpenDocs call. I attach a D-BUS trace showing an instance when opening a document will trigger several very slow canOpenDocs calls (5 seconds). Unfortunately, I haven't found yet a 100% recipe to reproduce it but clearly: 1) it only happens with many okular instances running 2) switching virtual desktops seems to make it worse Finally, the bug is not new, I has been happening for some time but progressively got worse as my number of open documents has increased recently. I happy to provide more logs/recompile stuff if needed, I just don't really know where to start at the moment. STEPS TO REPRODUCE 1. open lots of okular documents (I use PDFs), the size of the PDFs does not seem to matter 2. switch between windows/desktops 3. open a new document, hope to reproduce the bug, otherwise close it 4. return to step 2 OBSERVED RESULT opening/switching to a windows will take anywhere between 2 to 10 seconds EXPECTED RESULT should be almost instantenous SOFTWARE/OS VERSIONS Linux: 5.16.0-3-amd64 KDE Plasma Version: 5.24.2 KDE Frameworks Version: 5.90.0 Qt Version: 5.15.2 ADDITIONAL INFORMATION -- You are receiving this mail because: You are watching all bug changes.
