Bug 1976653

Summary: dracut lock-up of 1m30s in initrd due to new dbus-broker ordering causing slow boot
Product: [Fedora] Fedora Reporter: Dusan Bobak <drunkez>
Component: dbus-brokerAssignee: David Rheinsberg <daherrma>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 34CC: ade.rixon, adrien-xx-redhatbz, ahabig, alex.go4more, alex.j.kerzner, alexsilv, amessina, andy, ankit, balay, bcotton, belegdol, blu2lz, bmason, bmchugh, bruno.thomsen, bugzilla, bugzilla, buytenh, carlos.sepulveda, cesarb, cfeller, chriscarson60187, christof, daherrma, danielsun3164, denezmarchand, dfediuck, dgilbert, dimonych85, dominik, dracut-maint-list, drewdowling, drunkez, dsanzmor, eelena, elavarde, emcnabb, ewl+redhat, faber, fedora, florian, frank, fschwarz, fsumsal, fweimer, garrett.mitchener, g.collotta02, g.fhnrunznrqeqf, goeran, gsalinet, hdegoede, henrik, hpillay, hyphen9, i.maximets, ipazosat, iz0bbz, jburgess777, jesus, jneedle, jonathan, joshas, keithritter, larsper, lprosseda, m3lh0r, mail, marko.bevc, matushonek, mblaha, mike, mironov.ivan, mpredosin, mtessun, mvermaes, nalin, ol+redhat, orschiro, pablo.iranzo, palazzotti, pdwyer, phhs80, philipp.raich, pioann, quiffman, redhat, remy-redhat, rfrank, rgarcia, robatino, rsandu, sbobber, sbonnevi, scorreia, Simon.Gerhards, skrenger, stanley.king, stefan.hoelldampf, stefano.biagiotti, stefanrin, stein, stepglenn, suvi, tgunders, todoleza, tomastrnka, tom+f, trailtotale, troels, tseewald, viraptor, viraptor, walicki, wurstsemmel, yaneti, yjog, zbyszek, zingale
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: dbus-broker-29-2.fc34 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2021-07-30 01:01:38 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
journal.log wiht rd.debug
none
output from journalctl as requested by comment 14 none

Description Dusan Bobak 2021-06-27 21:28:04 UTC
Description of problem:
after recent upgrade F34 boot time is really bad

Version-Release number of selected component (if applicable):
[root@dellon drunkez]# uname -a
Linux dellon 5.12.12-300.fc34.x86_64 #1 SMP Fri Jun 18 14:30:51 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
[root@dellon drunkez]# date
Sun Jun 27 11:26:31 PM CEST 2021
[root@dellon drunkez]# systemctl --version
systemd 248 (v248.3-1.fc34)
+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 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified
[root@dellon drunkez]# 

How reproducible:
reboot

Steps to Reproduce:
1.
2.
3.

Actual results:
[root@dellon drunkez]# systemd-analyze  blame |head -n 5
1min 30.301s dracut-initqueue.service
      4.147s plymouth-quit-wait.service
      3.734s systemd-udev-settle.service
      1.221s fwupd.service
       764ms lvm2-monitor.service
[root@dellon drunkez]# 


Jun 27 22:54:59 dellon dracut-initqueue[533]: inactive          '/dev/fedora_localhost-live/swap' [<7.79 GiB] inherit
Jun 27 22:54:59 dellon dracut-initqueue[533]: inactive          '/dev/fedora_localhost-live/home' [397.56 GiB] inherit
Jun 27 22:54:59 dellon dracut-initqueue[533]: inactive          '/dev/fedora_localhost-live/root' [70.00 GiB] inherit
Jun 27 22:54:59 dellon systemd[1]: Found device /dev/mapper/fedora_localhost--live-root.
Jun 27 22:54:59 dellon systemd[1]: Reached target Initrd Root Device.
Jun 27 22:56:29 dellon dracut-initqueue[535]: WARNING: D-Bus notification failed: Transport endpoint is not connected
Jun 27 22:56:29 dellon systemd[1]: Found device /dev/mapper/fedora_localhost--live-swap.

Expected results:
boot log was without this D-BUs failure message

Jun 27 20:26:26 dellon dracut-initqueue[531]: inactive          '/dev/fedora_localhost-live/swap' [<7.79 GiB] inherit
Jun 27 20:26:26 dellon dracut-initqueue[531]: inactive          '/dev/fedora_localhost-live/home' [397.56 GiB] inherit
Jun 27 20:26:26 dellon dracut-initqueue[531]: inactive          '/dev/fedora_localhost-live/root' [70.00 GiB] inherit
Jun 27 20:26:26 dellon systemd[1]: Found device /dev/mapper/fedora_localhost--live-root.
Jun 27 20:26:26 dellon systemd[1]: Reached target Initrd Root Device.
Jun 27 20:26:26 dellon audit: BPF prog-id=9 op=LOAD



Additional info:

Comment 1 Henrik Nordström 2021-06-27 22:54:40 UTC
What is your kernel command line?

cat /proc/cmdline

Comment 2 Iván Pazos 2021-06-28 16:34:25 UTC
Hi,

I am facing the same issue. Today I upgraded to 


 I upgraded my laptop from Fedora 32 to Fedora 34 and everything works fine but it takes a lot to boot.

After a quick analysis I found out this service is consuming all the boot time 

[ipazosat@x1 ~]$ systemd-analyze blame
1min 30.453s dracut-initqueue.service


Logs:

 dracut-initqueue.service - dracut initqueue hook
     Loaded: loaded (/usr/lib/systemd/system/dracut-initqueue.service; static)
     Active: inactive (dead) since Mon 2021-06-28 18:07:54 CEST; 5min ago
       Docs: man:dracut-initqueue.service(8)
   Main PID: 480 (code=exited, status=0/SUCCESS)
        CPU: 0

Jun 28 18:06:23 x1 systemd[1]: Starting dracut initqueue hook...
Jun 28 18:06:23 x1 dracut-initqueue[500]: Scanning devices nvme0n1p3  for LVM logical volumes fedora_localhost-live/root
Jun 28 18:06:23 x1 dracut-initqueue[500]: fedora_localhost-live/swap
Jun 28 18:06:23 x1 dracut-initqueue[521]: inactive          '/dev/fedora_localhost-live/swap' [7.77 GiB] inherit
Jun 28 18:06:23 x1 dracut-initqueue[521]: inactive          '/dev/fedora_localhost-live/home' [159.11 GiB] inherit
Jun 28 18:06:23 x1 dracut-initqueue[521]: inactive          '/dev/fedora_localhost-live/root' [70.00 GiB] inherit
Jun 28 18:07:53 x1 dracut-initqueue[523]: WARNING: D-Bus notification failed: Transport endpoint is not connected
Jun 28 18:07:54 x1 systemd[1]: Finished dracut initqueue hook.
Jun 28 18:07:54 x1 systemd[1]: dracut-initqueue.service: Deactivated successfully.
Jun 28 18:07:54 x1 systemd[1]: Stopped dracut initqueue hook.

I don't have units failing in my laptop etc.

● x1
    State: running
     Jobs: 0 queued
   Failed: 0 units


Model is X1 Carbon GEN 7.

[ipazosat@x1 ~]$ cat /proc/cmdline 
BOOT_IMAGE=(hd0,gpt2)/vmlinuz-5.12.12-300.fc34.x86_64 root=/dev/mapper/fedora_localhost--live-root ro resume=/dev/mapper/fedora_localhost--live-swap rd.lvm.lv=fedora_localhost-live/root rd.lvm.lv=fedora_localhost-live/swap rhgb quiet


BR,

Iván

Comment 3 Ricardo Garcia 2021-06-29 06:16:08 UTC
Same problem here.

$ sudo systemd-analyze blame | head -1
1min 40.713s dracut-initqueue.service

$ cat /proc/cmdline 
BOOT_IMAGE=(hd0,gpt2)/vmlinuz-5.12.12-300.fc34.x86_64 root=/dev/mapper/fedora-root ro resume=/dev/mapper/fedora-swap rd.lvm.lv=fedora/root rd.luks.uuid=luks-e4b4abe4-9c4d-4d67-9faf-9148c7ad2642 rd.lvm.lv=fedora/swap rhgb quiet systemd.unified_cgroup_hierarchy=0

