[systemd-devel] systemd tries to terminate a process that seems to have exited

Thu May 5 01:41:18 UTC 2022

Hi,

This might be not a systemd issue. But the behavior is weird, and I'm not sure.

I'm trying to run GNOME in a docker container. And gnome-keyring fails to start:

https://gist.github.com/x-yuri/c3c715ea6355633de4546ae957a66410

I added debug statements, and in the log I see:

    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting Start
gnome-keyring for the Secrets Service, and PKCS #11...
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[309]: -- main: 1046
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]:
gnome-keyring-daemon: no process capabilities, insecure memory might
get used
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]: --
fork_and_print_environment: fork(), parent, 653
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: --
fork_and_print_environment: fork(), child, 684
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: couldn't
access control socket: /run/user/1000/keyring/control: No such file or
directory
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]: --
fork_and_print_environment: exit(0), 680
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: -- main:
return 0, 1210
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
State 'stop-sigterm' timed out. Killing.
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
Failed with result 'timeout'.
    May 02 05:10:32 ab6aaba04124 systemd[109]: Failed to start Start
gnome-keyring for the Secrets Service, and PKCS #11.

A longer version (w/ lines about a service activation):

    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting Start
gnome-keyring for the Secrets Service, and PKCS #11...
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[309]: -- main: 1046
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]:
gnome-keyring-daemon: no process capabilities, insecure memory might
get used
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]: --
fork_and_print_environment: fork(), parent, 653
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: --
fork_and_print_environment: fork(), child, 684
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: couldn't
access control socket: /run/user/1000/keyring/control: No such file or
directory
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]: --
fork_and_print_environment: exit(0), 680
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: -- main:
return 0, 1210
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Activating service name='org.freedesktop.secrets' requested
by ':1.19' (uid=1000 pid=251 comm="/usr/libexec/xdg-desktop-portal ")
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[347]: -- main: 1046
    May 02 05:09:02 ab6aaba04124 org.freedesktop.secrets[347]:
gnome-keyring-daemon: no process capabilities, insecure memory might
get used
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[347]: couldn't
access control socket: /run/user/1000/keyring/control: No such file or
directory
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Successfully activated service 'org.freedesktop.secrets'
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
State 'stop-sigterm' timed out. Killing.
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
Failed with result 'timeout'.
    May 02 05:10:32 ab6aaba04124 systemd[109]: Failed to start Start
gnome-keyring for the Secrets Service, and PKCS #11.

And even longer version (with duplicate and intervening lines):

    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting Start
gnome-keyring for the Secrets Service, and PKCS #11...
    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting GNOME Remote Desktop...
    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting Monitor
Session leader for GNOME Session...
    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting Session Migration...
    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting Rewrite
dynamic launcher portal entries...
    May 02 05:09:02 ab6aaba04124 systemd[109]: Finished Start
gnome-keyring as SSH agent.
    May 02 05:09:02 ab6aaba04124 systemd[109]: Started OpenSSH Agent.
    May 02 05:09:02 ab6aaba04124 systemd[109]: Started Monitor Session
leader for GNOME Session.
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[309]: -- main: 1046
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]:
gnome-keyring-daemon: no process capabilities, insecure memory might
get used
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]: --
fork_and_print_environment: fork(), parent, 653
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[309]: --
fork_and_print_environment: fork(), parent, 653
    May 02 05:09:02 ab6aaba04124 systemd[109]: Finished Rewrite
dynamic launcher portal entries.
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: --
fork_and_print_environment: fork(), child, 684
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: couldn't
access control socket: /run/user/1000/keyring/control: No such file or
directory
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[321]: --
fork_and_print_environment: fork(), child, 684
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[321]: couldn't access
control socket: /run/user/1000/keyring/control: No such file or
directory
    May 02 05:09:02 ab6aaba04124 systemd[109]: Finished Session Migration.
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]: --
fork_and_print_environment: exit(0), 680
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[309]: --
fork_and_print_environment: exit(0), 680
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: -- main:
return 0, 1210
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[321]: -- main: return 0, 1210
    May 02 05:09:02 ab6aaba04124 systemd[109]: Started GNOME Remote Desktop.
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Activating via systemd: service name='ca.desrt.dconf'
unit='dconf.service' requested by ':1.15' (uid=1000 pid=220
comm="/usr/libexec/ibus-ui-gtk3 ")
    May 02 05:09:02 ab6aaba04124 systemd[109]: Starting User
