| Summary: | kwin-6.0-overview-activities-shortcuts.py causes login slowdowns | ||
|---|---|---|---|
| Product: | [Plasma] kwin | Reporter: | Matt Fagnani <matt.fagnani> |
| Component: | general | Assignee: | KWin default assignee <kwin-bugs-null> |
| Status: | RESOLVED FIXED | ||
| Severity: | normal | CC: | henrik, kdelibs-bugs-null, nate, niccolo, vlad.zahorodnii |
| Priority: | NOR | Keywords: | qt6 |
| Version First Reported In: | 5.93.0 | ||
| Target Milestone: | --- | ||
| Platform: | Fedora RPMs | ||
| OS: | Linux | ||
| Latest Commit: | https://invent.kde.org/plasma/kwin/-/commit/7d456cd63ad29e7136a8d9edb162cad1e91eb237 | Version Fixed/Implemented In: | 6.0 |
| Sentry Crash Report: | |||
| Attachments: | strace /usr/libexec/kf6/kconf_update output | ||
|
Description
Matt Fagnani
2024-02-03 02:57:06 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.
Does the exact same issue reproduce on the next boot? (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. 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.
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.
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. A possibly relevant merge request was started @ https://invent.kde.org/plasma/kwin/-/merge_requests/5129 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 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 *** Bug 481543 has been marked as a duplicate of this bug. *** |