Bug 433408

Summary: [systemd] System powers off when sleep button is pressed instead of going to sleep
Product: [Plasma] Powerdevil Reporter: Szőts Ákos <szotsaki>
Component: generalAssignee: Plasma Bugs List <plasma-bugs>
Status: RESOLVED FIXED    
Severity: normal CC: aspotashev, boingo-00, kde, kde, magiblot, nate, nicolas.fella, rdieter, silvan.calarco, zawertun
Priority: NOR    
Version: 5.21.0   
Target Milestone: ---   
Platform: openSUSE   
OS: Linux   
Latest Commit: Version Fixed In: 5.22
Sentry Crash Report:
Attachments: tmp.patch
Screenshot_20210430_235239.png
powerdevil-5.21.5-fallback-to-xdg_session_id.patch
powerdevil-5.21.5-get_session-auto.patch

Description Szőts Ákos 2021-02-21 21:44:58 UTC
SUMMARY

When systemd startup is enabled in Plasma, pressing the sleep (power) button on the computer turns the PC off. The button is configured to make the PC go to sleep and it works fine when systemd is not enabled. 

STEPS TO REPRODUCE
1. Enable systemd startup with "kwriteconfig5 --file startkderc --group General --key systemdBoot true"
2. Make sure that you have "Sleep when the power button is pressed" as a desired action set up in Power settings module
3. Press the power button

OBSERVED RESULT

When systemd is enabled, it shuts down the computer instead of making it sleep.

Without systemd enabled after the power button pressed:
febr 21 22:28:16 openSUSE systemd-logind[780]: Power key pressed.
febr 21 22:28:16 openSUSE kded5[1658]: bluedevil: About to suspend
febr 21 22:28:16 openSUSE NetworkManager[1057]: <info>  [1613942896.6691] manager: sleep: sleep requested (sleeping: no  enabled: yes)
[...]
febr 21 22:28:16 openSUSE systemd[1]: Reached target Sleep.
febr 21 22:28:16 openSUSE systemd[1]: Starting Suspend...

With systemd enabled:
febr 21 22:30:07 openSUSE systemd-logind[746]: Power key pressed.
febr 21 22:30:07 openSUSE systemd-logind[746]: Powering Off...
febr 21 22:30:07 openSUSE systemd-logind[746]: System is powering down.
febr 21 22:30:07 openSUSE systemd[1]: Stopping Session 1 of user aki.
febr 21 22:30:07 openSUSE systemd[1]: Stopping Session c3 of user aki.
febr 21 22:30:07 openSUSE systemd[1]: Removed slice system-modprobe.slice.
febr 21 22:30:07 openSUSE sddm[1292]: Authentication error: "Process crashed"
febr 21 22:30:07 openSUSE sddm[1292]: Auth: sddm-helper crashed (exit code 15)
febr 21 22:30:07 openSUSE sddm[1292]: Authentication error: "Process crashed"
febr 21 22:30:07 openSUSE sddm[1292]: Auth: sddm-helper exited with 15
febr 21 22:30:07 openSUSE sddm[1292]: Display server stopping...

