[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
bug#55444: elogind startup race between shepherd and dbus-daemon
From: |
Ludovic Courtès |
Subject: |
bug#55444: elogind startup race between shepherd and dbus-daemon |
Date: |
Fri, 27 May 2022 15:54:44 +0200 |
User-agent: |
Gnus/5.13 (Gnus v5.13) Emacs/27.2 (gnu/linux) |
Ludovic Courtès <ludo@gnu.org> skribis:
> Currently (40a729a0e6f1d660b942241416c1e2c567616d4d), shepherd and
> dbus-daemon compete to start elogind: shepherd tries to start it
> eagerly, and dbus-daemon starts it on-demand upon bus activation.
>
> Sometimes dbus-daemon wins, and thus shepherd tries a few times to start
> it anyway, leading to the infamous:
Here’s an example where dbus-daemon wins:
--8<---------------cut here---------------start------------->8---
$ sudo grep --color -E '^May 27 .*(dbus.*login|elogind)' /var/log/messages
May 27 15:06:36 localhost dbus-daemon[326]: [system] Activating service
name='org.freedesktop.login1' requested by ':1.0' (uid=0 pid=307
comm="/gnu/store/2lis8khrdk0zzjzs5ydi8rs5h6f6wjr7-shadow") (using servicehelper)
May 27 15:06:37 localhost elogind-daemon[335]: New seat seat0.
May 27 15:06:37 localhost elogind-daemon[335]: Watching system buttons on
/dev/input/event2 (Power Button)
May 27 15:06:37 localhost elogind-daemon[335]: Watching system buttons on
/dev/input/event0 (Power Button)
May 27 15:06:37 localhost elogind-daemon[335]: Watching system buttons on
/dev/input/event1 (Sleep Button)
May 27 15:06:41 localhost elogind-daemon[335]: Watching system buttons on
/dev/input/event4 (Darfon HP USB Keyboard)
May 27 15:06:43 localhost elogind-daemon[335]: Watching system buttons on
/dev/input/event5 (Darfon HP USB Keyboard Consumer Control)
May 27 15:06:48 localhost dbus-daemon[326]: [system] Successfully activated
service 'org.freedesktop.login1'
May 27 15:06:54 localhost elogind-daemon[335]: New session c1 of user ludo.
May 27 15:07:45 localhost shepherd[1]: Service elogind has been started.
May 27 15:08:02 localhost shepherd[1]: Respawning elogind.
May 27 15:08:14 localhost shepherd[1]: Service elogind has been started.
May 27 15:08:32 localhost shepherd[1]: Respawning elogind.
May 27 15:08:43 localhost shepherd[1]: Service elogind has been started.
May 27 15:08:47 localhost vmunix: [ 25.123255] shepherd[1]: Service
file-system-/sys/fs/cgroup/elogind has been started.
May 27 15:08:53 localhost shepherd[1]: Respawning elogind.
May 27 15:08:59 localhost shepherd[1]: Service elogind has been started.
May 27 15:09:00 localhost vmunix: [ 79.976531] elogind[348]: elogind is
already running as PID 335
May 27 15:09:00 localhost vmunix: [ 107.880971] elogind[364]: elogind is
already running as PID 335
May 27 15:09:00 localhost vmunix: [ 109.160864] elogind-daemon[335]: New
session c2 of user ludo.
May 27 15:09:00 localhost vmunix: [ 135.017068] elogind[369]: elogind is
already running as PID 335
May 27 15:09:00 localhost vmunix: [ 159.849027] elogind[370]: elogind is
already running as PID 335
May 27 15:09:00 localhost vmunix: [ 181.608889] elogind[371]: elogind is
already running as PID 335
May 27 15:09:00 localhost shepherd[1]: Respawning elogind.
May 27 15:09:00 localhost shepherd[1]: Service elogind has been started.
May 27 15:09:04 localhost shepherd[1]: Respawning elogind.
May 27 15:09:04 localhost shepherd[1]: Service elogind has been started.
May 27 15:09:04 localhost elogind[410]: elogind is already running as PID 335
May 27 15:09:04 localhost shepherd[1]: Respawning elogind.
May 27 15:09:04 localhost shepherd[1]: Service elogind has been started.
May 27 15:09:05 localhost elogind[411]: elogind is already running as PID 335
May 27 15:09:05 localhost shepherd[1]: Respawning elogind.
May 27 15:09:05 localhost shepherd[1]: Service elogind has been started.
May 27 15:09:05 localhost elogind[412]: elogind is already running as PID 335
May 27 15:09:05 localhost shepherd[1]: Respawning elogind.
May 27 15:09:05 localhost shepherd[1]: Service elogind has been started.
May 27 15:09:05 localhost elogind[416]: elogind is already running as PID 335
May 27 15:09:05 localhost shepherd[1]: Respawning elogind.
May 27 15:09:05 localhost shepherd[1]: Service elogind has been started.
May 27 15:09:05 localhost elogind[417]: elogind is already running as PID 335
May 27 15:09:05 localhost shepherd[1]: Service elogind has been disabled.
May 27 15:09:08 localhost elogind-daemon[335]: New session c3 of user gdm.
May 27 15:12:08 localhost elogind-daemon[335]: New session c4 of user ludo.
--8<---------------cut here---------------end--------------->8---
(In this case ‘xorg-server’ started but ‘herd status elogind’ shows it
is stopped and disabled.)
Contrast with a successful startup where shepherd wins:
--8<---------------cut here---------------start------------->8---
May 27 11:03:55 localhost shepherd[1]: Service elogind has been started.
May 27 11:03:54 localhost elogind[476]: New seat seat0.
May 27 11:03:54 localhost elogind[476]: Watching system buttons on
/dev/input/event3 (Power Button)
May 27 11:03:54 localhost elogind[476]: Watching system buttons on
/dev/input/event1 (Power Button)
May 27 11:03:54 localhost elogind[476]: Watching system buttons on
/dev/input/event0 (Lid Switch)
May 27 11:03:54 localhost elogind[476]: Watching system buttons on
/dev/input/event2 (Sleep Button)
May 27 11:03:54 localhost elogind[476]: Watching system buttons on
/dev/input/event5 (Dell Dell USB Keyboard)
May 27 11:03:54 localhost dbus-daemon[470]: [system] Activating service
name='org.freedesktop.login1' requested by ':1.2' (uid=0 pid=477
comm="/gnu/store/qpaw2f734zlsq153fkn5afcv4k4fk63z-upower") (using servicehelper)
May 27 11:03:54 localhost elogind[476]: Watching system buttons on
/dev/input/event4 (AT Translated Set 2 keyboard)
May 27 11:03:55 localhost elogind[496]: elogind is already running as PID 476
May 27 11:03:55 localhost dbus-daemon[470]: [system] Successfully activated
service 'org.freedesktop.login1'
May 27 11:04:03 localhost vmunix: [ 2089.808033] shepherd[1]: Service
file-system-/sys/fs/cgroup/elogind has been started.
May 27 11:04:04 localhost elogind[476]: New session c1 of user gdm.
--8<---------------cut here---------------end--------------->8---
Besides, Gentoo recommends starting it from runit rather than on-demand:
https://wiki.gentoo.org/wiki/Elogind#Service
https://gitweb.gentoo.org/repo/gentoo.git/tree/sys-auth/elogind/elogind-241.1.ebuild?id=bea47cee314829edbb41453d1e89fa1d1d3f9993
They don’t seem to be doing anything to avoid the race though.
Ludo’.