This forum has been archived. All content is frozen. Please use KDE Discuss instead.

Logout takes too long to complete, stuck on black screen

Tags: None
(comma "," separated)
User avatar
Soukyuu
Registered Member
Posts
71
Karma
0
OS
The logout in Plasma 5.4 takes as long as it took in 5.3 - with 5.3 crashing, reloading, then finally logging out. With 5.4 the crash was fixed, but it still takes as long until I either get to sddm or the PC shuts down/reboots. The whole process takes about 8 seconds to complete. Visually, I can only see a black screen with a mouse cursor on it.

Here is the log snippet for a restart:
Code: Select all
Sep 05 01:19:31 kdeinit5[772]: Shutdown called with confirm  -1  type  1  and mode  -1
Sep 05 01:19:31 kdeinit5[772]: After modifications confirm is  -1  type is  1  and mode  3
Sep 05 01:19:32 kdeinit5[711]: powerdevil: DBus service  ":1.21"  is requesting inhibition
Sep 05 01:19:32 kdeinit5[711]: powerdevil: Added inhibition with cookie  1  from  "ksmserver"  with  "Shutting down system"
Sep 05 01:19:32 kdeinit5[711]: powerdevil: Added interrupt session
Sep 05 01:19:32 kdeinit5[772]: saveSession is  false
Sep 05 01:19:32 kdeinit5[772]: ksmserver: Saving legacy session apps
Sep 05 01:19:32 kdeinit5[772]: ksmserver: Done saving  2  legacy session apps
Sep 05 01:19:32 kdeinit5[772]: clients should be empty,  false
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: completeShutdownOrCheckpoint called
Sep 05 01:19:32 kdeinit5[772]: state is  7
Sep 05 01:19:38 kdeinit5[772]: ksmserver: Starting killing clients
Sep 05 01:19:38 kdeinit5[772]: ksmserver: completeShutdown: client  "/usr/bin/baloo_file" ( 101a413f13912e000144138736100000007720000 )
Sep 05 01:19:38 kdeinit5[772]: ksmserver: completeShutdown: client  "/usr/bin/krunner" ( 101a413f13912e000144138736100000007720001 )
Sep 05 01:19:38 kdeinit5[772]: ksmserver: completeShutdown: client  "kwinsmhelper" ( 101a413f13912e000144138736100000007720003 )
Sep 05 01:19:38 kdeinit5[772]: ksmserver: completeShutdown: client  "/usr/bin/plasmashell" ( 101a413f13912e000144138736100000007720004 )
Sep 05 01:19:38 kdeinit5[772]: ksmserver: completeShutdown: client  "/usr/lib/polkit-kde/polkit-kde-authentication-agent-1" ( 101a413f13912e0001441
Sep 05 01:19:38 kdeinit5[772]: ksmserver: completeShutdown: client  "/usr/bin/yakuake" ( 101a413f13912e000144138736200000007720006 )
Sep 05 01:19:38 kdeinit5[772]: ksmserver: completeShutdown: client  "pulseaudio" ( 101a413f13912e000144138736200000007720007 )
Sep 05 01:19:38 polkitd[596]: Unregistered Authentication Agent for unix-session:c2 (system bus name :1.24, object path /org/kde/PolicyKit1/Authent
Sep 05 01:19:38 kdeinit5[772]: ksmserver:  We killed all clients. We have now clients.count()= 9
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 9
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 8
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 7
Sep 05 01:19:38 polkit-kde-authentication-agent-1[795]: Destroying listener
Sep 05 01:19:38 polkit-kde-authentication-agent-1[795]: Removing listener  PolkitQt1::Agent::Listener(0x13e3090)
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 6
Sep 05 01:19:38 kwin_x11[781]: QXcbConnection: XCB error: 3 (BadWindow), sequence: 49101, resource id: 52428806, major code: 18 (ChangeProperty), m
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 5
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 4
Sep 05 01:19:38 kwin_x11[781]: QXcbConnection: XCB error: 3 (BadWindow), sequence: 49105, resource id: 46137359, major code: 18 (ChangeProperty), m
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 3
Sep 05 01:19:38 kwin_x11[781]: QXcbConnection: XCB error: 3 (BadWindow), sequence: 49109, resource id: 44040210, major code: 18 (ChangeProperty), m
Sep 05 01:19:38 kdeinit5[711]: Service  "org.kde.StatusNotifierHost-787" unregistered
Sep 05 01:19:38 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 2
Sep 05 01:19:38 kwin_x11[781]: QXcbConnection: XCB error: 3 (BadWindow), sequence: 49113, resource id: 50331880, major code: 18 (ChangeProperty), m
Sep 05 01:19:39 kdeinit5[772]: ksmserver: KSMServer::completeKilling clients.count()= 1
Sep 05 01:19:39 kdeinit5[772]: ksmserver: Starting killing WM
Sep 05 01:19:39 kdeinit5[772]: ksmserver: killWM: client  "kwin_x11" ( 101a413f13912e000144138736100000007720002 )
Sep 05 01:19:39 kdeinit5[772]: ksmserver: KSMServer::completeKillingWM clients.count()= 1
Sep 05 01:19:39 kdeinit5[772]: ksmserver: KSMServer::completeKillingWM clients.count()= 1
Sep 05 01:19:39 kdeinit5[711]: Service  ":1.249" unregistered
Sep 05 01:19:39 kdeinit5[772]: ksmserver: KSMServer::completeKillingWM clients.count()= 0
Sep 05 01:19:39 systemd-logind[456]: System is rebooting.
Sep 05 01:19:39 systemd[1]: Starting Store Sound Card State...
Sep 05 01:19:39 systemd[1]: Stopping Disk Manager...
Sep 05 01:19:39 avahi-daemon[1868]: Got SIGTERM, quitting.
Sep 05 01:19:39 avahi-daemon[1868]: Leaving mDNS multicast group on interface enp5s0.IPv4 with address <IP>
Sep 05 01:19:39 avahi-daemon[1868]: avahi-daemon 0.6.31 exiting.
Sep 05 01:19:39 systemd[1]: Stopping Avahi mDNS/DNS-SD Stack...
Sep 05 01:19:39 systemd[1]: Starting Generate shutdown-ramfs...
Sep 05 01:19:39 systemd[1]: Stopped target Graphical Interface.
Sep 05 01:19:39 systemd[1]: Stopping RealtimeKit Scheduling Policy Service...
Sep 05 01:19:39 systemd[1]: Stopping User Manager for UID 1000...
Sep 05 01:19:39 systemd[644]: Stopped target Default.
Sep 05 01:19:39 systemd[644]: Reached target Shutdown.
Sep 05 01:19:39 systemd[644]: Stopped target Basic System.
Sep 05 01:19:39 systemd[644]: Stopped target Sockets.
Sep 05 01:19:39 systemd[644]: Stopped target Timers.
Sep 05 01:19:39 systemd[644]: Stopped target Paths.
Sep 05 01:19:39 systemd[644]: Starting Exit the Session...
Sep 05 01:19:39 systemd[1]: Stopped Session c1 of user sddm.
Sep 05 01:19:39 sddm[493]: Signal received: SIGTERM
Sep 05 01:19:39 sddm[493]: Socket server stopping...
Sep 05 01:19:39 sddm[493]: Socket server stopped.
Sep 05 01:19:39 kernel: kactivitymanage[729]: segfault at 7f0ffc9e9d10 ip 00007f0ffcc33881 sp 00007fff3ee41878 error 4 in libQt5Sql.so.5.5.0[7f0ffcc1d000+41000]
Sep 05 01:19:39 sddm[493]: Display server stopping...
Sep 05 01:19:39 kdeinit5[708]: kdeinit5: Fatal IO error: client killed
Sep 05 01:19:39 kscreen_backend_launcher[739]: The X11 connection broke (error 1). Did the X11 server die?
Sep 05 01:19:39 kdeinit5[708]: kdeinit5: sending SIGHUP to children.
Sep 05 01:19:39 kactivitymanagerd[729]: The X11 connection broke (error 1). Did the X11 server die?
Sep 05 01:19:39 kdeinit5[711]: The X11 connection broke: I/O error (code 1)
Sep 05 01:19:39 kdeinit5[709]: The X11 connection broke (error 1). Did the X11 server die?
Sep 05 01:19:39 kdeinit5[772]: ksmserver: Fatal IO error: client killed
Sep 05 01:19:39 systemd[645]: pam_unix(systemd-user:session): session closed for user azure
Sep 05 01:19:39 kwalletd5[648]: The X11 connection broke (error 1). Did the X11 server die?
Sep 05 01:19:39 kwin_x11[781]: The X11 connection broke: I/O error (code 1)
Sep 05 01:19:39 ntfs-3g[433]: Unmounting /dev/sda1 (System)
Sep 05 01:19:39 kglobalaccel5[725]: The X11 connection broke (error 1). Did the X11 server die?
Sep 05 01:19:39 systemd[644]: Received SIGRTMIN+24 from PID 7027 (kill).
Sep 05 01:19:39 kdeinit5[708]: kdeinit5: sending SIGTERM to children.
Sep 05 01:19:39 kdeinit5[708]: kdeinit5: Exit.
Sep 05 01:19:39 systemd[579]: Reached target Shutdown.
Sep 05 01:19:39 systemd[1]: Stopping User Manager for UID 996...
Sep 05 01:19:39 systemd[1]: Stopped target Sound Card.
Sep 05 01:19:39 systemd[579]: Starting Exit the Session...
Sep 05 01:19:39 systemd[579]: Stopped target Default.
Sep 05 01:19:39 systemd[579]: Stopped target Basic System.
Sep 05 01:19:39 systemd[579]: Stopped target Paths.
Sep 05 01:19:39 systemd[579]: Stopped target Timers.
Sep 05 01:19:39 systemd[579]: Stopped target Sockets.
Sep 05 01:19:39 bluetoothd[451]: Endpoint unregistered: sender=:1.28 path=/MediaEndpoint/A2DPSource
Sep 05 01:19:39 systemd[1]: Removed slice system-systemd\x2dfsck.slice.
Sep 05 01:19:39 bluetoothd[451]: Endpoint unregistered: sender=:1.28 path=/MediaEndpoint/A2DPSink
Sep 05 01:19:39 systemd[1]: Stopping Authorization Manager...
Sep 05 01:19:39 systemd[1]: Stopped target Timers.
Sep 05 01:19:39 systemd[1]: Stopped Session c2 of user azure.
Sep 05 01:19:39 systemd[1]: Stopped target Multi-User System.
Sep 05 01:19:39 sddm[493]: Checking for pam module
Sep 05 01:19:39 sddm[493]: Got pam-login
Sep 05 01:19:39 sddm[493]: kwalletd: Waiting for hash on 15-
Sep 05 01:19:39 sddm[493]: kwalletd: waitingForEnvironment on: 19
Sep 05 01:19:39 sddm[493]: kwalletd: client connected
Sep 05 01:19:39 sddm[493]: kwalletd: client disconnected
Sep 05 01:19:39 systemd[1]: Stopping Initialize hardware monitoring sensors...
Sep 05 01:19:39 systemd-coredump[7033]: Process 729 (kactivitymanage) of user 1000 dumped core.
Sep 05 01:19:39 bluetoothd[451]: Disconnected from D-Bus. Exiting.
Sep 05 01:19:39 systemd[1]: Stopped Daily rotation of log files.
Sep 05 01:19:39 bluetoothd[451]: Stopping SDP server
Sep 05 01:19:39 systemd-logind[456]: Failed to abandon session scope: Transport endpoint is not connected
Sep 05 01:19:39 bluetoothd[451]: Exit
Sep 05 01:19:39 systemd[1]: Stopping D-Bus System Message Bus...
Sep 05 01:19:39 systemd[1]: Stopped Daily verification of password and group files.
Sep 05 01:19:39 systemd[1]: Stopping Login Service...
Sep 05 01:19:39 systemd[1]: Stopped Daily locate database update.
Sep 05 01:19:39 systemd[1]: Stopped target Login Prompts.
Sep 05 01:19:39 systemd[1]: Stopped Discard unused blocks once a week.
Sep 05 01:19:39 systemd[1]: Stopped Daily man-db cache update.
Sep 05 01:19:39 systemd[1]: Stopped target Bluetooth.
Sep 05 01:19:39 systemd[580]: pam_unix(systemd-user:session): session closed for user sddm
Sep 05 01:19:39 systemd[1]: Stopping Bluetooth service...
Sep 05 01:19:39 systemd[579]: Received SIGRTMIN+24 from PID 7034 (kill).
Sep 05 01:19:39 systemd[1]: Unmounted /run/user/1000/gvfs.
Sep 05 01:19:39 ca.desrt.dconf[665]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 bytes on an async read (g-io-error-quark, 0). Exiting.
Sep 05 01:19:39 systemd[1]: Stopped Bluetooth service.
Sep 05 01:19:39 systemd[1]: Stopped Login Service.
Sep 05 01:19:39 systemd[1]: Stopped D-Bus System Message Bus.
Sep 05 01:19:39 systemd[1]: Stopped User Manager for UID 996.
Sep 05 01:19:39 systemd[1]: Stopped Disk Manager.
Sep 05 01:19:39 systemd[1]: Stopped Authorization Manager.
Sep 05 01:19:39 systemd[1]: upower.service: Main process exited, code=exited, status=1/FAILURE
Sep 05 01:19:39 systemd[1]: Stopped Daemon for power management.
Sep 05 01:19:39 systemd[1]: upower.service: Unit entered failed state.
Sep 05 01:19:39 systemd[1]: upower.service: Failed with result 'exit-code'.
Sep 05 01:19:39 systemd[1]: Stopped User Manager for UID 1000.
Sep 05 01:19:39 systemd[1]: Stopped RealtimeKit Scheduling Policy Service.
Sep 05 01:19:39 systemd[1]: Stopped Avahi mDNS/DNS-SD Stack.
Sep 05 01:19:39 systemd[1]: Started Store Sound Card State.
Sep 05 01:19:39 org.a11y.Bus[665]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 bytes on an asyn
Sep 05 01:19:39 org.a11y.atspi.Registry[847]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 bytes
Sep 05 01:19:39 org.gtk.vfs.Daemon[665]: A connection to the bus can't be made
Sep 05 01:19:39 org.gtk.vfs.Daemon[665]: g_dbus_connection_real_closed: Remote peer vanished with error: Underlying GIOStream returned 0 bytes on a
Sep 05 01:19:39 org.kde.kuiserver[665]: kuiserver: Fatal IO error: client killed
Sep 05 01:19:39 sddm[493]: Checking for pam module
Sep 05 01:19:39 sddm[493]: Got pam-login
Sep 05 01:19:39 sddm[493]: kwalletd: Waiting for hash on 15-
Sep 05 01:19:39 sddm[493]: kwalletd: waitingForEnvironment on: 18
Sep 05 01:19:39 sddm[493]: kwalletd: client connected
Sep 05 01:19:39 sddm[493]: kwalletd: client disconnected
Sep 05 01:19:39 systemd[1]: Stopped Initialize hardware monitoring sensors.
Sep 05 01:19:39 mkinitcpio[7025]: ==> Starting build: none
Sep 05 01:19:39 mkinitcpio[7025]: -> Running build hook: [sd-shutdown]
Sep 05 01:19:39 mkinitcpio[7025]: ==> Build complete.
Sep 05 01:19:39 systemd[1]: Started Generate shutdown-ramfs.
Sep 05 01:19:39 systemd[1]: Removed slice user-1000.slice.
Sep 05 01:19:39 systemd[1]: Removed slice user-996.slice.
Sep 05 01:19:40 profile-sync-daemon[7062]: Sync successful
Sep 05 01:19:40 sddm[493]: Display server stopped.
A few things I can see:
- @01:19:32 there is a 6 second pause where nothing seems to be happening. What is it doing?
- @01:19:39 kactivitymanage segfaults
- right after that some processes seem to have not gotten the message the system is going down

Ignoring the crash, if there wasn't for the 6 second pause, then I'm sure I wouldn't have noticed anything.
I'm running newest packages and the nv 340xx driver. Should I report this as a bug?
User avatar
einar
Administrator
Posts
3402
Karma
7
OS
A good idea would be reporting the kactivitymanagerd crash, if you find a way to get a backtrace.


"Violence is the last refuge of the incompetent."
Image
Plasma FAQ maintainer - Plasma programming with Python
User avatar
pauledd
Registered Member
Posts
15
Karma
0
OS
I want to dig this out again because I also encounter this delayed logout/reboot.

Right after starting KDE and then log out to console, or shutdown, or reboot there is a (in my case) ~10 seconds delay. I can see how KDE quits kwin, the screen gets blank
and from there is a 10 seconds delay of whatever KDE is doing in that 10 seconds, then after that I can hear the KDE "bell" and my init system starts to do its job to reboot/shutdown etc...

Well, 10 seconds is not much but it feels awkward and 2001 when my PC had a very slow mechanical HDD... that doesnt fit into 2021. ^-^

I would like to find out what causes this delay but I dont know where to start.

My current system is:
Operating System: Gentoo Linux
KDE Plasma Version: 5.21.5
KDE Frameworks Version: 5.82.0
Qt Version: 5.15.2
Kernel Version: 5.10.52-gentoo
OS Type: 64-bit
Graphics Platform: X11
Processors: 32 × AMD Ryzen 9 5950X 16-Core Processor
Memory: 31.3 GiB of RAM
Graphics Processor: AMD Radeon RX 6900 XT

Ps: Forgot to mention that in ~1 of 10 cases KDE quits immediately with the bell sound and logout/reboot works as expected...


Bookmarks



Who is online

Registered users: bartoloni, Bing [Bot], Evergrowing, Google [Bot], q.ignora, watchstar