Dbus [system] Failed to activate service 'org.freedesktop.systemd1': timed out

Hi All,

My system has been running Leap 42.1 for years without issue. Recently I get random boot failures where the desktop doesn’t start.
/var/log/messages has the following and many similar messages.

dbus[812]: [system] Failed to activate service ‘org.freedesktop.systemd1’: timed out
systemd-logind[835]: Failed to enable subscription: Activation of org.freedesktop.systemd1 timed out

Restarting the system works but the problem randomly occurs again.

Any help in debugging the issue would be helpful.

Thanks!

Assuming that, the Leap 42.1 systemd package has installed ‘/usr/bin/busctl’ please check the output of:

> busctl list

There should be an entry for “org.freedesktop.systemd1” which looks something like this (taken from a Leap 15.4 system … )

NAME                                       PID PROCESS         USER    CONNECTION    UNIT                          SESSION DESCRIPTION
 .
 .
org.freedesktop.systemd1                     1 systemd         root    :1.0          init.scope                    -       -
 .
 .

Then, please check the output of:

> busctl status org.freedesktop.systemd1

There should be a command line entry similar to the following Leap 15.4 entry:

CommandLine=/usr/lib/systemd/systemd --switched-root --system --deserialize 30

@LdotN:

If you call the following:

> busctl tree org.freedesktop.systemd1

you’ll see that, the other D-Bus services depend on the the systemd service …

 # journalctl -b 0 --no-hostname --output=short-monotonic | grep -i 'dbus-daemon'
[    9.637659] dbus-daemon[981]: [system] Activating via systemd: service name='org.freedesktop.ColorManager' unit='colord.service' requested by ':1.3' (uid=0 pid=980 comm="/usr/sbin/cupsd -l ")
[    9.751952] dbus-daemon[981]: [system] Successfully activated service 'org.freedesktop.ColorManager'
[   10.625225] dbus-daemon[981]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.5' (uid=0 pid=984 comm="/usr/bin/python3 /usr/sbin/firewalld --nofork --no")
[   10.710319] dbus-daemon[981]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'

Unfortunately, the systemd D-Bus service doesn’t seem to write a systemd Journal entry when it starts …

User session startup:

karl@3400G:~> journalctl --user -b -u init.scope
Apr 10 21:06:20 3400G systemd[1410]: Queued start job for default target Main User Target.
Apr 10 21:06:20 3400G systemd[1410]: Created slice User Application Slice.
Apr 10 21:06:20 3400G systemd[1410]: Reached target Paths.
Apr 10 21:06:20 3400G systemd[1410]: Reached target Timers.
Apr 10 21:06:20 3400G systemd[1410]: Starting D-Bus User Message Bus Socket...
Apr 10 21:06:20 3400G systemd[1410]: Listening on Socket to launch DrKonqi for a systemd-coredump crash.
Apr 10 21:06:20 3400G systemd[1410]: Listening on PipeWire PulseAudio.
Apr 10 21:06:20 3400G systemd[1410]: Listening on PipeWire Multimedia System Socket.
Apr 10 21:06:20 3400G systemd[1410]: Listening on D-Bus User Message Bus Socket.
Apr 10 21:06:20 3400G systemd[1410]: Reached target Sockets.
Apr 10 21:06:20 3400G systemd[1410]: Reached target Basic System.
Apr 10 21:06:20 3400G systemd[1410]: Started Save jAlbum Project Files.
Apr 10 21:06:20 3400G systemd[1410]: Reached target Main User Target.
Apr 10 21:06:20 3400G systemd[1410]: Startup finished in 235ms.
Apr 10 21:06:20 3400G systemd[1410]: Created slice User Core Session Slice.
Apr 10 21:06:20 3400G systemd[1410]: Starting D-Bus User Message Bus...
Apr 10 21:06:20 3400G systemd[1410]: Started D-Bus User Message Bus.
Apr 10 21:06:20 3400G systemd[1410]: Reloading requested from client PID 1419 ('startplasma-x11')...
Apr 10 21:06:20 3400G systemd[1410]: Reloading...
Apr 10 21:06:21 3400G systemd[1410]: Reloading finished in 283 ms.
Apr 10 21:06:21 3400G systemd[1410]: Created slice User Background Tasks Slice.
Apr 10 21:06:21 3400G systemd[1410]: Starting Baloo File Indexer Daemon...
Apr 10 21:06:21 3400G systemd[1410]: Starting KDE Config Module Initialization...
Apr 10 21:06:21 3400G systemd[1410]: Starting User folders update...
Apr 10 21:06:21 3400G systemd[1410]: Finished User folders update.
Apr 10 21:06:21 3400G systemd[1410]: Reached target Session services which should run early before the graphical session is brought up.
Apr 10 21:06:21 3400G systemd[1410]: Starting Portal service...
Apr 10 21:06:21 3400G systemd[1410]: Started Baloo File Indexer Daemon.
Apr 10 21:06:21 3400G systemd[1410]: Starting flatpak document portal service...
Apr 10 21:06:21 3400G systemd[1410]: Starting sandboxed app permission store...
Apr 10 21:06:21 3400G systemd[1410]: Started sandboxed app permission store.
Apr 10 21:06:21 3400G systemd[1410]: Started flatpak document portal service.
Apr 10 21:06:21 3400G systemd[1410]: Starting Portal service (GTK/GNOME implementation)...
Apr 10 21:06:21 3400G systemd[1410]: Started KDE Config Module Initialization.
Apr 10 21:06:21 3400G systemd[1410]: Starting KDE Daemon...
Apr 10 21:06:21 3400G systemd[1410]: Starting KDE Session Management Server...
Apr 10 21:06:21 3400G systemd[1410]: Starting KDE Window Manager...
Apr 10 21:06:21 3400G systemd[1410]: Starting Virtual filesystem service...
Apr 10 21:06:21 3400G systemd[1410]: Started Virtual filesystem service.
Apr 10 21:06:21 3400G systemd[1410]: Started Portal service (GTK/GNOME implementation).
Apr 10 21:06:21 3400G systemd[1410]: Started KDE Daemon.
Apr 10 21:06:21 3400G systemd[1410]: Starting KDE Configuration Module Initialization (Phase 1)...
Apr 10 21:06:21 3400G systemd[1410]: Starting KDE Global Shortcuts Server...
Apr 10 21:06:21 3400G systemd[1410]: Finished KDE Configuration Module Initialization (Phase 1).
Apr 10 21:06:21 3400G systemd[1410]: Started KDE Global Shortcuts Server.
Apr 10 21:06:21 3400G systemd[1410]: Started KDE Session Management Server.
Apr 10 21:06:21 3400G systemd[1410]: Starting KDE Plasma Workspace...
Apr 10 21:06:21 3400G systemd[1410]: Started KDE Window Manager.
Apr 10 21:06:21 3400G systemd[1410]: Starting User preferences database...
Apr 10 21:06:21 3400G systemd[1410]: Started User preferences database.
Apr 10 21:06:21 3400G systemd[1410]: Starting KActivityManager Activity manager Service...
karl@3400G:~> 

