Race condition beim v7 cloop

Servus,

gestern (und ich auch schon mehrfach bei mir) haben wir den Effekt gefunden: Keine Anmeldung möglich. Auf der Console stellt man fest, dass der sssd-Daemon nicht läuft und zwar mit einem Timeout gar nicht startete.
Wir vermuten eine race condition, d.h. eine Abhängigkeit die in systemd fehlt.

systemctl restart sssd
systemctl restart lightdm

und man kann sich wieder anmelden.

ODer man rebootet und scheinbar kommt der Fall nicht so oft vor, d.h. nach reboot geht es gewöhnlich auch wieder.

VG, Tobias

Ja, kann ich bestätigen – es gab beim dist-upgrade aber auch ein Update des sssd Paketes.

(:thinking: … ist einer der Kritikpunkte bei systemd nicht gerade der, dass die Services nicht mehr so „linear“ und schön nacheinander hochfahren wie das mit SysV der Fall war???)

Das haben wir gestern auch diskutiert… Man muss evtl. nur die richtige Abhängigkeit finden… oder sssd kurz vor lightdm starten?

Zum debuggen: ein System bei dem sssd nicht beim start anlief:

# systemctl status sssd
● sssd.service - System Security Services Daemon
   Loaded: loaded (/lib/systemd/system/sssd.service; enabled; vendor preset: enabled)
   Active: failed (Result: timeout) since Tue 2019-09-24 08:00:17 CEST; 23min ago
  Process: 853 ExecStart=/usr/sbin/sssd -i ${DEBUG_LOGGER} (code=exited, status=0/SUCCESS)
 Main PID: 853 (code=exited, status=0/SUCCESS)

