Bug 480758 - kwin-6.0-overview-activities-shortcuts.py causes login slowdowns
Summary: kwin-6.0-overview-activities-shortcuts.py causes login slowdowns
Status: RESOLVED FIXED
Alias: None
Product: kwin
Classification: Plasma
Component: general (show other bugs)
Version: 5.93.0
Platform: Fedora RPMs Linux
: NOR normal
Target Milestone: ---
Assignee: KWin default assignee
URL:
Keywords: qt6
: 481543 (view as bug list)
Depends on:
Blocks:
 
Reported: 2024-02-03 02:57 UTC by Matt Fagnani
Modified: 2024-02-21 00:40 UTC (History)
5 users (show)

See Also:
Latest Commit:
Version Fixed In: 6.0
Sentry Crash Report:


Attachments
strace /usr/libexec/kf6/kconf_update output (57.24 KB, text/plain)
2024-02-06 12:10 UTC, Matt Fagnani
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Matt Fagnani 2024-02-03 02:57:06 UTC
SUMMARY

I updated a Fedora Rawhide/40 KDE Plasma installation from Plasma 5.92.0 to 5.93.0. I had previously set the splash screen to none in System Settings to work around the splash screen being shown for about 20 seconds with 5.92.0 even though the startup took about 5 s to complete https://bugs.kde.org/show_bug.cgi?id=479824 The desktop icons took about 20 seconds to appear when starting Plasma 5.93.0 on Wayland as opposed to about 5 s with 5.92.0 and earlier. The panel and background appeared after about 5 s with 5.93.0. This problem happened each of several times I started 5.93.0. I didn't see any obviously related journal messages that were new.

STEPS TO REPRODUCE
1. Boot a Fedora Rawhide KDE Plasma installation updated to 2024-2-2 with Plasma 5.93.0 downloaded from https://bodhi.fedoraproject.org/updates/FEDORA-2024-b19679b66a installed. The splash screen was previously set to None in System Settings.
2. Log in to Plasma 5.93.0 on Wayland
3. 

OBSERVED RESULT
The desktop icons took about 20 seconds to appear when starting Plasma 5.93.0

EXPECTED RESULT
The desktop icons should have taken about 5 seconds to appear when starting Plasma 5.93.0

SOFTWARE/OS VERSIONS
Linux/KDE Plasma: Fedora Rawhide/40
(available in About System)
KDE Plasma Version: 5.93.0
KDE Frameworks Version: 5.249.0
Qt Version: 6.6.1

ADDITIONAL INFORMATION
Comment 1 Matt Fagnani 2024-02-03 04:49:27 UTC
The journal had messages which started with Plasma 5.93.0 around 20 s after I started it like 
kded6[1771]: QProcess: Destroyed while process ("/usr/libexec/kf6/kconf_update") is still running.

