Bug 1981292

Summary: Boot is frozen for more than a minute, dracut wants to use D-Bus which is not started yet
Product: [Fedora] Fedora Reporter: Ilya Maximets <i.maximets>
Component: dracutAssignee: dracut-maint-list
Status: CLOSED DUPLICATE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 34CC: dracut-maint-list, jonathan, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2021-07-12 11:08:17 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:

Description Ilya Maximets 2021-07-12 09:52:12 UTC
Description of problem:

After upgrade f32->f34 system boot hangs for more than a minute in
the same place every time.

System log looks like this:

Jul 11 22:07:07 im-t490s dracut-initqueue[839]: Scanning devices dm-0  for LVM logical volumes fedora/root
Jul 11 22:07:07 im-t490s dracut-initqueue[839]: fedora/swap
Jul 11 22:07:07 im-t490s dracut-initqueue[860]: inactive          '/dev/fedora/swap' [15.64 GiB] inherit
Jul 11 22:07:07 im-t490s dracut-initqueue[860]: inactive          '/dev/fedora/home' [151.24 GiB] inherit
Jul 11 22:07:07 im-t490s dracut-initqueue[860]: inactive          '/dev/fedora/root' [<69.99 GiB] inherit
Jul 11 22:07:07 im-t490s systemd[1]: Found device /dev/mapper/fedora-root.
Jul 11 22:07:07 im-t490s systemd[1]: Reached target Initrd Root Device.
Jul 11 22:08:37 im-t490s dracut-initqueue[862]: WARNING: D-Bus notification failed: Transport endpoint is not connected
Jul 11 22:08:37 im-t490s systemd[1]: Found device /dev/mapper/fedora-swap.
Jul 11 22:08:37 im-t490s systemd[1]: Starting Resume from hibernation using device /dev/mapper/fedora-swap...
Jul 11 22:08:37 im-t490s systemd-hibernate-resume[878]: Could not resume from '/dev/mapper/fedora-swap' (253:2).
Jul 11 22:08:37 im-t490s systemd[1]: systemd-hibernate-resume@dev-mapper-fedora\x2dswap.service: Deactivated successfully.
Jul 11 22:08:37 im-t490s systemd[1]: Finished Resume from hibernation using device /dev/mapper/fedora-swap.
Jul 11 22:08:37 im-t490s audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-hibernate-resume@dev-mapper-fedora\x2dswap comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 11 22:08:37 im-t490s audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-hibernate-resume@dev-mapper-fedora\x2dswap comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 11 22:08:37 im-t490s systemd[1]: Reached target Local File Systems (Pre).
Jul 11 22:08:37 im-t490s systemd[1]: Reached target Local File Systems.
Jul 11 22:08:37 im-t490s systemd[1]: Reached target System Initialization.
Jul 11 22:08:37 im-t490s kernel: PM: Image not found (code -22)
Jul 11 22:08:37 im-t490s kernel: audit: type=1130 audit(1626034117.777:31): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-hibernate-resume@dev-mapper-fedora\x2dswap comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? re>
Jul 11 22:08:37 im-t490s kernel: audit: type=1131 audit(1626034117.777:32): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-hibernate-resume@dev-mapper-fedora\x2dswap comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? re>
Jul 11 22:08:37 im-t490s audit: BPF prog-id=15 op=LOAD
Jul 11 22:08:37 im-t490s kernel: audit: type=1334 audit(1626034117.779:33): prog-id=15 op=LOAD
Jul 11 22:08:37 im-t490s systemd[1]: Starting D-Bus System Message Bus...
Jul 11 22:08:37 im-t490s systemd[1]: Started D-Bus System Message Bus.
Jul 11 22:08:37 im-t490s audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=dbus-broker comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jul 11 22:08:37 im-t490s systemd[1]: Reached target Basic System.


In this case 1 minute and 30 seconds passed between following two messages:

Jul 11 22:07:07 im-t490s systemd[1]: Reached target Initrd Root Device.
Jul 11 22:08:37 im-t490s dracut-initqueue[862]: WARNING: D-Bus notification failed: Transport endpoint is not connected

The second message also suggests that dracut tried to use D-Bus,
but D-Bus will be started only after that down the log.

Version-Release number of selected component (if applicable):
dracut-055-3.fc34.x86_64

How reproducible:
Always

Steps to Reproduce:
1. Reboot

Actual results:
Boot takes a lot of time, because system is waiting and doing nothing
for more than a minute.

Expected results:
Boot works fine and fast.

Additional info:
ThinkPad T490s
Fedora34 KDE x11
Linux 5.12.14-300.fc34.x86_64

Comment 1 Ilya Maximets 2021-07-12 11:08:17 UTC

*** This bug has been marked as a duplicate of bug 1976653 ***