Bug 432643 - kdeconnect slowing down system shutdown
Summary: kdeconnect slowing down system shutdown
Status: RESOLVED FIXED
Alias: None
Product: ksmserver
Classification: Unclassified
Component: general (show other bugs)
Version: unspecified
Platform: Other Linux
: NOR normal with 1 vote (vote)
Target Milestone: ---
Assignee: David Edmundson
URL:
Keywords: efficiency
: 441062 441305 441828 443181 443296 447959 (view as bug list)
Depends on:
Blocks:
 
Reported: 2021-02-08 14:16 UTC by Mariusz Libera
Modified: 2022-01-14 08:57 UTC (History)
20 users (show)

See Also:
Latest Commit:
Version Fixed In: 5.24


Attachments
journalctl -b -1 --user (60.01 KB, text/x-log)
2021-02-08 14:16 UTC, Mariusz Libera
Details
ksmserver_reject_new_clients_when_in_killing_state.diff (999 bytes, patch)
2021-11-11 15:42 UTC, Tomasz Lemiech
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Mariusz Libera 2021-02-08 14:16:32 UTC
Created attachment 135506 [details]
journalctl -b -1 --user

Shut down and restart in Plasma is slower by about 8-10 seconds if kdeconnect is running. Removing kdeconnect fixes the problem. Attached log indicates kdeconnect is timing out.


SOFTWARE/OS VERSIONS
kdeconnect 20.12.2

Operating System: Arch Linux
KDE Plasma Version: 5.20.90
KDE Frameworks Version: 5.78.0
Qt Version: 5.15.2
Kernel Version: 5.10.14-arch1-1
OS Type: 64-bit
Processors: 8 × Intel® Core™ i7-8550U CPU @ 1.80GHz
Memory: 7.6 GiB of RAM
Graphics Processor: Mesa Intel® UHD Graphics 620
Comment 1 Nicolas Fella 2021-02-08 15:28:40 UTC
@David does this make sense to you?
Comment 2 Jacob 2021-02-14 09:46:09 UTC
I'm also experiencing this bug, and the slow down seems very similar to the slow down in bug 428903, I don't know maybe they're connected somehow.

SOFTWARE/OS VERSIONS
kdeconnect 20.12.2

Operating System: openSUSE Tumbleweed 20210210
KDE Plasma Version: 5.20.5
KDE Frameworks Version: 5.78.0
Qt Version: 5.15.2
Kernel Version: 5.10.12-1-default
OS Type: 64-bit
Graphics Processor: Mesa DRI Intel® UHD Graphics 630
Comment 3 Jacob 2021-02-14 10:06:08 UTC
Furthermore, if I go to the system tray > Configure System Tray > Entries > KDE Connect, and set it to disabled, the shutdown/logout time seems to be normal again.
Comment 4 Tony Green 2021-03-23 16:20:57 UTC
I have the same problem on my Manjaro system, running Plasma 5.21.3.

Looking at journald, I get a complete hang for nine seconds (which coincides with a blank screen), followed by:
Mar 23 16:10:10 antwerp ksmserver[71626]: org.kde.kf5.ksmserver: SmsDie timeout, client  "/usr/lib/kdeconnectd" ( 10c6e0e477000161651580000000716260016 )
Mar 23 16:10:10 antwerp kwin_x11[71588]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 30422, resource id: 23068679, major code: 18 (ChangeProperty), minor code: 0
Mar 23 16:10:10 antwerp org.kde.kdeconnect[74452]: ICE default IO error handler doing an exit(), pid = 74452, errno = 25
Mar 23 16:10:10 antwerp kwin_x11[71588]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 30454, resource id: 83886084, major code: 15 (QueryTree), minor code: 0
Mar 23 16:10:11 antwerp systemd[893]: Started Kill kwin and close other stuff if necessary after logout.
Mar 23 16:10:11 antwerp sddm-helper[71456]: [PAM] Closing session
Mar 23 16:10:11 antwerp sddm-helper[71456]: pam_unix(sddm:session): session closed for user tony
Mar 23 16:10:11 antwerp sddm-helper[71456]: pam_kwallet5(sddm:session): pam_kwallet5: pam_sm_close_session
Mar 23 16:10:11 antwerp sddm-helper[71456]: pam_kwallet5(sddm:setcred): pam_kwallet5: pam_sm_setcred
Mar 23 16:10:11 antwerp sddm-helper[71456]: [PAM] Ended.
Mar 23 16:10:11 antwerp sddm[69411]: Auth: sddm-helper exited successfully
Mar 23 16:10:11 antwerp at-spi-bus-launcher[71572]: X connection to :0.0 broken (explicit kill or server shutdown).
Mar 23 16:10:11 antwerp sddm[69411]: Socket server stopping...