Logs of systemd-logind without systemd enabled:
-- Logs begin at Fri 2020-06-12 14:50:46 CEST, end at Sun 2021-02-21 22:35:13 CET. --
febr 21 22:27:32 openSUSE systemd[1]: Starting User Login Management...
febr 21 22:27:32 openSUSE systemd-logind[780]: Watching system buttons on /dev/input/event1 (Power Button)
febr 21 22:27:32 openSUSE systemd-logind[780]: Watching system buttons on /dev/input/event0 (Power Button)
febr 21 22:27:32 openSUSE systemd-logind[780]: New seat seat0.
febr 21 22:27:32 openSUSE systemd[1]: Started User Login Management.
febr 21 22:27:32 openSUSE systemd-logind[780]: Watching system buttons on /dev/input/event17 (Dell Dell USB Keyboard)
febr 21 22:27:34 openSUSE systemd-logind[780]: Watching system buttons on /dev/input/event18 (Logitech MX Master 2S)
febr 21 22:27:35 openSUSE systemd-logind[780]: New session 1 of user aki.
febr 21 22:28:16 openSUSE systemd-logind[780]: Power key pressed.
febr 21 22:28:26 openSUSE systemd-logind[780]: Operation 'sleep' finished.
febr 21 22:28:56 openSUSE systemd-logind[780]: System is rebooting.
febr 21 22:28:56 openSUSE systemd-logind[780]: Session 1 logged out. Waiting for processes to exit.
febr 21 22:28:56 openSUSE systemd-logind[780]: Removed session 1.
febr 21 22:29:01 openSUSE systemd[1]: Stopping User Login Management...
febr 21 22:29:01 openSUSE systemd[1]: systemd-logind.service: Succeeded.
febr 21 22:29:01 openSUSE systemd[1]: Stopped User Login Management.

Logs of systemd-logind with systemd enabled:
-- Logs begin at Fri 2020-06-12 14:50:46 CEST, end at Sun 2021-02-21 22:35:13 CET. --
febr 21 22:29:25 openSUSE systemd[1]: Starting User Login Management...
febr 21 22:29:25 openSUSE systemd-logind[746]: Watching system buttons on /dev/input/event1 (Power Button)
febr 21 22:29:25 openSUSE systemd-logind[746]: Watching system buttons on /dev/input/event0 (Power Button)
febr 21 22:29:25 openSUSE systemd-logind[746]: New seat seat0.
febr 21 22:29:25 openSUSE systemd[1]: Started User Login Management.
febr 21 22:29:25 openSUSE systemd-logind[746]: Watching system buttons on /dev/input/event17 (Dell Dell USB Keyboard)
febr 21 22:29:28 openSUSE systemd-logind[746]: Watching system buttons on /dev/input/event18 (Logitech MX Master 2S)
febr 21 22:29:28 openSUSE systemd-logind[746]: New session 1 of user aki.
febr 21 22:30:07 openSUSE systemd-logind[746]: Power key pressed.
febr 21 22:30:07 openSUSE systemd-logind[746]: Powering Off...
febr 21 22:30:07 openSUSE systemd-logind[746]: System is powering down.
febr 21 22:30:07 openSUSE systemd-logind[746]: Session 1 logged out. Waiting for processes to exit.
febr 21 22:30:08 openSUSE systemd-logind[746]: Removed session 1.
febr 21 22:30:12 openSUSE systemd[1]: Stopping User Login Management...
febr 21 22:30:12 openSUSE systemd[1]: systemd-logind.service: Succeeded.
febr 21 22:30:12 openSUSE systemd[1]: Stopped User Login Management.

SOFTWARE/OS VERSIONS
Operating System: openSUSE Tumbleweed 20210217
KDE Plasma Version: 5.21.0
KDE Frameworks Version: 5.79.0
Qt Version: 5.15.2
Kernel Version: 5.10.16-1-default
OS Type: 64-bit
Graphics Platform: X11
Comment 1 Kai Uwe Broulik 2021-02-21 22:02:17 UTC
Looks like PowerDevil isn't running in systemd boot mode for some reason, can you check if it is?
Comment 2 David Edmundson 2021-02-21 22:41:58 UTC
Can you check in  both "ps ux" 

and " systemctl --user  status plasma-powerdevil.service   "
Comment 3 Szőts Ákos 2021-02-22 06:24:17 UTC
It seems it is running:

$ systemctl --user  status plasma-powerdevil.service
● plasma-powerdevil.service - Powerdevil
     Loaded: loaded (/usr/lib/systemd/user/plasma-powerdevil.service; static)
     Active: active (running) since Sun 2021-02-21 22:30:45 CET; 8h ago
   Main PID: 1702 (org_kde_powerde)
     CGroup: /user.slice/user-1000.slice/user@1000.service/background.slice/plasma-powerdevil.service
             └─1702 /usr/lib64/libexec/org_kde_powerdevil

