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

Raman Gupta rocketraman at gmail.com
Sat Jan 29 14:20:41 UTC 2022 

As a another test, I left plasmashell as a child process of my terminal
shell rather than starting it as a systemd user unit.

When doing it this way, plasmashell still crashed on monitor wake-up, but
my applications remained running.

Given that, it does seem like the crash of plasmashell in combination with
some behavior of systemd is the source of my applications being terminated
prematurely.

Regards,
Raman



On Fri, Jan 28, 2022 at 10:28 PM Raman Gupta <rocketraman 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.
>
>
> 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/20220129/65fe3a5b/attachment.htm>

More information about the systemd-devel mailing list