The suggestion by Jacob to remove kdeconnect from the system tray makes no difference here.
Comment 5 Tony Green 2021-03-23 16:25:05 UTC
(In reply to Tony Green from comment #4)
> I have the same problem on my Manjaro system, running Plasma 5.21.3.
> 
> Looking at journald, I get a complete hang for nine seconds (which coincides
> with a blank screen), followed by:
> Mar 23 16:10:10 antwerp ksmserver[71626]: org.kde.kf5.ksmserver: SmsDie
> timeout, client  "/usr/lib/kdeconnectd" (
> 10c6e0e477000161651580000000716260016 )
> Mar 23 16:10:10 antwerp kwin_x11[71588]: qt.qpa.xcb: QXcbConnection: XCB
> error: 3 (BadWindow), sequence: 30422, resource id: 23068679, major code: 18
> (ChangeProperty), minor code: 0
> Mar 23 16:10:10 antwerp org.kde.kdeconnect[74452]: ICE default IO error
> handler doing an exit(), pid = 74452, errno = 25
> Mar 23 16:10:10 antwerp kwin_x11[71588]: qt.qpa.xcb: QXcbConnection: XCB
> error: 3 (BadWindow), sequence: 30454, resource id: 83886084, major code: 15
> (QueryTree), minor code: 0
> Mar 23 16:10:11 antwerp systemd[893]: Started Kill kwin and close other
> stuff if necessary after logout.
> Mar 23 16:10:11 antwerp sddm-helper[71456]: [PAM] Closing session
> Mar 23 16:10:11 antwerp sddm-helper[71456]: pam_unix(sddm:session): session
> closed for user tony
> Mar 23 16:10:11 antwerp sddm-helper[71456]: pam_kwallet5(sddm:session):
> pam_kwallet5: pam_sm_close_session
> Mar 23 16:10:11 antwerp sddm-helper[71456]: pam_kwallet5(sddm:setcred):
> pam_kwallet5: pam_sm_setcred
> Mar 23 16:10:11 antwerp sddm-helper[71456]: [PAM] Ended.
> Mar 23 16:10:11 antwerp sddm[69411]: Auth: sddm-helper exited successfully
> Mar 23 16:10:11 antwerp at-spi-bus-launcher[71572]: X connection to :0.0
> broken (explicit kill or server shutdown).
> Mar 23 16:10:11 antwerp sddm[69411]: Socket server stopping...
> 
> The suggestion by Jacob to remove kdeconnect from the system tray makes no
> difference here.

In case it's helpful, here are the log messages mentioning kdeconnect from the time I started the shutdown to the time everything hung:

Mar 23 16:10:00 antwerp dbus-daemon[1248]: [session uid=1000 pid=1248] Activating service name='org.kde.kdeconnect' requested by ':1.656' (uid=1000 pid=71634 comm="/usr/bin/plasmashell ")
Mar 23 16:10:00 antwerp plasmashell[71634]: file:///home/tony/.local/share/plasma/plasmoids/com.github.zren.kdeconnectdevice/contents/ui/Device.qml:8: TypeError: Cannot read property 'configuration' of null
Mar 23 16:10:00 antwerp plasmashell[71634]: file:///home/tony/.local/share/plasma/plasmoids/com.github.zren.kdeconnectdevice/contents/ui/Device.qml:7: TypeError: Cannot read property 'configuration' of null
Mar 23 16:10:00 antwerp plasmashell[71634]: file:///home/tony/.local/share/plasma/plasmoids/com.github.zren.kdeconnectdevice/contents/ui/Device.qml:6: TypeError: Cannot read property 'configuration' of null
Mar 23 16:10:00 antwerp plasmashell[71634]: file:///home/tony/.local/share/plasma/plasmoids/com.github.zren.kdeconnectdevice/contents/ui/Device.qml:54: TypeError: Cannot read property 'configuration' of null
Mar 23 16:10:00 antwerp dbus-daemon[1248]: [session uid=1000 pid=1248] Successfully activated service 'org.kde.kdeconnect'
Mar 23 16:10:00 antwerp kdeconnectd[74452]: kdeconnect.core: Could not query capabilities from notifications server
Mar 23 16:10:10 antwerp ksmserver[71626]: org.kde.kf5.ksmserver: SmsDie timeout, client  "/usr/lib/kdeconnectd" ( 10c6e0e477000161651580000000716260016 )
Comment 6 Jakub Římal 2021-08-08 20:18:35 UTC
Same here, 9 seconds delay followed with

ksmserver[1209]: org.kde.kf5.ksmserver: SmsDie timeout, client  "/usr/lib/kdeconnectd" ( 10f913d13514c000162785590000000012090012 )

in my journalctl.

Disabling KDE Connect in the System Tray fixes it for me.
Comment 7 Jakub Římal 2021-08-08 20:20:28 UTC
Sorry, forgot to paste the system info:

Operating System: Manjaro Linux
KDE Plasma Version: 5.22.4
KDE Frameworks Version: 5.84.0
Qt Version: 5.15.2
Kernel Version: 5.10.53-1-MANJARO (64-bit)
Graphics Platform: X11
Processors: 8 × 11th Gen Intel® Core™ i7-1165G7 @ 2.80GHz
Memory: 15.4 GiB of RAM
Graphics Processor: Mesa Intel® Xe Graphics
Comment 8 Timothy B 2021-08-17 00:47:18 UTC
*** Bug 441062 has been marked as a duplicate of this bug. ***
Comment 9 Timothy B 2021-08-17 00:56:55 UTC
I'm getting this behavior too, both on my desktop and laptop. However, I managed to stop the slowdowns by quickly switching to a TTY and running `pkill -KILL kdeconnectd` (`killall` never worked for me so I use `pkill` instead). Unfortunately, I haven't figured out how to make that command run automatically right when I initiate the shutdown/logout process from my Plasma session.

SYSTEM INFORMATION (DESKTOP)
KDE Connect Version: 21.08.0
Operating System: Manjaro Linux
KDE Plasma Version: 5.22.4
KDE Frameworks Version: 5.85.0
Qt Version: 5.15.2
Kernel Version: 5.13.11-1-MANJARO (64-bit)
Graphics Platform: X11
Processors: 12 × AMD Ryzen 5 1600 Six-Core Processor
Memory: 15.6 GiB of RAM
Graphics Processor: Radeon RX 570 Series

SYSTEM INFORMATION (LAPTOP)
KDE Connect Version: 21.08.0
Operating System: Manjaro Linux
KDE Plasma Version: 5.22.4
KDE Frameworks Version: 5.85.0
Qt Version: 5.15.2
Kernel Version: 5.13.11-1-MANJARO (64-bit)
Graphics Platform: X11
Processors: 8 × AMD Ryzen 7 3700U with Radeon Vega Mobile Gfx
Memory: 6.7 GiB of RAM
Graphics Processor: AMD Radeon™ Vega 10 Graphics
Comment 10 Oliver Williamson 2021-08-23 11:02:05 UTC
*** Bug 441305 has been marked as a duplicate of this bug. ***
Comment 11 Tony Green 2021-08-23 11:06:36 UTC
I've noticed that this problem has gone away since the latest update via the Manjaro repos.

Looking at my update logs, this means that one of the following packages probably fixed it:
plasma-framework (5.85.0-2)
plasma-workspace (5.22.4-3)
Comment 12 David Edmundson 2021-08-23 11:33:13 UTC
I'm unaware of any changes in either that would be relevant. In any case, I don't think we can do much if it's not happening.
Comment 13 David Edmundson 2021-08-23 11:34:15 UTC
Also from a Ksmserver pov this all seems to be working as intended. We clearly asked kdeconnect to close and it did nothing till our timeout cane into effect.
Comment 14 Timothy B 2021-08-23 12:45:17 UTC
(In reply to David Edmundson from comment #13)
> We clearly asked kdeconnect to close and it did nothing till our timeout cane [sic] into effect.

So since you found out what's happening with kdeconnect at logout, then why mark the issue as RESOLVED/WORKSFORME? I believe this annoying behavior needs to be investigated even further and hopefully we get a fix sorted out out of those findings. Please open this back up to either REPORTED or CONFIRMED, or else this bug won't ever get fixed.

(In reply to Tony Green from comment #11)
> I've noticed that this problem has gone away since the latest update via the
> Manjaro repos.
> 
> Looking at my update logs, this means that one of the following packages
> probably fixed it:
> plasma-framework (5.85.0-2)
> plasma-workspace (5.22.4-3)

I had those versions installed about two weeks ago, and I added my comment on this right after the update. Even so, I still reproduced this on every single logout on my desktop but only about 3 out of 4 times on my laptop. I'm using the testing branch repositories, so you may have updated those packages very recently.

In the meantime, I've removed KDE Connect from both machines, as it's not worth my time getting frustrated dealing with the multitude of bugs in that half-baked app.
Comment 15 Timothy B 2021-08-23 12:48:54 UTC
> 3 out of 4 times on my laptop

Correction: I meant 1 out of 4 times. Sorry, I just woke up when I made the above comment.
Comment 16 Eduardo 2021-08-30 01:59:48 UTC
I have Arch Linux with the same package version:
plasma-framework 5.85.0-2
plasma-workspace 5.22.4-3

Also:
kdeconnect 21.08.0-1

And the bug is still happening for me, every single time.

So we cannot considered it fixed. I'm changing it to REOPENED.
Comment 17 malvin 2021-09-09 06:57:23 UTC
The same problem (9 seconds delay of shutdown) happens with with kdeconnect 20.12.3-2 in PureOS byzantium and Debian bullseye.

Are we sure that the problem is actually kdeconnectd not exiting properly? I am wondering about this line in the journalctl from Mariusz:

lut 08 14:53:03 ideapad520 systemd[908]: Started dbus-:1.2-org.kde.kdeconnect@0.service.

And a similar line in my own journalctl on shutdown (note the 10 second delay):

Sep 08 22:49:18 fourteen dbus-daemon[1708]: [session uid=1000 pid=1708] Activating service name='org.kde.kdeconnect' requested by ':1.44' (uid=1000 pid=1981 comm="/usr/bin/plasmashell ")
Sep 08 22:49:18 fourteen dbus-daemon[1708]: [session uid=1000 pid=1708] Successfully activated service 'org.kde.kdeconnect'
Sep 08 22:49:18 fourteen dbus-daemon[1708]: [session uid=1000 pid=1708] Activating service name='org.freedesktop.Notifications' requested by ':1.93' (uid=1000 pid=3736 comm="/usr/lib/x86_64-linux-gnu/libexec/kdeconnectd ")
Sep 08 22:49:28 fourteen org.kde.kdeconnect[3736]: ICE default IO error handler doing an exit(), pid = 3736, errno = 11

Does this mean my (older) plasma is using dbus-daemon instead of systemd to start KDE services? 

Anyway, in both cases, why is the service "org.kde.kdeconnect" being *activated* or *started*? Could it be some race condition that kdeconnect is killed but plasma or something else is restarting it?

I am also confused by whether "org.kde.kdeconnect" refers to the plasmoid or to the kdeconnectd process.

Sorry if this leads nowhere, but I was curious about what exactly is causing the delay here and would be very happy about a fix or workaround (I tried putting a pkill or killall into a LogOut script in Autostart, but that did not help).

Versions:
Operating System: PureOS 10.0
KDE Plasma Version: 5.20.5
KDE Frameworks Version: 5.78.0
Qt Version: 5.15.2
Kernel Version: 5.10.0-8-amd64
Comment 18 Nicolas Fella 2021-11-09 21:43:13 UTC
*** Bug 441828 has been marked as a duplicate of this bug. ***
Comment 19 Nicolas Fella 2021-11-09 21:43:22 UTC
*** Bug 443181 has been marked as a duplicate of this bug. ***
Comment 20 Nicolas Fella 2021-11-09 21:43:29 UTC
*** Bug 443296 has been marked as a duplicate of this bug. ***
Comment 21 Tomasz Lemiech 2021-11-11 15:41:50 UTC
Same thing here. Gentoo, no systemd, plasma-workspace-5.22.5, kdeconnect-21.04.3. Here is what happens:

- ksmserver sends SmsDie to its clients (including kdeconnectd)
- kdeconnectd exits correctly and immediately gets restarted via dbus (requested by plasmashell)
- the new kdeconnectd instance connects to ksmserver with a new client ID
- ksmserver wants to kill it, but SmsDie times out (here comes the 10-sec delay)
- finally everything quits.

So it's not the original kdeconnectd process which is causing the problem, but the new one, which came up after the first one exited. Presumably it's a race condition of some sort - the process might not yet be ready to handle messages from ksmserver (or maybe the message callbacks are not yet registered). Never mind - at this stage it does not respond to SmsDie.

Given the fact that ksmserver was about to shut down itself and was in the process of killing its clients, I think it shouldn't have accepted the new client in the first place. Otherwise if the new client had responded to SmsDie properly, it could have been restarted once again and in theory this could loop multiple times preventing ksmserver from emptying its client list completely.

Attached patch (ksmserver_reject_new_clients_when_in_killing_state.diff) does what the file name says. Works for me, no more hangs on exit.

Logs before (note the different client IDs of the initial kdeconnectd instance and the one which fails to respond to SmsDie):

org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664139800000190510004 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664139800000190510004 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664139800000190510004 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664139800000190510004 )
(...)
org.kde.kf5.ksmserver: Starting killing clients
(...)
org.kde.kf5.ksmserver: startKilling: client  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664139800000190510004 )
(...)
org.kde.kf5.ksmserver:  We killed all clients. We have now clients.count()= 7
(...)
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664141600000190510008 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664141600000190510008 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664141600000190510008 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664141600000190510008 )
org.kde.kf5.ksmserver: SmsDie timeout, client  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664141600000190510008 )