febr 21 22:30:45 openSUSE systemd[1491]: Starting Powerdevil...
febr 21 22:30:45 openSUSE systemd[1491]: Started Powerdevil.


$ ps aux| grep power
root        88  0.0  0.0      0     0 ?        I    febr21   0:00 [kworker/12:0-events_freezable_power_]
root       127  0.0  0.0      0     0 ?        I    febr21   0:00 [kworker/12:1-events_freezable_power_]
root      1095  0.0  0.0      0     0 ?        I    febr21   0:00 [kworker/0:2-events_power_efficient]
aki       1702  0.0  0.2 400584 43340 ?        Ssl  febr21   0:00 /usr/lib64/libexec/org_kde_powerdevil
root      1714  0.0  0.0 246976 10100 ?        Ssl  febr21   0:00 /usr/libexec/upower/upowerd
root     10472  0.0  0.0      0     0 ?        I    07:00   0:00 [kworker/0:0-events_power_efficient]


In the logs I cannot find anything related:
journalctl -u plasma-powerdevil.service
-- Logs begin at Fri 2020-06-12 14:50:46 CEST, end at Mon 2021-02-22 07:16:52 CET. --
-- No entries --


It seems that powerdevil logs (journalctl | grep powerdevil) are the same with and without systemd.

Without systemd:
febr 21 22:27:36 openSUSE dbus-daemon[710]: [system] Activating service name='org.kde.powerdevil.discretegpuhelper' requested by ':1.28' (uid=1000 pid=1757 comm="/usr/lib64/libexec/org_kde_powerdevil ") (using servicehelper)
febr 21 22:27:36 openSUSE dbus-daemon[710]: [system] Successfully activated service 'org.kde.powerdevil.discretegpuhelper'
febr 21 22:27:36 openSUSE dbus-daemon[710]: [system] Activating service name='org.kde.powerdevil.chargethresholdhelper' requested by ':1.28' (uid=1000 pid=1757 comm="/usr/lib64/libexec/org_kde_powerdevil ") (using servicehelper)
febr 21 22:27:36 openSUSE dbus-daemon[710]: [system] Successfully activated service 'org.kde.powerdevil.chargethresholdhelper'
febr 21 22:27:36 openSUSE dbus-daemon[710]: [system] Activating service name='org.kde.powerdevil.backlighthelper' requested by ':1.28' (uid=1000 pid=1757 comm="/usr/lib64/libexec/org_kde_powerdevil ") (using servicehelper)
febr 21 22:27:36 openSUSE backlighthelper[1853]: org.kde.powerdevil: no kernel backlight interface found
febr 21 22:27:36 openSUSE dbus-daemon[710]: [system] Successfully activated service 'org.kde.powerdevil.backlighthelper'
febr 21 22:27:36 openSUSE dbus-daemon[1533]: [session uid=1000 pid=1533] Activating service name='org.kde.KScreen' requested by ':1.21' (uid=1000 pid=1757 comm="/usr/lib64/libexec/org_kde_powerdevil ")

