Description of problem: Since the 5th of July, the boot process takes a long and stays for few minutes stuck after the "Reached target Initrd Root Device" step. This wasn't the case before on the same machine. Version-Release number of selected component (if applicable): dracut-055-3.fc34.x86_64 dracut-config-rescue-055-3.fc34.x86_64 dracut-network-055-3.fc34.x86_64 dracut-squash-055-3.fc34.x86_64 How reproducible: Always (since the 5th of July apparently) Steps to Reproduce: 1. reboot 2. and check the boot process Actual results: The boot process gets stuck for a few minutes (roughly 2min, but it's fluctuating) Expected results: The boot process is fluent... Additional info: journalctl seems to show the issue (notice the jump in time): ``` Jul 23 08:25:29 elavarde-t590 systemd[1]: Found device /dev/mapper/FedoCSB-Root. Jul 23 08:25:29 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 23 08:26:59 elavarde-t590 dracut-initqueue[840]: WARNING: D-Bus notification failed: Transport endpoint is not connected ``` Similar result with systemd-analyze: ``` # systemd-analyze blame 1min 41.009s dracut-initqueue.service 11.458s fwupd.service 10.022s systemd-cryptsetup@luks\x2d687b21c8\x2d0b3d\x2d4d7b\x2dae31\x2d0ad> 8.355s NetworkManager-wait-online.service 4.101s plymouth-quit-wait.service 1.031s firewalld.service 1.012s initrd-switch-root.service [... all other services below 1s ...] ``` ``` # journalctl | grep -e "Reached target Initrd Root Device" -e "WARNING: D-Bus notification failed:" Dec 02 08:02:37 elavarde-t590 systemd[1]: Reached target Initrd Root Device. [...] Jul 02 07:43:48 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 05 08:34:17 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 05 08:35:47 elavarde-t590 dracut-initqueue[2416]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 06 08:42:01 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 06 08:43:31 elavarde-t590 dracut-initqueue[814]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 07 08:10:12 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 07 08:11:42 elavarde-t590 dracut-initqueue[10787]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 08 09:04:24 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 08 09:05:54 elavarde-t590 dracut-initqueue[17399]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 12 09:07:20 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 12 09:08:50 elavarde-t590 dracut-initqueue[920]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 13 08:45:11 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 13 08:46:41 elavarde-t590 dracut-initqueue[898]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 14 11:02:57 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 14 11:04:27 elavarde-t590 dracut-initqueue[1392]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 19 09:35:00 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 19 09:36:30 elavarde-t590 dracut-initqueue[3293]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 20 09:42:41 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 20 09:44:11 elavarde-t590 dracut-initqueue[811]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 21 08:04:11 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 21 08:05:41 elavarde-t590 dracut-initqueue[2792]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 22 07:46:30 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 22 07:48:00 elavarde-t590 dracut-initqueue[1015]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 23 08:25:29 elavarde-t590 systemd[1]: Reached target Initrd Root Device. Jul 23 08:26:59 elavarde-t590 dracut-initqueue[840]: WARNING: D-Bus notification failed: Transport endpoint is not connected ``` If I look what I installed before the 5th of July (2nd of July): ``` Transaction ID : 342 Begin time : Fri 02 Jul 2021 07:55:01 Begin rpmdb : 2587:72f341e19202a58616a1415b9012e656b6a0764a End time : Fri 02 Jul 2021 07:57:44 (163 seconds) End rpmdb : 2587:d935c78df76ead8d56014c27ba2343d04a2cb752 User : Eric Lavarde <elavarde> Return-Code : Success Releasever : 34 Command Line : upgrade Comment : Packages Altered: Install kernel-5.12.13-300.fc34.x86_64 @updates Install kernel-core-5.12.13-300.fc34.x86_64 @updates Install kernel-debug-devel-5.12.13-300.fc34.x86_64 @updates Install kernel-devel-5.12.13-300.fc34.x86_64 @updates Install kernel-modules-5.12.13-300.fc34.x86_64 @updates Upgrade ansible-2.9.23-1.fc34.noarch @updates Upgraded ansible-2.9.21-1.fc34.noarch @@System Upgrade ansible-test-2.9.23-1.fc34.noarch @updates Upgraded ansible-test-2.9.21-1.fc34.noarch @@System Upgrade bind-libs-32:9.16.18-1.fc34.x86_64 @updates Upgraded bind-libs-32:9.16.16-1.fc34.x86_64 @@System Upgrade bind-license-32:9.16.18-1.fc34.noarch @updates Upgraded bind-license-32:9.16.16-1.fc34.noarch @@System Upgrade bind-utils-32:9.16.18-1.fc34.x86_64 @updates Upgraded bind-utils-32:9.16.16-1.fc34.x86_64 @@System Upgrade cups-filters-1.28.9-1.fc34.x86_64 @updates Upgraded cups-filters-1.28.8-1.fc34.x86_64 @@System Upgrade cups-filters-libs-1.28.9-1.fc34.x86_64 @updates Upgraded cups-filters-libs-1.28.8-1.fc34.x86_64 @@System Upgrade firewalld-0.9.4-1.fc34.noarch @updates Upgraded firewalld-0.9.3-3.fc34.noarch @@System Upgrade firewalld-filesystem-0.9.4-1.fc34.noarch @updates Upgraded firewalld-filesystem-0.9.3-3.fc34.noarch @@System Upgrade gdisk-1.0.8-1.fc34.x86_64 @updates Upgraded gdisk-1.0.7-1.fc34.x86_64 @@System Upgrade gobject-introspection-1.68.0-4.fc34.x86_64 @updates Upgraded gobject-introspection-1.68.0-3.fc34.x86_64 @@System Upgrade ibus-typing-booster-2.11.5-1.fc34.noarch @updates Upgraded ibus-typing-booster-2.11.4-1.fc34.noarch @@System Upgrade iio-sensor-proxy-3.1-1.fc34.x86_64 @updates Upgraded iio-sensor-proxy-3.0-3.fc34.x86_64 @@System Upgrade kernel-headers-5.12.13-300.fc34.x86_64 @updates Upgraded kernel-headers-5.12.9-300.fc34.x86_64 @@System Upgrade libgcrypt-1.9.3-3.fc34.x86_64 @updates Upgraded libgcrypt-1.9.3-2.fc34.x86_64 @@System Upgrade libipa_hbac-2.5.1-2.fc34.x86_64 @updates Upgraded libipa_hbac-2.5.1-1.fc34.x86_64 @@System Upgrade libsss_autofs-2.5.1-2.fc34.x86_64 @updates Upgraded libsss_autofs-2.5.1-1.fc34.x86_64 @@System Upgrade libsss_certmap-2.5.1-2.fc34.x86_64 @updates Upgraded libsss_certmap-2.5.1-1.fc34.x86_64 @@System Upgrade libsss_idmap-2.5.1-2.fc34.x86_64 @updates Upgraded libsss_idmap-2.5.1-1.fc34.x86_64 @@System Upgrade libsss_nss_idmap-2.5.1-2.fc34.x86_64 @updates Upgraded libsss_nss_idmap-2.5.1-1.fc34.x86_64 @@System Upgrade libsss_sudo-2.5.1-2.fc34.x86_64 @updates Upgraded libsss_sudo-2.5.1-1.fc34.x86_64 @@System Upgrade libtpms-0.8.4-1.20210624gita594c4692a.fc34.1.x86_64 @updates Upgraded libtpms-0.8.3-0.20210601git9e736d5281.fc34.1.x86_64 @@System Upgrade libuser-0.63-4.fc34.x86_64 @updates Upgraded libuser-0.63-3.fc34.x86_64 @@System Upgrade libxcrypt-4.4.23-1.fc34.x86_64 @updates Upgraded libxcrypt-4.4.22-2.fc34.x86_64 @@System Upgrade libxcrypt-compat-4.4.23-1.fc34.x86_64 @updates Upgraded libxcrypt-compat-4.4.22-2.fc34.x86_64 @@System Upgrade libxcrypt-devel-4.4.23-1.fc34.x86_64 @updates Upgraded libxcrypt-devel-4.4.22-2.fc34.x86_64 @@System Upgrade openldap-2.4.57-5.fc34.x86_64 @updates Upgraded openldap-2.4.57-4.fc34.x86_64 @@System Upgrade perl-Module-CoreList-1:5.20210620-1.fc34.noarch @updates Upgraded perl-Module-CoreList-1:5.20210521-1.fc34.noarch @@System Upgrade perl-Module-CoreList-tools-1:5.20210620-1.fc34.noarch @updates Upgraded perl-Module-CoreList-tools-1:5.20210521-1.fc34.noarch @@System Upgrade pipewire-0.3.31-2.fc34.x86_64 @updates Upgraded pipewire-0.3.30-4.fc34.x86_64 @@System Upgrade pipewire-alsa-0.3.31-2.fc34.x86_64 @updates Upgraded pipewire-alsa-0.3.30-4.fc34.x86_64 @@System Upgrade pipewire-gstreamer-0.3.31-2.fc34.x86_64 @updates Upgraded pipewire-gstreamer-0.3.30-4.fc34.x86_64 @@System Upgrade pipewire-jack-audio-connection-kit-0.3.31-2.fc34.x86_64 @updates Upgraded pipewire-jack-audio-connection-kit-0.3.30-4.fc34.x86_64 @@System Upgrade pipewire-libs-0.3.31-2.fc34.x86_64 @updates Upgraded pipewire-libs-0.3.30-4.fc34.x86_64 @@System Upgrade pipewire-pulseaudio-0.3.31-2.fc34.x86_64 @updates Upgraded pipewire-pulseaudio-0.3.30-4.fc34.x86_64 @@System Upgrade pipewire-utils-0.3.31-2.fc34.x86_64 @updates Upgraded pipewire-utils-0.3.30-4.fc34.x86_64 @@System Upgrade python-setuptools-wheel-53.0.0-2.fc34.noarch @updates Upgraded python-setuptools-wheel-53.0.0-1.fc34.noarch @@System Upgrade python3-click-help-colors-0.9-1.fc34.noarch @updates Upgraded python3-click-help-colors-0.8-4.fc34.noarch @@System Upgrade python3-firewall-0.9.4-1.fc34.noarch @updates Upgraded python3-firewall-0.9.3-3.fc34.noarch @@System Upgrade python3-google-auth-1:1.32.0-1.fc34.noarch @updates Upgraded python3-google-auth-1:1.30.2-1.fc34.noarch @@System Upgrade python3-setuptools-53.0.0-2.fc34.noarch @updates Upgraded python3-setuptools-53.0.0-1.fc34.noarch @@System Upgrade selinux-policy-34.12-1.fc34.noarch @updates Upgraded selinux-policy-34.11-1.fc34.noarch @@System Upgrade selinux-policy-minimum-34.12-1.fc34.noarch @updates Upgraded selinux-policy-minimum-34.11-1.fc34.noarch @@System Upgrade selinux-policy-targeted-34.12-1.fc34.noarch @updates Upgraded selinux-policy-targeted-34.11-1.fc34.noarch @@System Upgrade sssd-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-ad-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-ad-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-client-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-client-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-common-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-common-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-common-pac-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-common-pac-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-ipa-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-ipa-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-kcm-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-kcm-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-krb5-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-krb5-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-krb5-common-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-krb5-common-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-ldap-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-ldap-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-nfs-idmap-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-nfs-idmap-2.5.1-1.fc34.x86_64 @@System Upgrade sssd-proxy-2.5.1-2.fc34.x86_64 @updates Upgraded sssd-proxy-2.5.1-1.fc34.x86_64 @@System Upgrade vim-X11-2:8.2.3070-1.fc34.x86_64 @updates Upgraded vim-X11-2:8.2.3046-1.fc34.x86_64 @@System Upgrade vim-common-2:8.2.3070-1.fc34.x86_64 @updates Upgraded vim-common-2:8.2.3046-1.fc34.x86_64 @@System Upgrade vim-default-editor-2:8.2.3070-1.fc34.noarch @updates Upgraded vim-default-editor-2:8.2.3046-1.fc34.noarch @@System Upgrade vim-enhanced-2:8.2.3070-1.fc34.x86_64 @updates Upgraded vim-enhanced-2:8.2.3046-1.fc34.x86_64 @@System Upgrade vim-filesystem-2:8.2.3070-1.fc34.noarch @updates Upgraded vim-filesystem-2:8.2.3046-1.fc34.noarch @@System Upgrade vim-minimal-2:8.2.3070-1.fc34.x86_64 @updates Upgraded vim-minimal-2:8.2.3046-1.fc34.x86_64 @@System Upgrade google-chrome-beta-92.0.4515.80-1.x86_64 @google-chrome Upgraded google-chrome-beta-92.0.4515.70-1.x86_64 @@System Reason Change Box2D-2.4.1-5.fc34.x86_64 @fedora Removed kernel-5.12.10-300.fc34.x86_64 @@System Removed kernel-core-5.12.10-300.fc34.x86_64 @@System Removed kernel-debug-devel-5.12.10-300.fc34.x86_64 @@System Removed kernel-devel-5.12.10-300.fc34.x86_64 @@System Removed kernel-modules-5.12.10-300.fc34.x86_64 @@System Scriptlet output: 1 warning: /etc/cups/cups-browsed.conf created as /etc/cups/cups-browsed.conf.rpmnew 2 dkms: removing: v4l2loopback 0.12.5 (5.12.10-300.fc34.x86_64) (x86_64) 3 4 -------- Uninstall Beginning -------- 5 Module: v4l2loopback 6 Version: 0.12.5 7 Kernel: 5.12.10-300.fc34.x86_64 (x86_64) 8 ------------------------------------- 9 10 Status: Before uninstall, this module version was ACTIVE on this kernel. 11 12 v4l2loopback.ko.xz: 13 - Uninstallation 14 - Deleting from: /lib/modules/5.12.10-300.fc34.x86_64/extra/ 15 - Original module 16 - No original module was found for this module on this kernel. 17 - Use the dkms install command to reinstall any previous module version. 18 19 depmod.... 20 21 DKMS: uninstall completed. 22 warning: file /lib/modules/5.12.10-300.fc34.x86_64/updates: remove failed: No such file or directory 23 dkms: running auto installation service for kernel 5.12.13-300.fc34.x86_64 24 25 Kernel preparation unnecessary for this kernel. Skipping... 26 27 Building module: 28 cleaning build area.... 29 make -j8 KERNELRELEASE=5.12.13-300.fc34.x86_64 KERNEL_DIR=/lib/modules/5.12.13-300.fc34.x86_64/build all.... 30 cleaning build area.... 31 32 DKMS: build completed. 33 34 v4l2loopback.ko.xz: 35 Running module version sanity check. 36 - Original module 37 - No original module exists within this kernel 38 - Installation 39 - Installing to /lib/modules/5.12.13-300.fc34.x86_64/extra/ 40 41 depmod..... 42 43 DKMS: install completed. 44 Done. 45 dkms: running auto installation service for kernel 5.12.13-300.fc34.x86_64 46 Done. ``` Another colleague has a similar issue (Gnome/Workstation spin), but a colleague with the i3 spin doesn't have the issue. Both also have Fedora 34.
I digged further into this since it was happening for me as well. I grepped and searched around for the string in my initramfs and found two files which contain this string, both binary and both related to lvm. I then downloaded the lvm source code used to built the lvm2 package (which is the binary that provides the lvm binary) based on the URLs here https://src.fedoraproject.org/rpms/lvm2/blob/rawhide/f/lvm2.spec. In this tar archive we find exactly one fail that contains the string: lib/notify/lvmnotify.c. Hence I would guess that this is where the error is originating from, however I do not consider myself by any means clever enough about lvm or dracut in order to really debug this further. One thing would be interesting though, since this is apparently tied to LVM which is afaik not used anymore with BRTFS: @elavarde do you and your colleague who have the issue both run LVM? And does the colleague with the i3 spin not run LVM? If the answer to both of these questions is yes I would guess that my digging is right and we'd at least know where the bug is coming from.
In my case it can be observed in a mixed environment using LVM and BTRFS. Some, hopefully useful, info below ``` $ systemd-analyze blame 2min 46.940s dracut-initqueue.service 2min 43.279s systemd-cryptsetup@luks\x2d94f5ffc7\x2d1bd7\x2d44d9\x2d9404\x2dec00fc3566ab.service 1min 16.329s systemd-cryptsetup@luks\x2d6af5e4a6\x2dac09\x2d4c30\x2da168\x2d4ba1683d2821.service 6.234s NetworkManager-wait-online.service 3.561s plymouth-quit-wait.service 3.191s systemd-cryptsetup@luks\x2d23027a8f\x2d0a4f\x2d4f1b\x2d8d83\x2d47a1d0c529e4.service 2.164s docker.service 1.488s systemd-udev-settle.service [...] $ cat /etc/fstab [...] /dev/mapper/luks-94f5ffc7-1bd7-44d9-9404-ec00fc3566ab / ext4 defaults,x-systemd.device-timeout=0 1 1 /dev/mapper/luks-23027a8f-0a4f-4f1b-8d83-47a1d0c529e4 /home btrfs defaults,x-systemd.device-timeout=0 1 2 /dev/mapper/luks-6af5e4a6-ac09-4c30-a168-4ba1683d2821 none swap pri=1,x-systemd.device-timeout=0 0 0 $ journalctl -u dracut-initqueue Jul 19 10:13:10 Matt-T490s systemd[1]: Starting dracut initqueue hook... Jul 19 10:13:10 Matt-T490s dracut-initqueue[600]: Scanning devices nvme0n1p3 for LVM logical volumes fedora_matt-lenovo/root Jul 19 10:13:10 Matt-T490s dracut-initqueue[600]: fedora_matt-lenovo/swap Jul 19 10:13:10 Matt-T490s dracut-initqueue[621]: inactive '/dev/fedora_matt-lenovo/root' [200.00 GiB] inherit Jul 19 10:13:10 Matt-T490s dracut-initqueue[621]: inactive '/dev/fedora_matt-lenovo/home' [500.00 GiB] inherit Jul 19 10:13:10 Matt-T490s dracut-initqueue[621]: inactive '/dev/fedora_matt-lenovo/swap' [16.00 GiB] inherit Jul 19 10:14:41 Matt-T490s dracut-initqueue[623]: WARNING: D-Bus notification failed: Transport endpoint is not connected Jul 19 10:15:57 Matt-T490s systemd[1]: Finished dracut initqueue hook. Jul 19 10:15:57 Matt-T490s systemd[1]: dracut-initqueue.service: Deactivated successfully. Jul 19 10:15:57 Matt-T490s systemd[1]: Stopped dracut initqueue hook. ```
I now edited the kernel command line (it works by pressing e while you are in the grub menu which drops you in an emacs ish editor, then going into the line where how to load linux is described), removing the quiet and rhgb flag and adding the rd.debug flag (which according to documentation is equivalent to letting dracut's scripts run with set -x). Then I just let the kernel boot and get a ton more output. Afterwards you can checkout journalctl -u dracut-initqueue again and search for the jump in time before the warning is printed which in my case looks like this: ``` ligurien dracut-initqueue[528]: + '[' -n '' ']' ligurien dracut-initqueue[507]: + for LV in $LVS ligurien dracut-initqueue[529]: + lvm lvchange --yes -K -ay --ignorelockingfailure --ignoremonitoring --poll n fedora_localhost-live/root ligurien dracut-initqueue[530]: + vinfo ligurien dracut-initqueue[530]: + read -r line ligurien dracut-initqueue[530]: + info 'WARNING: D-Bus notification failed: Transport endpoint is not connected' ligurien dracut-initqueue[530]: + echo 'WARNING: D-Bus notification failed: Transport endpoint is not connected' ligurien dracut-initqueue[530]: + read -r line ligurien dracut-initqueue[530]: WARNING: D-Bus notification failed: Transport endpoint is not connected ligurien dracut-initqueue[530]: + '[' -n '' ']' ``` so it appears that lvm lvchange --yes -K -ay --ignorelockingfailure --ignoremonitoring --poll n fedora_localhost-live/root is at fault for this? Can anyone reproduce this?
Since lvm's dbus notification system seems to be at fault her I just went into /etc/lvm/lvm.conf, set notify_dbus=0 (default is 1), rebuilt my initramfs with sudo dracut -f and that seemed to fix it. Meaning that my system did both boot without the huge overhead on dracut-initqueue and doesn't seem to be broken from this config change. Again I'm not close to knowledgible enough about dracut or lvm2 to know whether I'm potentially doing something bad but at least as a workaround this seems to be fine. Would be very nice if someone who actually knows their way around these tools could verify whether this is fine.
Marking as a duplicate of bug 1976653, which has an associated fix in updates-testing. https://bodhi.fedoraproject.org/updates/FEDORA-2021-7b6767f8af *** This bug has been marked as a duplicate of bug 1976653 ***