Package: guix;
Reported by: Ludovic Courtès <ludo <at> gnu.org>
Date: Mon, 16 May 2022 08:27:01 UTC
Severity: important
Done: Ludovic Courtès <ludo <at> gnu.org>
Bug is archived. No further changes may be made.
View this message in rfc822 format
From: Ludovic Courtès <ludo <at> gnu.org> To: 55444 <at> debbugs.gnu.org Subject: bug#55444: elogind startup race between shepherd and dbus-daemon Date: Fri, 27 May 2022 15:54:44 +0200
Ludovic Courtès <ludo <at> 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’.
GNU bug tracking system
Copyright (C) 1999 Darren O. Benham,
1997,2003 nCipher Corporation Ltd,
1994-97 Ian Jackson.