With systemd:
febr 21 22:29:29 openSUSE dbus-daemon[684]: [system] Activating service name='org.kde.powerdevil.discretegpuhelper' requested by ':1.25' (uid=1000 pid=1684 comm="/usr/lib64/libexec/org_kde_powerdevil ") (using servicehelper)
febr 21 22:29:29 openSUSE dbus-daemon[684]: [system] Successfully activated service 'org.kde.powerdevil.discretegpuhelper'
febr 21 22:29:29 openSUSE dbus-daemon[684]: [system] Activating service name='org.kde.powerdevil.chargethresholdhelper' requested by ':1.25' (uid=1000 pid=1684 comm="/usr/lib64/libexec/org_kde_powerdevil ") (using servicehelper)
febr 21 22:29:29 openSUSE dbus-daemon[684]: [system] Successfully activated service 'org.kde.powerdevil.chargethresholdhelper'
febr 21 22:29:29 openSUSE dbus-daemon[684]: [system] Activating service name='org.kde.powerdevil.backlighthelper' requested by ':1.25' (uid=1000 pid=1684 comm="/usr/lib64/libexec/org_kde_powerdevil ") (using servicehelper)
febr 21 22:29:29 openSUSE backlighthelper[1773]: org.kde.powerdevil: no kernel backlight interface found
febr 21 22:29:29 openSUSE dbus-daemon[684]: [system] Successfully activated service 'org.kde.powerdevil.backlighthelper'
febr 21 22:29:29 openSUSE dbus-daemon[1494]: [session uid=1000 pid=1494] Activating service name='org.kde.KScreen' requested by ':1.23' (uid=1000 pid=1684 comm="/usr/lib64/libexec/org_kde_powerdevil ")
febr 21 22:30:07 openSUSE systemd[1477]: plasma-powerdevil.service: Succeeded.
Comment 4 magiblot 2021-03-07 15:40:33 UTC
I'm having the same issue. I observed that:

* After starting a Plasma session, pressing the Power button or closing the laptop lid are not handled by Plasma and result in poweroff/suspension.
* After waking up from suspension, the Plasma session handles the Power button and the laptop lid properly.
Comment 5 Nate Graham 2021-04-29 16:05:57 UTC
Cannot reproduce FWIW.
Comment 6 Szőts Ákos 2021-04-29 18:02:30 UTC
If you could tell me commands to execute, log locations, or any other clues how to help debugging this, I'd be glad to.
Comment 7 Yaroslav Sidlovsky 2021-04-30 17:39:37 UTC
Similar bug: https://bugs.kde.org/show_bug.cgi?id=365100.
Comment 8 Yaroslav Sidlovsky 2021-04-30 17:43:28 UTC
Actually I've already found 2 more similar bugs:
https://bugs.kde.org/show_bug.cgi?id=365100
https://bugs.kde.org/show_bug.cgi?id=434153