I ran /usr/libexec/kf6/kconf_update in Konsole, and it finished after about 30 s. When I logged out and in to Plasma after that, the desktop icons appeared after about 2 s. /usr/libexec/kf6/kconf_update still being running 20 s into startup might've delayed the desktop icons from being shown.
Comment 2 Nate Graham 2024-02-05 21:56:41 UTC
Does the exact same issue reproduce on the next boot?
Comment 3 Matt Fagnani 2024-02-06 07:13:01 UTC
(In reply to Nate Graham from comment #2)
> Does the exact same issue reproduce on the next boot?

Yes, this problem happened the same way on the next boot until I ran /usr/libexec/kf6/kconf_update in Konsole. Then the desktop icons appeared after 2-5 s of starting Plasma. I had to run /usr/libexec/kf6/kconf_update in Konsole separately for each of two users on the system to work around the problem. The problem started again today right after a dnf offline upgrade which included kwin-5.93.0-2.fc40 and plasma-integration-5.93.0-3.fc40. I ran /usr/libexec/kf6/kconf_update in Konsole again for both users and the problem stopped. /usr/libexec/kf6/kconf_update took about 30-40 s to run in Konsole the first time I ran it, and its output had a line like QProcess: Destroyed while process ("/usr/bin/python3") is still running when that happened. The python program being run might've delayed /usr/libexec/kf6/kconf_update which delayed kded6 which slowed the desktop icons from appearing. /usr/libexec/kf6/kconf_update took about 1 s to run in Konsole the second and third time I ran it in Konsole after today's update as my user, and it didn't have the python containing line I mentioned. The output of kconf_update kded6 in the journal was about 20 s after starting Plasma when the problem happened and about 3-5 s after when it didn't. Thanks.
Comment 4 Matt Fagnani 2024-02-06 07:38:06 UTC
To clarify, the lines like kded6[1771]: QProcess: Destroyed while process ("/usr/libexec/kf6/kconf_update") is still running. didn't appear in the journal after I ran /usr/libexec/kf6/kconf_update in Konsole for that user, but other messages from kconf_update and kded6 appeared about 3-5 s after starting Plasma when the problem didn't happen.
Comment 5 Matt Fagnani 2024-02-06 12:10:52 UTC
Created attachment 165606 [details]
strace /usr/libexec/kf6/kconf_update output

To make the problem start happening again, I logged out of Plasma, switched to another VT and reinstalled kwin with sudo dnf reinstall kwin*. When I logged in to Plasma after that, the problem happened. I ran Konsole before the desktop icons appeared and ps aux | grep python showed a process /usr/bin/python3 /usr/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py I ran strace /usr/libexec/kf6/kconf_update in Konsole. The strace output showed that kconf_update was waiting on /usr/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py for about 30 s after which it timed out and was killed with the error QProcess: Destroyed while process ("/usr/bin/python3") is still running.

openat(AT_FDCWD, "/usr/share/kconf_update/kwin.upd", O_RDONLY|O_CLOEXEC) = 4
statx(4, "", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT|AT_EMPTY_PATH, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=571, ...}) = 0
statx(4, "", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT|AT_EMPTY_PATH, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=571, ...}) = 0
statx(4, "", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT|AT_EMPTY_PATH, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=571, ...}) = 0
read(4, "# SPDX-FileCopyrightText: 2023 N"..., 16384) = 571
read(4, "", 15813)                      = 0
statx(AT_FDCWD, "/home/matt/.local/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd130) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/home/matt/.local/share/flatpak/exports/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd130) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/var/lib/flatpak/exports/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd130) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/usr/local/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd130) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/usr/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0755, stx_size=869, ...}) = 0
getcwd("/home/matt", 4096)              = 11
statx(AT_FDCWD, "/home/matt/.local/bin/python3", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd070) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/home/matt/bin/python3", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd070) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/usr/lib64/ccache/python3", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd070) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/usr/local/bin/python3", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, 0x7ffe30dcd070) = -1 ENOENT (No such file or directory)
statx(AT_FDCWD, "/usr/bin/python3", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0755, stx_size=15976, ...}) = 0
access("/usr/bin/python3", X_OK)        = 0
pipe2([5, 6], O_CLOEXEC)                = 0
pipe2([7, 8], O_CLOEXEC)                = 0
pipe2([9, 10], O_CLOEXEC)               = 0
pipe2([11, 12], O_CLOEXEC)              = 0
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
waitid(P_PIDFD, 2147483647, NULL, WNOHANG|WEXITED, NULL) = -1 EBADF (Bad file descriptor)
clone(child_stack=0x7ffe30dcd130, flags=CLONE_VM|CLONE_PIDFD|CLONE_VFORK|SIGCHLD, parent_tid=[13]) = 69375
close(12)                               = 0
close(5)                                = 0
fcntl(6, F_GETFL)                       = 0x1 (flags O_WRONLY)
fcntl(6, F_SETFL, O_WRONLY|O_NONBLOCK)  = 0
close(8)                                = 0
fcntl(7, F_GETFL)                       = 0 (flags O_RDONLY)
fcntl(7, F_SETFL, O_RDONLY|O_NONBLOCK)  = 0
close(10)                               = 0
fcntl(9, F_GETFL)                       = 0 (flags O_RDONLY)
fcntl(9, F_SETFL, O_RDONLY|O_NONBLOCK)  = 0
ppoll([{fd=11, events=POLLIN}], 1, {tv_sec=60, tv_nsec=0}, NULL, 8) = 1 ([{fd=11, revents=POLLHUP}], left {tv_sec=59, tv_nsec=999998295})
read(11, "", 16)                        = 0
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
close(11)                               = 0
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
ppoll([{fd=-1}, {fd=7, events=POLLIN}, {fd=9, events=POLLIN}, {fd=13, events=POLLIN}], 4, {tv_sec=60, tv_nsec=0}, NULL, ) = ? ERESTARTNOHAND (To be restarted if no handler)
--- SIGWINCH {si_signo=SIGWINCH, si_code=SI_KERNEL} ---
ppoll([{fd=-1}, {fd=7, events=POLLIN}, {fd=9, events=POLLIN}, {fd=13, events=POLLIN}], 4, {tv_sec=18, tv_nsec=330338566}, NULL, 8) = 0 (Timeout)
write(2, "QProcess: Destroyed while proces"..., 73QProcess: Destroyed while process ("/usr/bin/python3") is still running.
) = 73
kill(69375, SIGKILL)                    = 0
ppoll([{fd=-1}, {fd=7, events=POLLIN}, {fd=9, events=POLLIN}, {fd=13, events=POLLIN}], 4, {tv_sec=30, tv_nsec=0}, NULL, 8) = 3 ([{fd=7, revents=POLLHUP}, {fd=9, revents=POLLHUP}, {fd=13, revents=POLLIN}], left {tv_sec=29, tv_nsec=998870093})
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=69375, si_uid=1000, si_status=SIGKILL, si_utime=2 /* 0.02 s */, si_stime=0} ---