$ sudo journalctl -b -u dracut-initqueue.service
-- Journal begins at Fri 2021-01-08 08:31:53 CET, ends at Tue 2021-06-29 08:10:14 CEST. --
Jun 29 07:46:24 localhost.localdomain systemd[1]: Starting dracut initqueue hook...
Jun 29 07:46:35 localhost.localdomain dracut-initqueue[721]: Scanning devices dm-0  for LVM logical volumes fedora/root
Jun 29 07:46:35 localhost.localdomain dracut-initqueue[721]: fedora/swap
Jun 29 07:46:35 localhost.localdomain dracut-initqueue[743]: inactive          '/dev/fedora/swap' [7.78 GiB] inherit
Jun 29 07:46:35 localhost.localdomain dracut-initqueue[743]: inactive          '/dev/fedora/home' [<894.89 GiB] inherit
Jun 29 07:46:35 localhost.localdomain dracut-initqueue[743]: inactive          '/dev/fedora/root' [50.00 GiB] inherit
Jun 29 07:48:05 localhost.localdomain dracut-initqueue[745]: WARNING: D-Bus notification failed: Transport endpoint is not connected
Jun 29 07:48:05 localhost.localdomain systemd[1]: Finished dracut initqueue hook.
Jun 29 07:48:05 localhost.localdomain systemd[1]: dracut-initqueue.service: Deactivated successfully.
Jun 29 07:48:05 localhost.localdomain systemd[1]: Stopped dracut initqueue hook.

This problem started to happen a couple of days ago:

-- Boot c997dd7f982b4ddba44687cc30aa7893 --
Jun 26 11:52:33 localhost.localdomain systemd[1]: Starting dracut initqueue hook...
Jun 26 11:52:56 localhost.localdomain dracut-initqueue[892]: Scanning devices dm-0  for LVM logical volumes fedora/root
Jun 26 11:52:56 localhost.localdomain dracut-initqueue[892]: fedora/swap
Jun 26 11:52:56 localhost.localdomain dracut-initqueue[913]: inactive          '/dev/fedora/swap' [7.78 GiB] inherit
Jun 26 11:52:56 localhost.localdomain dracut-initqueue[913]: inactive          '/dev/fedora/home' [<894.89 GiB] inherit
Jun 26 11:52:56 localhost.localdomain dracut-initqueue[913]: inactive          '/dev/fedora/root' [50.00 GiB] inherit
Jun 26 11:52:56 localhost.localdomain systemd[1]: Finished dracut initqueue hook.
Jun 26 11:52:56 localhost.localdomain systemd[1]: dracut-initqueue.service: Deactivated successfully.
Jun 26 11:52:56 localhost.localdomain systemd[1]: Stopped dracut initqueue hook.
-- Boot e130f712098347768c3481fea9143c41 --
Jun 26 11:58:03 localhost.localdomain systemd[1]: Starting dracut initqueue hook...
Jun 26 11:58:12 localhost.localdomain dracut-initqueue[707]: Scanning devices dm-0  for LVM logical volumes fedora/root
Jun 26 11:58:12 localhost.localdomain dracut-initqueue[707]: fedora/swap
Jun 26 11:58:12 localhost.localdomain dracut-initqueue[728]: inactive          '/dev/fedora/swap' [7.78 GiB] inherit
Jun 26 11:58:12 localhost.localdomain dracut-initqueue[728]: inactive          '/dev/fedora/home' [<894.89 GiB] inherit
Jun 26 11:58:12 localhost.localdomain dracut-initqueue[728]: inactive          '/dev/fedora/root' [50.00 GiB] inherit
Jun 26 11:59:43 localhost.localdomain dracut-initqueue[730]: WARNING: D-Bus notification failed: Transport endpoint is not connected
Jun 26 11:59:43 localhost.localdomain systemd[1]: Finished dracut initqueue hook.
Jun 26 11:59:43 localhost.localdomain systemd[1]: dracut-initqueue.service: Deactivated successfully.
Jun 26 11:59:43 localhost.localdomain systemd[1]: Stopped dracut initqueue hook.

dnf history shows I upgraded around that moment, at 2021-06-26 11:55. dracut was not upgraded, but dbus-broker was. Perhaps that's the issue?

Transaction ID : 771
Begin time     : Sat 26 Jun 2021 11:55:02 AM CEST
Begin rpmdb    : 2878:43d2b0ad8a3a1726a1144c156f05d3d7887e763d
End time       : Sat 26 Jun 2021 11:57:23 AM CEST (141 seconds)
End rpmdb      : 2877:11a12724f93cb5006c00a2fcb70c53cdb5afaa90
User           : root <root>
Return-Code    : Success
Releasever     : 
Command Line   : 
Comment        : 
Packages Altered:
    Install  kernel-5.12.12-300.fc34.x86_64                              @updates
    Install  kernel-core-5.12.12-300.fc34.x86_64                         @updates
    Install  kernel-debug-devel-5.12.12-300.fc34.x86_64                  @updates
    Install  kernel-devel-5.12.12-300.fc34.x86_64                        @updates
    Install  kernel-modules-5.12.12-300.fc34.x86_64                      @updates
    Install  kernel-modules-extra-5.12.12-300.fc34.x86_64                @updates
    Upgrade  cmake-3.20.5-1.fc34.x86_64                                  @updates
    Upgrade  cmake-data-3.20.5-1.fc34.noarch                             @updates
    Upgrade  cmake-filesystem-3.20.5-1.fc34.x86_64                       @updates
    Upgrade  cmake-rpm-macros-3.20.5-1.fc34.noarch                       @updates
    Upgrade  dbus-broker-29-1.fc34.x86_64                                @updates
    Upgrade  gst-editing-services-1.19.1-2.1.18.4.fc34.x86_64            @updates
    Upgrade  gstreamer1-1.19.1-2.1.18.4.fc34.x86_64                      @updates
    Upgrade  gstreamer1-plugins-bad-free-1.19.1-2.1.18.4.fc34.x86_64     @updates
    Upgrade  gstreamer1-plugins-base-1.19.1-2.1.18.4.fc34.x86_64         @updates
    Upgrade  gstreamer1-plugins-good-1.19.1-2.1.18.4.fc34.x86_64         @updates
    Upgrade  gstreamer1-plugins-good-gtk-1.19.1-2.1.18.4.fc34.x86_64     @updates
    Upgrade  gstreamer1-plugins-good-qt-1.19.1-2.1.18.4.fc34.x86_64      @updates
    Upgrade  gstreamer1-plugins-ugly-free-1.19.1-2.1.18.4.fc34.x86_64    @updates
    Upgrade  libinput-1.18.0-2.fc34.x86_64                               @updates
    Upgrade  libinput-devel-1.18.0-2.fc34.x86_64                         @updates
    Upgrade  libxcrypt-4.4.22-2.fc34.i686                                @updates
    Upgrade  libxcrypt-4.4.22-2.fc34.x86_64                              @updates
    Upgrade  libxcrypt-compat-4.4.22-2.fc34.x86_64                       @updates
    Upgrade  libxcrypt-devel-4.4.22-2.fc34.i686                          @updates
    Upgrade  libxcrypt-devel-4.4.22-2.fc34.x86_64                        @updates
    Upgrade  nano-5.8-2.fc34.x86_64                                      @updates
    Upgrade  nano-default-editor-5.8-2.fc34.noarch                       @updates
    Upgrade  pam-1.5.1-6.fc34.x86_64                                     @updates
    Upgrade  pipewire-0.3.30-4.fc34.x86_64                               @updates
    Upgrade  pipewire-alsa-0.3.30-4.fc34.x86_64                          @updates
    Upgrade  pipewire-gstreamer-0.3.30-4.fc34.x86_64                     @updates
    Upgrade  pipewire-jack-audio-connection-kit-0.3.30-4.fc34.x86_64     @updates
    Upgrade  pipewire-libs-0.3.30-4.fc34.x86_64                          @updates
    Upgrade  pipewire-pulseaudio-0.3.30-4.fc34.x86_64                    @updates
    Upgrade  pipewire-utils-0.3.30-4.fc34.x86_64                         @updates
    Upgrade  ripgrep-13.0.0-1.fc34.x86_64                                @updates
    Upgrade  rpmautospec-rpm-macros-0.2.3-1.fc34.noarch                  @updates
    Upgrade  tigervnc-1.11.0-12.fc34.x86_64                              @updates
    Upgrade  tigervnc-icons-1.11.0-12.fc34.noarch                        @updates
    Upgrade  tigervnc-license-1.11.0-12.fc34.noarch                      @updates
    Upgrade  totem-1:3.38.1-1.fc34.x86_64                                @updates
    Upgrade  totem-video-thumbnailer-1:3.38.1-1.fc34.x86_64              @updates
    Upgrade  usermode-1.114-2.fc34.x86_64                                @updates
    Upgrade  xorg-x11-server-Xwayland-21.1.1-3.fc34.x86_64               @updates
    Upgraded kernel-5.12.9-300.fc34.x86_64                               @@System
    Upgraded kernel-core-5.12.9-300.fc34.x86_64                          @@System
    Upgraded kernel-debug-devel-5.12.9-300.fc34.x86_64                   @@System
    Upgraded kernel-devel-5.12.9-300.fc34.x86_64                         @@System
    Upgraded kernel-modules-5.12.9-300.fc34.x86_64                       @@System
    Upgraded kernel-modules-extra-5.12.9-300.fc34.x86_64                 @@System
    Removed  kmod-VirtualBox-5.12.9-300.fc34.x86_64-6.1.22-1.fc34.x86_64 @@System
    Upgraded cmake-3.20.3-1.fc34.x86_64                                  @@System
    Upgraded cmake-data-3.20.3-1.fc34.noarch                             @@System
    Upgraded cmake-filesystem-3.20.3-1.fc34.x86_64                       @@System
    Upgraded cmake-rpm-macros-3.20.3-1.fc34.noarch                       @@System
    Upgraded dbus-broker-28-3.fc34.x86_64                                @@System
    Upgraded gst-editing-services-1.19.1-1.fc34.x86_64                   @@System
    Upgraded gstreamer1-1.19.1-1.fc34.x86_64                             @@System
    Upgraded gstreamer1-plugins-bad-free-1.19.1-2.fc34.x86_64            @@System
    Upgraded gstreamer1-plugins-base-1.19.1-1.fc34.x86_64                @@System
    Upgraded gstreamer1-plugins-good-1.19.1-1.fc34.x86_64                @@System
    Upgraded gstreamer1-plugins-good-gtk-1.19.1-1.fc34.x86_64            @@System
    Upgraded gstreamer1-plugins-good-qt-1.19.1-1.fc34.x86_64             @@System
    Upgraded gstreamer1-plugins-ugly-free-1.19.1-1.fc34.x86_64           @@System
    Upgraded libinput-1.18.0-1.fc34.x86_64                               @@System
    Upgraded libinput-devel-1.18.0-1.fc34.x86_64                         @@System
    Upgraded libxcrypt-4.4.20-2.fc34.i686                                @@System
    Upgraded libxcrypt-4.4.20-2.fc34.x86_64                              @@System
    Upgraded libxcrypt-compat-4.4.20-2.fc34.x86_64                       @@System
    Upgraded libxcrypt-devel-4.4.20-2.fc34.i686                          @@System
    Upgraded libxcrypt-devel-4.4.20-2.fc34.x86_64                        @@System
    Upgraded nano-5.6.1-1.fc34.x86_64                                    @@System
    Upgraded nano-default-editor-5.6.1-1.fc34.noarch                     @@System
    Upgraded pam-1.5.1-5.fc34.x86_64                                     @@System
    Upgraded pipewire-0.3.30-2.fc34.x86_64                               @@System
    Upgraded pipewire-alsa-0.3.30-2.fc34.x86_64                          @@System
    Upgraded pipewire-gstreamer-0.3.30-2.fc34.x86_64                     @@System
    Upgraded pipewire-jack-audio-connection-kit-0.3.30-2.fc34.x86_64     @@System
    Upgraded pipewire-libs-0.3.30-2.fc34.x86_64                          @@System
    Upgraded pipewire-pulseaudio-0.3.30-2.fc34.x86_64                    @@System
    Upgraded pipewire-utils-0.3.30-2.fc34.x86_64                         @@System
    Upgraded ripgrep-12.1.1-6.fc34.x86_64                                @@System
    Upgraded rpmautospec-rpm-macros-0.2.1-1.fc34.noarch                  @@System
    Upgraded tigervnc-1.11.0-11.fc34.x86_64                              @@System
    Upgraded tigervnc-icons-1.11.0-11.fc34.noarch                        @@System
    Upgraded tigervnc-license-1.11.0-11.fc34.noarch                      @@System
    Upgraded totem-1:3.38.0-6.fc34.x86_64                                @@System
    Upgraded totem-video-thumbnailer-1:3.38.0-6.fc34.x86_64              @@System
    Upgraded usermode-1.114-1.fc34.x86_64                                @@System
    Upgraded xorg-x11-server-Xwayland-21.1.1-2.fc34.x86_64               @@System