Logs after (the new kdeconnectd instance tries to connect but gets rejected):

org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664088900000157090004 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664088900000157090004 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664088900000157090004 )
org.kde.kf5.ksmserver: New client properties:  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664088900000157090004 )
(...)
org.kde.kf5.ksmserver: Starting killing clients
(...)
org.kde.kf5.ksmserver: startKilling: client  "/usr/lib64/libexec/kdeconnectd" ( 10e0656c69000163664088900000157090004 )
(...)
org.kde.kf5.ksmserver:  We killed all clients. We have now clients.count()= 11
(...)
org.kde.kf5.ksmserver: Connection rejected: ksmserver is shutting down
Comment 22 Tomasz Lemiech 2021-11-11 15:42:50 UTC
Created attachment 143454 [details]
ksmserver_reject_new_clients_when_in_killing_state.diff
Comment 23 Eduardo 2021-11-12 06:04:31 UTC
That's great!

Are you planning to submit a merge request?

Do you know if there is a reason for plasmashell requesting another instance of kdeconnectd after the first one just died?  If there is no reason, maybe we should patch this end as well.
Comment 24 Nicolas Fella 2021-11-12 12:21:32 UTC
The applet, which runs as part of the plasmashell process, uses DBus to communicate with kdeconnectd. I assume what happens is that the applet makes a call to kdeconnected which is not running anymore. Since kdeconnectd is DBus-activatable it will get launched to be able to respond to the call
Comment 25 Bug Janitor Service 2021-11-12 17:54:31 UTC
A possibly relevant merge request was started @ https://invent.kde.org/plasma/plasma-workspace/-/merge_requests/1198
Comment 26 Eduardo 2021-11-13 02:16:25 UTC
(In reply to Nicolas Fella from comment #24)
> Since kdeconnectd is DBus-activatable it will get launched to be able to respond to the call

What happens to this new kdeconnectd when we have this patch applied? Does it keep running forever or is it killed somehow?
Comment 27 Tomasz Lemiech 2021-11-13 09:42:43 UTC
(In reply to Eduardo from comment #26)
> What happens to this new kdeconnectd when we have this patch applied? Does
> it keep running forever or is it killed somehow?

It gets killed together with everything else. I don't see it lingering after I log off from KDE.
Comment 28 David Edmundson 2021-12-18 21:56:30 UTC
Git commit 71f88e9049d15f41abd0eb703e3faec5fac4b6b5 by David Edmundson, on behalf of Tomasz Lemiech.
Committed on 18/12/2021 at 16:07.
Pushed by davidedmundson into branch 'master'.

ksmserver: reject new clients when shutting down

When ksmserver is about to shut down and in the process of killing its
clients, it shouldn't accept connections from new clients.

M  +14   -2    ksmserver/server.cpp

https://invent.kde.org/plasma/plasma-workspace/commit/71f88e9049d15f41abd0eb703e3faec5fac4b6b5
Comment 29 Nate Graham 2022-01-12 17:28:14 UTC
*** Bug 447959 has been marked as a duplicate of this bug. ***