Journal of user dbus-demon:

karl@3400G:~> journalctl --user -b0 _PID=1434 --no-pager 
Apr 10 21:06:20 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.freedesktop.systemd1'
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.freedesktop.portal.Desktop' unit='xdg-desktop-portal.service' requested by ':1.4' (uid=1000 pid=1525 comm="/usr/bin/kcminit_startup")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.freedesktop.portal.Documents' unit='xdg-document-portal.service' requested by ':1.6' (uid=1000 pid=1528 comm="/usr/libexec/xdg-desktop-portal")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.freedesktop.impl.portal.PermissionStore' unit='xdg-permission-store.service' requested by ':1.7' (uid=1000 pid=1536 comm="/usr/libexec/xdg-document-portal")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore'
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.freedesktop.portal.Documents'
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.gtk' unit='xdg-desktop-portal-gtk.service' requested by ':1.6' (uid=1000 pid=1528 comm="/usr/libexec/xdg-desktop-portal")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.9' (uid=1000 pid=1551 comm="/usr/libexec/xdg-desktop-portal-gtk")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.gtk.vfs.Daemon'
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.freedesktop.impl.portal.desktop.gtk'
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.kde.kglobalaccel' unit='plasma-kglobalaccel.service' requested by ':1.13' (uid=1000 pid=1565 comm="/usr/bin/ksmserver")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.kde.kglobalaccel'
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.kde' unit='plasma-xdg-desktop-portal-kde.service' requested by ':1.6' (uid=1000 pid=1528 comm="/usr/libexec/xdg-desktop-portal")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='ca.desrt.dconf' unit='dconf.service' requested by ':1.18' (uid=1000 pid=1560 comm="/usr/bin/kded5")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'ca.desrt.dconf'
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.kde.ActivityManager' unit='plasma-kactivitymanagerd.service' requested by ':1.20' (uid=1000 pid=1625 comm="/usr/bin/plasmashell --no-respawn")
Apr 10 21:06:21 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.kde.ActivityManager'
Apr 10 21:06:22 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.freedesktop.impl.portal.desktop.kde'
Apr 10 21:06:22 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.freedesktop.portal.Desktop'
Apr 10 21:06:22 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Activating via systemd: service name='org.kde.KScreen' unit='plasma-kscreen.service' requested by ':1.25' (uid=1000 pid=1672 comm="/usr/libexec/org_kde_powerdevil")
Apr 10 21:06:22 3400G dbus-daemon[1434]: [session uid=1000 pid=1434] Successfully activated service 'org.kde.KScreen'
karl@3400G:~> 