Comment 4 Tomáš Trnka 2021-06-29 08:16:13 UTC
The delay is due to a 90-second timeout when dracut-initqueue tries to call DBus immediately after finding the root device:

čen 29 09:45:20 electra dracut-initqueue[676]: Scanning devices dm-0  for LVM logical volumes electra/root
čen 29 09:45:20 electra dracut-initqueue[676]: electra/swap
čen 29 09:45:20 electra dracut-initqueue[697]: inactive          '/dev/electra/root' [50.00 GiB] inherit
čen 29 09:45:20 electra dracut-initqueue[697]: inactive          '/dev/electra/home' [340.00 GiB] inherit
čen 29 09:45:20 electra dracut-initqueue[697]: inactive          '/dev/electra/swap' [8.00 GiB] inherit
čen 29 09:45:20 electra systemd[1]: Found device /dev/mapper/electra-root.
čen 29 09:45:20 electra systemd[1]: Reached target Initrd Root Device.
čen 29 09:46:50 electra dracut-initqueue[699]: WARNING: D-Bus notification failed: Transport endpoint is not connected
čen 29 09:46:50 electra systemd[1]: Found device /dev/electra/swap.
čen 29 09:46:50 electra systemd[1]: Starting Resume from hibernation using device /dev/electra/swap...
čen 29 09:46:50 electra systemd-hibernate-resume[714]: Could not resume from '/dev/electra/swap' (253:2).
čen 29 09:46:50 electra kernel: PM: Image not found (code -22)
čen 29 09:46:50 electra systemd[1]: systemd-hibernate-resume: Deactivated successfully.
čen 29 09:46:50 electra systemd[1]: Finished Resume from hibernation using device /dev/electra/swap.
čen 29 09:46:50 electra systemd[1]: Reached target Local File Systems (Pre).
čen 29 09:46:50 electra systemd[1]: Reached target Local File Systems.
čen 29 09:46:50 electra systemd[1]: Reached target System Initialization.

At this point, dbus-broker isn't running yet, so the call can't succeed. This is due to the following recent commit to dbus-broker,
which explicitly orders it after sysinit.target (which, as you can see above, is reached long after the affected DBus call).

https://github.com/bus1/dbus-broker/commit/28af5ac996c94922fc49660e0efa955f57575187
In F34 as of https://bodhi.fedoraproject.org/updates/FEDORA-2021-221498e066

> From 28af5ac996c94922fc49660e0efa955f57575187 Mon Sep 17 00:00:00 2001
> From: David Rheinsberg <david.rheinsberg>
> Date: Mon, 21 Jun 2021 11:12:41 +0200
> Subject: [PATCH] units: explicitly order against dbus.socket and
>  sysinit.target
> 
> First of all, order all our units after dbus.socket. This is implicit
> in systemd for all socket activated units. However, dues to the aliasing
> to dbus.service, this is only true if our units are enabled. Hence, by
> being explicit, we make sure the dependency is correctly shown when
> debugging disabled services as well.
> 
> Secondly, make sure to order after sysinit.target, so basic system
> setup is done before we start. This is especially important to make sure
> the launcher can resolve user names and read the disk.
> 
> Signed-off-by: David Rheinsberg <david.rheinsberg>

