Created attachment 118341 [details] Journal of one of the affected shutdowns SUMMARY I'm using KDE Plasma 5.15.1 on Arch Linux and for some time I have been experiencing slow shutdowns/reboots/logouts. When I click the respective option in Application Launcher, then for a couple of seconds nothing happens (I have logout prompt disabled), then the taskbar becomes grey (as if compositing was turned off), and only a while later does Plasma exit and return to console. The PC shuts down 2-3 s later. STEPS TO REPRODUCE Unfortunately, I have no idea what to do to reproduce this bug. It happened spontaneously during one session, and persisted ever since. During this session I've been doing some configuration, but nothing too deep, just some System Settings tweaking. OBSERVED RESULT KDE Plasma closes after ~15 s after clicking shutdown menu option EXPECTED RESULT KDE Plasma should close almost instantly and return to framebuffer console, where the shutdown process continues SOFTWARE/OS VERSIONS Windows: N/A MacOS: N/A Linux/KDE Plasma: Linux 4.20.11 (available in About System) KDE Plasma Version: 5.15.1 KDE Frameworks Version: 5.55.0 Qt Version: 5.12.1 ADDITIONAL INFORMATION Those journal entries are what is happening during the delay in closing Plasma (see attachment for full log): lut 23 10:48:01 arch-desktop ksmserver[868]: org.kde.kf5.ksmserver: SmsDie timeout, client "/usr/bin/kwin_x11" ( 10139fecddb000155091335700000008680000 ) lut 23 10:48:01 arch-desktop ksmserver[868]: org.kde.kf5.ksmserver: SmsDie timeout, client "/usr/bin/plasmashell" ( 10139fecddb000155091335800000008680007 ) lut 23 10:48:06 arch-desktop ksmserver[868]: org.kde.kf5.ksmserver: SmsDie WM timeout
I'm experiencing the same exact problem on a fresh Debian/unstable install. In addition, I've checked (running htop on a separate console on CTRL+ALT+F1) that /usr/bin/plasmashell is running at 100% CPU during those 15 seconds after I click logout. I tried to quit everything on the tray bar, to disable the compositor at startup (and thus all graphical effects), to stop pulseaudio, and to uninstall libpam-kwallet5. No luck. Debian unstable Linux 4.19.20-1 (2019-02-11) plasmashell 5.14.5 Qt: 5.11.3 KDE Frameworks: 5.54.0 kf5-config: 1.0 Relevant parts from journalctl: Feb 24 14:26:02 debian polkitd(authority=local)[617]: Unregistered Authentication Agent for unix-session:41 (system bus name :1.1320, object path /org/kde/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) Feb 24 14:26:02 debian sddm[626]: kwalletd5: Checking for pam module Feb 24 14:26:02 debian sddm[626]: kwalletd5: Got pam-login param Feb 24 14:26:02 debian sddm[626]: kwalletd5: Waiting for hash on 7- Feb 24 14:26:02 debian sddm[626]: kwalletd5: waitingForEnvironment on: 3 Feb 24 14:26:02 debian sddm[626]: kwalletd5: client connected Feb 24 14:26:02 debian sddm[626]: kwalletd5: client disconnected Feb 24 14:26:17 debian sddm-helper[12052]: [PAM] Closing session Feb 24 14:26:17 debian sddm-helper[12052]: pam_unix(sddm:session): session closed for user marco Feb 24 14:26:17 debian sddm-helper[12052]: pam_kwallet5(sddm:session): pam_kwallet5: pam_sm_close_session Feb 24 14:26:17 debian sddm-helper[12052]: [PAM] Ended. Feb 24 14:26:17 debian sddm-helper[12052]: pam_kwallet5(sddm:setcred): pam_kwallet5: pam_sm_setcred Feb 24 14:26:17 debian sddm[626]: Auth: sddm-helper exited successfully Feb 24 14:26:17 debian pulseaudio[11433]: XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0" Feb 24 14:26:17 debian pulseaudio[11433]: after 19 requests (19 known processed) with 0 events remaining. Feb 24 14:26:17 debian sddm[626]: Socket server stopping... Feb 24 14:26:17 debian org.kde.kuiserver[981]: The X11 connection broke (error 1). Did the X11 server die? Feb 24 14:26:17 debian org.kde.kglobalaccel[981]: The X11 connection broke (error 1). Did the X11 server die? Feb 24 14:26:17 debian org.kde.ActivityManager[981]: The X11 connection broke (error 1). Did the X11 server die? Feb 24 14:26:17 debian org.kde.KScreen[981]: The X11 connection broke (error 1). Did the X11 server die? Feb 24 14:26:17 debian sddm[626]: Socket server stopped. Feb 24 14:26:17 debian sddm[626]: Display server stopping...
I've been investigating, and I think we're misreading the logs. What should happen is Plasmashell disables session management and immediately responds to the session manager that it is ignoring the request. As soon as all session controlled apps have finished, ksmserver starts killing everything else, including plasmashell. A bit quirky, but does seem to work. The fact that we're in SMSDie is fine, the fact that it's timing out is weird. --- There's a bug in plasmashell, somewhere - ideally I need a gdb trace of plasmashell when it's in this high CPU state. Though I appreciate that will be hard to get. --- What's also weird is it thinks kwin_x11 is a client, it should detect that it's the WM and treat it differently. Can I have your ~/.config/ksmserverrc --- Also can you add export QT_LOGGING_RULES='org.kde.kf5.ksmserver.debug=true' to something that gets sourced before login (/etc/profile.d/debug.sh is one of the most reliable) and then reattach a new log if you can reproduce after starting with this env set. It'll print a lot more for ksmserver.
Created attachment 118361 [details] Another journal, with QT_LOGGING_RULES As for the ~/.config/ksmserverrc, this is everything it contains: [General] confirmLogout=false excludeApps= loginMode=default offerShutdown=true shutdownType=0 In the full log, only the end is relevant as I have only relogged in after setting the environment variable. The relevant part starts at 19:24:21.
I also experience very slow start and shutdown, also Plasma 5 on Arch, system on SSD. Someone suggested it may be my desktop widgets - and teh widgets load exactly the moment the 10-15 sec long "hang time" in the middle of teh GUI loading ends. Does the reporter here use widgets? Also, I'm a noob so please let me know what logs should I uploaded and how to get them. Journal from the moment of logging in via console: https://pastebin.com/vjMN7Y0y Some interesting parts with several sec delays: Mar 09 07:19:31 Camelot systemd[1]: Started Session 1 of user storm. Mar 09 07:19:32 Camelot kernel: resource sanity check: requesting [mem 0x000c0000-0x000fffff], which spans more than PCI Bus 0000:00 [mem 0x000d0000-0x000d3fff window] Mar 09 07:19:32 Camelot kernel: caller _nv001094rm+0xe3/0x1d0 [nvidia] mapping multiple BARs Mar 09 07:19:33 Camelot systemd[659]: Started D-Bus User Message Bus. Mar 09 07:19:35 Camelot systemd-timesyncd[585]: Synchronized to time server 5.39.184.5:123 (2.arch.pool.ntp.org). Mar 09 07:19:38 Camelot dbus-daemon[705]: [session uid=1000 pid=705] Activating service name='org.kde.kglobalaccel' requested by ':1.5' (uid=1000 pid=739 comm="kded5 [kdeinit5] ") Mar 09 07:19:38 Camelot dbus-daemon[705]: [session uid=1000 pid=705] Successfully activated service 'org.kde.kglobalaccel' Mar 09 07:19:39 Camelot dbus-daemon[589]: [system] Activating via systemd: service name='org.freedesktop.ColorManager' unit='colord.service' requested by ':1.23' (uid=1000 pid=739 comm="kded5 [kdeinit5] ") Mar 09 07:19:45 Camelot dbus-daemon[589]: [system] Activating via systemd: service name='org.freedesktop.UDisks2' unit='udisks2.service' requested by ':1.59' (uid=1000 pid=888 comm="/usr/bin/dolphin -session 10afd0e16500015516182050") Mar 09 07:19:45 Camelot systemd[1]: Starting Disk Manager... Mar 09 07:19:45 Camelot udisksd[1053]: udisks daemon version 2.8.1 starting Mar 09 07:19:58 Camelot dbus-daemon[705]: [session uid=1000 pid=705] Activating service name='org.kde.kuiserver' requested by ':1.20' (uid=1000 pid=840 comm="/usr/bin/plasmashell ") Mar 09 07:19:58 Camelot dbus-daemon[705]: [session uid=1000 pid=705] Successfully activated service 'org.kde.kuiserver' Mar 09 07:20:10 Camelot dbus-daemon[589]: [system] Failed to activate service 'org.freedesktop.UDisks2': timed out (service_start_timeout=25000ms) Mar 09 07:20:14 Camelot dbus-daemon[589]: [system] Activating via systemd: service name='org.freedesktop.UDisks2' unit='udisks2.service' requested by ':1.59' (uid=1000 pid=888 comm="/usr/bin/dolphin -session 10afd0e16500015516182050") Mar 09 07:20:18 Camelot dbus-daemon[589]: [system] Successfully activated service 'org.freedesktop.UDisks2' Mar 09 07:20:18 Camelot systemd[1]: Started Disk Manager. Not sure if my issue is related.
[storm@Camelot] (~) $ systemd-analyze blame 32.659s udisks2.service 8.064s dhcpcd@enp3s0.service 724ms lvm2-monitor.service 680ms systemd-logind.service 631ms systemd-journal-flush.service 555ms dev-sda2.device 396ms home-storm-misc-swapfile.swap 273ms systemd-timesyncd.service 207ms upower.service 198ms systemd-fsck@dev-disk-by\x2duuid-68CB\x2d49A9.service 198ms systemd-fsck@dev-disk-by\x2duuid-6140ad0c\x2dca18\x2d42ca\x2dacd4\x2d0ed77f7f0700.service 192ms systemd-udevd.service 172ms systemd-fsck@dev-disk-by\x2duuid-9b9b2009\x2d57e5\x2d473c\x2d97cd\x2deaa63c3dc8b8.service 127ms user@1000.service 113ms polkit.service 94ms systemd-modules-load.service 71ms systemd-udev-trigger.service 69ms home.mount 58ms systemd-journald.service 52ms systemd-tmpfiles-setup-dev.service 47ms boot.mount 38ms systemd-binfmt.service 35ms systemd-tmpfiles-clean.service 34ms home-storm-misc.mount 33ms systemd-tmpfiles-setup.service [...] This corresponds with my second snippet above.
Sorry for the comment spam. Apparently udisk2 is not the culprit. I remoed that issue via disabling Dropbox (see: https://bbs.archlinux.org/viewtopic.php?id=239449 ) but that didn't solve the problem. Now: systemd-analyze blame 8.213s dhcpcd@enp3s0.service 2.833s udisks2.service 682ms systemd-journal-flush.service 675ms systemd-logind.service 619ms lvm2-monitor.service 551ms dev-sda2.device 388ms home-storm-misc-swapfile.swap 289ms systemd-timesyncd.service 269ms upower.service 255ms systemd-fsck@dev-disk-by\x2duuid-68CB\x2d49A9.service 191ms systemd-fsck@dev-disk-by\x2duuid-6140ad0c\x2dca18\x2d42ca\x2dacd4\x2d0ed77f7f0700.service 189ms systemd-udevd.service 160ms systemd-fsck@dev-disk-by\x2duuid-9b9b2009\x2d57e5\x2d473c\x2d97cd\x2deaa63c3dc8b8.service 156ms user@1000.service 116ms polkit.service 103ms packagekit.service 85ms systemd-udev-trigger.service 83ms systemd-modules-load.service 78ms home.mount 66ms systemd-journald.service 60ms boot.mount 45ms systemd-tmpfiles-setup-dev.service systemd-analyze critical-chain: multi-user.target @10.253s └─getty.target @10.252s └─getty@tty1.service @10.251s └─systemd-user-sessions.service @10.242s +7ms └─network.target @10.240s └─dhcpcd@enp3s0.service @2.025s +8.213s └─basic.target @2.023s └─sockets.target @2.022s └─dbus.socket @2.021s └─sysinit.target @2.019s └─systemd-timesyncd.service @1.729s +289ms └─systemd-tmpfiles-setup.service @1.692s +33ms └─local-fs.target @1.690s └─tmp.mount @1.686s +3ms └─swap.target @1.681s └─home-storm-misc-swapfile.swap @1.292s +388ms └─home-storm-misc.mount @1.262s +28ms └─home.mount @1.141s +78ms └─systemd-fsck@dev-disk-by\x2duuid-6140ad0c\x2dca18\x2d42ca\x2dacd4\x2d0ed77f7f0700.service @949ms +191ms └─local-fs-pre.target @939ms └─lvm2-monitor.service @318ms +619ms └─lvm2-lvmetad.service @364ms └─systemd-journald.socket @312ms └─system.slice @295ms └─-.slice @295ms (Ignore the 8 sec for DHCP, that happens before login and is due to my crap router) Journal: https://pastebin.com/q8CRRte0
New information was provided; changing status for inspection.
This problem occurs on a fresh openSUSE Tumbleweed install too. After clicking shutdown menu option, KDE hang about 20s, then system begin shutdown. SOFTWARE/OS VERSIONS Operating System: openSUSE Tumbleweed 20201030 KDE Plasma Version: 5.20.2 KDE Frameworks Version: 5.75.0 Qt Version: 5.15.1 Kernel Version: 5.9.1-1-default OS Type: 64-bit ADDITIONAL INFORMATION Relevant logs: Nov 07 10:14:48 suse ksmserver[1658]: org.kde.kf5.ksmserver: SmsDie timeout, client "/usr/bin/plasma-discover" ( 1073757365000160456969200000017050037 ) Nov 07 10:14:38 suse systemd[1503]: app-\x2fusr\x2fbin\x2fdolphin-bd8fcda6dbba4b208896911902a680ba.scope: Succeeded. Nov 07 10:14:38 suse kded5[1635]: Service ":1.33" unregistered Nov 07 10:14:38 suse systemd[1503]: app-\x2fusr\x2flib64\x2flibexec\x2fxdg\x2ddesktop\x2dportal\x2dkde-13a33e03223a4d46aca604f39886be7c.scope: Succeeded. Nov 07 10:14:38 suse systemd[1503]: app-\x2fusr\x2flib64\x2flibexec\x2fbaloorunner-909ba7e66bf3436da20c1563151d663f.scope: Succeeded. Nov 07 10:14:38 suse polkitd[1028]: Unregistered Authentication Agent for unix-session:2 (system bus name :1.34, object path /org/kde/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) Nov 07 10:14:38 suse polkit-kde-authentication-agent-1[1675]: Removing listener PolkitQt1::Agent::Listener(0x5569ca7467f0) Nov 07 10:14:38 suse polkit-kde-authentication-agent-1[1675]: Destroying listener Nov 07 10:14:23 suse dbus-daemon[1522]: [session uid=1000 pid=1522] Successfully activated service 'org.kde.Shutdown' Nov 07 10:14:22 suse dbus-daemon[1522]: [session uid=1000 pid=1522] Activating service name='org.kde.Shutdown' requested by ':1.16' (uid=1000 pid=1658 comm="/usr/bin/ksmserver ") Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: kf.plasma.core: findInCache with a lastModified timestamp of 0 is deprecated Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: kf.plasma.core: findInCache with a lastModified timestamp of 0 is deprecated Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: kf.plasma.core: findInCache with a lastModified timestamp of 0 is deprecated Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:413:631: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:413:379: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:413:129: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:412:129: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:411:129: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:410:129: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:409:130: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:408:393: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:408:130: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:407:130: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: qt.svg: <input>:406:376: Could not add child element to parent element because the types are incorrect. Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: kf.plasma.core: findInCache with a lastModified timestamp of 0 is deprecated Nov 07 10:14:20 suse ksmserver-logout-greeter[5055]: Cyclic dependency detected between "file:///usr/lib64/qt5/qml/org/kde/kirigami.2/styles/org.kde.desktop.plasma/Units.qml" and "file:///usr/lib64/qt5/qml/org/kde/kirigami.2/styles/org.kde.desktop.plasma/Units.qml" Nov 07 10:14:20 suse dbus-daemon[1522]: [session uid=1000 pid=1522] Successfully activated service 'org.kde.LogoutPrompt' Nov 07 10:14:20 suse dbus-daemon[1522]: [session uid=1000 pid=1522] Activating service name='org.kde.LogoutPrompt' requested by ':1.20' (uid=1000 pid=1672 comm="/usr/bin/plasmashell ") WORKAROUND: The default KDE settings, "System Settings -> Startup and Shutdown -> Desktop Session -> On Login" is "Restroe previous session", change it to "Start with an empty session", this problem will disappear.
It seems that "/usr/bin/plasma-discover" prevent KDE from really shutdown. After killing plasma-discover process manually before shutdown, this problem disappear too.
Yes, I can confirm the same thing. *** This bug has been marked as a duplicate of bug 428175 ***