preferences database...
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Successfully activated service 'ca.desrt.dconf'
    May 02 05:09:02 ab6aaba04124 systemd[109]: Started User
preferences database.
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Successfully activated service
'org.freedesktop.impl.portal.desktop.gtk'
    May 02 05:09:02 ab6aaba04124 systemd[109]: Started Portal service
(GTK/GNOME implementation).
    May 02 05:09:02 ab6aaba04124 xdg-desktop-por[251]: Failed to load
RealtimeKit property:
GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name
org.freedesktop.RealtimeKit1 was not provided by any .service files
    May 02 05:09:02 ab6aaba04124 xdg-desktop-por[251]: Failed to load
RealtimeKit property:
GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name
org.freedesktop.RealtimeKit1 was not provided by any .service files
    May 02 05:09:02 ab6aaba04124 xdg-desktop-por[251]: Failed to load
RealtimeKit property:
GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name
org.freedesktop.RealtimeKit1 was not provided by any .service files
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Activating service name='org.freedesktop.secrets' requested
by ':1.19' (uid=1000 pid=251 comm="/usr/libexec/xdg-desktop-portal ")
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[347]: -- main: 1046
    May 02 05:09:02 ab6aaba04124 org.freedesktop.secrets[347]:
gnome-keyring-daemon: no process capabilities, insecure memory might
get used
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[347]: couldn't
access control socket: /run/user/1000/keyring/control: No such file or
directory
    May 02 05:09:02 ab6aaba04124 gnome-keyring-d[347]: couldn't access
control socket: /run/user/1000/keyring/control: No such file or
directory
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Successfully activated service 'org.freedesktop.secrets'
    May 02 05:09:02 ab6aaba04124 dbus-daemon[124]: [session uid=1000
pid=124] Successfully activated service
'org.freedesktop.portal.Desktop'
    May 02 05:09:02 ab6aaba04124 systemd[109]: Started Portal service.
    May 02 05:09:11 ab6aaba04124 systemd[1]:
NetworkManager-dispatcher.service: Deactivated successfully.
    May 02 05:09:31 ab6aaba04124 systemd[1]:
systemd-hostnamed.service: Deactivated successfully.
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
State 'stop-sigterm' timed out. Killing.
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
Failed with result 'timeout'.
    May 02 05:10:32 ab6aaba04124 systemd[109]: Failed to start Start
gnome-keyring for the Secrets Service, and PKCS #11.

gnome-keyring starts one child, but both exit soon. Nevertheless
systemd for some reason tries to kill it, and times out:

    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[309]: --
fork_and_print_environment: exit(0), 680
    May 02 05:09:02 ab6aaba04124 gnome-keyring-daemon[321]: -- main:
return 0, 1210
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
State 'stop-sigterm' timed out. Killing.
    May 02 05:10:32 ab6aaba04124 systemd[109]: gnome-keyring.service:
Failed with result 'timeout'.
    May 02 05:10:32 ab6aaba04124 systemd[109]: Failed to start Start
gnome-keyring for the Secrets Service, and PKCS #11.

I can only reproduce it on Debian 8. Which kind of makes it
unimportant. But the behavior is so weird (either gnome-keyring is
blocked in/after exit(), or systemd tries to kill a process that
exited), that I can't help but think about what is really going on
there.

A link to the topic on the GNOME forum (just in case):

https://discourse.gnome.org/t/gnome-gets-stuck-because-of-gnome-keyring/9630

Regards,
Yuri