As a workaround until this gets fixed properly, just edit /usr/lib/systemd/system/dbus-broker.service and remove "sysinit.target" from the "After=" line. (Or if you want it the kosher way, copy that file into /etc/systemd/system and customize it there. But then you'll have to remember to remove the file once this gets fixed in the package.) Afterwards, run "dracut -f" to rebuild your initramfs.

Comment 5 Henrik Nordström 2021-06-30 00:40:10 UTC
*** Bug 1976621 has been marked as a duplicate of this bug. ***

Comment 6 Henrik Nordström 2021-06-30 00:42:23 UTC
Can confirm that the workaround in comment #4 works (Bug #1976621)

Comment 7 Jonathan Jacobson 2021-06-30 04:54:27 UTC
*** Bug 1976989 has been marked as a duplicate of this bug. ***

Comment 8 Silvio Schneider 2021-06-30 16:01:08 UTC
I use
dnf update --exclude=dracut*
till this is fixed.

Comment 9 Justin M. Forbes 2021-06-30 18:02:23 UTC
*** Bug 1977919 has been marked as a duplicate of this bug. ***

Comment 10 Henrik Nordström 2021-06-30 18:47:14 UTC
Another workaround

(Ricardo Garcia in Bug #1976989) 
> In my case setting notify_dbus=0 in /etc/lvm/lvm.conf and running "dracut
> -f" as root did fix the issue.

Comment 11 Hans de Goede 2021-07-01 11:02:32 UTC
*** Bug 1978109 has been marked as a duplicate of this bug. ***

Comment 12 Hans de Goede 2021-07-01 11:04:22 UTC
*** Bug 1978218 has been marked as a duplicate of this bug. ***

Comment 13 Denis Marchand 2021-07-03 09:28:51 UTC
Hi,

I have two computers with F34 fully upgraded on : kernel-5.12.13-300.fc34.x86_64 and dracut-055-2.fc34.x86_64.

On one of them no problem :

sudo systemd-analyze blame | grep dracut-initqueue\.service
215ms dracut-initqueue.service

On the other one, the bug is there :

sudo systemd-analyze blame | grep dracut-initqueue\.service
1min 30.421s dracut-initqueue.service

I don't know why there is such a difference.

Regards,

Denez

Comment 14 Chris Murphy 2021-07-03 19:00:59 UTC
Who has the problem, who also has any crypto_LUKS devices attached at boot time? Could someone who is having this problem boot with rd.debug and attach a journal? 

journalctl -b -o short-monotonic --no-hostname > journal.log

Comment 15 Chris Carson 2021-07-03 20:40:23 UTC
I tried to reproduce the problem to provide the information Chris Murphy requested in Comment 14 - and the problem is gone.

Details:
I had the problem on two systems, one with and one without encrypted partitions mounted at boot time.  To work around I downgraded
dracut on both system; that took me from 55-2 to 53-4.  When I updated both back to 55-2 to reproduce the problem, the problem did
not recur on either system.


I explored the history a bit.  The dracut installed at the time of my f33->f34 upgrade was 53-5.  A subsequent upgrade took me to
54-12.  Following that I was at 55-2. Why going back to 53-4 and forward to 55-2 suppressed the problem, I can't say.

Comment 16 Chris Murphy 2021-07-03 21:31:09 UTC
Note that downgrading/upgrading dracut has a good chance of not fixing or recreating the problem on its own. You'll need to rebuild the initramfs *with the version of dracut* you're testing, because dracut issues (and fixes) get baked into the initramfs.

Comment 17 Henrik Nordström 2021-07-03 21:39:46 UTC
To trigger the problem the initrd need to be built with both a dracut-055-2, and with the latest dbus-broker update.

The cause to the problem is a change in dbus-broker, causing it not to start at the time dracut expects it to start.

The workaround in Comment #4 reverts the core cause to the problem, modifying the start condition for dbus-broker. But there is apparently some discussion on what is the proper fix as the change in dbus-broker is there for a reason.

Comment 18 Chris Murphy 2021-07-03 22:47:29 UTC
Thanks for the summary Henrik. Obviously I glossed over comment 4. oops!

Comment 19 Satish Balay 2021-07-04 00:43:29 UTC
Created attachment 1797740 [details]
journal.log wiht rd.debug

On this box - /home is the encrypted partition.

Comment 20 Harish Pillay 2021-07-04 02:11:59 UTC
Created attachment 1797742 [details]
output from journalctl as requested by comment 14

Comment 21 Silvio Schneider 2021-07-04 07:54:04 UTC
*** Bug 1976873 has been marked as a duplicate of this bug. ***

Comment 22 Julian Sikorski 2021-07-04 09:59:35 UTC
*** Bug 1979013 has been marked as a duplicate of this bug. ***

Comment 23 Henrik Nordström 2021-07-06 09:13:59 UTC
(In reply to Henrik Nordström from comment #17)
> To trigger the problem the initrd need to be built with both a dracut-055-2,
> and with the latest dbus-broker update.

Actually dacut-054 or later.

> The cause to the problem is a change in dbus-broker, causing it not to start
> at the time dracut expects it to start.
> 
> The workaround in Comment #4 reverts the core cause to the problem,
> modifying the start condition for dbus-broker. But there is apparently some
> discussion on what is the proper fix as the change in dbus-broker is there
> for a reason.

Forgot to add that the system need to be configured forhibernate/resume operation to trigger this. How it triggers this is still unclear to me.

But the latter is just a trigger, not the cause, I think.

Don't quite understand yet how the resume= command line argument triggers it, or why it also makes a difference for the boot screen setup.

See Bug #1976621 for more tests regarding dracut versions and resume= command line option.

Comment 24 Tomáš Trnka 2021-07-06 09:26:08 UTC
(In reply to Henrik Nordström from comment #23)
> (In reply to Henrik Nordström from comment #17)
> But the latter is just a trigger, not the cause, I think.
> 
> Don't quite understand yet how the resume= command line argument triggers
> it, or why it also makes a difference for the boot screen setup.

That's because systemd-hibernate-resume (in my case) is generated from
the kernel command line, and it is ordered Before=local-fs-pre.target, which in turn is in an ordering
chain of local-fs-pre.target → local-fs.target → sysinit.target → dbus-broker.service.

If you don't have a resume=, local-fs-pre won't do much after the point where the root dev appears
and local-fs.target will be reached as soon as the root device is found and mounted (which is when
the DBus call gets triggered) and dbus-broker will thus be online in time to catch that call.

Comment 25 Henrik Nordström 2021-07-06 11:14:31 UTC
(In reply to Tomáš Trnka from comment #24)

> If you don't have a resume=, local-fs-pre won't do much after the point
> where the root dev appears
> and local-fs.target will be reached as soon as the root device is found and
> mounted (which is when
> the DBus call gets triggered) and dbus-broker will thus be online in time to
> catch that call.

Still something missing in the explanation I think. Are you saying it's currently timing related where the dbus notification just happens to work without resume?

The systemd-hibernate-resume@.service slice places a dependency on the swap device before local-fs-pre.target, delaying local-fs-pre.target a bit.

And what exactly is it that generates the dbus event, and why? Logs indicate it's triggered via dracut-initqueue, not systemd. From what I can gather from the log messages it's from "lvm lvscan" in usr/sbin/lvm_scan (/usr/lib/dracut/modules.d/90lvm/lvm_scan.sh), which is apparently sourced by dracut-initqueue somehow. Apparently etc/udev/rules.d/64-lvm.rules (/usr/lib/dracut/modules.d/90lvm/64-lvm.rules)

And is there any drawbacks from the dbus-broker startup workaround in comment #4? The dbus-broker commit it reverts says "This is especially important to make sure the launcher can resolve user names and read the disk.". And how do this guarantee that the boot order is correct for this dbus notification to work? Or is it still just timing dependent?

Comment 26 Tomáš Trnka 2021-07-06 13:09:22 UTC
(In reply to Henrik Nordström from comment #25)
> (In reply to Tomáš Trnka from comment #24)
> Still something missing in the explanation I think. Are you saying it's
> currently timing related where the dbus notification just happens to work
> without resume?

The point is that without resume=, starting dbus-broker is independent from the
initqueue processing (which is on the DBus call), so it's pretty much guaranteed
that dbus-broker will start in time to catch the call (it has a 90-second timeout)
and unblock initqueue. With resume=, dbus-broker can't get started until the DBus
call finishes or times out.

> The systemd-hibernate-resume@.service slice places a dependency on the swap
> device before local-fs-pre.target, delaying local-fs-pre.target a bit.

Yes, but that "a bit" is the crucial bit here. The sequence of operations is as follows:

1) initqueue runs /sbin/lvm_scan
2) /sbin/lvm_scan runs "lvchange -ay" or "vgchange -ay" to activate selected LVs/VGs
   depending on rd.lvm.* arguments on the kernel cmdline
3) lvchange/vgchange activates root LV
4) lvchange/vgchange fires a notification of the activated LV via DBus
5) lvchange/vgchange proceeds to activate other LVs, such as the swap LV

As soon as 3) happens, systemd notices the root device (reaching local-fs-pre.target)
and proceeds to mount the root FS, reaching local-fs.target and subsequently sysinit.target,
which unblocks dbus-broker.service.

So if there's no resume=, local-fs-pre.target only depends on the root device and nothing else,
so all the other targets will be reached in parallel with initqueue sitting at the DBus call,
dbus-broker will eventually come up and unblock the whole thing.

If there's a resume= from a LV that would get activated in step 5, the whole thing deadlocks
because step 5 can't be reached before DBus is ready and DBus can't start before step 5 is
done (because sysinit.target then depends on the swap device through local-fs-pre.target).

> And what exactly is it that generates the dbus event, and why? Logs indicate
> it's triggered via dracut-initqueue, not systemd. From what I can gather
> from the log messages it's from "lvm lvscan" in usr/sbin/lvm_scan
> (/usr/lib/dracut/modules.d/90lvm/lvm_scan.sh), which is apparently sourced
> by dracut-initqueue somehow. Apparently etc/udev/rules.d/64-lvm.rules
> (/usr/lib/dracut/modules.d/90lvm/64-lvm.rules)

Exactly, it's a notification of a LV activation, fired by lvm if the "notify_dbus"
setting is enabled in lvm.conf. And lvm_scan is enqueued into the initqueue by 
etc/udev/rules.d/64-lvm.rules.

> And is there any drawbacks from the dbus-broker startup workaround in
> comment #4? The dbus-broker commit it reverts says "This is especially
> important to make sure the launcher can resolve user names and read the
> disk.". 

Well, that's just dbus-broker assuming it can't get much work done without a root
file system, which is not a valid assumption inside the initramfs. Any name resolution
mechanism requiring SSSD and/or the network is bound to fail in the initramfs anyway.

> And how do this guarantee that the boot order is correct for this
> dbus notification to work? Or is it still just timing dependent?

Assuming that your dbus-broker isn't configured to run under an user that requires
network name resolution, everything should work. All the files necessary for dbus-broker
to start should be bundled by dracut in the initramfs image, so not having any filesystems
should not be an issue. Eliminating the dependency on sysinit.target just breaks the dependency
cycle.

Comment 27 Marko Bevc 2021-07-08 09:57:56 UTC
I can confirm, got the same issue going from F33->F34 on T490s and https://bugzilla.redhat.com/show_bug.cgi?id=1976653#c4 solved it here! Thanks.

Comment 28 Demetris M 2021-07-08 19:58:22 UTC
The issue arose for me after a F33->F34 update but the workaround in comment 4 did not work for me. I did run `sudo dracut -f` afterwards. I will follow this bug for developments.

Comment 29 Henrik Nordström 2021-07-09 08:38:38 UTC
(In reply to Demetris M from comment #28)
> The issue arose for me after a F33->F34 update but the workaround in comment
> 4 did not work for me. I did run `sudo dracut -f` afterwards. I will follow
> this bug for developments.

Did you follow both steps? Edit /usr/lib/systemd/system/dbus-broker.service and THEN run dracut -f?

Comment 30 Demetris M 2021-07-09 08:55:18 UTC
(In reply to Henrik Nordström from comment #29)
> Did you follow both steps? Edit /usr/lib/systemd/system/dbus-broker.service
> and THEN run dracut -f?

Yes, with the caveat that I did copy the service file to /etc/systemd/system and made the changes there, like the comment suggested. I confirmed that the correct path was active with systemctl status. I will try to edit /usr/lib/systemd/system/dbus-broker.service directly and report any difference in the outcome.

Comment 31 Demetris M 2021-07-09 09:16:25 UTC
(In reply to Henrik Nordström from comment #29)
> (In reply to Demetris M from comment #28)
> > The issue arose for me after a F33->F34 update but the workaround in comment
> > 4 did not work for me. I did run `sudo dracut -f` afterwards. I will follow
> > this bug for developments.
> 
> Did you follow both steps? Edit /usr/lib/systemd/system/dbus-broker.service
> and THEN run dracut -f?

Update: There is no difference in the outcome, the workaround didn't work on my system.

To be clear, I made sure the service file was reloaded after editing it.

Comment 32 Henrik Nordström 2021-07-09 11:34:29 UTC
(In reply to Demetris M from comment #31)
> Update: There is no difference in the outcome, the workaround didn't work on
> my system.
> 
> To be clear, I made sure the service file was reloaded after editing it.

Which kernel were you running when running "dracut -f"? If nothing is specified then it only rebuilds the initramfs for the current running kernel, not other versions.

If not running the kernel where the boot is delayed then you must also specify the kernel version to dracut.

a) Let the computer sit until it boots. Then run "dracut -f".

or

b) Boot another kernel version with an initrd which do not delay the boot. Then run "dracut -f 5.12.13-300.fc34.x86_64" (or whatever kernel version is it you want to rebuild the initramfs for, "rpm -q kernel" for installed versions)

Comment 33 Demetris M 2021-07-10 11:53:24 UTC
(In reply to Henrik Nordström from comment #32)
> Which kernel were you running when running "dracut -f"? If nothing is
> specified then it only rebuilds the initramfs for the current running
> kernel, not other versions.
> 
> If not running the kernel where the boot is delayed then you must also
> specify the kernel version to dracut.
> 
> a) Let the computer sit until it boots. Then run "dracut -f".
> 
> or
> 
> b) Boot another kernel version with an initrd which do not delay the boot.
> Then run "dracut -f 5.12.13-300.fc34.x86_64" (or whatever kernel version is
> it you want to rebuild the initramfs for, "rpm -q kernel" for installed
> versions)


Hi, thank you for the instructions. I can confirm that the workaround has now worked after a fresh attempt, although I am not sure exactly what step I missed before (I was booting the problematic -latest- kernel version, and running dracut -f without a kernel specified, and then rebooting the same latest version).

Comment 34 Ilya Maximets 2021-07-12 11:08:15 UTC
*** Bug 1981292 has been marked as a duplicate of this bug. ***

Comment 35 Ilya Maximets 2021-07-12 11:10:50 UTC
Suggesting to update the title of this BZ, otherwise there will be more and more
duplicates.  Search in bugzilla is horrible especially if title is not very
informative.

Comment 36 Leonard Ehrenfried 2021-07-12 11:36:58 UTC
So I can see that there this was caused by the following issues/commits

https://github.com/bus1/dbus-broker/issues/268
https://github.com/bus1/dbus-broker/commit/28af5ac996c94922fc49660e0efa955f57575187

They contain a little bit of discussion but seeing that Lennart Poettering has openend the ticket it seems unlikely that it will be rolled back.

Is there another thread that discusses solutions? The Github commit mentions contributing a separate unit file for initrd, for example.

Comment 37 Habig, Alec 2021-07-12 13:10:53 UTC
Rolling that back seems the obvious solution given the severity of the regression it introduced vs the subtleties of the improvements it made.  For several weeks now, anyone running (or installing) Fedora on a laptop can't boot unless they're glacially patient.  The population of users and potential users who can find this bugzilla and implement the workaround is surely only a fraction of those who've added themselves to the CC list.

If the upstream dbus people say "not our problem", then reverting it in the fedora spec file seems straightforward enough till a long-term compromise is reached.

Comment 38 Marko Bevc 2021-07-12 14:26:13 UTC
Agree ^^

Comment 39 Dominik 'Rathann' Mierzejewski 2021-07-12 15:45:51 UTC
As a counter data point, I did add myself to Cc of this bug out of curiosity,
but I'm not seeing this 1.5 minute boot delay on any of my machines (and they
had a couple of kernel updates since the fix was released).

The fix to the original bug does work for me and makes one of my VMs boot
properly instead of booting without network connectivity.

So, I'd very much like to see the fix not being reverted.

Comment 40 Chris Murphy 2021-07-12 16:29:36 UTC
(In reply to Dominik 'Rathann' Mierzejewski from comment #39)
> As a counter data point, I did add myself to Cc of this bug out of curiosity,
> but I'm not seeing this 1.5 minute boot delay on any of my machines

Same. I never experienced this bug. Currently I have:

dracut-055-3.fc34.x86_64
dbus-broker-29-1.fc34.x86_64
kernel-5.13.1-300.fc34.x86_64

Comment 41 Habig, Alec 2021-07-12 16:40:41 UTC
It appears that having suspend/resume enabled in one's booting kernel is required to trigger the problem.  So, if you're running on a laptop: it's a problem; if not, no worries.  Comments 24 and following have a discussion of how/why this might matter.  If people without the problem also happen to have resume set, then maybe there's some other way out of the problem?

Comment 42 remyabel 2021-07-12 16:47:44 UTC
> So, I'd very much like to see the fix not being reverted.

What purpose does saying you are not experiencing the issue without providing additional info provide? You're just adding noise to the issue. I and many others do experience this issue and the dbus broker workaround works. I subscribed to the bug to see when a fix will be provided. If the problem doesn't exist for you great, not sure why preventing a fix for other people is in any way productive.

Comment 43 Demetris M 2021-07-12 17:51:41 UTC
For what it's worth, as a laptop user I also found this bug intrusive at the highest degree. Achieving reliable suspend and hibernation on Linux eas a great achievement and giving that up for some nearly invisible benefit is incomprehensible.

Comment 44 remyabel 2021-07-12 18:03:24 UTC
I don't think the issue is unique to laptops. I'm on a desktop and don't use suspend/hibernate. I experience the issue in the OP whenever I reboot my computer.

Comment 45 Chris Murphy 2021-07-12 18:15:56 UTC
If resume=UUID=<swapUUID> boot parameter is needed to trigger the bug, that might explain the variable results. Fedora 33 and newer do not create a swap partition by default and thus this boot parameter doesn't exist. It would only be present on systems upgraded from Fedora 32 and older; or custom installations with a swap partition added manually.

Comment 46 Göran Uddeborg 2021-07-12 20:16:26 UTC
I tried that on my Lenovo laptop. Normally it has a resume=/dev/mapper/… option set. When I entered the boot menu and edited out that option, it no longer hangs for a minute and a half during the boot.

Comment 47 Dominik 'Rathann' Mierzejewski 2021-07-12 20:21:09 UTC
(In reply to remyabel from comment #42)
> > So, I'd very much like to see the fix not being reverted.
> 
> What purpose does saying you are not experiencing the issue without
> providing additional info provide? You're just adding noise to the issue. I
> and many others do experience this issue and the dbus broker workaround
> works. I subscribed to the bug to see when a fix will be provided. If the
> problem doesn't exist for you great, not sure why preventing a fix for other
> people is in any way productive.

Well, because reverting the dbus-broker dependencies fix as proposed in
Comment 37 would break my VM? Without the fix, I need to manually log in to
the console and restart systemd-networkd to get network connectivity.

Comment 48 wurstsemmel 2021-07-13 17:51:05 UTC
This bug slows down boot on my laptop since some time. I found this bug report via a post on Ask Fedora (https://ask.fedoraproject.org/t/slow-boot-initrd-dracut-initqueue-service/10278/4).

Some details below:

Filesystem: /, /home and swap within LVM with LUKS. Swap partition with 26 GB, system allows hibernation to disk.
Laptop: Dell XPS 13 with 16 GB RAM
OS: Fedora 34, upgrading since Fedora ~28

$ systemd-analyze blame
1min 45.652s dracut-initqueue.service

$ cat /proc/cmdline
BOOT_IMAGE=(hd0,gpt4)/vmlinuz-5.12.14-300.fc34.x86_64 root=/dev/mapper/fedora_localhost--live-root ro resume=/dev/mapper/fedora_localhost--live-swap rd.lvm.lv=fedora_localhost-live/root rd.luks.uuid=luks-0eb6e5b3-704e-4df7-a28b-c37ae7264274 rd.lvm.lv=fedora_localhost-live/swap rhgb quiet

$ rpm -q dracut
dracut-055-3.fc34.x86_64

$ uname -r
5.12.14-300.fc34.x86_64

$ rpm -q dbus-broker
dbus-broker-29-1.fc34.x86_64

Comment 49 Henrik Nordström 2021-07-14 11:29:47 UTC
(In reply to wurstsemmel from comment #48)
> This bug slows down boot on my laptop since some time. I found this bug
> report via a post on Ask Fedora
> 
> $ cat /proc/cmdline
> resume=/dev/mapper/fedora_localhost--live-swap

Any of the workarounds mentioned related to this bug should help on your system


Workaround from comment #4: Revert the dbus-broker change, allowing it to start early as it did before the last update:

0. Let the system sit until it boots.

1. Edit /usr/lib/systemd/system/dbus-broker.service and remove "sysinit.target" from the "After=" line. 

2. Run "dracut -f" to rebuild the initramfs.

Note: if you boot another kernel version then you need to specify the kernel version for which you want to rebuild the initrd to dracut. By default it only rebuilds the initrd for the current booted kernel.



Or disable hibernate/resume from disk support. Most people do not use this and having the option enabled triggers the bug even if you do not use it. Does not affect normal suspend to ram.

grubby --remove-args=resume --update-kernel=ALL



Or disable dbus notification in lvm.

0. Let the system sit until it boots.

1. Edit /etc/lvm/lvm.conf and change notify_dbus to 0 (the normal setting is 1).

2. Run "dracut -f" to rebuild the initramfs.

Note: if you boot another kernel version then you need to specify the kernel version for which you want to rebuild the initrd to dracut. By default it only rebuilds the initrd for the current booted kernel.


then reboot to verify

Comment 50 Henrik Nordström 2021-07-14 11:31:27 UTC
(In reply to Dominik 'Rathann' Mierzejewski from comment #47)

> Well, because reverting the dbus-broker dependencies fix as proposed in
> Comment 37 would break my VM? Without the fix, I need to manually log in to
> the console and restart systemd-networkd to get network connectivity.

Is there anything special with the network setup in your VM? Why does changing the startup priority of dbus-broker break your VM?

Comment 51 Dominik 'Rathann' Mierzejewski 2021-07-14 11:47:46 UTC
(In reply to Henrik Nordström from comment #50)
> (In reply to Dominik 'Rathann' Mierzejewski from comment #47)
> 
> > Well, because reverting the dbus-broker dependencies fix as proposed in
> > Comment 37 would break my VM? Without the fix, I need to manually log in to
> > the console and restart systemd-networkd to get network connectivity.
> 
> Is there anything special with the network setup in your VM? Why does
> changing the startup priority of dbus-broker break your VM?

I'm using systemd-networkd instead of NetworkManager to minimize the OS footprint.
It has 2 static IPs, so there's not need for all the NM features, anyway.
systemd-networkd fails to start if dbus-broker is unavailable.
See bug 1948042 , https://github.com/systemd/systemd/issues/19212 and
https://github.com/bus1/dbus-broker/issues/268 for context.

Comment 52 Alex Silva 2021-07-15 15:32:56 UTC
I am also having this issue on my working laptop.  Lenovo T590.
The workarounds listed in this thread apply only to current booted kernel "By default it only rebuilds the initrd for the current booted kernel".
I think I prefer to wait to the final solution, than have to be configure a workaround every time a new kernel is released.   Any ideas when the solution will be provided?

I have Fedora 34 installed from scratch on my Lenovo T590 and personal Toshiba laptop.
I don't have the issue on the Toshiba laptop.

The difference I noticed is : on my working laptop I am using LUKS encryption.  
All worked fine until kernel: 5.12.12-300.fc34.x86_64
After the kernel update to kernel-5.12.13-300.fc34.x86_64, the issue manifested for the first time.
Since then, the problem is there.  I tried kernel-5.12.14-300.fc34.x86_64 and currently running kernel-5.12.15-300.fc34.x86_64.

Same kernels running on the Toshiba laptop, which doesn't use LUKS, no issues with booting time.  

T590 info:

cat /proc/cmdline
BOOT_IMAGE=(hd0,gpt2)/vmlinuz-5.12.15-300.fc34.x86_64 root=/dev/mapper/fedora_localhost--live-root ro resume=/dev/mapper/fedora_localhost--live-swap rd.lvm.lv=fedora_localhost-live/root rd.luks.uuid=luks-818c257a-2dd9-4736-9833-886d3fa4f5ae rd.lvm.lv=fedora_localhost-live/swap rhgb quiet

systemd-analyze blame | head -1
1min 42.488s dracut-initqueue.service

dracut --version
dracut 055-3.fc34

dbus-broker --version
dbus-broker 29

Comment 53 Tomáš Trnka 2021-07-15 15:42:19 UTC
(In reply to Alex Silva from comment #52)
> I think I prefer to wait to the final solution, than have to be configure a
> workaround every time a new kernel is released.

This is not the case. Any kernels installed (or reinstalled) after you edit the service file will pick up the workaround automatically.

The issue does not have anything to do with the version of the kernel. It all depends on when the kernel was installed (initramfs was built). Any initramfs built after the dbus-broker update that broke this will suffer from the issue, any initramfs built after applying the workaround will not.

You can also manually rebuild the initramfs images for other kernel versions than the current booted one by passing the path and kernel version as arguments to "dracut -f".

Comment 54 Alex Silva 2021-07-15 18:32:47 UTC
Hi Tomas
(In reply to Tomáš Trnka from comment #53)
> The issue does not have anything to do with the version of the kernel. It
> all depends on when the kernel was installed (initramfs was built). Any
> initramfs built after the dbus-broker update that broke this will suffer
> from the issue, any initramfs built after applying the workaround will not.

I am just checking this on my Toshiba laptop, which doesn't have the issue.

cat /proc/cmdline
BOOT_IMAGE=(hd1,gpt2)/vmlinuz-5.12.15-300.fc34.x86_64 root=UUID=234fb6ee-8a6a-4e4e-8812-7c0bfabd8ef5 ro rootflags=subvol=root rhgb quiet

rpm -q dbus-broker
dbus-broker-29-1.fc34.x86_64

rpm -q dracut
dracut-055-3.fc34.x86_64


systemd-analyze blame 
20.622s firewalld.service
20.296s upower.service
20.061s sssd.service
10.391s NetworkManager-wait-online.service
 9.286s systemd-udev-settle.service
 8.691s systemd-journal-flush.service
 8.572s udisks2.service
 8.203s lvm2-monitor.service
 7.443s ModemManager.service
 6.634s plymouth-quit-wait.service
 6.036s systemd-udevd.service
 3.888s initrd-switch-root.service
 1.572s dracut-initqueue.service

Following your response "Any initramfs built after the dbus-broker update that broke this will suffer from the issue".
Why I am not seeing this on this laptop?  Does it occurs only with systems with LUKS encryption?  As far as I can see it has the updated dbus-broker.

If you know the dbus-broker update is root cause of the problem, why the the update is not reverted?
Is a solution going to be provided to this, or only the 2 workarounds listed in the thread?

Thanks in advance

Comment 55 Ilya Maximets 2021-07-15 18:42:08 UTC
(In reply to Alex Silva from comment #54)
> I am just checking this on my Toshiba laptop, which doesn't have the issue.
> 
> cat /proc/cmdline
> BOOT_IMAGE=(hd1,gpt2)/vmlinuz-5.12.15-300.fc34.x86_64
> root=UUID=234fb6ee-8a6a-4e4e-8812-7c0bfabd8ef5 ro rootflags=subvol=root rhgb
> quiet

If you'll read comments in this BZ, you'll see that the issue is triggered only
if you have 'resume=' in cmdline.  You have it in T590, but not on Toshiba one.

Comment 56 Alex Silva 2021-07-16 06:50:55 UTC
(In reply to Ilya Maximets from comment #55)
> If you'll read comments in this BZ, you'll see that the issue is triggered
> only
> if you have 'resume=' in cmdline.  You have it in T590, but not on Toshiba
> one.

Indeed, but my response was based on Tomas' reply: "Any initramfs built after the dbus-broker update that broke this will suffer from the issue, any initramfs built after applying the workaround will not."

Also in the comments you refer to, I can find this: 
"Well, that's just dbus-broker assuming it can't get much work done without a root file system, which is not a valid assumption inside the initramfs."

I think the question which needs to be answered is:  When is this bug going to be fixed?

It seems Engineering knows the root cause.  2 workarounds have been listed in the thread.  
Will a final solution/fix will be available or people should be just counting on the workaround only?  Maybe a dbus-broker which can make valid assumptions?
It is about 3 weeks already since this has been reported.

Comment 57 Henrik Nordström 2021-07-18 22:46:32 UTC
(In reply to Dominik 'Rathann' Mierzejewski from comment #51)

> I'm using systemd-networkd instead of NetworkManager to minimize the OS
> footprint.
> It has 2 static IPs, so there's not need for all the NM features, anyway.
> systemd-networkd fails to start if dbus-broker is unavailable.
> See bug 1948042 , https://github.com/systemd/systemd/issues/19212 and
> https://github.com/bus1/dbus-broker/issues/268 for context.

Why is dbus-broker unavailable for you withg the start order workaround? The workaround only starts dbus-broker earlier, it does not inhibit it.

Comment 58 Stefano Corti 2021-07-19 11:05:40 UTC
Same problem here, and the workaround in comment #4 is working.

I'd say this bug should be assigned to the dbus-broker component, and not dracut. But I don't know how to change that.

Comment 59 Leonard Ehrenfried 2021-07-19 11:34:37 UTC
The upstream maintainer has indicated that he would accept a separate unit file just for initrd purposes: https://github.com/bus1/dbus-broker/commit/28af5ac996c94922fc49660e0efa955f57575187#commitcomment-52981075

Would this be the correct solution?

Comment 60 Chris Murphy 2021-07-19 18:34:29 UTC
This looks like the current explanation of what's going on? But no resolution yet?
https://github.com/bus1/dbus-broker/commit/28af5ac996c94922fc49660e0efa955f57575187#commitcomment-53378469

It does look to me like the problem started with dbus-broker-29-1.fc34 and has happened in such a way that isn't easy to just back out of Fedora 34. But also (hindsight being 20/20) it was not adequately tested. It was simultaneously pushed to Rawhide and F34. And didn't get extra time for testing in Bodhi. But yeah it seems like this needs a fix and backport for Fedora. I'll switch it to dbus-broker and see if David can give an opinion what still needs to be fixed or reassign it as appropriate because it's not going anywhere while assigned to dracut.

Comment 61 Henrik Nordström 2021-07-19 23:44:06 UTC
(In reply to Chris Murphy from comment #60)
> This looks like the current explanation of what's going on? But no
> resolution yet?
> https://github.com/bus1/dbus-broker/commit/
> 28af5ac996c94922fc49660e0efa955f57575187#commitcomment-53378469

Thats my summary of that I have understood so far in this (and related) bugzilla discussions. But not entirely sure on if the dbus-broker dependency is a real dependency for systemd to notice the lvm device state, or just holding back the lvm scan but then I don't understand why it works without resume, It is a bit concusing with initqueue, systemd and dbus interactions all mixed, and not less cunfusing buy the other seemingly unrelated things that change only because the resume service is there with it's dependencies. There very likely is more than one issue here, for one thing I do not see how/why the bootscreen changes apparence only because the boot gets delayed if everything worked the way they should.

Just not sure who to blame for the core of the issue. Feels to me like the dbus-broker change just surfaced the can of bugs and is not the core problem.

The change was made because dbus-broker do not want to run as early. Depends on system stuff not yet in place. This is a valid claim I think.

Having systemd swap-device.device unit state depend on dbus-broker seems odd. This kind of implies that dbus have to be operational before the root/swap/and whatever other early probed devices. 

Having lvm scan send dbus notifications before dbus is supposed to be operational also seems odd. Maybe that is the actual problem? Disabling lvm dbus notifications is mentioned as a workaround.



The resume service have these systemd dependencies:

BindsTo=%i.device
Wants=local-fs-pre.target
After=%i.device
Before=local-fs-pre.target

Where %i is the resume device (normally the swap) and is listed as an rd.lvm.lv, just as the root device, to have it enabled by dracut.

But then, what is local-fs.target really when using dracut? Or even the sysinit.target as now required by dbus-broker? Both seem to have a bit different meaning in dracut.bootup than in the standalone bootup.

Sorry, feels a bit like the rabbit hole only goes deeper.

Comment 62 Richard Guest 2021-07-22 10:23:48 UTC
This might not be terribly helpful, but it at least adds another data point... so FWIW I have been suffering from this issue recently, on my Latitude 5490.

And unfortunately (although probably unrelated) suspend/resume was causing me some grief, often failing and requiring a hard reboot. With secureboot, LVM and LUKS, a reboot is slow enough to start with - throw in an additional 90 second delay and my patience has been seriously tested!

Anyway, I read the commentary above and decided the simplest and safest thing to do in my case would be to downgrade dracut and force a rebuild of my current initramfs. So that's what I did.

dnf downgrade dracut-053-4.fc34.x86_64
dracut -f

And it's done the job. Back to a sub-30 second boot time.
And coincidentally, suspend-resume seems to be working far more reliably too!


I will continue to watch avidly for a long term fix.

Comment 63 Yogendra Jog 2021-07-22 13:36:29 UTC
Same problem here, Lenovo X1 Carbon, workaround in comment #4 applies perfectly.

Comment 64 Alex. H. F. 2021-07-23 13:07:28 UTC
Same problem here, immediately after upgrade to Fedora 34 (XFCE).

Running on VirtualBox VM with same configuration as priorly used with FC33 (without boot up delay).

Comment 65 Mirko Predosin 2021-07-23 20:31:43 UTC
(In reply to Richard Guest from comment #62)

> 
> Anyway, I read the commentary above and decided the simplest and safest
> thing to do in my case would be to downgrade dracut and force a rebuild of
> my current initramfs. So that's what I did.
> 
> dnf downgrade dracut-053-4.fc34.x86_64
> dracut -f
> 

I can confirm that this fix works as well.  Thanks!

Comment 66 Justin M. Forbes 2021-07-24 15:53:56 UTC
*** Bug 1981009 has been marked as a duplicate of this bug. ***

Comment 67 Ivan Mironov 2021-07-24 19:49:20 UTC
While this bug is not critical, it is very annoying.

When this happened for the first time, I thought that new kernel version is broken and whole system just hangs during boot. After waiting ~10 seconds I force-rebooted my system and chose older kernel in grub. I realized that everything actually works as normal after the 1.5 minutes timeout only because once I forgot to choose older kernel during boot and got distracted by a phone call.

Comment 68 charles profitt 2021-07-26 17:41:55 UTC
#4 resolves the issue on my system as well. My system is a Lenovo ThinkPad X1 Carbon 6th generation.

Comment 69 wurstsemmel 2021-07-27 20:42:09 UTC
(In reply to Henrik Nordström from comment #49)
> Any of the workarounds mentioned related to this bug should help on your
> system

Thank you for your detailed description of the available workarounds! I used the workaround from comment #4, which works nicely.

Comment 70 Gianni Salinetti 2021-07-29 06:49:11 UTC
Same issue here after upgrading from Fedora 32 to Fedora 34.
The workaround suggested on comment #4 worked seamlessly.

Comment 71 Fedora Update System 2021-07-29 11:09:02 UTC
FEDORA-2021-7b6767f8af has been submitted as an update to Fedora 34. https://bodhi.fedoraproject.org/updates/FEDORA-2021-7b6767f8af

Comment 72 Ben Cotton 2021-07-29 12:56:47 UTC
*** Bug 1985205 has been marked as a duplicate of this bug. ***

Comment 73 Paul Smith 2021-07-29 14:01:03 UTC
(In reply to Fedora Update System from comment #71)
> FEDORA-2021-7b6767f8af has been submitted as an update to Fedora 34.
> https://bodhi.fedoraproject.org/updates/FEDORA-2021-7b6767f8af

That does not fix the issue:

---------------------------------------
$ systemd-analyze blame
1min 31.106s dracut-initqueue.service
      6.914s NetworkManager-wait-online.service
      3.535s akmods.service
      3.283s firewalld.service

...

# rpm -q dbus-broker
dbus-broker-29-2.fc34.x86_64
# 
---------------------------------------

Comment 74 Hans de Goede 2021-07-29 14:04:59 UTC
(In reply to Paul Smith from comment #73)
> (In reply to Fedora Update System from comment #71)
> > FEDORA-2021-7b6767f8af has been submitted as an update to Fedora 34.
> > https://bodhi.fedoraproject.org/updates/FEDORA-2021-7b6767f8af
> 
> That does not fix the issue:

Did you regenerate the initrd after installing the update?

To regenerate the initrd for the kernel which you are currently running run: "sudo dracut -f"

Comment 75 Paul Smith 2021-07-29 14:10:28 UTC
(In reply to Hans de Goede from comment #74)
> (In reply to Paul Smith from comment #73)
> > (In reply to Fedora Update System from comment #71)
> > > FEDORA-2021-7b6767f8af has been submitted as an update to Fedora 34.
> > > https://bodhi.fedoraproject.org/updates/FEDORA-2021-7b6767f8af
> > 
> > That does not fix the issue:
> 
> Did you regenerate the initrd after installing the update?
> 
> To regenerate the initrd for the kernel which you are currently running run:
> "sudo dracut -f"

Thanks, Hans! After having regenerated the initrd with "sudo dracut -f", the problem was fixed.

Comment 76 Drew Dowling 2021-07-29 17:21:14 UTC
I got this fixed using the new package mentioned in #71. Here are the steps I used. If I did this wrong please let me know as I'm not very experienced with kernel stuff

Manually downloaded the version I needed from https://koji.fedoraproject.org/koji/buildinfo?buildID=1811133

ran 

$ sudo dnf install /home/me/Downloads/dbus-broker-29-2.fc34.x86_64.rpm
$ sudo dracut -f
$ sudo shutdown -r now

The system restarted without the 90 second delay.

Is there anything else I missed?

Comment 77 Fedora Update System 2021-07-30 01:01:38 UTC
FEDORA-2021-7b6767f8af has been pushed to the Fedora 34 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 78 Eric Lavarde 2021-07-30 06:16:37 UTC
FWIW, I used `sudo dnf upgrade --advisory=FEDORA-2021-7b6767f8af` and, because I had a pending kernel update, I had to make sure it's the initrd of the kernel running _after_ reboot which is "patched" with `sudo dracut --kver 5.13.5-200.fc34.x86_64 --force`.

Comment 79 Richard Guest 2021-07-30 09:57:08 UTC
Yup. Tested here. Looks good to me, too!

Comment 80 Lorenzo Prosseda 2021-07-30 12:06:51 UTC
Hi, I can confirm that after upgrading my Fedora 34 install using --advisory=FEDORA-2021-7b6767f8af argument, I had the delayed boot issue resolved.

Comment 81 alex.j.kerzner 2021-07-30 23:57:28 UTC
Confirmed fixed for me as well, thanks.

Comment 82 g.collotta02 2021-08-16 16:14:44 UTC
This does't fix it for me. I applied the updates, and did "sudo dracut -f"
Is there more troubleshoting I can do?

"$ systemd-analyze
Startup finished in 1.183s (kernel) + 1min 35.818s (initrd) + 24.587s (userspace) = 2min 1.589s"

"$ systemd-analyze blame
1min 34.272s dracut-initqueue.service"

Comment 83 Henrik Nordström 2021-08-16 20:38:22 UTC
(In reply to g.collotta02 from comment #82)
> This does't fix it for me. I applied the updates, and did "sudo dracut -f"
> Is there more troubleshoting I can do?

Did you boot the troublesome kernel entry before running "dracut -f"? If you boot another kernel then you must give the desired kernel version to dracut in order to regenerate the proper initramfs boot file.

Comment 84 g.collotta02 2021-08-17 08:08:22 UTC
(In reply to Henrik Nordström from comment #83)
> 
> Did you boot the troublesome kernel entry before running "dracut -f"? If you
> boot another kernel then you must give the desired kernel version to dracut
> in order to regenerate the proper initramfs boot file.

I've only been booting the latest kernel (5.13.9-200.fc34.x86_64), tried re-running dracut -f also specifying the kernel, but nothing seems to change.
I've followed this thread, is there anything else I should check to be sure everything is set as it should?

Comment 85 Lennert Buytenhek 2021-08-17 13:46:04 UTC
*** Bug 1976641 has been marked as a duplicate of this bug. ***

Comment 86 Viktor 2021-09-05 19:52:58 UTC
This bug reappeared as I installed and started using kernel 5.13.14-200. I experienced this issue previously, but after the fix was pushed everything was fine for a while (readded sysinit.target to dbus-broker.service). Now when I boot the latest kernel once again dbus-broker takes 90 seconds to start.

Reapplying the fix in @comment 4 works. Let me know what info you need to keep triaging.

Comment 87 Tomáš Trnka 2021-09-05 20:59:18 UTC
(In reply to Viktor from comment #86)
> This bug reappeared as I installed and started using kernel 5.13.14-200. I
> experienced this issue previously, but after the fix was pushed everything
> was fine for a while (readded sysinit.target to dbus-broker.service).

If by "the fix" you mean the update to dbus-broker-29-2.fc34.x86_64, then it
does exactly the same as comment 4 above. There should thus be nothing to reapply,
sysinit.target should not be on the Before= line of the service file as shipped
in the dbus-broker RPM.

If you then added that dependency by hand, you have just undone the workaround
and manually restored the broken state.

Comment 88 Tomáš Trnka 2021-09-05 21:01:13 UTC
(In reply to Tomáš Trnka from comment #87)
> sysinit.target should not be on the Before= line of the service file as

Oops, sorry, of course I mean the After= line.

Comment 89 Viktor 2021-09-06 19:22:17 UTC
(In reply to Tomáš Trnka from comment #87)
> (In reply to Viktor from comment #86)
> > This bug reappeared as I installed and started using kernel 5.13.14-200. I
> > experienced this issue previously, but after the fix was pushed everything
> > was fine for a while (readded sysinit.target to dbus-broker.service).
> 
> If by "the fix" you mean the update to dbus-broker-29-2.fc34.x86_64, then it
> does exactly the same as comment 4 above. There should thus be nothing to
> reapply,
> sysinit.target should not be on the Before= line of the service file as
> shipped
> in the dbus-broker RPM.
> 
> If you then added that dependency by hand, you have just undone the
> workaround
> and manually restored the broken state.
That's strange, because I definitely had sysinit.target in the After= line for a few kernel versions and everything worked as expected. Reinstalling dbus-broker did remove sysinit.target as you mentioned. Nevermind; sorry for taking up your time!

Comment 90 dimonych 2022-06-17 03:31:49 UTC
Same problem with dracut-initqueue.service in fedora 36 fixes here not works

Comment 91 Keith R 2022-07-27 05:54:44 UTC
(In reply to dimonych from comment #90)
> Same problem with dracut-initqueue.service in fedora 36 fixes here not works

Me, as well. 
I just pulled my hair out wasting many hours trying every solution listed here, as well as, reinstalling the OS several times. I'm gonna give up on Fedora completely. I reboot frequently to switch OSes and this bug is a dealbreaker. Thanks to everyone who contributed already, but any other fix ideas would be greatly appreciated.