[systemd-devel] systemd killing processes on monitor wakeup?

Raman Gupta rocketraman at gmail.com
Sat Jan 29 03:28:30 UTC 2022 

>
> Try to set the systemd user instance's log level to 'debug'; I'm guessing
> it's not that systemd kills processes directly but that something triggers
> a 'systemctl stop' of the session .scope that they were in.


Here are the logs at debug level with some annotations inline:

*<wake up at 21:57:30>*

Jan 28 21:57:34 edison plasmashell[3114743]: KCrash: Application
'plasmashell' crashing...
Jan 28 21:57:34 edison plasmashell[3114743]: KCrash: Attempting to start
/usr/libexec/drkonqi

*<This is because of https://bugs.kde.org/show_bug.cgi?id=396359
<https://bugs.kde.org/show_bug.cgi?id=396359>, could be related to
subsequent events but I'm pretty sure I've seen this same problem even when
Plasma doesn't crash>*

Jan 28 21:57:34 edison systemd[2551]: Got message type=signal
sender=org.freedesktop.DBus destination=n/a path=/org/freedesktop/DBus
interface=org.freedesktop.DBus member=NameOwnerChanged cookie=4294967295
reply_cookie=0 signature=sss error-name=n/a error-message=n/a
Jan 28 21:57:34 edison systemd[2551]: plasma-plasmashell.service: D-Bus
name org.kde.plasmashell now not owned by anyone.
Jan 28 21:57:34 edison systemd[2551]: plasma-plasmashell.service: Changed
running -> stop-sigterm
Jan 28 21:57:34 edison systemd[2551]: Sent message type=signal sender=n/a
destination=n/a
path=/org/freedesktop/systemd1/unit/plasma_2dplasmashell_2eservice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged
cookie=10389 reply_cookie=0 signature=sa{sv}as error-name=n/a
error-message=n/a
Jan 28 21:57:34 edison systemd[2551]: Sent message type=signal sender=n/a
destination=n/a
path=/org/freedesktop/systemd1/unit/plasma_2dplasmashell_2eservice
interface=org.freedesktop.DBus.Properties member=PropertiesChanged
cookie=10390 reply_cookie=0 signature=sa{sv}as error-name=n/a
error-message=n/a
Jan 28 21:57:34 edison systemd[2551]: Received SIGCHLD from PID 3326812
(idea.sh).
Jan 28 21:57:34 edison systemd[2551]: Child 3326812 (idea.sh) died
(code=killed, status=15/TERM)

*<This seems to indicate that systemd is receiving notification that IDEA
died. Not sure why killsnoop.py seems to think that systemd is the process
that sends the SIGTERM -- it's still unclear to me where IDEA is receiving
the SIGTERM from>*

Jan 28 21:57:34 edison systemd[2551]: plasma-plasmashell.service: Child
3326812 belongs to plasma-plasmashell.service.
Jan 28 21:57:34 edison systemd[2551]: Child 3114994 (kio_http_cache_) died
(code=killed, status=15/TERM)
Jan 28 21:57:34 edison systemd[2551]: plasma-plasmashell.service: Child
3114994 belongs to plasma-plasmashell.service.
Jan 28 21:57:34 edison systemd[2551]: Child 3328167 (adb) died
(code=killed, status=15/TERM)
Jan 28 21:57:34 edison systemd[2551]: plasma-plasmashell.service: Child
3328167 belongs to plasma-plasmashell.service.
Jan 28 21:57:34 edison systemd[2551]: Received SIGCHLD from PID 3328167
(n/a).

*<bunch more processes dying similarly, plasma restarting, etc.>*

Can't think of any events directly related to monitor wakeup that systemd
> would react to (unless you meant the processes die on full system suspend
> that usually follows). Do you have any screensaver running? Do the
> processes actually get killed when the monitor goes to sleep or only when
> it wakes up?


No screensaver, just the lock screen. It's a desktop -- it doesn't
hibernate. The monitors just go to sleep according to the energy settings,
and then they wake up when there is keyboard or mouse activity. The
processes get killed only at wake-up time -- not at sleep time. It's also
at wake up time, not at login time.

Just as a test I killed plasmashell to see if that would cause other
processes to shut down (recognizing that a SIGTERM is not the same as a
crash). It did not. All processes remained running.

Regards,
Raman





On Fri, Jan 28, 2022 at 6:41 AM Mantas Mikulėnas <grawity at gmail.com> wrote:

> Try to set the systemd user instance's log level to 'debug'; I'm guessing
> it's not that systemd kills processes directly but that something triggers
> a 'systemctl stop' of the session .scope that they were in.
>
> Can't think of any events directly related to monitor wakeup that systemd
> would react to (unless you meant the processes die on full system suspend
> that usually follows). Do you have any screensaver running? Do the
> processes actually get killed when the monitor goes to sleep or only when
> it wakes up?
>
> On Wed, Jan 26, 2022, 15:39 Raman Gupta <rocketraman at gmail.com> wrote:
>
>> Does anyone have any tips for debugging this or getting more information?
>> Should I create an issue for this?
>>
>> On Sun, Jan 23, 2022 at 3:43 PM Raman Gupta <rocketraman at gmail.com>
>> wrote:
>>
>>> (A variation of this message was originally sent to fedora-users)
>>>
>>> I have a couple processes that have been consistently dying every time I
>>> wake up my monitors after the system has been idle. One is Slack Desktop
>>> and the other is IntelliJ IDEA.
>>>
>>> I used an eBPF program (killsnoop.py at
>>> https://github.com/iovisor/bcc/blob/master/tools/killsnoop.py) to trace
>>> where the signal to shut down these processes was coming from, and it
>>> appears that systemd is sending pretty much every active process signal 15
>>> and then 18.
>>>
>>> TIME      PID    COMM             SIG  TPID   RESULT
>>> ... on monitor wakeup ...
>>> 12:16:58  2551   systemd          15   2938613 0
>>> 12:16:58  2551   systemd          18   2938613 0
>>> 12:16:58  2551   systemd          15   2938814 0
>>> 12:16:58  2551   systemd          18   2938814 0
>>> 12:16:58  2551   systemd          15   2938832 0
>>> 12:16:58  2551   systemd          18   2938832 0
>>> 12:16:58  2551   systemd          15   2938978 0
>>> 12:16:58  2551   systemd          18   2938978 0
>>> 12:16:58  2551   systemd          15   2939432 0
>>> 12:16:58  2551   systemd          18   2939432 0
>>> 12:16:58  2551   systemd          15   2939899 0
>>> 12:16:58  2551   systemd          18   2939899 0
>>> 12:16:58  2551   systemd          15   2942192 0
>>> 12:16:58  2551   systemd          18   2942192 0
>>> ...
>>>
>>> Process 2551 is the PDF of the source of the signal according to
>>> killsnoop, 15 and 18 are the signals being sent, and TPID is the target
>>> PID, which among many others, does include my dying processes. Process 2551
>>> is indeed systemd, specifically the user process:
>>>
>>> raman       2551       1  0 Jan07 ?        00:00:10
>>> /usr/lib/systemd/systemd --user
>>>
>>> This behavior is relatively new. What is going on here? I haven't found
>>> any other reports of this behavior anywhere else.
>>>
>>> I'm using systemd-249.9-1.fc35 on Fedora 35.
>>>
>>> Regards,
>>> Raman
>>>
>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/systemd-devel/attachments/20220128/8c98fb06/attachment.htm>

More information about the systemd-devel mailing list