I'm attaching the strace output. ps aux | grep python also showed /usr/bin/python3 /usr/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py while strace /usr/libexec/kf6/kconf_update was waiting. So /usr/share/kconf_update/kwin-6.0-overview-activities-shortcuts.py timing out might've led kconf_update to time out and kded6 and the desktop icons to be delayed by 20 s.
Comment 6 Nate Graham 2024-02-06 19:34:14 UTC
Thanks. I was going to ask you to use `lsof` to find which exact files were open during the hang, but you read my mind. :) It looks like that specific script may be the culprit here. Moving to KWin for investigation.
Comment 7 Bug Janitor Service 2024-02-06 20:44:16 UTC
A possibly relevant merge request was started @ https://invent.kde.org/plasma/kwin/-/merge_requests/5129
Comment 8 Vlad Zahorodnii 2024-02-08 14:01:23 UTC
Git commit 540dff30e7f014809fa25e9889f6174dec285f53 by Vlad Zahorodnii.
Committed on 08/02/2024 at 13:48.
Pushed by vladz into branch 'master'.

kconf_update: Drop kwin-6.0-overview-activities-shortcuts script

There are a few issues:

- it's incompatible with Version 6 format
- activity shortcuts cannot be changed in kwin
- overview shortcuts don't need to be touched

M  +0    -2    kconf_update/CMakeLists.txt
D  +0    -20   kconf_update/kwin-6.0-overview-activities-shortcuts.py
M  +0    -7    kconf_update/kwin.upd

https://invent.kde.org/plasma/kwin/-/commit/540dff30e7f014809fa25e9889f6174dec285f53
Comment 9 Vlad Zahorodnii 2024-02-08 15:25:48 UTC
Git commit 7d456cd63ad29e7136a8d9edb162cad1e91eb237 by Vlad Zahorodnii.
Committed on 08/02/2024 at 15:13.
Pushed by vladz into branch 'Plasma/6.0'.

kconf_update: Drop kwin-6.0-overview-activities-shortcuts script

There are a few issues:

- it's incompatible with Version 6 format
- activity shortcuts cannot be changed in kwin
- overview shortcuts don't need to be touched
(cherry picked from commit 540dff30e7f014809fa25e9889f6174dec285f53)

M  +0    -2    kconf_update/CMakeLists.txt
D  +0    -20   kconf_update/kwin-6.0-overview-activities-shortcuts.py
M  +0    -7    kconf_update/kwin.upd

https://invent.kde.org/plasma/kwin/-/commit/7d456cd63ad29e7136a8d9edb162cad1e91eb237
Comment 10 Henrik Harmsen 2024-02-19 13:47:02 UTC
*** Bug 481543 has been marked as a duplicate of this bug. ***