Seems that bug affects Fedora and openSUSE users.
Comment 9 Yaroslav Sidlovsky 2021-04-30 19:46:15 UTC
After some debugging I found that `PolicyAgent::setupSystemdInhibition` called only after resume (see: https://invent.kde.org/plasma/powerdevil/-/blob/master/daemon/actions/bundled/suspendsession.cpp#L56).
And not called on PowerDevil start.
Comment 10 Yaroslav Sidlovsky 2021-04-30 19:50:10 UTC
Created attachment 138037 [details]
tmp.patch

I don't think this patch is correct enough but on my PC issue is gone after applying it.
Comment 11 Ilya Bizyaev 2021-04-30 19:55:35 UTC
Marking the report as confirmed as it affects multiple users.
Comment 12 Yaroslav Sidlovsky 2021-04-30 20:02:12 UTC
*** Bug 434153 has been marked as a duplicate of this bug. ***
Comment 13 Yaroslav Sidlovsky 2021-04-30 20:33:14 UTC
In log I see this:
```
апр 30 23:30:13 fedora org_kde_powerdevil[16323]: org.kde.powerdevil: The session is not registered with systemd
```
So that's why `setupSystemdInhibition()` is not called from https://invent.kde.org/plasma/powerdevil/-/blob/aba840037bb732661ea749d13aa401317a795d00/daemon/powerdevilpolicyagent.cpp#L292.
Comment 14 Yaroslav Sidlovsky 2021-04-30 20:54:06 UTC
Created attachment 138040 [details]
Screenshot_20210430_235239.png

Reply from org.freedesktop.login1.Manager when doing `systemctl --user restart plasma-powerdevil.service`.
Comment 15 Yaroslav Sidlovsky 2021-05-02 11:25:55 UTC
Szőts Ákos, could you please run this script in the konsole and show paste output:
```
dbus-send --system --print-reply --dest=org.freedesktop.login1 /org/freedesktop/login1 org.freedesktop.login1.Manager.GetSessionByPID uint32:$(pgrep konsole)
```

(it should be only 1 konsole running at time of executing this script).

At my PC it shows this:
```
Error org.freedesktop.login1.NoSessionForPID: PID 3536 does not belong to any known session
```

So systemd doesn't treat Konsole as part of any user session.
Similar check exists in code of powerdevil and it fails every time on Fedora & openSUSE: https://invent.kde.org/plasma/powerdevil/-/blob/aba840037bb732661ea749d13aa401317a795d00/daemon/powerdevilpolicyagent.cpp#L239.

The behaviour described above can be simply reproduced on Fedora 34 KDE Live, just start it in the VM and execute dbus-send command.
Link to the iso: https://download.fedoraproject.org/pub/fedora/linux/releases/34/Spins/x86_64/iso/Fedora-KDE-Live-x86_64-34-1.2.iso.
Comment 16 Yaroslav Sidlovsky 2021-05-05 00:28:29 UTC
Created attachment 138154 [details]
powerdevil-5.21.5-fallback-to-xdg_session_id.patch

Patch to fallback session detection by getting value from XDG_SESSION_ID env. variable.

Still want to hear some comments from devs - is it ok that GetSessionByPID not working as expected on Fedora?
Comment 17 David Edmundson 2021-05-05 00:35:42 UTC
It is expected, yes.

Using "/auto" as the session path would also work.
Comment 18 Yaroslav Sidlovsky 2021-05-05 00:59:58 UTC
Created attachment 138156 [details]
powerdevil-5.21.5-get_session-auto.patch

Thanks!
Comment 19 Bug Janitor Service 2021-05-05 11:39:21 UTC
A possibly relevant merge request was started @ https://invent.kde.org/plasma/powerdevil/-/merge_requests/50
Comment 20 Yaroslav Sidlovsky 2021-05-07 14:44:09 UTC
Git commit d7c1181a5736bc5c6b2585fb0df9065510efcd7c by Yaroslav Sidlovsky.
Committed on 05/05/2021 at 11:32.
Pushed by ngraham into branch 'master'.

GetSessionByPID DBUS call always fails on newer systemd versions

GetSessionByPID returns this error:
```
Error org.freedesktop.login1.NoSessionForPID: PID 2469 does not belong to any known session
```
So instead we will get session by calling GetSession("auto").
Tested on Fedora, should also work on openSUSE & KDE Neon.

M  +1    -1    daemon/powerdevilpolicyagent.cpp

https://invent.kde.org/plasma/powerdevil/commit/d7c1181a5736bc5c6b2585fb0df9065510efcd7c
Comment 21 Nate Graham 2021-05-07 14:46:52 UTC
Git commit 2d56fc5b4ae61021a7522196a00a4b6697bac80a by Nate Graham, on behalf of Yaroslav Sidlovsky.
Committed on 07/05/2021 at 14:46.
Pushed by ngraham into branch 'Plasma/5.21'.

GetSessionByPID DBUS call always fails on newer systemd versions

GetSessionByPID returns this error:
```
Error org.freedesktop.login1.NoSessionForPID: PID 2469 does not belong to any known session
```
So instead we will get session by calling GetSession("auto").
Tested on Fedora, should also work on openSUSE & KDE Neon.


(cherry picked from commit d7c1181a5736bc5c6b2585fb0df9065510efcd7c)

M  +1    -1    daemon/powerdevilpolicyagent.cpp

https://invent.kde.org/plasma/powerdevil/commit/2d56fc5b4ae61021a7522196a00a4b6697bac80a