Sep 24 08:00:11 client01 systemd[1]: Starting System Security Services Daemon...
Sep 24 08:00:12 client01 sssd[853]: Starting up
Sep 24 08:00:13 client01 sssd[be[928]: Starting up
Sep 24 08:00:16 client01 systemd[1]: sssd.service: Start operation timed out. Terminating.
Sep 24 08:00:16 client01 sssd[be[928]: Shutting down
Sep 24 08:00:17 client01 sssd[1003]: Starting up
Sep 24 08:00:17 client01 sssd[1006]: Starting up
Sep 24 08:00:17 client01 systemd[1]: sssd.service: Failed with result 'timeout'.
Sep 24 08:00:17 client01 systemd[1]: Failed to start System Security Services Daemon.

Systemd „Starting“

 grep 'systemd\[' /var/log/syslog.1  | grep ^Sep\ 24 | grep Starting
Sep 24 08:00:06 client01 systemd[1]: Starting Flush Journal to Persistent Storage...
Sep 24 08:00:06 client01 systemd[1]: Starting Clean up any mess left by 0dns-up...
Sep 24 08:00:06 client01 systemd[1]: Starting AppArmor initialization...
Sep 24 08:00:06 client01 systemd[1]: Starting Set console font and keymap...
Sep 24 08:00:06 client01 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data...
Sep 24 08:00:06 client01 systemd[1]: Starting Nameserver information manager...
Sep 24 08:00:06 client01 systemd[1]: Starting Create Volatile Files and Directories...
Sep 24 08:00:06 client01 systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Sep 24 08:00:06 client01 systemd[1]: Starting Network Name Resolution...
Sep 24 08:00:06 client01 systemd[1]: Starting udev Kernel Device Manager...
Sep 24 08:00:06 client01 systemd[1]: Starting Show Plymouth Boot Screen...
Sep 24 08:00:06 client01 systemd[1]: Starting Raise network interfaces...
Sep 24 08:00:06 client01 systemd[1]: Starting resolvconf-pull-resolved.service...
Sep 24 08:00:06 client01 systemd[1]: Starting Restore /etc/resolv.conf if the system crashed before the ppp link was shut down...
Sep 24 08:00:06 client01 systemd[1]: Starting Avahi mDNS/DNS-SD Stack...
Sep 24 08:00:06 client01 systemd[1]: Starting LSB: Record successful boot for GRUB...
Sep 24 08:00:06 client01 systemd[1]: Starting Modem Manager...
Sep 24 08:00:06 client01 systemd[1]: Starting Disk Manager...
Sep 24 08:00:06 client01 systemd[1]: Starting Network Manager...
Sep 24 08:00:06 client01 systemd[1]: Starting LSB: Speech Dispatcher...
Sep 24 08:00:06 client01 systemd[1]: Starting Initialize hardware monitoring sensors...
Sep 24 08:00:06 client01 systemd[1]: Starting VirtualBox Linux kernel module...
Sep 24 08:00:06 client01 systemd[1]: Starting Detect the available GPUs and deal with any system changes...
Sep 24 08:00:06 client01 systemd[1]: Starting Dispatcher daemon for systemd-networkd...
Sep 24 08:00:06 client01 systemd[1]: Starting LSB: automatic crash report generation...
Sep 24 08:00:06 client01 systemd[1]: Starting WPA supplicant...
Sep 24 08:00:06 client01 systemd[1]: Starting System Logging Service...
Sep 24 08:00:06 client01 systemd[1]: Starting Authorization Manager...
Sep 24 08:00:06 client01 systemd[1]: Starting Discard unused blocks...
Sep 24 08:00:07 client01 systemd[1]: Starting Hostname Service...
Sep 24 08:00:08 client01 systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 24 08:00:08 client01 systemd[1]: Starting chrony, an NTP client/server...
Sep 24 08:00:08 client01 systemd[1]: Starting OpenBSD Secure Shell server...
Sep 24 08:00:08 client01 systemd[1]: Starting Message of the Day...
Sep 24 08:00:08 client01 systemd[1]: Starting Samba NMB Daemon...
Sep 24 08:00:08 client01 systemd[1]: Starting Tool to automatically collect and submit kernel crash signatures...
Sep 24 08:00:08 client01 systemd[1]: Starting LSB: mausdaemon...
Sep 24 08:00:08 client01 systemd[1]: Starting /etc/rc.local Compatibility...
Sep 24 08:00:09 client01 systemd[1]: Starting Daily apt download activities...
Sep 24 08:00:09 client01 systemd[1]: Starting LSB: disk temperature monitoring daemon...
Sep 24 08:00:09 client01 systemd[1]: Starting linuxmuster: switch local and remote home depending on ad server connection...
Sep 24 08:00:09 client01 systemd[1]: Starting Network Manager...
Sep 24 08:00:11 client01 systemd[1]: Starting System Security Services Daemon...
Sep 24 08:00:11 client01 systemd[1]: Starting resolvconf-pull-resolved.service...
Sep 24 08:00:14 client01 systemd[1]: Starting Samba SMB Daemon...
Sep 24 08:00:17 client01 systemd[1]: Starting Accounts Service...
Sep 24 08:00:17 client01 systemd[1]: Starting Login Service...
Sep 24 08:00:17 client01 systemd[1]: Starting Permit User Sessions...
Sep 24 08:00:18 client01 systemd[1]: Starting Light Display Manager...
Sep 24 08:00:18 client01 systemd[1]: Starting Hold until boot process finishes up...
Sep 24 08:00:19 client01 systemd[1]: Starting Set console scheme...
Sep 24 08:00:19 client01 systemd[1]: Starting "x11vnc"...
Sep 24 08:00:19 client01 systemd[1]: Starting Manage, Install and Generate Color Profiles...
Sep 24 08:00:19 client01 systemd[1]: Starting Daily apt upgrade and clean activities...
Sep 24 08:00:24 client01 systemd[1]: Starting User Manager for UID 109...
Sep 24 08:00:25 client01 systemd[1]: Starting vboxautostart-service.service...
Sep 24 08:00:25 client01 systemd[1]: Starting vboxweb-service.service...
Sep 24 08:00:25 client01 systemd[1]: Starting vboxballoonctrl-service.service...
Sep 24 08:00:25 client01 systemd[1]: Starting Update UTMP about System Runlevel Changes...
Sep 24 08:00:26 client01 systemd[1234]: Starting D-Bus User Message Bus Socket.
Sep 24 08:00:26 client01 systemd[1234]: Starting Virtual filesystem service...
Sep 24 08:00:27 client01 systemd[1234]: Starting Accessibility services bus...
Sep 24 08:00:28 client01 systemd[1]: Starting Time & Date Service...
Sep 24 08:00:29 client01 systemd[1]: Starting RealtimeKit Scheduling Policy Service...
Sep 24 08:00:29 client01 systemd[1]: Starting "x11vnc"...
Sep 24 08:00:29 client01 systemd[1]: Starting Daemon for power management...
Sep 24 08:00:52 client01 systemd[1]: Starting User Manager for UID 0...
Sep 24 08:00:52 client01 systemd[1423]: Starting D-Bus User Message Bus Socket.
Sep 24 08:00:55 client01 systemd[1423]: Starting Virtual filesystem service...

etwas genauer:


Sep 24 08:00:09 client01 systemd[1]: Stopped Network Manager.
Sep 24 08:00:09 client01 systemd[1]: Starting Network Manager...
Sep 24 08:00:10 client01 systemd[1]: Received SIGRTMIN+20 from PID 397 (plymouthd).
Sep 24 08:00:10 client01 systemd[1]: Started Network Manager.
Sep 24 08:00:11 client01 systemd[1]: Started linuxmuster: switch local and remote home depending on ad server connection.
Sep 24 08:00:11 client01 systemd[1]: Starting System Security Services Daemon...
Sep 24 08:00:11 client01 systemd[1]: Started Message of the Day.
Sep 24 08:00:11 client01 systemd[1]: Started LSB: disk temperature monitoring daemon.
Sep 24 08:00:11 client01 systemd[1]: Starting resolvconf-pull-resolved.service...
Sep 24 08:00:11 client01 systemd[1]: udisks2.service: State 'stop-sigterm' timed out. Killing.
Sep 24 08:00:11 client01 systemd[1]: udisks2.service: Killing process 515 (udisksd) with signal SIGKILL.
Sep 24 08:00:11 client01 systemd[1]: udisks2.service: Main process exited, code=killed, status=9/KILL
Sep 24 08:00:11 client01 systemd[1]: udisks2.service: Failed with result 'timeout'.
Sep 24 08:00:11 client01 systemd[1]: Failed to start Disk Manager.
Sep 24 08:00:14 client01 systemd[1]: nmbd.service: Start operation timed out. Terminating.
Sep 24 08:00:14 client01 systemd[1]: nmbd.service: Failed with result 'timeout'.
Sep 24 08:00:14 client01 systemd[1]: Failed to start Samba NMB Daemon.
Sep 24 08:00:14 client01 systemd[1]: Starting Samba SMB Daemon...
Sep 24 08:00:14 client01 systemd[1]: Started resolvconf-pull-resolved.service.
Sep 24 08:00:14 client01 systemd[1]: Reloading OpenBSD Secure Shell server.
Sep 24 08:00:14 client01 systemd[1]: Reloaded OpenBSD Secure Shell server.
Sep 24 08:00:15 client01 systemd[1]: Started Samba SMB Daemon.
Sep 24 08:00:16 client01 systemd[1]: sssd.service: Start operation timed out. Terminating.
Sep 24 08:00:16 client01 systemd[1]: Reloading OpenBSD Secure Shell server.
Sep 24 08:00:17 client01 systemd[1]: Reloaded OpenBSD Secure Shell server.
Sep 24 08:00:17 client01 systemd[1]: sssd.service: Failed with result 'timeout'.
Sep 24 08:00:17 client01 systemd[1]: Failed to start System Security Services Daemon.
Sep 24 08:00:17 client01 systemd[1]: Reached target User and Group Name Lookups.
Sep 24 08:00:17 client01 systemd[1]: Starting Accounts Service...
Sep 24 08:00:17 client01 systemd[1]: Starting Login Service...
Sep 24 08:00:17 client01 systemd[1]: Starting Permit User Sessions...
Sep 24 08:00:17 client01 systemd[1]: Started CUPS Scheduler.
Sep 24 08:00:17 client01 systemd[1]: Started Make remote CUPS printers available locally.
Sep 24 08:00:18 client01 systemd[1]: Started Permit User Sessions.
Sep 24 08:00:18 client01 systemd[1]: Starting Light Display Manager...
Sep 24 08:00:18 client01 systemd[1]: Starting Hold until boot process finishes up...
Sep 24 08:00:18 client01 systemd[1]: Started Accounts Service.
Sep 24 08:00:18 client01 systemd[1]: Started Login Service.

Außerdem fällt auf, dass nicht nur sssd einen timeout hat.

grep 'systemd\[' /var/log/syslog.1  | grep ^Sep\ 24 | grep -i timeout
Sep 24 08:00:06 client01 systemd[1]: dev-vda3.device: Job dev-vda3.device/start failed with result 'timeout'.
Sep 24 08:00:07 client01 systemd[1]: networkd-dispatcher.service: Failed with result 'timeout'.
Sep 24 08:00:08 client01 systemd[1]: ModemManager.service: Failed with result 'timeout'.
Sep 24 08:00:08 client01 systemd[1]: NetworkManager.service: Failed with result 'timeout'.
Sep 24 08:00:11 client01 systemd[1]: udisks2.service: Failed with result 'timeout'.
Sep 24 08:00:14 client01 systemd[1]: nmbd.service: Failed with result 'timeout'.
Sep 24 08:00:17 client01 systemd[1]: sssd.service: Failed with result 'timeout'.
Sep 24 08:00:24 client01 systemd[1]: x11vnc.service: Failed with result 'timeout'.
  • vda3 kann man ignorieren und damit auch udisks2 vermutlich

Dominik scheint die Lösung gefunden zu haben, siehe Bugfixes für bionic.cloop 919