They’re the D-Bus services started by the systemd D-Bus service –

 # systemctl status dbus.service
● dbus.service - D-Bus System Message Bus
     Loaded: loaded (/usr/lib/systemd/system/dbus.service; static)
     Active: active (running) since Tue 2023-04-11 08:49:39 CEST; 6h ago
TriggeredBy: ● dbus.socket
       Docs: man:dbus-daemon(1)
   Main PID: 981 (dbus-daemon)
      Tasks: 1 (limit: 4915)
     CGroup: /system.slice/dbus.service
             └─ 981 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog>

Apr 11 09:47:35 ??? dbus-daemon[981]: [system] Activating via systemd: service name='net.hadess.PowerProfiles' unit=>
Apr 11 09:47:36 ??? dbus-daemon[981]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' u>
Apr 11 09:47:36 ??? dbus-daemon[981]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Apr 11 09:47:36 ??? dbus-daemon[981]: [system] Successfully activated service 'net.hadess.PowerProfiles'
Apr 11 09:47:37 ??? dbus-daemon[981]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez>
Apr 11 09:47:39 ??? dbus-daemon[981]: [system] Activating service name='org.kde.kded.smart' requested by ':1.42' (ui>
Apr 11 09:47:39 ??? dbus-daemon[981]: [system] Successfully activated service 'org.kde.kded.smart'
Apr 11 09:47:55 ??? dbus-daemon[981]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' uni>
Apr 11 09:47:55 ??? dbus-daemon[981]: [system] Successfully activated service 'org.freedesktop.PackageKit'
Apr 11 09:48:02 ??? dbus-daemon[981]: [system] Failed to activate service 'org.bluez': timed out (service_start_time>
 #
 # systemctl status dbus.socket 
● dbus.socket - D-Bus System Message Bus Socket
     Loaded: loaded (/usr/lib/systemd/system/dbus.socket; static)
     Active: active (running) since Tue 2023-04-11 08:49:39 CEST; 6h ago
   Triggers: ● dbus.service
     Listen: /run/dbus/system_bus_socket (Stream)
     CGroup: /system.slice/dbus.socket

Apr 11 08:49:39 ??? systemd[1]: Listening on D-Bus System Message Bus Socket.
 #

There ain’t no Bluetooth hardware on this machine – therefore the D-Bus Bluetooth service doesn’t start … :nerd_face:

@LdotN:

If you recursively grep for “dbus.socket” and “dbus.service” in ‘/usr/lib/systemd/’ you should find that, there’s quite a number of systemd services which are dependent on the systemd D-Bus service and socket.

  • The systemd D-Bus service and socket are started due to “After=”, “Requires=”, “Wants=” and “Requisite=” systemd dependencies in other systemd services but, there ain’t no record of either the systemd D-Bus service or, the associated socket, being started in the systemd Journal – for whatever reason …

Hi Donald,

Thank you for the replies.

Below is the output of busctl as you asked (system booted fine for this session), followed by the recursive grep from /usr/lib/systemd/.
The problem seems random. The system boots and runs normally and every once in a while Fails.
When it fails, I cannot log in. Desktop is black. Nor can I ssh into the system.

busctl list | grep org.freedesktop.systemd1
org.freedesktop.systemd1 1 systemd root :1.0 -

busctl status org.freedesktop.systemd1
Failed to get credentials: No such process

Output of recursive grep:

egrep -R “dbus.socket” *
system/multi-user.target.wants/systemd-logind.service:# Ask for the dbus socket. If running over kdbus, the socket will
system/multi-user.target.wants/systemd-logind.service:Wants=dbus.socket
system/multi-user.target.wants/systemd-logind.service:After=dbus.socket
system/multi-user.target.wants/dbus.service:Requires=dbus.socket
system/display-manager.service:Wants=remote-fs.target dbus.socket systemd-user-sessions.service
system/display-manager.service:After=remote-fs.target dbus.socket systemd-user-sessions.service getty@tty7.service plymouth-quit.service
system/dbus-org.freedesktop.login1.service:# Ask for the dbus socket. If running over kdbus, the socket will
system/dbus-org.freedesktop.login1.service:Wants=dbus.socket
system/dbus-org.freedesktop.login1.service:After=dbus.socket
system/systemd-logind.service:# Ask for the dbus socket. If running over kdbus, the socket will
system/systemd-logind.service:Wants=dbus.socket
system/systemd-logind.service:After=dbus.socket
system/dbus.service:Requires=dbus.socket
Binary file systemd matches
mythtv@b9:/usr/lib/systemd> egrep -R “dbus.service” *
system/wickedd-auto4.service:Requisite=dbus.service
system/wickedd-auto4.service:After=local-fs.target dbus.service SuSEfirewall2_init.service
system/wickedd-dhcp4.service:Requisite=dbus.service
system/wickedd-dhcp4.service:After=local-fs.target dbus.service SuSEfirewall2_init.service
system/wickedd-dhcp6.service:Requisite=dbus.service
system/wickedd-dhcp6.service:After=local-fs.target dbus.service SuSEfirewall2_init.service
system/wickedd-nanny.service:Requisite=dbus.service
system/wickedd-nanny.service:After=local-fs.target dbus.service SuSEfirewall2_init.service wickedd.service
system/wickedd.service:Requisite=dbus.service

If the system has been running for a few years, is there enough free space in the /tmp and /var partitions?

  • The systemd Journal can also suffer from size and damage issues –
    Please check the following:
 # journalctl --verify
 # journalctl --disk-usage

If the systemd Journal is too large or, it had bad entries or errors, then, in the past, it used to occasionally misbehave –

  • After archiving any Journal entries which need to be retained, execute –

# journalctl --vacuum-time=?days/weeks/months

None of the partitions exceed 52% capacity.

journalctl --verify produced corruption messages for 2 user journals.

Invalid tail monotonic timestamp
File corruption detected at /var/log/journal/…/user… (Bad message)

The user journal files being pointed to have date stamps of December 2023 and August 2022. The latest boot problem occurred 2023-04-09.

journalctl --disk-usage

Journals take up 464.0M on disk.

I’ll try to clear the journals but don’t see an option for --vacuum-time
journalctl --version
systemd 210

# journalctl --vacuum-time=2months

will remove all the systemd Journal entries which are older than two months ago.

Then, given the age of of the system, an intermittent hardware issue –

  • If, the system has more than one memory card, swap the memory cards between the slots being used.
  • Re-seat the physical components attached to the Mainboard –
    power connectors; memory card; CPU; graphics card; disk drive cables; etc. etc.
  • Remove any dust accumulated on the Mainboard.

journalctl doesn’t recognize --vacuum-time.
–help doesn’t show any options for clearing the journals.
Maybe an old version? Output of --version is shown below.

# journalctl --vacuum-time=2months
   journalctl: unrecognized option '--vacuum-time=2months'

journalctl --version

systemd 210
+PAM +LIBWRAP +AUDIT +SELINUX -IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ +SECCOMP +APPARMOR

Good suggestions. Thanks.

I didn’t remember to take account of the systemd Journal version differences – as an example and taking account of the fact that on this system I usually keep only a few months of systemd Journal –

 # journalctl --disk-usage 
Archived and active journals take up 648.0M in the file system.
 # journalctl --vacuum-time=12months
Vacuuming done, freed 0B of archived journals from /run/log/journal.
Vacuuming done, freed 0B of archived journals from /var/log/journal.
Vacuuming done, freed 0B of archived journals from /var/log/journal/02d4bd6562f443dc87a4204963c403f6.
 # journalctl --vacuum-time=6months
Vacuuming done, freed 0B of archived journals from /var/log/journal.
Vacuuming done, freed 0B of archived journals from /var/log/journal/02d4bd6562f443dc87a4204963c403f6.
Vacuuming done, freed 0B of archived journals from /run/log/journal.
 # journalctl --vacuum-time=5months
Vacuuming done, freed 0B of archived journals from /var/log/journal/02d4bd6562f443dc87a4204963c403f6.
Vacuuming done, freed 0B of archived journals from /run/log/journal.
Vacuuming done, freed 0B of archived journals from /var/log/journal.
 # journalctl --vacuum-time=4months
Vacuuming done, freed 0B of archived journals from /var/log/journal/02d4bd6562f443dc87a4204963c403f6.
Vacuuming done, freed 0B of archived journals from /run/log/journal.
Vacuuming done, freed 0B of archived journals from /var/log/journal.
 #

Of course, the systemd journaling on your system is an other version – on this Leap 15.4 system, the systemd Journal version is:

 # journalctl --version 
systemd 249 (249.16+suse.171.gdad0071f15)
+PAM +AUDIT +SELINUX +APPARMOR -IMA -SMACK +SECCOMP +GCRYPT +GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=hybrid
 #

You’ll have to check the “journalctl” man page on your system for the correct option syntax to vacuum the space the Journal needs on the disk.